[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

[Xen-devel] Debian stable kernel got timer issue when running as PV guest



(Sorry for duplicate mail, got a typo in the mailing list address...)

Hi,

Recently we got some reports of Debian(2.6.32-41 package) migration hang on some certain machines. I've identified one issue in Xen, but I think there is probably another issue in the kernel.

Here is the case.

[    0.000000] Booting paravirtualized kernel on Xen                                                                                                                                                                                               
[    0.000000] Xen version: 3.4.2 (preserve-AD)                                                                                                                                                                                                    
[    0.000000] NR_CPUS:32 nr_cpumask_bits:32 nr_cpu_ids:1 nr_node_ids:1                                                                                                                                                                            
[    0.000000] PERCPU: Embedded 15 pages/cpu @c1608000 s37656 r0 d23784 u65536                                                                                                                                                                     
[    0.000000] pcpu-alloc: s37656 r0 d23784 u65536 alloc=16*4096                                                                                                                                                                                   
[    0.000000] pcpu-alloc: [0] 0                                                                                                                                                                                                                   
[508119.807590] trying to map vcpu_info 0 at c1609010, mfn 992cac, offset 16                                                                                                                                                                       
[508119.807593] cpu 0 using vcpu_info at c1609010                                                                                                                                                                                                  
[508119.807594] Xen: using vcpu_info placement                                                                                                                                                                                                     
[508119.807598] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 32416   

Dmesg show that when booting, timestamp of printk jumped from 0 to a big number([508119.807590] in this case) immediately. 

And when migrating:

[509508.914333] suspending xenstore...                                                                                                                                                                                                             
[516212.055921] trying to map vcpu_info 0 at c1609010, mfn 895fd7, offset 16                                                                                                                                                                       
[516212.055930] cpu 0 using vcpu_info at c1609010

Timestamp jumped again. We can reproduce above issues on our Sandy Bridge machines.

After this, call trace and guest hang maybe observed on some machines:

[516383.019499] INFO: task xenwatch:12 blocked for more than 120 seconds.                                                                                                                                                                          
[516383.019566] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.                                                                                                                                                          
[516383.019578] xenwatch      D c1610e20     0    12      2 0x00000000                                                                                                                                                                             
[516383.019591]  c781eec0 00000246 c1610e58 c1610e20 c781f300 c1441e20 c1441e20 001cf000                                                                                                                                                           
[516383.019605]  c781f07c c1610e20 00000000 00000001 c1441e20 c62e01c0 c1610e20 c62e01c0                                                                                                                                                           
[516383.019617]  c127e18e c781f07c c7830020 c7830020 c1441e20 c1441e20 c127f2f1 c781f080                                                                                                                                                           
[516383.019629] Call Trace:                                                                                                                                                                                                                        
[516383.019640]  [<c127e18e>] ? schedule+0x78f/0x7dc                                                                                                                                                                                               
[516383.019645]  [<c127f2f1>] ? _spin_unlock_irqrestore+0xd/0xf                                                                                                                                                                                    
[516383.019649]  [<c127e4a1>] ? schedule_timeout+0x20/0xb0                                                                                                                                                                                         
[516383.019656]  [<c100573c>] ? xen_force_evtchn_callback+0xc/0x10                                                                                                                                                                                 
[516383.019660]  [<c127e3aa>] ? wait_for_common+0xa4/0x100                                                                                                                                                                                         
[516383.019665]  [<c1033315>] ? default_wake_function+0x0/0x8                                                                                                                                                                                      
[516383.019671]  [<c104a144>] ? kthread_stop+0x4f/0x8e                                                                                                                                                                                             
[516383.019675]  [<c1047883>] ? cleanup_workqueue_thread+0x3a/0x45                                                                                                                                                                                 
[516383.019679]  [<c1047903>] ? destroy_workqueue+0x56/0x85                                                                                                                                                                                        
[516383.019684]  [<c106a395>] ? stop_machine_destroy+0x23/0x37                                                                                                                                                                                     
[516383.019690]  [<c11962d8>] ? shutdown_handler+0x200/0x22f                                                                                                                                                                                       
[516383.019694]  [<c1197439>] ? xenwatch_thread+0xdc/0x103                                                                                                                                                                                         
[516383.019698]  [<c104a322>] ? autoremove_wake_function+0x0/0x2d                                                                                                                                                                                  
[516383.019701]  [<c119735d>] ? xenwatch_thread+0x0/0x103                                                                                                                                                                                          
[516383.019705]  [<c104a0f0>] ? kthread+0x61/0x66                                                                                                                                                                                                  
[516383.019709]  [<c104a08f>] ? kthread+0x0/0x66                                                                                                                                                                                                   
[516383.019714]  [<c1008d87>] ? kernel_thread_helper+0x7/0x10  

But I cannot reproduce it call trace and hang on our Sandy Bridge.

I've spent some time to identify the timestamp jump issue, and finally found it's due to Invarient TSC (CPUID Leaf 0x80000007 EDX:8, also called non-stop TSC). The present of the feature would enable a parameter in the kernel named: sched_clock_stable. Seems this parameter is unable to work with Xen's pvclock. If sched_clock_stable() is set, value returned by xen_clocksource_read() would be returned as sched_clock_cpu() directly, but CMIIW the value returned by xen_clocksource_read() is based on host(vcpu) uptime rather than this VM's uptime, then result in the timestamp jump.

I've compiled a kernel, force sched_clock_stable=0, then it solved the timestamp jump issue as expected. Luckily, seems it also solved the call trace and guest hang issue as well.

Attachment is a (untested) patch to mask the CPUID leaf 0x80000007. I think the issue can be easily reproduced using a Westmere or SandyBridge machine(my old colleagues at Intel said the feature likely existed after Nehalem) running newer version of PV guest, check the guest cpuinfo you would see nonstop_tsc, and you would notice the abnormal timestamp of printk.

Sorry I don't have a Xen unstable environment by hand now. But I think this should be the case we saw.

BTW: the original environment is xen-3.4.2, but I found the feature remain unmasked by latest xen-unstable tree.

--
regards
Yang, Sheng




--
--
regards
Yang, Sheng

Attachment: 0001-libxc-disable-invarient-TSC-for-PV-guest.patch
Description: Binary data

_______________________________________________
Xen-devel mailing list
Xen-devel@xxxxxxxxxxxxx
http://lists.xen.org/xen-devel

 


Rackspace

Lists.xenproject.org is hosted with RackSpace, monitoring our
servers 24x7x365 and backed by RackSpace's Fanatical Support®.