Messages in this thread | | | Date | Wed, 14 May 2008 15:30:33 +0300 | From | Avi Kivity <> | Subject | Re: [BUG] cpu hotplug vs scheduler |
| |
Dmitry Adamushko wrote: > Hi, > > >> [ ... ] >> >> [4298303.713901] Call Trace: >> [4298303.713901] [<ffffffff804373fe>] schedule+0x414/0x6ab >> [4298303.713901] [<ffffffff8023060a>] ? hrtick_set+0x9d/0xe8 >> [4298303.713901] [<ffffffff8043772f>] ? thread_return+0x9a/0xbf >> [4298303.713901] [<ffffffff80231652>] migration_thread+0x185/0x22d >> [4298303.713901] [<ffffffff802314cd>] ? migration_thread+0x0/0x22d >> [4298303.713901] [<ffffffff8024afe6>] kthread+0x49/0x77 >> [4298303.713901] [<ffffffff8020d228>] child_rip+0xa/0x12 >> [4298303.713901] [<ffffffff8024af9d>] ? kthread+0x0/0x77 >> [4298303.713901] [<ffffffff8020d21e>] ? child_rip+0x0/0x12 >> [4298303.713901] >> [4298303.713901] >> [4298303.713901] Code: c0 74 28 48 8b 7b 58 4c 8d 60 f0 48 85 ff 74 10 4c >> 89 e6 e8 df cc ff ff 85 c0 75 04 4c 8b 63 58 4c 89 e6 48 89 df e8 4a e5 ff >> ff <49> 8b 9c 24 58 01 00 00 48 85 db 75 bf 49 83 ec 38 4c 89 ef 4c >> [4298303.713901] RIP [<ffffffff8022e722>] pick_next_task_fair+0x55/0x7c >> >> This seems to be the assignment to cfs_rq after pick_next_entity(). >> > > [ cc'ed a few folks. ] > > > So the cfs-tree likely gets out-of-sync. I pressume, it won't be > reproducible with CONFIG_SCHED_GROUP options being disabled. > > Anyway, would you try one of these debug-patches (not sure about the > workability of the second one though :-/) > > Let's check what are the values for 'cfs_rq->weight.load/nr_running'. > >
Got this for the first patch:
[4302727.615522] Booting processor 3/7 ip 6000 [4302727.625923] Initializing CPU#3 [4302727.625923] Calibrating delay using timer specific routine.. 5319.76 BogoMIPS (lpj=2659883) [4302727.625923] CPU: L1 I cache: 32K, L1 D cache: 32K [4302727.625923] CPU: L2 cache: 4096K [4302727.625923] CPU: Physical Processor ID: 3 [4302727.625923] CPU: Processor Core ID: 1 [4302727.625923] x86 PAT enabled: cpu 3, old 0x7040600070406, new 0x7010600070106 [4302727.692484] CPU3: Intel(R) Xeon(R) CPU 5150 @ 2.66GHz stepping 06 [4302727.694236] checking TSC synchronization [CPU#1 -> CPU#3]: passed. [4302727.824185] Switched to high resolution mode on CPU 3 [4302727.859184] kvm: enabling virtualization on CPU3 [4302727.859714] Sched Debug Version: v0.07, 2.6.26-rc2 #726 [4302727.859714] now at 6918576.148656 msecs [4302727.859714] .sysctl_sched_latency : 60.000000 [4302727.859714] .sysctl_sched_min_granularity : 12.000000 [4302727.859714] .sysctl_sched_wakeup_granularity : 30.000000 [4302727.859714] .sysctl_sched_child_runs_first : 0.000001 [4302727.860191] .sysctl_sched_features : 895 [4302727.860191] [4302727.860191] cpu#0, 2659.999 MHz [4302727.860191] .nr_running : 2 [4302727.860191] .load : 841 [4302727.860191] .nr_switches : 3427530 [4302727.861205] .nr_load_updates : 2183358 [4302727.861205] .nr_uninterruptible : 15 [4302727.861205] .jiffies : 4301585875 [4302727.861205] .next_balance : 4301.585696 [4302727.861205] .curr->pid : 4678 [4302727.861205] .clock : 6918579.002757 [4302727.862216] .cpu_load[0] : 841 [4302727.862216] .cpu_load[1] : 841 [4302727.862216] .cpu_load[2] : 841 [4302727.862216] .cpu_load[3] : 841 [4302727.862216] .cpu_load[4] : 841 [4302727.862216] [4302727.862216] cfs_rq[0]: [4302727.867209] .exec_clock : 3970.569663 [4302727.867209] .MIN_vruntime : 0.000001 [4302727.867209] .min_vruntime : 5178969.408050 [4302727.867209] .max_vruntime : 0.000001 [4302727.867209] .spread : 0.000000 [4302727.867209] .spread0 : 0.000000 [4302727.867209] .nr_running : 0 [4302727.867209] .load : 0 [4302727.867209] .bkl_count : 513 [4302727.867209] .nr_spread_over : 6 [4302727.867209] .shares : 1024 [4302727.867209] [4302727.867209] cfs_rq[0]: [4302727.867209] .exec_clock : 14.588517 [4302727.867209] .MIN_vruntime : 0.000001 [4302727.867209] .min_vruntime : 5178971.405628 [4302727.867209] .max_vruntime : 0.000001 [4302727.867209] .spread : 0.000000 [4302727.867209] .spread0 : 0.000000 [4302727.867209] .nr_running : 0 [4302727.867209] .load : 0 [4302727.867209] .bkl_count : 513 [4302727.867209] .nr_spread_over : 0 [4302727.867209] .shares : 1024 [4302727.867209] [4302727.867209] cfs_rq[0]: [4302727.867209] .exec_clock : 41.615870 [4302727.867209] .MIN_vruntime : 0.000001 [4302727.867209] .min_vruntime : 5178973.403544 [4302727.867209] .max_vruntime : 0.000001 [4302727.867209] .spread : 0.000000 [4302727.867209] .spread0 : 0.000000 [4302727.867209] .nr_running : 0 [4302727.867209] .load : 0 [4302727.867209] .bkl_count : 513 [4302727.867209] .nr_spread_over : 2 [4302727.867209] .shares : 1024 [4302727.867209] [4302727.867209] cfs_rq[0]: [4302727.867209] .exec_clock : 0.000000 [4302727.867209] .MIN_vruntime : 0.000001 [4302727.867209] .min_vruntime : 5178975.401320 [4302727.867209] .max_vruntime : 0.000001 [4302727.867209] .spread : 0.000000 [4302727.867209] .spread0 : 0.000000 [4302727.867209] .nr_running : 0 [4302727.867209] .load : 0 [4302727.867209] .bkl_count : 513 [4302727.867209] .nr_spread_over : 0 [4302727.867209] .shares : 0 [4302727.867209] [4302727.867209] cfs_rq[0]: [4302727.867209] .exec_clock : 0.000001 [4302727.867209] .MIN_vruntime : 0.000001 [4302727.867209] .min_vruntime : 5178977.398314 [4302727.867209] .max_vruntime : 0.000001 [4302727.867209] .spread : 0.000000 [4302727.867209] .spread0 : 0.000000 [4302727.867209] .nr_running : 0 [4302727.867209] .load : 0 [4302727.867209] .bkl_count : 513 [4302727.867209] .nr_spread_over : 0 [4302727.867209] .shares : 0 [4302727.867209] [4302727.867209] cfs_rq[0]: [4302727.867209] .exec_clock : 2165242.484786 [4302727.867209] .MIN_vruntime : 10323214.742376 [4302727.867209] .min_vruntime : 5178979.396488 [4302727.867209] .max_vruntime : 10323214.742376 [4302727.867209] .spread : 0.000000 [4302727.867209] .spread0 : 0.000000 [4302727.867209] .nr_running : 2 [4302727.867209] .load : 2048 [4302727.867209] .bkl_count : 513 [4302727.867209] .nr_spread_over : 1789825 [4302727.867209] .shares : 843 [4302727.867209] [4302727.867209] runnable tasks: [4302727.867209] task PID tree-key switches prio exec-runtime sum-exec sum-sleep [4302727.867209] ---------------------------------------------------------------------------------------------------------- [4302727.867209] Rqemu-system-x86 4678 10323337.578253 553310 120 10323337.578255 1380505.796830 42439.250368 [4302727.867209] [4302727.867209] cpu#1, 2659.999 MHz [4302727.867209] .nr_running : 3 [4302727.867209] .load : 415 [4302727.867209] .nr_switches : 629498 [4302727.867209] .nr_load_updates : 838874 [4302727.867209] .nr_uninterruptible : -6 [4302727.867209] .jiffies : 4301585895 [4302727.867209] .next_balance : 4301.585634 [4302727.867209] .curr->pid : 7799 [4302727.867209] .clock : 6918576.130865 [4302727.867209] .cpu_load[0] : 415 [4302727.867209] .cpu_load[1] : 415 [4302727.867209] .cpu_load[2] : 415 [4302727.867209] .cpu_load[3] : 415 [4302727.867209] .cpu_load[4] : 415 [4302727.867209] [4302727.867209] cfs_rq[1]: [4302727.867209] .exec_clock : 74.637431 [4302727.867209] .MIN_vruntime : 0.000001 [4302727.867209] .min_vruntime : 759396.868495 [4302727.867209] .max_vruntime : 0.000001 [4302727.867209] .spread : 0.000000 [4302727.867209] .spread0 : -4419588.520858 [4302727.867209] .nr_running : 0 [4302727.867209] .load : 0 [4302727.867209] .bkl_count : 299 [4302727.867209] .nr_spread_over : 1 [4302727.867209] .shares : 0 [4302727.867209] [4302727.867209] cfs_rq[1]: [4302727.867209] .exec_clock : 22.707771 [4302727.867209] .MIN_vruntime : 0.000001 [4302727.867209] .min_vruntime : 759396.868495 [4302727.867209] .max_vruntime : 0.000001 [4302727.867209] .spread : 0.000000 [4302727.867209] .spread0 : -4419590.518446 [4302727.867209] .nr_running : 0 [4302727.867209] .load : 0 [4302727.867209] .bkl_count : 299 [4302727.867209] .nr_spread_over : 1 [4302727.867209] .shares : 0 [4302727.867209] [4302727.867209] cfs_rq[1]: [4302727.867209] .exec_clock : 0.033026 [4302727.867209] .MIN_vruntime : 0.000001 [4302727.867209] .min_vruntime : 759396.868495 [4302727.867209] .max_vruntime : 0.000001 [4302727.867209] .spread : 0.000000 [4302727.867209] .spread0 : -4419590.518446 [4302727.867209] .nr_running : 0 [4302727.867209] .load : 0 [4302727.867209] .bkl_count : 299 [4302727.867209] .nr_spread_over : 0 [4302727.867209] .shares : 0 [4302727.867209] [4302727.867209] cfs_rq[1]: [4302727.867209] .exec_clock : 0.000000 [4302727.867209] .MIN_vruntime : 0.000001 [4302727.867209] .min_vruntime : 759396.868495 [4302727.867209] .max_vruntime : 0.000001 [4302727.867209] .spread : 0.000000 [4302727.867209] .spread0 : -4419590.518446 [4302727.867209] .nr_running : 0 [4302727.867209] .load : 0 [4302727.867209] .bkl_count : 299 [4302727.867209] .nr_spread_over : 0 [4302727.867209] .shares : 0 [4302727.867209] [4302727.867209] cfs_rq[1]: [4302727.867209] .exec_clock : 0.026450 [4302727.867209] .MIN_vruntime : 0.000001 [4302727.867209] .min_vruntime : 759396.868495 [4302727.867209] .max_vruntime : 0.000001 [4302727.867209] .spread : 0.000000 [4302727.867209] .spread0 : -4419590.518446 [4302727.867209] .nr_running : 0 [4302727.867209] .load : 0 [4302727.867209] .bkl_count : 299 [4302727.867209] .nr_spread_over : 0 [4302727.867209] .shares : 0 [4302727.867209] [4302727.867210] cfs_rq[1]: [4302727.867210] .exec_clock : 754981.092689 [4302727.867210] .MIN_vruntime : 1239813.449102 [4302727.867210] .min_vruntime : 759396.868495 [4302727.867210] .max_vruntime : 1239819.334711 [4302727.867210] .spread : 5.885609 [4302727.867210] .spread0 : -4419590.518446 [4302727.867210] .nr_running : 3 [4302727.867210] .load : 3072 [4302727.867210] .bkl_count : 299 [4302727.867210] .nr_spread_over : 53817 [4302727.867210] .shares : 415 [4302727.867210] [4302727.867210] runnable tasks: [4302727.867210] task PID tree-key switches prio exec-runtime sum-exec sum-sleep [4302727.867210] ---------------------------------------------------------------------------------------------------------- [4302727.900184] qemu-system-x86 4987 1239813.449102 709828 120 1239813.449102 1410504.949783 22865.206608 [4302727.900184] qemu-system-x86 5052 1239819.334711 530481 120 1239819.334711 1365146.519564 50937.064744 [4302727.900184] Rtoggle-processo 7799 1239811.208673 47886 120 1239811.208673 57552.631854 1592798.974913 [4302727.900184] [4302727.900184] cpu#3, 2659.999 MHz [4302727.900184] .nr_running : 1 [4302727.900184] .load : 285 [4302727.900184] .nr_switches : 611209 [4302727.900184] .nr_load_updates : 843051 [4302727.900184] .nr_uninterruptible : -2 [4302727.900184] .jiffies : 4301585916 [4302727.900184] .next_balance : 4301.586873 [4302727.900184] .curr->pid : 0 [4302727.900184] .clock : 6918576.376068 [4302727.900184] .cpu_load[0] : 0 [4302727.900184] .cpu_load[1] : 0 [4302727.900184] .cpu_load[2] : 0 [4302727.900184] .cpu_load[3] : 181 [4302727.900184] .cpu_load[4] : 1108 [4302727.900184] [4302727.900184] cfs_rq[3]: [4302727.900184] .exec_clock : 8.224765 [4302727.900184] BUG: spinlock recursion on CPU#3, swapper/0 [4302727.900184] lock: ffff81000103df00, .magic: dead4ead, .owner: swapper/0, .owner_cpu: 3 [4302727.900184] Pid: 0, comm: swapper Not tainted 2.6.26-rc2 #726 [4302727.900184] [4302727.900184] Call Trace: [4302727.900184] [<ffffffff803249de>] spin_bug+0x9e/0xe9 [4302727.900184] [<ffffffff80324af4>] _raw_spin_lock+0x41/0x123 [4302727.900184] [<ffffffff80439638>] _spin_lock_irqsave+0x2f/0x37 [4302727.900184] [<ffffffff8022ef7c>] print_cfs_rq+0xca/0x46a [4302727.900184] [<ffffffff80231f97>] sched_debug_show+0x7a3/0xb8c [4302727.900184] [<ffffffff8023238d>] sysrq_sched_debug_show+0xd/0xf [4302727.900184] [<ffffffff802323ee>] pick_next_task_fair+0x5f/0x86 [4302727.900184] [<ffffffff804373f6>] schedule+0x3fc/0x6ab [4302727.900184] [<ffffffff8024e03f>] ? ktime_get_ts+0x49/0x4e [4302727.900184] [<ffffffff80253a28>] ? tick_nohz_stop_idle+0x2d/0x54 [4302727.900184] [<ffffffff8021283f>] ? mwait_idle+0x0/0x59 [4302727.900184] [<ffffffff8020ae37>] cpu_idle+0xc8/0xd7 [4302727.900184] [<ffffffff804332f1>] start_secondary+0x173/0x178 [4302727.900184]
-- error compiling committee.c: too many arguments to function
| |