[Xen-devel] [PATCH] update_vcpu_system_time work-around

[Ryan Harper <ryanh@xxxxxxxxxx>]

* Ryan Harper <ryanh@xxxxxxxxxx> [2006-04-21 14:03]:
> * Ryan Harper <ryanh@xxxxxxxxxx> [2006-04-20 17:47]:
> > 
> > ns_offset is calculated from get_nsec_offset().  I'm going to dig
> > a little further, but I wanted to get what I'm seeing out there.
> 
> static u64 get_nsec_offset(struct shadow_time_info *shadow)
> {
>    u64 now, delta;
>    rdtscll(now);
>    delta = now - shadow->tsc_timestamp;
>    return scale_delta(delta, shadow->tsc_to_nsec_mul, shadow->tsc_shift);
> }
> 
> For some currently unknown reason, now is < shadow->tsc_timestamp;  This
> results in a very large delta value, which is scaled up even larger.
> 
> The output from the multi-cpu clock info dump doesn't show anything
> bogus:
> 
> (XEN) Min = 68672793737292 ; Max = 68672793747633 ; Diff = 10341 (10 
> microseconds)
> (XEN) Min = 68899728719792 ; Max = 68899728727283 ; Diff = 7491 (7 
> microseconds)
> 
> Any thoughts on why the shadow copy of the tsc_timestamp would be > than
> the value returned from reading the tsc would be helpful.
> 
> Very likely this is related to the hardware, this is a 4-node x460
> 32-way.  I've not reproduced this on anything but multi-node setups.  

I've used this patch to work-around an issue that I don't have root
cause on, but hopefully should help shed some light on the real issue.
When I launch a domain with a cpus string which invokes
set_vcpu_affinity() calls, the result is that when the guest time is
updated, the wrong cpu's tsc is being used.  This leads to the guest
getting calculating a bogus delta value when the guest processor's tsc
is slower than the tsc of the processor xen grabs the shadow timestamp
from.  

Launching the following domain:

[root@x460-3 ~]# xm create /tmp/dom1.cfg -c -n
Using config file "/tmp/dom1.cfg".
(vm
    (name dom1)
    (memory 768)
    (ssidref 131074)
    (on_poweroff destroy)
    (on_reboot destroy)
    (on_crash destroy)
    (vcpus 2)
    (cpus '2,3')
    (image
        (linux
            (kernel /boot/vmlinuz-2.6.16-xenU-smp)
            (root '/dev/sda1 ro')
            (args 4)
        )
    )
    (device (vbd (uname phy:/dev/virt-blkdev-backend/dom1) (dev sda1) (mode w)))
    (device (vbd (uname phy:/dev/sdc1) (dev sda2) (mode r)))
    (device (vif))
)

[root@x460-3 ~]# xm vcpu-list 1
Name                              ID  VCPU  CPU  State  Time(s)  CPU Affinity
dom1                               1     0    2   -b-      13.6  2
dom1                               1     1    3   -b-       7.4  3


Here is some output I see on the multi-node box console where I was
encountering the bugus delta values:

(XEN) ACK! Comparing DOM1 VCPU0 's tsc_timestamp to CPU31 instead of CPU2, 
fixing...
(XEN) ACK! Comparing DOM1 VCPU0 's tsc_timestamp to CPU31 instead of CPU2, 
fixing...
(XEN) ACK! Comparing DOM1 VCPU0 's tsc_timestamp to CPU31 instead of CPU2, 
fixing...
(XEN) ACK! Comparing DOM1 VCPU0 's tsc_timestamp to CPU31 instead of CPU2, 
fixing...
(XEN) ACK! Comparing DOM1 VCPU1 's tsc_timestamp to CPU0 instead of CPU3, 
fixing...
(XEN) ACK! Comparing DOM1 VCPU1 's tsc_timestamp to CPU0 instead of CPU3, 
fixing...
(XEN) ACK! Comparing DOM1 VCPU0 's tsc_timestamp to CPU31 instead of CPU2, 
fixing...
(XEN) ACK! Updating DOM1 VCPU0 's tsc_timestamp from CPU31 instead of CPU2, 
fixing...
(XEN) ACK! Comparing DOM1 VCPU1 's tsc_timestamp to CPU0 instead of CPU3, 
fixing...
(XEN) ACK! Updating DOM1 VCPU1 's tsc_timestamp from CPU0 instead of CPU3, 
fixing...
(XEN) ACK! Comparing DOM1 VCPU0 's tsc_timestamp to CPU31 instead of CPU2, 
fixing...

This work-around is only masking the real issue.  I'm hoping someone
else can help me track down why update_vcpu_system_time() is being
called from the wrong CPU after pinning operations.

-- 
Ryan Harper
Software Engineer; Linux Technology Center
IBM Corp., Austin, Tx
(512) 838-9253   T/L: 678-9253
ryanh@xxxxxxxxxx


diffstat output:
 time.c |   19 +++++++++++++++++--
 1 files changed, 17 insertions(+), 2 deletions(-)

Signed-off-by: Ryan Harper <ryanh@xxxxxxxxxx>
---
diff -r 65894fff3649 xen/arch/x86/time.c
--- a/xen/arch/x86/time.c       Fri Apr 21 13:03:07 2006
+++ b/xen/arch/x86/time.c       Fri Apr 21 21:38:07 2006
@@ -672,10 +672,18 @@
 
 static inline void __update_vcpu_system_time(struct vcpu *v)
 {
+    unsigned int cpu = smp_processor_id();
     struct cpu_time       *t;
     struct vcpu_time_info *u;
 
-    t = &cpu_time[smp_processor_id()];
+    if ( v->processor != cpu ) {
+        printk("ACK! Updating DOM%d VCPU%d 's tsc_timestamp from "
+               "CPU%d instead of CPU%d, fixing...\n", 
+               v->domain->domain_id, v->vcpu_id, cpu, v->processor);
+        cpu = v->processor;
+    }
+
+    t = &cpu_time[cpu];
     u = &v->domain->shared_info->vcpu_info[v->vcpu_id].time;
 
     version_update_begin(&u->version);
@@ -690,8 +698,15 @@
 
 void update_vcpu_system_time(struct vcpu *v)
 {
+    unsigned int cpu = smp_processor_id();
+    if ( v->processor != cpu ) {
+        printk("ACK! Comparing DOM%d VCPU%d 's tsc_timestamp to "
+               "CPU%d instead of CPU%d, fixing...\n", 
+               v->domain->domain_id, v->vcpu_id, cpu, v->processor);
+        cpu = v->processor;
+    }
     if ( v->domain->shared_info->vcpu_info[v->vcpu_id].time.tsc_timestamp != 
-         cpu_time[smp_processor_id()].local_tsc_stamp )
+         cpu_time[cpu].local_tsc_stamp )
         __update_vcpu_system_time(v);
 }
 

_______________________________________________
Xen-devel mailing list
Xen-devel@xxxxxxxxxxxxxxxxxxx
http://lists.xensource.com/xen-devel