@@ -1411,6 +1411,10 @@ struct kvm_arch {
struct delayed_work kvmclock_update_work;
struct delayed_work kvmclock_sync_work;
+ u64 old_master_kernel_ns;
+ u64 old_master_cycle_now;
+ s64 old_kvmclock_offset;
+
struct kvm_xen_hvm_config xen_hvm_config;
/* reads protected by irq_srcu, writes by irq_lock */
@@ -2819,7 +2819,7 @@ static inline u64 vgettsc(struct pvclock_clock *clock, u64 *tsc_timestamp,
* As with get_kvmclock_base_ns(), this counts from boot time, at the
* frequency of CLOCK_MONOTONIC_RAW (hence adding gtos->offs_boot).
*/
-static int do_kvmclock_base(s64 *t, u64 *tsc_timestamp)
+int do_kvmclock_base(s64 *t, u64 *tsc_timestamp)
{
struct pvclock_gtod_data *gtod = &pvclock_gtod_data;
unsigned long seq;
@@ -2861,6 +2861,27 @@ static int do_monotonic(s64 *t, u64 *tsc_timestamp)
return mode;
}
+u64 mydebug_get_kvmclock_ns(u64 master_kernel_ns, u64 master_cycle_now, s64 kvmclock_offset, u64 tsc)
+{
+ struct pvclock_vcpu_time_info hv_clock;
+ u64 ret;
+
+ hv_clock.tsc_timestamp = master_cycle_now;
+ hv_clock.system_time = master_kernel_ns + kvmclock_offset;
+
+ /* both __this_cpu_read() and rdtsc() should be on the same cpu */
+ get_cpu();
+
+ kvm_get_time_scale(NSEC_PER_SEC, __this_cpu_read(cpu_tsc_khz) * 1000LL,
+ &hv_clock.tsc_shift,
+ &hv_clock.tsc_to_system_mul);
+ ret = __pvclock_read_cycles(&hv_clock, tsc);
+
+ put_cpu();
+
+ return ret;
+}
+
static int do_realtime(struct timespec64 *ts, u64 *tsc_timestamp)
{
struct pvclock_gtod_data *gtod = &pvclock_gtod_data;
@@ -2988,6 +3009,10 @@ static void pvclock_update_vm_gtod_copy(struct kvm *kvm)
host_tsc_clocksource = kvm_get_time_and_clockread(
&ka->master_kernel_ns,
&ka->master_cycle_now);
+ ka->old_master_kernel_ns = ka->master_kernel_ns;
+ ka->old_master_cycle_now = ka->master_cycle_now;
+ printk("MYDEBUG: old_master_kernel_ns = %llu, old_master_cycle_now = %llu\n",
+ ka->old_master_kernel_ns, ka->old_master_cycle_now);
ka->use_master_clock = host_tsc_clocksource && vcpus_matched
&& !ka->backwards_tsc_observed
@@ -6989,6 +7014,8 @@ static int kvm_vm_ioctl_set_clock(struct kvm *kvm, void __user *argp)
else
now_raw_ns = get_kvmclock_base_ns();
ka->kvmclock_offset = data.clock - now_raw_ns;
+ ka->old_kvmclock_offset = ka->kvmclock_offset;
+ printk("MYDEBUG: old_kvmclock_offset = %lld\n", ka->old_kvmclock_offset);
kvm_end_pvclock_update(kvm);
return 0;
}
new file mode 120000
@@ -0,0 +1 @@
+/home/mlin/build.upstream/b.sh
\ No newline at end of file
@@ -399,6 +399,7 @@ int __kvm_mmu_topup_memory_cache(struct kvm_mmu_memory_cache *mc, int capacity,
return mc->nobjs >= min ? 0 : -ENOMEM;
mc->objects[mc->nobjs++] = obj;
}
+
return 0;
}
@@ -998,6 +999,78 @@ static void kvm_destroy_vm_debugfs(struct kvm *kvm)
}
}
+extern int do_kvmclock_base(s64 *t, u64 *tsc_timestamp);
+extern u64 mydebug_get_kvmclock_ns(u64 master_kernel_ns, u64 master_cycle_now, s64 kvmclock_offset, u64 tsc);
+
+static ssize_t kvm_mydebug_pvclock_read(struct file *file, char __user *buf,
+ size_t len, loff_t *ppos)
+{
+ struct kvm *kvm = file->private_data;
+ struct kvm_arch *ka;
+ char buffer[256];
+ ssize_t ret, copied;
+ u64 new_master_kernel_ns;
+ u64 new_master_cycle_now;
+ u64 old_ns, new_ns;
+ u64 tsc;
+
+ if (!kvm) {
+ pr_err("file->private_data is NULL\n");
+ return -EINVAL;
+ }
+
+ ka = &kvm->arch;
+
+ do_kvmclock_base(&new_master_kernel_ns, &new_master_cycle_now);
+
+ tsc = rdtsc();
+
+ old_ns = mydebug_get_kvmclock_ns(ka->old_master_kernel_ns, ka->old_master_cycle_now, ka->old_kvmclock_offset, tsc);
+ new_ns = mydebug_get_kvmclock_ns(new_master_kernel_ns, new_master_cycle_now, ka->old_kvmclock_offset, tsc);
+
+ ret = snprintf(buffer, sizeof(buffer),
+ "old: master_kernel_ns: %llu\n"
+ "old: master_cycle_now: %llu\n"
+ "old: ns: %llu\n"
+ "new: master_kernel_ns: %llu\n"
+ "new: master_cycle_now: %llu\n"
+ "new: ns: %llu\n\n"
+ "tsc %llu\n"
+ "kvmclock_offset %lld\n"
+ "diff: ns: %lld\n",
+ ka->old_master_kernel_ns, ka->old_master_cycle_now, old_ns,
+ new_master_kernel_ns, new_master_cycle_now, new_ns,
+ tsc, ka->old_kvmclock_offset,
+ old_ns - new_ns
+ );
+
+ if (ret < 0)
+ return ret;
+
+ if ((size_t)ret > sizeof(buffer))
+ ret = sizeof(buffer);
+
+ if (*ppos >= ret)
+ return 0; /* EOF */
+
+ copied = min(len, (size_t)(ret - *ppos));
+
+ if (copy_to_user(buf, buffer + *ppos, copied)) {
+ pr_err("copy_to_user failed\n");
+ return -EFAULT;
+ }
+
+ *ppos += copied;
+
+ return copied;
+}
+
+static const struct file_operations kvm_pvclock_fops = {
+ .owner = THIS_MODULE,
+ .read = kvm_mydebug_pvclock_read,
+ .open = simple_open,
+};
+
static int kvm_create_vm_debugfs(struct kvm *kvm, const char *fdname)
{
static DEFINE_MUTEX(kvm_debugfs_lock);
@@ -1063,6 +1136,8 @@ static int kvm_create_vm_debugfs(struct kvm *kvm, const char *fdname)
&stat_fops_per_vm);
}
+ debugfs_create_file("pvclock", 0444, kvm->debugfs_dentry, kvm, &kvm_pvclock_fops);
+
kvm_arch_create_vm_debugfs(kvm);
return 0;
out_err:
Hi, After performing a live migration on a QEMU guest OS that had been running for over 30 days, we noticed that the guest OS time was more than 2 seconds behind the actual time. After extensive debugging, we found that this issue is related to master_kernel_ns and master_cycle_now. When the guest OS starts, the host initializes a pair of master_kernel_ns and master_cycle_now values. After live migration, the host updates these values. Our debugging showed that if the host does not update master_kernel_ns/master_cycle_now, the guest OS time remains correct. To illustrate how updating master_kernel_ns/master_cycle_now leads to the guest OS time drifting backward, we applied the following debug patch: The patch adds a KVM debugfs entry to trigger time calculations and print the results. The patch runs on the host side, but we use __pvclock_read_cycles() to simulate the guest OS updating its time. Example Output: # cat /sys/kernel/debug/kvm/946-13/pvclock old: master_kernel_ns: 15119778316 old: master_cycle_now: 37225912658 old: ns: 1893199569691 new: master_kernel_ns: 1908210098649 new: master_cycle_now: 4391329912268 new: ns: 1893199548401 tsc 4391329912368 kvmclock_offset -15010550291 diff: ns: 21290 Explanation of Parameters: Input: "old: master_kernel_ns:" The master_kernel_ns value recorded when the guest OS started (remains unchanged during testing). "old: master_cycle_now:" The master_cycle_now value recorded when the guest OS started (remains unchanged during testing). "new: master_kernel_ns:" The latest master_kernel_ns value at the time of reading. "new: master_cycle_now:" The latest master_cycle_now value at the time of reading. tsc: The rdtsc() value at the time of reading. kvmclock_offset: The offset recorded by KVM_SET_CLOCK when the guest OS started (remains unchanged during testing). Output: "old: ns:" Time in nanoseconds calculated using the old master_kernel_ns/master_cycle_now. "new: ns:" Time in nanoseconds calculated using the new master_kernel_ns/master_cycle_now. "diff: ns:" (old ns - new ns), representing the time drift relative to the guest OS start time. Test Script: #!/bin/bash qemu_pid=$(pidof qemu-system-x86_64) while [ 1 ] ; do echo "=====================================" echo "Guest OS running time: $(ps -p $qemu_pid -o etime= | awk '{print $1}')" cat /sys/kernel/debug/kvm/*/pvclock echo sleep 10 done Test Results: Below are the first and last parts of a >2-hour test run. As time progresses, the time drift calculated using the latest master_kernel_ns/master_cycle_now increases monotonically. After 2 hours and 18 minutes, the guest OS time drifted by approximately 93 milliseconds. I have uploaded an image for a more intuitive visualization of the time drift: https://postimg.cc/crCDWtD7 Is this a real problem? If there is any fix patch, I’d be happy to test it. Thanks! 1 ===================================== 2 guest os running time: 00:50 3 old: master_kernel_ns: 15119778316 4 old: master_cycle_now: 37225912658 5 old: ns: 48092694964 6 new: master_kernel_ns: 63103244699 7 new: master_cycle_now: 147587790614 8 new: ns: 48092694425 9 10 tsc 147587790654 11 kvmclock_offset -15010550291 12 diff: ns: 539 13 14 ===================================== 15 guest os running time: 01:00 16 old: master_kernel_ns: 15119778316 17 old: master_cycle_now: 37225912658 18 old: ns: 58139026532 19 new: master_kernel_ns: 73149576143 20 new: master_cycle_now: 170694333104 21 new: ns: 58139025879 22 23 tsc 170694333168 24 kvmclock_offset -15010550291 25 diff: ns: 653 26 27 ===================================== 28 guest os running time: 01:10 29 old: master_kernel_ns: 15119778316 30 old: master_cycle_now: 37225912658 31 old: ns: 68183772122 32 new: master_kernel_ns: 83194321616 33 new: master_cycle_now: 193797227862 34 new: ns: 68183771357 35 36 tsc 193797227936 37 kvmclock_offset -15010550291 38 diff: ns: 765 39 40 ===================================== 41 guest os running time: 01:20 42 old: master_kernel_ns: 15119778316 43 old: master_cycle_now: 37225912658 44 old: ns: 78225289157 45 new: master_kernel_ns: 93235838545 46 new: master_cycle_now: 216892696976 47 new: ns: 78225288279 48 49 tsc 216892697034 50 kvmclock_offset -15010550291 51 diff: ns: 878 52 53 ===================================== 54 guest os running time: 01:30 55 old: master_kernel_ns: 15119778316 56 old: master_cycle_now: 37225912658 57 old: ns: 88268955340 58 new: master_kernel_ns: 103279504612 59 new: master_cycle_now: 239993109102 60 new: ns: 88268954349 61 62 tsc 239993109168 63 kvmclock_offset -15010550291 64 diff: ns: 991 65 66 ===================================== 67 guest os running time: 01:40 68 old: master_kernel_ns: 15119778316 69 old: master_cycle_now: 37225912658 70 old: ns: 98313212581 71 new: master_kernel_ns: 113323761740 72 new: master_cycle_now: 263094880668 73 new: ns: 98313211476 74 75 tsc 263094880732 76 kvmclock_offset -15010550291 77 diff: ns: 1105 ..... ..... 10160 ===================================== 10161 guest os running time: 02:17:11 10162 old: master_kernel_ns: 15119778316 10163 old: master_cycle_now: 37225912658 10164 old: ns: 8229817213297 10165 new: master_kernel_ns: 8244827670997 10166 new: master_cycle_now: 18965537819524 10167 new: ns: 8229817120748 10168 10169 tsc 18965537819622 10170 kvmclock_offset -15010550291 10171 diff: ns: 92549 10172 ===================================== 10173 guest os running time: 02:17:21 10174 old: master_kernel_ns: 15119778316 10175 old: master_cycle_now: 37225912658 10176 old: ns: 8239861074959 10177 new: master_kernel_ns: 8254871532564 10178 new: master_cycle_now: 18988638681302 10179 new: ns: 8239860982297 10180 10181 tsc 18988638681358 10182 kvmclock_offset -15010550291 10183 diff: ns: 92662 10184 ===================================== 10185 guest os running time: 02:17:31 10186 old: master_kernel_ns: 15119778316 10187 old: master_cycle_now: 37225912658 10188 old: ns: 8249904622988 10189 new: master_kernel_ns: 8264915080459 10190 new: master_cycle_now: 19011738821632 10191 new: ns: 8249904530213 10192 10193 tsc 19011738821736 10194 kvmclock_offset -15010550291 10195 diff: ns: 92775^@ 10196 ===================================== 10197 guest os running time: 02:17:41 10198 old: master_kernel_ns: 15119778316 10199 old: master_cycle_now: 37225912658 10200 old: ns: 8259949369203 10201 new: master_kernel_ns: 8274959826576 10202 new: master_cycle_now: 19034841717872 10203 new: ns: 8259949276315 10204 10205 tsc 19034841717942 10206 kvmclock_offset -15010550291 10207 diff: ns: 92888 10208 ===================================== 10209 guest os running time: 02:17:51 10210 old: master_kernel_ns: 15119778316 10211 old: master_cycle_now: 37225912658 10212 old: ns: 8269996849598 10213 new: master_kernel_ns: 8285007306846 10214 new: master_cycle_now: 19057950902658 10215 new: ns: 8269996756597 10216 10217 tsc 19057950902756 10218 kvmclock_offset -15010550291 10219 diff: ns: 93001^@ 10220 ===================================== 10221 guest os running time: 02:18:02 10222 old: master_kernel_ns: 15119778316 10223 old: master_cycle_now: 37225912658 10224 old: ns: 8280039094317 10225 new: master_kernel_ns: 8295049551453 10226 new: master_cycle_now: 19081048045430 10227 new: ns: 8280039001203 10228 10229 tsc 19081048045526 10230 kvmclock_offset -15010550291 10231 diff: ns: 93114^@ pvclock debugfs patch --- arch/x86/include/asm/kvm_host.h | 4 +++ arch/x86/kvm/x86.c | 29 +++++++++++++++- b.sh | 1 + virt/kvm/kvm_main.c | 75 +++++++++++++++++++++++++++++++++++++++++ 4 files changed, 108 insertions(+), 1 deletion(-)