linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* mm: hangs in collapse_huge_page
@ 2014-04-16  2:06 Sasha Levin
  2014-04-24 16:46 ` Sasha Levin
  2014-04-30 15:42 ` Kirill A. Shutemov
  0 siblings, 2 replies; 8+ messages in thread
From: Sasha Levin @ 2014-04-16  2:06 UTC (permalink / raw)
  To: linux-mm; +Cc: LKML, Dave Jones, Andrew Morton

Hi all,

I often see hung task triggering in khugepaged within collapse_huge_page().

I've initially assumed the case may be that the guests are too loaded and
the warning occurs because of load, but after increasing the timeout to
1200 sec I still see the warning.

Here's what I get in the log, up to the point the guest reboots:

[ 2406.651012] INFO: task khugepaged:3562 blocked for more than 1200 seconds.
[ 2406.653331]       Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2406.656549] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 2406.662008] khugepaged      D ffff88019fa1e4b8  5408  3562      2 0x00000000
[ 2406.663773]  ffff8803d6afbb08 0000000000000002 ffffffffb056e740 ffff8803d6b28000
[ 2406.666549]  ffff8803d6afbfd8 00000000001d79c0 00000000001d79c0 00000000001d79c0
[ 2406.669558]  ffff88019fac8000 ffff8803d6b28000 ffff8803d6afbaf8 ffff8803d6b28000
[ 2406.673316] Call Trace:
[ 2406.676062] ? _raw_spin_unlock_irq (arch/x86/include/asm/paravirt.h:819 include/linux/spinlock_api_smp.h:168 kernel/locking/spinlock.c:199)
[ 2406.678384] schedule (kernel/sched/core.c:2750)
[ 2406.680418] rwsem_down_write_failed (kernel/locking/rwsem-xadd.c:240)
[ 2406.683053] ? get_parent_ip (kernel/sched/core.c:2472)
[ 2406.684950] call_rwsem_down_write_failed (arch/x86/lib/rwsem.S:106)
[ 2406.686998] ? khugepaged_do_scan (arch/x86/include/asm/atomic.h:26 mm/huge_memory.c:1989 mm/huge_memory.c:2591 mm/huge_memory.c:2709)
[ 2406.689314] ? lock_contended (kernel/locking/lockdep.c:3734 kernel/locking/lockdep.c:3812)
[ 2406.691611] ? down_write (kernel/locking/rwsem.c:50 (discriminator 2))
[ 2406.693657] ? collapse_huge_page.isra.30 (arch/x86/include/asm/atomic.h:26 mm/huge_memory.c:1989 mm/huge_memory.c:2378)
[ 2406.696508] collapse_huge_page.isra.30 (arch/x86/include/asm/atomic.h:26 mm/huge_memory.c:1989 mm/huge_memory.c:2378)
[ 2406.699123] ? debug_smp_processor_id (lib/smp_processor_id.c:57)
[ 2406.701570] ? put_lock_stats.isra.12 (arch/x86/include/asm/preempt.h:98 kernel/locking/lockdep.c:254)
[ 2406.704058] ? khugepaged_do_scan (include/linux/spinlock.h:343 mm/huge_memory.c:2533 mm/huge_memory.c:2629 mm/huge_memory.c:2709)
[ 2406.706517] ? get_parent_ip (kernel/sched/core.c:2472)
[ 2406.708746] khugepaged_do_scan (mm/huge_memory.c:2633 mm/huge_memory.c:2709)
[ 2406.711252] khugepaged (include/linux/freezer.h:64 mm/huge_memory.c:2722 mm/huge_memory.c:2747)
[ 2406.713333] ? bit_waitqueue (kernel/sched/wait.c:291)
[ 2406.715703] ? khugepaged_do_scan (mm/huge_memory.c:2739)
[ 2406.718031] kthread (kernel/kthread.c:210)
[ 2406.720004] ? kthread_create_on_node (kernel/kthread.c:176)
[ 2406.722590] ret_from_fork (arch/x86/kernel/entry_64.S:555)
[ 2406.724780] ? kthread_create_on_node (kernel/kthread.c:176)
[ 2406.727349] 1 lock held by khugepaged/3562:
[ 2406.728975] #0: (&mm->mmap_sem){++++++}, at: collapse_huge_page.isra.30 (arch/x86/include/asm/atomic.h:26 mm/huge_memory.c:1989 mm/huge_memory.c:2378)
[ 2406.733683] BUG: using __this_cpu_write() in preemptible [00000000] code: khungtaskd/3540
[ 2406.735837] caller is __this_cpu_preempt_check+0x13/0x20
[ 2406.737191] CPU: 21 PID: 3540 Comm: khungtaskd Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2406.739790]  ffffffffb17b99f5 ffff880436b5bd58 ffffffffb05223a7 0000000000000007
[ 2406.741834]  0000000000000015 ffff880436b5bd88 ffffffffadb306d9 00000000000004b0
[ 2406.744275]  00000000003ffecf 00000000000002cf ffff8803d6b28000 ffff880436b5bd98
[ 2406.746446] Call Trace:
[ 2406.747118] dump_stack (lib/dump_stack.c:52)
[ 2406.748927] check_preemption_disabled (arch/x86/include/asm/preempt.h:80 lib/smp_processor_id.c:49)
[ 2406.750736] __this_cpu_preempt_check (lib/smp_processor_id.c:63)
[ 2406.752708] touch_softlockup_watchdog (kernel/watchdog.c:142)
[ 2406.754405] touch_nmi_watchdog (kernel/watchdog.c:170)
[ 2406.756063] watchdog (kernel/hung_task.c:122 kernel/hung_task.c:180 kernel/hung_task.c:236)
[ 2406.757444] ? watchdog (include/linux/rcupdate.h:800 kernel/hung_task.c:169 kernel/hung_task.c:236)
[ 2406.759472] ? reset_hung_task_detector (kernel/hung_task.c:224)
[ 2406.766326] kthread (kernel/kthread.c:210)
[ 2406.769513] ? kthread_create_on_node (kernel/kthread.c:176)
[ 2406.773602] ret_from_fork (arch/x86/kernel/entry_64.S:555)
[ 2406.776132] ? kthread_create_on_node (kernel/kthread.c:176)
[ 2406.778998] sending NMI to all CPUs:
[ 2406.781135] NMI backtrace for cpu 21
[ 2406.783323] CPU: 21 PID: 3540 Comm: khungtaskd Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2406.789592] task: ffff880436a88000 ti: ffff880436b5a000 task.ti: ffff880436b5a000
[ 2406.790928] RIP: native_write_msr_safe (arch/x86/include/asm/msr.h:95)
[ 2406.790928] RSP: 0018:ffff880436b5bd28  EFLAGS: 00000082
[ 2406.790928] RAX: 0000000000000400 RBX: 0000000000000015 RCX: 0000000000000830
[ 2406.790928] RDX: 0000000000000015 RSI: 0000000000000400 RDI: 0000000000000830
[ 2406.790928] RBP: ffff880436b5bd28 R08: ffffffffb30bc580 R09: 0000000000000000
[ 2406.790928] R10: 0000000000000001 R11: 3a73555043206c6c R12: ffffffffb30bc580
[ 2406.790928] R13: 0000000000000015 R14: 0000000000080000 R15: 000000000000b022
[ 2406.790928] FS:  0000000000000000(0000) GS:ffff880467000000(0000) knlGS:0000000000000000
[ 2406.790928] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2406.790928] CR2: 00007f07ed23d099 CR3: 0000000031e2d000 CR4: 00000000000006a0
[ 2406.790928] Stack:
[ 2406.790928]  ffff880436b5bd88 ffffffffad0b3ac2 ffff880436b5bd98 0000000000000282
[ 2406.790928]  0000000000000002 0000000200000008 ffff880436b5bda8 0000000000002710
[ 2406.790928]  00000000003ffecf 00000000000002cf ffff8803d6b28000 ffff8803d6b28000
[ 2406.790928] Call Trace:
[ 2406.790928] __x2apic_send_IPI_mask (arch/x86/include/asm/paravirt.h:133 arch/x86/include/asm/apic.h:169 arch/x86/include/asm/x2apic.h:26 arch/x86/kernel/apic/x2apic_phys.c:52)
[ 2406.790928] x2apic_send_IPI_all (arch/x86/kernel/apic/x2apic_phys.c:77)
[ 2406.790928] arch_trigger_all_cpu_backtrace (include/linux/bitmap.h:265 include/linux/cpumask.h:443 arch/x86/kernel/apic/hw_nmi.c:54)
[ 2406.790928] watchdog (kernel/hung_task.c:124 kernel/hung_task.c:180 kernel/hung_task.c:236)
[ 2406.790928] ? watchdog (include/linux/rcupdate.h:800 kernel/hung_task.c:169 kernel/hung_task.c:236)
[ 2406.790928] ? reset_hung_task_detector (kernel/hung_task.c:224)
[ 2406.790928] kthread (kernel/kthread.c:210)
[ 2406.790928] ? kthread_create_on_node (kernel/kthread.c:176)
[ 2406.790928] ret_from_fork (arch/x86/kernel/entry_64.S:555)
[ 2406.790928] ? kthread_create_on_node (kernel/kthread.c:176)
[ 2406.790928] Code: 00 55 89 f9 48 89 e5 0f 32 31 ff 89 c0 48 c1 e2 20 89 3e 48 09 c2 5d 48 89 d0 c3 66 0f 1f 44 00 00 55 89 f0 89 f9 48 89 e5 0f 30 <31> c0 5d c3 66 90 55 89 f9 48 89 e5 0f 33 89 c0 48 c1 e2 20 5d
[ 2406.732546] NMI backtrace for cpu 2
[ 2406.790928] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 129.351 msecs
[ 2406.732546] CPU: 2 PID: 0 Comm: swapper/2 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2406.732546] task: ffff8801ee8f8000 ti: ffff88002ad6e000 task.ti: ffff88002ad6e000
[ 2406.732546] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2406.732546] RSP: 0018:ffff88002ad6fe28  EFLAGS: 00000282
[ 2406.732546] RAX: ffff8801ee8f8000 RBX: ffff88002ad6ffd8 RCX: 0000000000000000
[ 2406.732546] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2406.732546] RBP: ffff88002ad6fe28 R08: 0000000000000000 R09: 0000000000000000
[ 2406.732546] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2406.732546] R13: ffff88002ad6e000 R14: ffffffffb30bc580 R15: ffff88002ad6ffd8
[ 2406.732546] FS:  0000000000000000(0000) GS:ffff880095000000(0000) knlGS:0000000000000000
[ 2406.732546] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2406.732546] CR2: 00007f026359f170 CR3: 0000000031e2d000 CR4: 00000000000006a0
[ 2406.732546] Stack:
[ 2406.732546]  ffff88002ad6fe48 ffffffffad07c04d ffff88002ad6ffd8 0000000000000000
[ 2406.732546]  ffff88002ad6fe58 ffffffffad07cd4f ffff88002ad6fed8 ffffffffad1b73f5
[ 2406.732546]  0000000000000000 b14dfbbab381bb01 ffff88002ad6ffd8 000000000000f000
[ 2406.732546] Call Trace:
[ 2406.732546] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2406.732546] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2406.732546] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2406.732546] cpu_startup_entry (??:?)
[ 2406.732546] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2406.732546] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2406.726090] NMI backtrace for cpu 11
[ 2407.051480] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 269.944 msecs
[ 2406.726090] CPU: 11 PID: 0 Comm: swapper/11 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2406.726090] task: ffff88002ad88000 ti: ffff88002ad84000 task.ti: ffff88002ad84000
[ 2406.726090] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2406.726090] RSP: 0018:ffff88002ad85e28  EFLAGS: 00000282
[ 2406.726090] RAX: ffff88002ad88000 RBX: ffff88002ad85fd8 RCX: 0000000000000000
[ 2406.726090] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2406.726090] RBP: ffff88002ad85e28 R08: 0000000000000000 R09: 0000000000000000
[ 2406.726090] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2406.726090] R13: ffff88002ad84000 R14: ffffffffb30bc580 R15: ffff88002ad85fd8
[ 2406.726090] FS:  0000000000000000(0000) GS:ffff880285000000(0000) knlGS:0000000000000000
[ 2406.726090] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2406.726090] CR2: 00007f5b4d8d397a CR3: 0000000031e2d000 CR4: 00000000000006a0
[ 2406.726090] Stack:
[ 2406.726090]  ffff88002ad85e48 ffffffffad07c04d ffff88002ad85fd8 0000000000000000
[ 2406.726090]  ffff88002ad85e58 ffffffffad07cd4f ffff88002ad85ed8 ffffffffad1b73f5
[ 2406.726090]  0000000000000000 e0335f8592de6dea ffff88002ad85fd8 000000000000f000
[ 2406.726090] Call Trace:
[ 2406.726090] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2406.726090] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2406.726090] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2406.726090] cpu_startup_entry (??:?)
[ 2406.726090] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2406.726090] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2406.770400] NMI backtrace for cpu 4
[ 2407.227620] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 446.006 msecs
[ 2406.770400] CPU: 4 PID: 0 Comm: swapper/4 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2406.770400] task: ffff880436910000 ti: ffff88002ad72000 task.ti: ffff88002ad72000
[ 2406.770400] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2406.770400] RSP: 0018:ffff88002ad73e28  EFLAGS: 00000282
[ 2406.770400] RAX: ffff880436910000 RBX: ffff88002ad73fd8 RCX: 0000000000000000
[ 2406.770400] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2406.770400] RBP: ffff88002ad73e28 R08: 0000000000000000 R09: 0000000000000000
[ 2406.770400] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2406.770400] R13: ffff88002ad72000 R14: ffffffffb30bc580 R15: ffff88002ad73fd8
[ 2406.770400] FS:  0000000000000000(0000) GS:ffff880127000000(0000) knlGS:0000000000000000
[ 2406.770400] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2406.770400] CR2: 00007f0e063095e0 CR3: 000000005e3c5000 CR4: 00000000000006a0
[ 2406.770400] Stack:
[ 2406.770400]  ffff88002ad73e48 ffffffffad07c04d ffff88002ad73fd8 0000000000000000
[ 2406.770400]  ffff88002ad73e58 ffffffffad07cd4f ffff88002ad73ed8 ffffffffad1b73f5
[ 2406.770400]  0000000000000000 78cea51f19eb6d9a ffff88002ad73fd8 000000000000f000
[ 2406.770400] Call Trace:
[ 2406.770400] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2406.770400] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2406.770400] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2406.770400] cpu_startup_entry (??:?)
[ 2406.770400] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2406.770400] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2406.770587] NMI backtrace for cpu 8
[ 2407.392169] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 610.715 msecs
[ 2406.770587] CPU: 8 PID: 0 Comm: swapper/8 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2406.770587] task: ffff880316910000 ti: ffff88002ad7e000 task.ti: ffff88002ad7e000
[ 2406.770587] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2406.770587] RSP: 0018:ffff88002ad7fe28  EFLAGS: 00000282
[ 2406.770587] RAX: ffff880316910000 RBX: ffff88002ad7ffd8 RCX: 0000000000000000
[ 2406.770587] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2406.770587] RBP: ffff88002ad7fe28 R08: 0000000000000000 R09: 0000000000000000
[ 2406.770587] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2406.770587] R13: ffff88002ad7e000 R14: ffffffffb30bc580 R15: ffff88002ad7ffd8
[ 2406.770587] FS:  0000000000000000(0000) GS:ffff8801ef000000(0000) knlGS:0000000000000000
[ 2406.770587] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2406.770587] CR2: 00007fd82dbefb80 CR3: 0000000031e2d000 CR4: 00000000000006a0
[ 2406.770587] Stack:
[ 2406.770587]  ffff88002ad7fe48 ffffffffad07c04d ffff88002ad7ffd8 0000000000000000
[ 2406.770587]  ffff88002ad7fe58 ffffffffad07cd4f ffff88002ad7fed8 ffffffffad1b73f5
[ 2406.770587]  0000000000000000 c37c456b12092c72 ffff88002ad7ffd8 000000000000f000
[ 2406.770587] Call Trace:
[ 2406.770587] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2406.770587] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2406.770587] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2406.770587] cpu_startup_entry (??:?)
[ 2406.770587] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2406.770587] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2406.776572] NMI backtrace for cpu 9
[ 2407.455680] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 674.457 msecs
[ 2406.776572] CPU: 9 PID: 0 Comm: swapper/9 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2406.776572] task: ffff880436918000 ti: ffff88002ad80000 task.ti: ffff88002ad80000
[ 2406.776572] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2406.776572] RSP: 0018:ffff88002ad81e28  EFLAGS: 00000282
[ 2406.776572] RAX: ffff880436918000 RBX: ffff88002ad81fd8 RCX: 0000000000000000
[ 2406.776572] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2406.776572] RBP: ffff88002ad81e28 R08: 0000000000000000 R09: 0000000000000000
[ 2406.776572] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2406.776572] R13: ffff88002ad80000 R14: ffffffffb30bc580 R15: ffff88002ad81fd8
[ 2406.776572] FS:  0000000000000000(0000) GS:ffff880220e00000(0000) knlGS:0000000000000000
[ 2406.776572] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2406.776572] CR2: 00007fd9fe85e099 CR3: 0000000031e2d000 CR4: 00000000000006a0
[ 2406.776572] Stack:
[ 2406.776572]  ffff88002ad81e48 ffffffffad07c04d ffff88002ad81fd8 0000000000000000
[ 2406.776572]  ffff88002ad81e58 ffffffffad07cd4f ffff88002ad81ed8 ffffffffad1b73f5
[ 2406.776572]  0000000000000000 982768e623c64a41 ffff88002ad81fd8 000000000000f000
[ 2406.776572] Call Trace:
[ 2406.776572] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2406.776572] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2406.776572] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2406.776572] cpu_startup_entry (??:?)
[ 2406.776572] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2406.776572] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2406.773931] NMI backtrace for cpu 16
[ 2407.522960] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 741.709 msecs
[ 2406.773931] CPU: 16 PID: 0 Comm: swapper/16 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2406.773931] task: ffff880316920000 ti: ffff88002ad9a000 task.ti: ffff88002ad9a000
[ 2406.773931] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2406.773931] RSP: 0018:ffff88002ad9be28  EFLAGS: 00000282
[ 2406.773931] RAX: ffff880316920000 RBX: ffff88002ad9bfd8 RCX: 0000000000000000
[ 2406.773931] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2406.773931] RBP: ffff88002ad9be28 R08: 0000000000000000 R09: 0000000000000000
[ 2406.773931] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2406.773931] R13: ffff88002ad9a000 R14: ffffffffb30bc580 R15: ffff88002ad9bfd8
[ 2406.773931] FS:  0000000000000000(0000) GS:ffff880377000000(0000) knlGS:0000000000000000
[ 2406.773931] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2406.773931] CR2: 00007faa2c8d59de CR3: 0000000031e2d000 CR4: 00000000000006a0
[ 2406.773931] Stack:
[ 2406.773931]  ffff88002ad9be48 ffffffffad07c04d ffff88002ad9bfd8 0000000000000000
[ 2406.773931]  ffff88002ad9be58 ffffffffad07cd4f ffff88002ad9bed8 ffffffffad1b73f5
[ 2406.773931]  0000000000000000 fc58c7b9f54f958d ffff88002ad9bfd8 000000000000f000
[ 2406.773931] Call Trace:
[ 2406.773931] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2406.773931] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2406.773931] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2406.773931] cpu_startup_entry (??:?)
[ 2406.773931] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2406.773931] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2406.791002] NMI backtrace for cpu 7
[ 2407.623400] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 842.127 msecs
[ 2406.791002] CPU: 7 PID: 0 Comm: swapper/7 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2406.791002] task: ffff8801ee900000 ti: ffff88002ad7c000 task.ti: ffff88002ad7c000
[ 2406.791002] RIP: native_write_msr_safe (arch/x86/include/asm/msr.h:95)
[ 2406.791002] RSP: 0018:ffff88002ad7dcf8  EFLAGS: 00000046
[ 2406.791002] RAX: 000000007fffffff RBX: ffff8801bd00f040 RCX: 0000000000000838
[ 2406.791002] RDX: 0000000000000000 RSI: 000000007fffffff RDI: 0000000000000838
[ 2406.791002] RBP: ffff88002ad7dcf8 R08: 0000000000800000 R09: ffffffffffffffff
[ 2406.791002] R10: 00032cdb7c0be5d4 R11: 0000000000000000 R12: 00000007ff111e51
[ 2406.791002] R13: 0000000000000001 R14: 0000000000000001 R15: ffff8801bd1d0a40
[ 2406.791002] FS:  0000000000000000(0000) GS:ffff8801bd000000(0000) knlGS:0000000000000000
[ 2406.791002] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2406.791002] CR2: 00007f0c5de1e099 CR3: 0000000031e2d000 CR4: 00000000000006a0
[ 2406.791002] Stack:
[ 2406.791002]  ffff88002ad7dd08 ffffffffad0b3831 ffff88002ad7dd18 ffffffffad0ac09d
[ 2406.791002]  ffff88002ad7dd48 ffffffffad1f6bca 0000000000000000 00000238653e3600
[ 2406.791002]  0000000000000001 0000000000000000 ffff88002ad7dd68 ffffffffad1f9600
[ 2406.791002] Call Trace:
[ 2406.791002] native_apic_msr_write (arch/x86/include/asm/paravirt.h:133 arch/x86/include/asm/apic.h:136)
[ 2406.791002] lapic_next_event (arch/x86/kernel/apic/apic.c:483)
[ 2406.791002] clockevents_program_event (kernel/time/clockevents.c:270)
[ 2406.791002] tick_program_event (kernel/time/tick-oneshot.c:32)
[ 2406.791002] hrtimer_force_reprogram (kernel/hrtimer.c:574)
[ 2406.791002] __remove_hrtimer (kernel/hrtimer.c:915)
[ 2406.791002] hrtimer_try_to_cancel (kernel/hrtimer.c:952 kernel/hrtimer.c:1078)
[ 2406.791002] hrtimer_cancel (kernel/hrtimer.c:1100)
[ 2406.791002] tick_nohz_restart (kernel/time/tick-sched.c:841)
[ 2406.791002] tick_nohz_idle_exit (kernel/time/tick-sched.c:879 include/linux/jump_label.h:105 include/linux/context_tracking_state.h:27 include/linux/vtime.h:22 kernel/time/tick-sched.c:887 kernel/time/tick-sched.c:929)
[ 2406.791002] cpu_idle_loop (kernel/sched/idle.c:241)
[ 2406.791002] cpu_startup_entry (??:?)
[ 2406.791002] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2406.791002] Code: 00 55 89 f9 48 89 e5 0f 32 31 ff 89 c0 48 c1 e2 20 89 3e 48 09 c2 5d 48 89 d0 c3 66 0f 1f 44 00 00 55 89 f0 89 f9 48 89 e5 0f 30 <31> c0 5d c3 66 90 55 89 f9 48 89 e5 0f 33 89 c0 48 c1 e2 20 5d
[ 2406.780287] NMI backtrace for cpu 10
[ 2406.791002] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 1087.712 msecs
[ 2406.780287] CPU: 10 PID: 0 Comm: swapper/10 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2406.780287] task: ffff880556938000 ti: ffff88002ad82000 task.ti: ffff88002ad82000
[ 2406.780287] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2406.780287] RSP: 0018:ffff88002ad83e28  EFLAGS: 00000282
[ 2406.780287] RAX: ffff880556938000 RBX: ffff88002ad83fd8 RCX: 0000000000000000
[ 2406.780287] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2406.780287] RBP: ffff88002ad83e28 R08: 0000000000000000 R09: 0000000000000000
[ 2406.780287] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2406.780287] R13: ffff88002ad82000 R14: ffffffffb30bc580 R15: ffff88002ad83fd8
[ 2406.780287] FS:  0000000000000000(0000) GS:ffff880253000000(0000) knlGS:0000000000000000
[ 2406.780287] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2406.780287] CR2: 00007fb641e0d070 CR3: 0000000031e2d000 CR4: 00000000000006a0
[ 2406.780287] Stack:
[ 2406.780287]  ffff88002ad83e48 ffffffffad07c04d ffff88002ad83fd8 0000000000000000
[ 2406.780287]  ffff88002ad83e58 ffffffffad07cd4f ffff88002ad83ed8 ffffffffad1b73f5
[ 2406.780287]  0000000000000000 9f3d8b5b532a750a ffff88002ad83fd8 000000000000f000
[ 2406.780287] Call Trace:
[ 2406.780287] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2406.780287] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2406.780287] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2406.780287] cpu_startup_entry (??:?)
[ 2406.780287] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2406.780287] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2406.790114] NMI backtrace for cpu 1
[ 2408.073317] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 1291.403 msecs
[ 2406.790114] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2406.790114] task: ffff8800948f0000 ti: ffff88002ad6c000 task.ti: ffff88002ad6c000
[ 2406.790114] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2406.790114] RSP: 0018:ffff88002ad6de28  EFLAGS: 00000282
[ 2406.790114] RAX: ffff8800948f0000 RBX: ffff88002ad6dfd8 RCX: 0000000000000000
[ 2406.790114] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2406.790114] RBP: ffff88002ad6de28 R08: 0000000000000000 R09: 0000000000000000
[ 2406.790114] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2406.790114] R13: ffff88002ad6c000 R14: ffffffffb30bc580 R15: ffff88002ad6dfd8
[ 2406.790114] FS:  0000000000000000(0000) GS:ffff880063000000(0000) knlGS:0000000000000000
[ 2406.790114] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2406.790114] CR2: 00007faa2c8d59de CR3: 0000000031e2d000 CR4: 00000000000006a0
[ 2406.790114] Stack:
[ 2406.790114]  ffff88002ad6de48 ffffffffad07c04d ffff88002ad6dfd8 0000000000000000
[ 2406.790114]  ffff88002ad6de58 ffffffffad07cd4f ffff88002ad6ded8 ffffffffad1b73f5
[ 2406.790114]  0000000000000000 070355202ebd0a66 ffff88002ad6dfd8 000000000000f000
[ 2406.790114] Call Trace:
[ 2406.790114] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2406.790114] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2406.790114] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2406.790114] cpu_startup_entry (??:?)
[ 2406.790114] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2406.790114] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2406.773449] NMI backtrace for cpu 12
[ 2408.114944] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 1333.636 msecs
[ 2406.773449] CPU: 12 PID: 0 Comm: swapper/12 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2406.773449] task: ffff88002ad8b000 ti: ffff88002ad86000 task.ti: ffff88002ad86000
[ 2406.773449] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2406.773449] RSP: 0018:ffff88002ad87e28  EFLAGS: 00000282
[ 2406.773449] RAX: ffff88002ad8b000 RBX: ffff88002ad87fd8 RCX: 0000000000000000
[ 2406.773449] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2406.773449] RBP: ffff88002ad87e28 R08: 0000000000000000 R09: 0000000000000000
[ 2406.773449] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2406.773449] R13: ffff88002ad86000 R14: ffffffffb30bc580 R15: ffff88002ad87fd8
[ 2406.773449] FS:  0000000000000000(0000) GS:ffff8802b7000000(0000) knlGS:0000000000000000
[ 2406.773449] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2406.773449] CR2: 00007f5fae0ef170 CR3: 0000000031e2d000 CR4: 00000000000006a0
[ 2406.773449] Stack:
[ 2406.773449]  ffff88002ad87e48 ffffffffad07c04d ffff88002ad87fd8 0000000000000000
[ 2406.773449]  ffff88002ad87e58 ffffffffad07cd4f ffff88002ad87ed8 ffffffffad1b73f5
[ 2406.773449]  0000000000000000 c6410aa475d0509c ffff88002ad87fd8 000000000000f000
[ 2406.773449] Call Trace:
[ 2406.773449] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2406.773449] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2406.773449] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2406.773449] cpu_startup_entry (??:?)
[ 2406.773449] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2406.773449] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2406.783731] NMI backtrace for cpu 20
[ 2406.783731] CPU: 20 PID: 0 Comm: swapper/20 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2406.783731] task: ffff8802b6918000 ti: ffff88002adaa000 task.ti: ffff88002adaa000
[ 2406.783731] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2406.783731] RSP: 0018:ffff88002adabe28  EFLAGS: 00000282
[ 2406.783731] RAX: ffff8802b6918000 RBX: ffff88002adabfd8 RCX: 0000000000000000
[ 2406.783731] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2406.783731] RBP: ffff88002adabe28 R08: 0000000000000000 R09: 0000000000000000
[ 2406.783731] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2406.783731] R13: ffff88002adaa000 R14: ffffffffb30bc580 R15: ffff88002adabfd8
[ 2406.783731] FS:  0000000000000000(0000) GS:ffff880437000000(0000) knlGS:0000000000000000
[ 2406.783731] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2406.783731] CR2: 00007f9fbf31f170 CR3: 0000000031e2d000 CR4: 00000000000006a0
[ 2406.783731] Stack:
[ 2406.783731]  ffff88002adabe48 ffffffffad07c04d ffff88002adabfd8 0000000000000000
[ 2406.783731]  ffff88002adabe58 ffffffffad07cd4f ffff88002adabed8 ffffffffad1b73f5
[ 2406.783731]  0000000000000000 ec4da5f4ddcd59c7 ffff88002adabfd8 000000000000f000
[ 2406.783731] Call Trace:
[ 2406.783731] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2406.783731] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2406.783731] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2406.783731] cpu_startup_entry (??:?)
[ 2406.783731] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2406.783731] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2406.780604] NMI backtrace for cpu 17
[ 2406.780604] CPU: 17 PID: 0 Comm: swapper/17 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2406.780604] task: ffff880496920000 ti: ffff88002ad9c000 task.ti: ffff88002ad9c000
[ 2406.780604] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2406.780604] RSP: 0018:ffff88002ad9de28  EFLAGS: 00000282
[ 2406.780604] RAX: ffff880496920000 RBX: ffff88002ad9dfd8 RCX: 0000000000000000
[ 2406.780604] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2406.780604] RBP: ffff88002ad9de28 R08: 0000000000000000 R09: 0000000000000000
[ 2406.780604] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2406.780604] R13: ffff88002ad9c000 R14: ffffffffb30bc580 R15: ffff88002ad9dfd8
[ 2406.780604] FS:  0000000000000000(0000) GS:ffff8803a7000000(0000) knlGS:0000000000000000
[ 2406.780604] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2406.780604] CR2: 00007f446d8cd170 CR3: 0000000031e2d000 CR4: 00000000000006a0
[ 2406.780604] Stack:
[ 2406.780604]  ffff88002ad9de48 ffffffffad07c04d ffff88002ad9dfd8 0000000000000000
[ 2406.780604]  ffff88002ad9de58 ffffffffad07cd4f ffff88002ad9ded8 ffffffffad1b73f5
[ 2406.780604]  0000000000000000 970676ae9739a05a ffff88002ad9dfd8 000000000000f000
[ 2406.780604] Call Trace:
[ 2406.780604] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2406.780604] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2406.780604] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2406.780604] cpu_startup_entry (??:?)
[ 2406.780604] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2406.780604] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2406.773106] NMI backtrace for cpu 18
[ 2406.773106] CPU: 18 PID: 0 Comm: swapper/18 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2406.773106] task: ffff880616928000 ti: ffff88002ad9e000 task.ti: ffff88002ad9e000
[ 2406.773106] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2406.773106] RSP: 0018:ffff88002ad9fe28  EFLAGS: 00000282
[ 2406.773106] RAX: ffff880616928000 RBX: ffff88002ad9ffd8 RCX: 0000000000000000
[ 2406.773106] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2406.773106] RBP: ffff88002ad9fe28 R08: 0000000000000000 R09: 0000000000000000
[ 2406.773106] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2406.773106] R13: ffff88002ad9e000 R14: ffffffffb30bc580 R15: ffff88002ad9ffd8
[ 2406.773106] FS:  0000000000000000(0000) GS:ffff8803d7000000(0000) knlGS:0000000000000000
[ 2406.773106] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2406.773106] CR2: 00007f5b4d3ff099 CR3: 0000000031e2d000 CR4: 00000000000006a0
[ 2406.773106] Stack:
[ 2406.773106]  ffff88002ad9fe48 ffffffffad07c04d ffff88002ad9ffd8 0000000000000000
[ 2406.773106]  ffff88002ad9fe58 ffffffffad07cd4f ffff88002ad9fed8 ffffffffad1b73f5
[ 2406.773106]  0000000000000000 ccdf3c6031d54cd1 ffff88002ad9ffd8 000000000000f000
[ 2406.773106] Call Trace:
[ 2406.773106] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2406.773106] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2406.773106] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2406.773106] cpu_startup_entry (??:?)
[ 2406.773106] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2406.773106] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2406.770609] NMI backtrace for cpu 13
[ 2406.770609] CPU: 13 PID: 0 Comm: swapper/13 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2406.770609] task: ffff8803d6928000 ti: ffff88002ad90000 task.ti: ffff88002ad90000
[ 2406.770609] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2406.770609] RSP: 0018:ffff88002ad91e28  EFLAGS: 00000282
[ 2406.770609] RAX: ffff8803d6928000 RBX: ffff88002ad91fd8 RCX: 0000000000000000
[ 2406.770609] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2406.770609] RBP: ffff88002ad91e28 R08: 0000000000000000 R09: 0000000000000000
[ 2406.770609] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2406.770609] R13: ffff88002ad90000 R14: ffffffffb30bc580 R15: ffff88002ad91fd8
[ 2406.770609] FS:  0000000000000000(0000) GS:ffff8802e7000000(0000) knlGS:0000000000000000
[ 2406.770609] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2406.770609] CR2: 00007f10cbecf070 CR3: 0000000031e2d000 CR4: 00000000000006a0
[ 2406.770609] Stack:
[ 2406.770609]  ffff88002ad91e48 ffffffffad07c04d ffff88002ad91fd8 0000000000000000
[ 2406.770609]  ffff88002ad91e58 ffffffffad07cd4f ffff88002ad91ed8 ffffffffad1b73f5
[ 2406.770609]  0000000000000000 618f5836413e64b6 ffff88002ad91fd8 000000000000f000
[ 2406.770609] Call Trace:
[ 2406.770609] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2406.770609] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2406.770609] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2406.770609] cpu_startup_entry (??:?)
[ 2406.770609] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2406.770609] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2406.785234] NMI backtrace for cpu 19
[ 2406.785234] CPU: 19 PID: 0 Comm: swapper/19 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2406.785234] task: ffff88018a910000 ti: ffff88002ada8000 task.ti: ffff88002ada8000
[ 2406.785234] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2406.785234] RSP: 0018:ffff88002ada9e28  EFLAGS: 00000282
[ 2406.785234] RAX: ffff88018a910000 RBX: ffff88002ada9fd8 RCX: 0000000000000000
[ 2406.785234] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2406.785234] RBP: ffff88002ada9e28 R08: 0000000000000000 R09: 0000000000000000
[ 2406.785234] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2406.785234] R13: ffff88002ada8000 R14: ffffffffb30bc580 R15: ffff88002ada9fd8
[ 2406.785234] FS:  0000000000000000(0000) GS:ffff880407000000(0000) knlGS:0000000000000000
[ 2406.785234] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2406.785234] CR2: 00007f7bc2f1d099 CR3: 0000000031e2d000 CR4: 00000000000006a0
[ 2406.785234] Stack:
[ 2406.785234]  ffff88002ada9e48 ffffffffad07c04d ffff88002ada9fd8 0000000000000000
[ 2406.785234]  ffff88002ada9e58 ffffffffad07cd4f ffff88002ada9ed8 ffffffffad1b73f5
[ 2406.785234]  0000000000000000 43f465af05da1bde ffff88002ada9fd8 000000000000f000
[ 2406.785234] Call Trace:
[ 2406.785234] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2406.785234] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2406.785234] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2406.785234] cpu_startup_entry (??:?)
[ 2406.785234] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2406.785234] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2406.722636] NMI backtrace for cpu 5
[ 2406.722636] CPU: 5 PID: 0 Comm: swapper/5 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2406.722636] task: ffff880556930000 ti: ffff88002ad74000 task.ti: ffff88002ad74000
[ 2406.722636] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2406.722636] RSP: 0018:ffff88002ad75e28  EFLAGS: 00000282
[ 2406.722636] RAX: ffff880556930000 RBX: ffff88002ad75fd8 RCX: 0000000000000000
[ 2406.722636] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2406.722636] RBP: ffff88002ad75e28 R08: 0000000000000000 R09: 0000000000000000
[ 2406.722636] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2406.722636] R13: ffff88002ad74000 R14: ffffffffb30bc580 R15: ffff88002ad75fd8
[ 2406.722636] FS:  0000000000000000(0000) GS:ffff880158e00000(0000) knlGS:0000000000000000
[ 2406.722636] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2406.722636] CR2: 00007f9ba4e9f170 CR3: 0000000031e2d000 CR4: 00000000000006a0
[ 2406.722636] Stack:
[ 2406.722636]  ffff88002ad75e48 ffffffffad07c04d ffff88002ad75fd8 0000000000000000
[ 2406.722636]  ffff88002ad75e58 ffffffffad07cd4f ffff88002ad75ed8 ffffffffad1b73f5
[ 2406.722636]  0000000000000000 9a6095db8c2e6f9a ffff88002ad75fd8 000000000000f000
[ 2406.722636] Call Trace:
[ 2406.722636] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2406.722636] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2406.722636] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2406.722636] cpu_startup_entry (??:?)
[ 2406.722636] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2406.722636] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2406.780256] NMI backtrace for cpu 0
[ 2406.780256] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2406.780256] task: ffffffffb1e344c0 ti: ffffffffb1e00000 task.ti: ffffffffb1e00000
[ 2406.780256] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2406.780256] RSP: 0000:ffffffffb1e01e38  EFLAGS: 00000282
[ 2406.780256] RAX: ffffffffb1e344c0 RBX: ffffffffb1e01fd8 RCX: 0000000000000000
[ 2406.780256] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2406.780256] RBP: ffffffffb1e01e38 R08: 0000000000000000 R09: 0000000000000000
[ 2406.780256] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2406.780256] R13: ffffffffb1e00000 R14: ffffffffb30bc580 R15: ffffffffb1e01fd8
[ 2406.780256] FS:  0000000000000000(0000) GS:ffff88002be00000(0000) knlGS:0000000000000000
[ 2406.780256] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2406.780256] CR2: 00007f0e067fe821 CR3: 0000000031e2d000 CR4: 00000000000006b0
[ 2406.780256] Stack:
[ 2406.780256]  ffffffffb1e01e58 ffffffffad07c04d ffffffffb1e01fd8 0000000000000000
[ 2406.780256]  ffffffffb1e01e68 ffffffffad07cd4f ffffffffb1e01ee8 ffffffffad1b73f5
[ 2406.780256]  0000000000000000 d81b28d1e484efc7 ffffffffb1e01fd8 0000000000000002
[ 2406.780256] Call Trace:
[ 2406.780256] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2406.780256] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2406.780256] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2406.780256] cpu_startup_entry (??:?)
[ 2406.780256] rest_init (init/main.c:398)
[ 2406.780256] ? rest_init (init/main.c:373)
[ 2406.780256] start_kernel (init/main.c:653)
[ 2406.780256] ? repair_env_string (init/main.c:260)
[ 2406.780256] ? early_idt_handlers (arch/x86/kernel/head_64.S:340)
[ 2406.780256] x86_64_start_reservations (arch/x86/kernel/head64.c:194)
[ 2406.780256] x86_64_start_kernel (arch/x86/kernel/head64.c:183)
[ 2406.780256] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2406.790091] NMI backtrace for cpu 3
[ 2406.790091] CPU: 3 PID: 0 Comm: swapper/3 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2406.790091] task: ffff880316908000 ti: ffff88002ad70000 task.ti: ffff88002ad70000
[ 2406.790091] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2406.790091] RSP: 0018:ffff88002ad71e28  EFLAGS: 00000282
[ 2406.790091] RAX: ffff880316908000 RBX: ffff88002ad71fd8 RCX: 0000000000000000
[ 2406.790091] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2406.790091] RBP: ffff88002ad71e28 R08: 0000000000000000 R09: 0000000000000000
[ 2406.790091] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2406.790091] R13: ffff88002ad70000 R14: ffffffffb30bc580 R15: ffff88002ad71fd8
[ 2406.790091] FS:  0000000000000000(0000) GS:ffff8800c7000000(0000) knlGS:0000000000000000
[ 2406.790091] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2406.790091] CR2: 00007fbb037b0334 CR3: 0000000031e2d000 CR4: 00000000000006a0
[ 2406.790091] Stack:
[ 2406.790091]  ffff88002ad71e48 ffffffffad07c04d ffff88002ad71fd8 0000000000000000
[ 2406.790091]  ffff88002ad71e58 ffffffffad07cd4f ffff88002ad71ed8 ffffffffad1b73f5
[ 2406.790091]  0000000000000000 a42a8a608a0df9ca ffff88002ad71fd8 000000000000f000
[ 2406.790091] Call Trace:
[ 2406.790091] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2406.790091] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2406.790091] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2406.790091] cpu_startup_entry (??:?)
[ 2406.790091] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2406.790091] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2408.693358] NMI backtrace for cpu 15
[ 2408.693358] CPU: 15 PID: 0 Comm: swapper/15 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2408.722811] task: ffff88018a908000 ti: ffff88002ad98000 task.ti: ffff88002ad98000
[ 2408.722811] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2408.722811] RSP: 0018:ffff88002ad99e28  EFLAGS: 00000282
[ 2408.722811] RAX: ffff88018a908000 RBX: ffff88002ad99fd8 RCX: 0000000000000000
[ 2408.722811] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2408.722811] RBP: ffff88002ad99e28 R08: 0000000000000000 R09: 0000000000000000
[ 2408.722811] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2408.722811] R13: ffff88002ad98000 R14: ffffffffb30bc580 R15: ffff88002ad99fd8
[ 2408.722811] FS:  0000000000000000(0000) GS:ffff880347000000(0000) knlGS:0000000000000000
[ 2408.722811] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2408.722811] CR2: 00007f93c7ead070 CR3: 0000000031e2d000 CR4: 00000000000006a0
[ 2408.722811] Stack:
[ 2408.722811]  ffff88002ad99e48 ffffffffad07c04d ffff88002ad99fd8 0000000000000000
[ 2408.722811]  ffff88002ad99e58 ffffffffad07cd4f ffff88002ad99ed8 ffffffffad1b73f5
[ 2408.722811]  0000000000000000 d415927b269676da ffff88002ad99fd8 000000000000f000
[ 2408.722811] Call Trace:
[ 2408.722811] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2408.722811] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2408.722811] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2408.722811] cpu_startup_entry (??:?)
[ 2408.722811] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2408.722811] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2408.722619] NMI backtrace for cpu 14
[ 2408.722619] CPU: 14 PID: 0 Comm: swapper/14 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2408.722619] task: ffff8805b6908000 ti: ffff88002ad92000 task.ti: ffff88002ad92000
[ 2408.722619] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2408.722619] RSP: 0018:ffff88002ad93e28  EFLAGS: 00000282
[ 2408.722619] RAX: ffff8805b6908000 RBX: ffff88002ad93fd8 RCX: 0000000000000000
[ 2408.722619] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2408.722619] RBP: ffff88002ad93e28 R08: 0000000000000000 R09: 0000000000000000
[ 2408.722619] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2408.722619] R13: ffff88002ad92000 R14: ffffffffb30bc580 R15: ffff88002ad93fd8
[ 2408.722619] FS:  0000000000000000(0000) GS:ffff880317000000(0000) knlGS:0000000000000000
[ 2408.722619] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2408.722619] CR2: 00007f30be8c9730 CR3: 0000000157401000 CR4: 00000000000006a0
[ 2408.722619] Stack:
[ 2408.722619]  ffff88002ad93e48 ffffffffad07c04d ffff88002ad93fd8 0000000000000000
[ 2408.722619]  ffff88002ad93e58 ffffffffad07cd4f ffff88002ad93ed8 ffffffffad1b73f5
[ 2408.722619]  0000000000000000 89f157ff9e713d03 ffff88002ad93fd8 000000000000f000
[ 2408.837217] Call Trace:
[ 2408.837217] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2408.837217] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2408.837217] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2408.837217] cpu_startup_entry (??:?)
[ 2408.837217] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2408.837217] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2408.691691] NMI backtrace for cpu 6
[ 2408.691691] CPU: 6 PID: 0 Comm: swapper/6 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2408.691691] task: ffff8800948f8000 ti: ffff88002ad76000 task.ti: ffff88002ad76000
[ 2408.691691] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2408.691691] RSP: 0018:ffff88002ad77e28  EFLAGS: 00000282
[ 2408.691691] RAX: ffff8800948f8000 RBX: ffff88002ad77fd8 RCX: 0000000000000000
[ 2408.691691] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2408.691691] RBP: ffff88002ad77e28 R08: 0000000000000000 R09: 0000000000000000
[ 2408.691691] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2408.691691] R13: ffff88002ad76000 R14: ffffffffb30bc580 R15: ffff88002ad77fd8
[ 2408.691691] FS:  0000000000000000(0000) GS:ffff88018b000000(0000) knlGS:0000000000000000
[ 2408.691691] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2408.691691] CR2: 00007f1f306df170 CR3: 0000000031e2d000 CR4: 00000000000006a0
[ 2408.691691] Stack:
[ 2408.691691]  ffff88002ad77e48 ffffffffad07c04d ffff88002ad77fd8 0000000000000000
[ 2408.691691]  ffff88002ad77e58 ffffffffad07cd4f ffff88002ad77ed8 ffffffffad1b73f5
[ 2408.691691]  0000000000000000 154a1c73da38ea65 ffff88002ad77fd8 000000000000f000
[ 2408.691691] Call Trace:
[ 2408.691691] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2408.691691] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2408.691691] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2408.691691] cpu_startup_entry (??:?)
[ 2408.691691] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2408.691691] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2408.696506] NMI backtrace for cpu 23
[ 2408.696506] CPU: 23 PID: 0 Comm: swapper/23 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2408.696506] task: ffff880616930000 ti: ffff88002adb0000 task.ti: ffff88002adb0000
[ 2408.696506] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2408.696506] RSP: 0018:ffff88002adb1e28  EFLAGS: 00000282
[ 2408.696506] RAX: ffff880616930000 RBX: ffff88002adb1fd8 RCX: 0000000000000000
[ 2408.696506] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2408.696506] RBP: ffff88002adb1e28 R08: 0000000000000000 R09: 0000000000000000
[ 2408.696506] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2408.696506] R13: ffff88002adb0000 R14: ffffffffb30bc580 R15: ffff88002adb1fd8
[ 2408.696506] FS:  0000000000000000(0000) GS:ffff8804c7000000(0000) knlGS:0000000000000000
[ 2408.696506] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2408.696506] CR2: 00007faa2c8d59de CR3: 0000000031e2d000 CR4: 00000000000006a0
[ 2408.696506] Stack:
[ 2408.696506]  ffff88002adb1e48 ffffffffad07c04d ffff88002adb1fd8 0000000000000000
[ 2408.696506]  ffff88002adb1e58 ffffffffad07cd4f ffff88002adb1ed8 ffffffffad1b73f5
[ 2408.696506]  0000000000000000 5f651cf4a238a6ff ffff88002adb1fd8 000000000000f000
[ 2408.696506] Call Trace:
[ 2408.696506] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2408.696506] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2408.696506] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2408.696506] cpu_startup_entry (??:?)
[ 2408.696506] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2408.696506] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2408.837579] NMI backtrace for cpu 22
[ 2408.837579] CPU: 22 PID: 0 Comm: swapper/22 Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2408.837579] task: ffff8804f6938000 ti: ffff88002adae000 task.ti: ffff88002adae000
[ 2408.837579] RIP: native_safe_halt (arch/x86/include/asm/irqflags.h:50)
[ 2408.837579] RSP: 0018:ffff88002adafe28  EFLAGS: 00000282
[ 2408.837579] RAX: ffff8804f6938000 RBX: ffff88002adaffd8 RCX: 0000000000000000
[ 2408.837579] RDX: 0000000000000000 RSI: ffffffffb1820b10 RDI: ffffffffb17b99f5
[ 2408.837579] RBP: ffff88002adafe28 R08: 0000000000000000 R09: 0000000000000000
[ 2408.837579] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000
[ 2408.837579] R13: ffff88002adae000 R14: ffffffffb30bc580 R15: ffff88002adaffd8
[ 2408.837579] FS:  0000000000000000(0000) GS:ffff880497000000(0000) knlGS:0000000000000000
[ 2408.837579] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2408.837579] CR2: 00007fffb3da2ff8 CR3: 0000000031e2d000 CR4: 00000000000006a0
[ 2408.837579] Stack:
[ 2408.837579]  ffff88002adafe48 ffffffffad07c04d ffff88002adaffd8 0000000000000000
[ 2408.837579]  ffff88002adafe58 ffffffffad07cd4f ffff88002adafed8 ffffffffad1b73f5
[ 2408.837579]  0000000000000000 21d4616f708a6f6a ffff88002adaffd8 000000000000f000
[ 2408.837579] Call Trace:
[ 2408.837579] default_idle (arch/x86/include/asm/paravirt.h:111 arch/x86/kernel/process.c:310)
[ 2408.837579] arch_cpu_idle (arch/x86/kernel/process.c:302)
[ 2408.837579] cpu_idle_loop (kernel/sched/idle.c:179 kernel/sched/idle.c:226)
[ 2408.837579] cpu_startup_entry (??:?)
[ 2408.837579] start_secondary (arch/x86/kernel/smpboot.c:267)
[ 2408.837579] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84
[ 2409.043054] Kernel panic - not syncing: hung_task: blocked tasks
[ 2409.046306] CPU: 21 PID: 3540 Comm: khungtaskd Not tainted 3.15.0-rc1-next-20140415-sasha-00020-gaa90d09 #398
[ 2409.050074]  00000000003ffecf ffff880436b5bd38 ffffffffb05223a7 0000000000000001
[ 2409.050074]  ffffffffb16caa40 ffff880436b5bdb8 ffffffffb0513f93 ffff880436b5bd58
[ 2409.050074]  0000000000000008 ffff880436b5bdc8 ffff880436b5bd68 0000000000001f15
[ 2409.050074] Call Trace:
[ 2409.050074] dump_stack (lib/dump_stack.c:52)
[ 2409.050074] panic (kernel/panic.c:117)
[ 2409.050074] watchdog (kernel/hung_task.c:124 kernel/hung_task.c:180 kernel/hung_task.c:236)
[ 2409.050074] ? watchdog (include/linux/rcupdate.h:800 kernel/hung_task.c:169 kernel/hung_task.c:236)
[ 2409.050074] ? reset_hung_task_detector (kernel/hung_task.c:224)
[ 2409.050074] kthread (kernel/kthread.c:210)
[ 2409.050074] ? kthread_create_on_node (kernel/kthread.c:176)
[ 2409.050074] ret_from_fork (arch/x86/kernel/entry_64.S:555)
[ 2409.050074] ? kthread_create_on_node (kernel/kthread.c:176)
[ 2409.050074] Dumping ftrace buffer:
[ 2409.050074]    (ftrace buffer empty)
[ 2409.050074] Kernel Offset: 0x2c000000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)


Thanks,
Sasha

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: mm: hangs in collapse_huge_page
  2014-04-16  2:06 mm: hangs in collapse_huge_page Sasha Levin
@ 2014-04-24 16:46 ` Sasha Levin
  2014-04-30 15:42 ` Kirill A. Shutemov
  1 sibling, 0 replies; 8+ messages in thread
From: Sasha Levin @ 2014-04-24 16:46 UTC (permalink / raw)
  To: linux-mm; +Cc: LKML, Dave Jones, Andrew Morton

On 04/15/2014 10:06 PM, Sasha Levin wrote:
> Hi all,
> 
> I often see hung task triggering in khugepaged within collapse_huge_page().
> 
> I've initially assumed the case may be that the guests are too loaded and
> the warning occurs because of load, but after increasing the timeout to
> 1200 sec I still see the warning.

Ping? It happens quite often right now.


Thanks,
Sasha

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: mm: hangs in collapse_huge_page
  2014-04-16  2:06 mm: hangs in collapse_huge_page Sasha Levin
  2014-04-24 16:46 ` Sasha Levin
@ 2014-04-30 15:42 ` Kirill A. Shutemov
  2014-05-01 14:38   ` Hillf Danton
                     ` (2 more replies)
  1 sibling, 3 replies; 8+ messages in thread
From: Kirill A. Shutemov @ 2014-04-30 15:42 UTC (permalink / raw)
  To: Sasha Levin, Andrea Arcangeli; +Cc: linux-mm, LKML, Dave Jones, Andrew Morton

On Tue, Apr 15, 2014 at 10:06:56PM -0400, Sasha Levin wrote:
> Hi all,
> 
> I often see hung task triggering in khugepaged within collapse_huge_page().
> 
> I've initially assumed the case may be that the guests are too loaded and
> the warning occurs because of load, but after increasing the timeout to
> 1200 sec I still see the warning.

I suspect it's race (although I didn't track down exact scenario) with
__khugepaged_exit().

Comment in __khugepaged_exit() says that khugepaged_test_exit() always
called under mmap_sem:

2045 void __khugepaged_exit(struct mm_struct *mm)
...
2063         } else if (mm_slot) {
2064                 /*
2065                  * This is required to serialize against
2066                  * khugepaged_test_exit() (which is guaranteed to run
2067                  * under mmap sem read mode). Stop here (after we
2068                  * return all pagetables will be destroyed) until
2069                  * khugepaged has finished working on the pagetables
2070                  * under the mmap_sem.
2071                  */
2072                 down_write(&mm->mmap_sem);
2073                 up_write(&mm->mmap_sem);
2074         }
2075 }

But this is not true. At least khugepaged_scan_mm_slot() calls it without
the sem:

2566 static unsigned int khugepaged_scan_mm_slot(unsigned int pages,
2567                                             struct page **hpage)
...
2046 {
2047         struct mm_slot *mm_slot;
2048         int free = 0;
2049 
2050         spin_lock(&khugepaged_mm_lock);
2051         mm_slot = get_mm_slot(mm);
2052         if (mm_slot && khugepaged_scan.mm_slot != mm_slot) {
2053                 hash_del(&mm_slot->hash);
2054                 list_del(&mm_slot->mm_node);
2055                 free = 1;
2056         }
2057         spin_unlock(&khugepaged_mm_lock);
2058 
2059         if (free) {
2060                 clear_bit(MMF_VM_HUGEPAGE, &mm->flags);
2061                 free_mm_slot(mm_slot);
2062                 mmdrop(mm);

Not sure yet if it's a real problem or not. Andrea, could you comment on
this?

Sasha, please try patch below.

Not-Yet-Signed-off-by: Kirill A. Shutemov <kirill.shutemov@linux.intel.com>

diff --git a/mm/huge_memory.c b/mm/huge_memory.c
index b4b1feba6472..1c6ace5207b9 100644
--- a/mm/huge_memory.c
+++ b/mm/huge_memory.c
@@ -1986,6 +1986,8 @@ static void insert_to_mm_slots_hash(struct mm_struct *mm,
 
 static inline int khugepaged_test_exit(struct mm_struct *mm)
 {
+       VM_BUG_ON(!rwsem_is_locked(&mm->mmap_sem) &&
+                       !spin_is_locked(&khugepaged_mm_lock));
        return atomic_read(&mm->mm_users) == 0;
 }
 
@@ -2062,14 +2064,16 @@ void __khugepaged_exit(struct mm_struct *mm)
                mmdrop(mm);
        } else if (mm_slot) {
                /*
-                * This is required to serialize against
-                * khugepaged_test_exit() (which is guaranteed to run
-                * under mmap sem read mode). Stop here (after we
-                * return all pagetables will be destroyed) until
-                * khugepaged has finished working on the pagetables
+                * This is required to serialize against khugepaged_test_exit()
+                * (which is guaranteed to run under mmap sem read mode or
+                * khugepaged_mm_lock).
+                * Stop here (after we return all pagetables will be destroyed)
+                * until khugepaged has finished working on the pagetables
                 * under the mmap_sem.
                 */
                down_write(&mm->mmap_sem);
+               spin_lock(&khugepaged_mm_lock);
+               spin_unlock(&khugepaged_mm_lock);
                up_write(&mm->mmap_sem);
        }
 }
-- 
 Kirill A. Shutemov

^ permalink raw reply related	[flat|nested] 8+ messages in thread

* Re: mm: hangs in collapse_huge_page
  2014-04-30 15:42 ` Kirill A. Shutemov
@ 2014-05-01 14:38   ` Hillf Danton
  2014-05-11  0:34   ` Sasha Levin
  2015-04-30 22:17   ` Sasha Levin
  2 siblings, 0 replies; 8+ messages in thread
From: Hillf Danton @ 2014-05-01 14:38 UTC (permalink / raw)
  To: Kirill A. Shutemov
  Cc: Sasha Levin, Andrea Arcangeli, linux-mm, LKML, Dave Jones, Andrew Morton

hi all

On Wed, Apr 30, 2014 at 11:42 PM, Kirill A. Shutemov
<kirill@shutemov.name> wrote:
> On Tue, Apr 15, 2014 at 10:06:56PM -0400, Sasha Levin wrote:
>> Hi all,
>>
>> I often see hung task triggering in khugepaged within collapse_huge_page().
>>
>> I've initially assumed the case may be that the guests are too loaded and
>> the warning occurs because of load, but after increasing the timeout to
>> 1200 sec I still see the warning.
>
> I suspect it's race (although I didn't track down exact scenario) with
> __khugepaged_exit().
>
> Comment in __khugepaged_exit() says that khugepaged_test_exit() always
> called under mmap_sem:
>
> 2045 void __khugepaged_exit(struct mm_struct *mm)
> ...
> 2063         } else if (mm_slot) {
> 2064                 /*
> 2065                  * This is required to serialize against
> 2066                  * khugepaged_test_exit() (which is guaranteed to run
> 2067                  * under mmap sem read mode). Stop here (after we
> 2068                  * return all pagetables will be destroyed) until
> 2069                  * khugepaged has finished working on the pagetables
> 2070                  * under the mmap_sem.
> 2071                  */
> 2072                 down_write(&mm->mmap_sem);
> 2073                 up_write(&mm->mmap_sem);
> 2074         }
> 2075 }
>
> But this is not true. At least khugepaged_scan_mm_slot() calls it without
> the sem:
>
> 2566 static unsigned int khugepaged_scan_mm_slot(unsigned int pages,
> 2567                                             struct page **hpage)
> ...
> 2046 {
> 2047         struct mm_slot *mm_slot;
> 2048         int free = 0;
> 2049
> 2050         spin_lock(&khugepaged_mm_lock);
> 2051         mm_slot = get_mm_slot(mm);
> 2052         if (mm_slot && khugepaged_scan.mm_slot != mm_slot) {
> 2053                 hash_del(&mm_slot->hash);
> 2054                 list_del(&mm_slot->mm_node);
> 2055                 free = 1;
> 2056         }
> 2057         spin_unlock(&khugepaged_mm_lock);
> 2058
> 2059         if (free) {
> 2060                 clear_bit(MMF_VM_HUGEPAGE, &mm->flags);
> 2061                 free_mm_slot(mm_slot);
> 2062                 mmdrop(mm);
>
> Not sure yet if it's a real problem or not. Andrea, could you comment on
> this?
>
> Sasha, please try patch below.
>
This box is quite,

 CPU:  0 PID: 0 Comm: swapper/0
 CPU:  1 PID: 0 Comm: swapper/1
 CPU:  2 PID: 0 Comm: swapper/2
 CPU:  3 PID: 0 Comm: swapper/3
 CPU:  4 PID: 0 Comm: swapper/4
 CPU:  5 PID: 0 Comm: swapper/5
 CPU:  6 PID: 0 Comm: swapper/6
 CPU:  7 PID: 0 Comm: swapper/7
 CPU:  8 PID: 0 Comm: swapper/8
 CPU:  9 PID: 0 Comm: swapper/9
 CPU: 10 PID: 0 Comm: swapper/10
 CPU: 11 PID: 0 Comm: swapper/11
 CPU: 12 PID: 0 Comm: swapper/12
 CPU: 13 PID: 0 Comm: swapper/13
 CPU: 14 PID: 0 Comm: swapper/14
 CPU: 15 PID: 0 Comm: swapper/15
 CPU: 16 PID: 0 Comm: swapper/16
 CPU: 17 PID: 0 Comm: swapper/17
 CPU: 18 PID: 0 Comm: swapper/18
 CPU: 19 PID: 0 Comm: swapper/19
 CPU: 20 PID: 0 Comm: swapper/20
 CPU: 21 PID: 3540 Comm: khungtaskd
 CPU: 22 PID: 0 Comm: swapper/22
 CPU: 23 PID: 0 Comm: swapper/23

and lets make more noise.

Hillf
---

--- a/mm/huge_memory.c Thu May  1 22:20:20 2014
+++ b/mm/huge_memory.c Thu May  1 22:24:06 2014
@@ -2732,7 +2732,8 @@ static void khugepaged_wait_work(void)
  }

  if (khugepaged_enabled())
- wait_event_freezable(khugepaged_wait, khugepaged_wait_event());
+ wait_event_freezable_timeout(khugepaged_wait, khugepaged_wait_event(),
+ msecs_to_jiffies(2000));
 }

 static int khugepaged(void *none)
--

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: mm: hangs in collapse_huge_page
  2014-04-30 15:42 ` Kirill A. Shutemov
  2014-05-01 14:38   ` Hillf Danton
@ 2014-05-11  0:34   ` Sasha Levin
  2014-05-14 21:29     ` Kirill A. Shutemov
  2015-04-30 22:17   ` Sasha Levin
  2 siblings, 1 reply; 8+ messages in thread
From: Sasha Levin @ 2014-05-11  0:34 UTC (permalink / raw)
  To: Kirill A. Shutemov, Andrea Arcangeli
  Cc: linux-mm, LKML, Dave Jones, Andrew Morton

On 04/30/2014 11:42 AM, Kirill A. Shutemov wrote:
> On Tue, Apr 15, 2014 at 10:06:56PM -0400, Sasha Levin wrote:
>> > Hi all,
>> > 
>> > I often see hung task triggering in khugepaged within collapse_huge_page().
>> > 
>> > I've initially assumed the case may be that the guests are too loaded and
>> > the warning occurs because of load, but after increasing the timeout to
>> > 1200 sec I still see the warning.
> I suspect it's race (although I didn't track down exact scenario) with
> __khugepaged_exit().
> 
> Comment in __khugepaged_exit() says that khugepaged_test_exit() always
> called under mmap_sem:
> 
> 2045 void __khugepaged_exit(struct mm_struct *mm)
> ...
> 2063         } else if (mm_slot) {
> 2064                 /*
> 2065                  * This is required to serialize against
> 2066                  * khugepaged_test_exit() (which is guaranteed to run
> 2067                  * under mmap sem read mode). Stop here (after we
> 2068                  * return all pagetables will be destroyed) until
> 2069                  * khugepaged has finished working on the pagetables
> 2070                  * under the mmap_sem.
> 2071                  */
> 2072                 down_write(&mm->mmap_sem);
> 2073                 up_write(&mm->mmap_sem);
> 2074         }
> 2075 }
> 
> But this is not true. At least khugepaged_scan_mm_slot() calls it without
> the sem:
> 
> 2566 static unsigned int khugepaged_scan_mm_slot(unsigned int pages,
> 2567                                             struct page **hpage)
> ...
> 2046 {
> 2047         struct mm_slot *mm_slot;
> 2048         int free = 0;
> 2049 
> 2050         spin_lock(&khugepaged_mm_lock);
> 2051         mm_slot = get_mm_slot(mm);
> 2052         if (mm_slot && khugepaged_scan.mm_slot != mm_slot) {
> 2053                 hash_del(&mm_slot->hash);
> 2054                 list_del(&mm_slot->mm_node);
> 2055                 free = 1;
> 2056         }
> 2057         spin_unlock(&khugepaged_mm_lock);
> 2058 
> 2059         if (free) {
> 2060                 clear_bit(MMF_VM_HUGEPAGE, &mm->flags);
> 2061                 free_mm_slot(mm_slot);
> 2062                 mmdrop(mm);
> 
> Not sure yet if it's a real problem or not. Andrea, could you comment on
> this?
> 
> Sasha, please try patch below.

That patch really solved the problem for me, I didn't see a single hang
up until today. So I suspect that while that patch is good there is another
(smaller) case which may case a hang.

[ 6006.253399] INFO: task khugepaged:3814 blocked for more than 1200 seconds.
[ 6006.254711]       Tainted: G        W     3.15.0-rc4-next-20140508-sasha-00020-gec9304b-dirty #452
[ 6006.257591] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 6006.260710] khugepaged      D ffff8805bb7a64b8  4968  3814      2 0x00000000
[ 6006.263261]  ffff880291e61b48 0000000000000002 ffffffff955890d0 ffff8802927f0000
[ 6006.264986]  ffff880291e61fd8 00000000001d7840 00000000001d7840 00000000001d7840
[ 6006.265923]  ffff8805b040b000 ffff8802927f0000 ffff880291e61b38 ffff8802927f0000
[ 6006.267193] Call Trace:
[ 6006.267629] ? _raw_spin_unlock_irq (arch/x86/include/asm/paravirt.h:819 include/linux/spinlock_api_smp.h:168 kernel/locking/spinlock.c:199)
[ 6006.268673] schedule (kernel/sched/core.c:2765)
[ 6006.269674] rwsem_down_write_failed (kernel/locking/rwsem-xadd.c:289)
[ 6006.270998] ? get_parent_ip (kernel/sched/core.c:2485)
[ 6006.271984] call_rwsem_down_write_failed (arch/x86/lib/rwsem.S:106)
[ 6006.273240] ? khugepaged_scan_mm_slot (mm/huge_memory.c:1991 mm/huge_memory.c:2598)
[ 6006.274327] ? lock_contended (kernel/locking/lockdep.c:3734 kernel/locking/lockdep.c:3812)
[ 6006.275299] ? down_write (kernel/locking/rwsem.c:50 (discriminator 2))
[ 6006.276126] ? collapse_huge_page.isra.31 (mm/huge_memory.c:1991 mm/huge_memory.c:2385)
[ 6006.277281] collapse_huge_page.isra.31 (mm/huge_memory.c:1991 mm/huge_memory.c:2385)
[ 6006.278328] ? debug_smp_processor_id (lib/smp_processor_id.c:57)
[ 6006.279534] ? put_lock_stats.isra.12 (arch/x86/include/asm/preempt.h:98 kernel/locking/lockdep.c:254)
[ 6006.281314] ? khugepaged_scan_mm_slot (include/linux/spinlock.h:343 mm/huge_memory.c:2540 mm/huge_memory.c:2636)
[ 6006.282140] ? get_parent_ip (kernel/sched/core.c:2485)
[ 6006.283039] khugepaged_scan_mm_slot (mm/huge_memory.c:2640)
[ 6006.284074] khugepaged (include/linux/spinlock.h:343 mm/huge_memory.c:2720 mm/huge_memory.c:2753)
[ 6006.284986] ? bit_waitqueue (kernel/sched/wait.c:291)
[ 6006.285864] ? khugepaged_scan_mm_slot (mm/huge_memory.c:2746)
[ 6006.286897] kthread (kernel/kthread.c:210)
[ 6006.287705] ? kthread_create_on_node (kernel/kthread.c:176)
[ 6006.288796] ret_from_fork (arch/x86/kernel/entry_64.S:553)
[ 6006.289668] ? kthread_create_on_node (kernel/kthread.c:176)
[ 6006.291708] 1 lock held by khugepaged/3814:
[ 6006.292368] #0: (&mm->mmap_sem){++++++}, at: collapse_huge_page.isra.31 (mm/huge_memory.c:1991 mm/huge_memory.c:2385)


Thanks,
Sasha

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: mm: hangs in collapse_huge_page
  2014-05-11  0:34   ` Sasha Levin
@ 2014-05-14 21:29     ` Kirill A. Shutemov
  0 siblings, 0 replies; 8+ messages in thread
From: Kirill A. Shutemov @ 2014-05-14 21:29 UTC (permalink / raw)
  To: Sasha Levin; +Cc: Andrea Arcangeli, linux-mm, LKML, Dave Jones, Andrew Morton

On Sat, May 10, 2014 at 08:34:40PM -0400, Sasha Levin wrote:
> On 04/30/2014 11:42 AM, Kirill A. Shutemov wrote:
> > Sasha, please try patch below.
> 
> That patch really solved the problem for me, I didn't see a single hang
> up until today. So I suspect that while that patch is good there is another
> (smaller) case which may case a hang.

Looks like my patch didn't fix the problem but hide it. Most like due some
shift in timings because of additional lock/unlock.

I'll try to look more for a real issue.

> 
> [ 6006.253399] INFO: task khugepaged:3814 blocked for more than 1200 seconds.
> [ 6006.254711]       Tainted: G        W     3.15.0-rc4-next-20140508-sasha-00020-gec9304b-dirty #452
> [ 6006.257591] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 6006.260710] khugepaged      D ffff8805bb7a64b8  4968  3814      2 0x00000000
> [ 6006.263261]  ffff880291e61b48 0000000000000002 ffffffff955890d0 ffff8802927f0000
> [ 6006.264986]  ffff880291e61fd8 00000000001d7840 00000000001d7840 00000000001d7840
> [ 6006.265923]  ffff8805b040b000 ffff8802927f0000 ffff880291e61b38 ffff8802927f0000
> [ 6006.267193] Call Trace:
> [ 6006.267629] ? _raw_spin_unlock_irq (arch/x86/include/asm/paravirt.h:819 include/linux/spinlock_api_smp.h:168 kernel/locking/spinlock.c:199)
> [ 6006.268673] schedule (kernel/sched/core.c:2765)
> [ 6006.269674] rwsem_down_write_failed (kernel/locking/rwsem-xadd.c:289)
> [ 6006.270998] ? get_parent_ip (kernel/sched/core.c:2485)
> [ 6006.271984] call_rwsem_down_write_failed (arch/x86/lib/rwsem.S:106)
> [ 6006.273240] ? khugepaged_scan_mm_slot (mm/huge_memory.c:1991 mm/huge_memory.c:2598)
> [ 6006.274327] ? lock_contended (kernel/locking/lockdep.c:3734 kernel/locking/lockdep.c:3812)
> [ 6006.275299] ? down_write (kernel/locking/rwsem.c:50 (discriminator 2))
> [ 6006.276126] ? collapse_huge_page.isra.31 (mm/huge_memory.c:1991 mm/huge_memory.c:2385)
> [ 6006.277281] collapse_huge_page.isra.31 (mm/huge_memory.c:1991 mm/huge_memory.c:2385)
> [ 6006.278328] ? debug_smp_processor_id (lib/smp_processor_id.c:57)
> [ 6006.279534] ? put_lock_stats.isra.12 (arch/x86/include/asm/preempt.h:98 kernel/locking/lockdep.c:254)
> [ 6006.281314] ? khugepaged_scan_mm_slot (include/linux/spinlock.h:343 mm/huge_memory.c:2540 mm/huge_memory.c:2636)
> [ 6006.282140] ? get_parent_ip (kernel/sched/core.c:2485)
> [ 6006.283039] khugepaged_scan_mm_slot (mm/huge_memory.c:2640)
> [ 6006.284074] khugepaged (include/linux/spinlock.h:343 mm/huge_memory.c:2720 mm/huge_memory.c:2753)
> [ 6006.284986] ? bit_waitqueue (kernel/sched/wait.c:291)
> [ 6006.285864] ? khugepaged_scan_mm_slot (mm/huge_memory.c:2746)
> [ 6006.286897] kthread (kernel/kthread.c:210)
> [ 6006.287705] ? kthread_create_on_node (kernel/kthread.c:176)
> [ 6006.288796] ret_from_fork (arch/x86/kernel/entry_64.S:553)
> [ 6006.289668] ? kthread_create_on_node (kernel/kthread.c:176)
> [ 6006.291708] 1 lock held by khugepaged/3814:
> [ 6006.292368] #0: (&mm->mmap_sem){++++++}, at: collapse_huge_page.isra.31 (mm/huge_memory.c:1991 mm/huge_memory.c:2385)
> 
> 
> Thanks,
> Sasha
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/

-- 
 Kirill A. Shutemov

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: mm: hangs in collapse_huge_page
  2014-04-30 15:42 ` Kirill A. Shutemov
  2014-05-01 14:38   ` Hillf Danton
  2014-05-11  0:34   ` Sasha Levin
@ 2015-04-30 22:17   ` Sasha Levin
  2015-04-30 22:24     ` Kirill A. Shutemov
  2 siblings, 1 reply; 8+ messages in thread
From: Sasha Levin @ 2015-04-30 22:17 UTC (permalink / raw)
  To: Kirill A. Shutemov, Andrea Arcangeli
  Cc: linux-mm, LKML, Dave Jones, Andrew Morton

On 04/30/2014 11:42 AM, Kirill A. Shutemov wrote:
> diff --git a/mm/huge_memory.c b/mm/huge_memory.c
> index b4b1feba6472..1c6ace5207b9 100644
> --- a/mm/huge_memory.c
> +++ b/mm/huge_memory.c
> @@ -1986,6 +1986,8 @@ static void insert_to_mm_slots_hash(struct mm_struct *mm,
>  
>  static inline int khugepaged_test_exit(struct mm_struct *mm)
>  {
> +       VM_BUG_ON(!rwsem_is_locked(&mm->mmap_sem) &&
> +                       !spin_is_locked(&khugepaged_mm_lock));
>         return atomic_read(&mm->mm_users) == 0;
>  }

I've managed to hit this during testing:

[ 8048.304275] kernel BUG at mm/huge_memory.c:2060!
[ 8048.305878] invalid opcode: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC KASAN
[ 8048.307479] Modules linked in: quota_v2 quota_tree xfs libcrc32c x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel ast kvm ttm drm_kms_helper crct10dif_pclmul crc32_pclmul drm ghash_clmulni_intel aesni_
intel aes_x86_64 lrw glue_helper ablk_helper cryptd joydev i2c_algo_bit sb_edac syscopyarea sysfillrect edac_core sysimgblt lpc_ich ipmi_si ipmi_msghandler ioatdma shpchp mac_hid btrfs xor mlx4_en vxlan raid6_pq
hid_generic ixgbe mlx4_core usbhid hid dca megaraid_sas ahci ptp libahci pps_core mdio
[ 8048.314422] CPU: 31 PID: 13065 Comm: thp01 Not tainted 4.1.0-rc1-next-20150430+ #8
[ 8048.316215] Hardware name: Oracle Corporation OVCA X3-2             /ASSY,MOTHERBOARD,1U   , BIOS 17021300 06/19/2012
[ 8048.318070] task: ffff8837ba9b3b40 ti: ffff8837bfcf8000 task.ti: ffff8837bfcf8000
[ 8048.319941] RIP: __khugepaged_enter (mm/huge_memory.c:2059 mm/huge_memory.c:2075)
[ 8048.321856] RSP: 0018:ffff8837bfcff8a0  EFLAGS: 00010246
[ 8048.323752] RAX: 000000000000d800 RBX: ffff8837b8314b00 RCX: 0000000000000000
[ 8048.325665] RDX: 00000000000000d8 RSI: 00000000000000fc RDI: ffff8837b8314ba8
[ 8048.327570] RBP: ffff8837bfcff8e0 R08: ffff8837df1e5040 R09: ffffed06f4b701b8
[ 8048.329486] R10: 000000002a82d01f R11: 1ffff106f82c0f77 R12: ffff8837a5b80d98
[ 8048.331414] R13: ffff8837c6c58b80 R14: ffff8837c6c58bd0 R15: 0000000000000000
[ 8048.333357] FS:  00007f238e593740(0000) GS:ffff8837df1c0000(0000) knlGS:0000000000000000
[ 8048.335329] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 8048.337304] CR2: 00007f8a8d2c4740 CR3: 00000037c7c10000 CR4: 00000000000407e0
[ 8048.339369] Stack:
[ 8048.341343]  0000000000000000 00000007fffffffe ffff883700000001 ffff8837b8314b00
[ 8048.343382]  00007fffffc00000 ffff8837c6c58b80 ffff8837c6c58bd0 0000000000000000
[ 8048.345421]  ffff8837bfcff910 ffffffff815cfa60 ffff8837bfcff910 ffffffff81249cd3
[ 8048.347473] Call Trace:
[ 8048.349502] khugepaged_enter_vma_merge (include/linux/khugepaged.h:46 mm/huge_memory.c:2115)
[ 8048.351584] ? up_write (kernel/locking/rwsem.h:9 kernel/locking/rwsem.c:93)
[ 8048.353654] expand_downwards (mm/mmap.c:2278)
[ 8048.355719] ? __mem_cgroup_count_vm_event (mm/memcontrol.c:1156)
[ 8048.357791] handle_mm_fault (mm/memory.c:2673 mm/memory.c:3250 mm/memory.c:3371 mm/memory.c:3400)
[ 8048.359886] ? follow_page_pte (mm/gup.c:48)
[ 8048.361952] ? __pmd_alloc (mm/memory.c:3382)
[ 8048.364020] ? _raw_spin_unlock (./arch/x86/include/asm/preempt.h:95 include/linux/spinlock_api_smp.h:154 kernel/locking/spinlock.c:183)
[ 8048.366083] ? follow_page_pte (mm/gup.c:125)
[ 8048.368139] ? follow_page_mask (mm/gup.c:209)
[ 8048.370181] __get_user_pages (mm/gup.c:285 mm/gup.c:477)
[ 8048.372214] ? follow_page_mask (mm/gup.c:420)
[ 8048.374242] ? might_fault (./arch/x86/include/asm/current.h:14 mm/memory.c:3762)
[ 8048.376269] get_user_pages (mm/gup.c:818)
[ 8048.378295] copy_strings.isra.20 (fs/exec.c:197 fs/exec.c:510)
[ 8048.380392] ? count.isra.18.constprop.36 (fs/exec.c:454)
[ 8048.382439] ? copy_strings_kernel (fs/exec.c:556)
[ 8048.384464] do_execveat_common.isra.32 (fs/exec.c:1577)
[ 8048.386469] ? do_execveat_common.isra.32 (include/linux/spinlock.h:312 fs/exec.c:1263 fs/exec.c:1518)
[ 8048.388448] ? prepare_bprm_creds (fs/exec.c:1475)
[ 8048.390395] ? kmem_cache_alloc (include/trace/events/kmem.h:53 mm/slub.c:2524)
[ 8048.392309] ? getname_flags (fs/namei.c:135)
[ 8048.394187] ? up_read (./arch/x86/include/asm/rwsem.h:156 kernel/locking/rwsem.c:81)
[ 8048.396027] ? getname_flags (fs/namei.c:146)
[ 8048.397869] SyS_execve (fs/exec.c:1701)
[ 8048.399715] stub_execve (arch/x86/kernel/entry_64.S:510)
[ 8048.401482] ? system_call_fastpath (arch/x86/kernel/entry_64.S:261)
[ 8048.403207] Code: 1f 84 00 00 00 00 00 b8 f4 ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f b7 05 a9 fb db 01 0f b6 d4 31 d0 a8 fe 0f 85 3e fe ff ff <0f> 0b 66 2e 0f 1f 84 00 00 00 00 00 48 89 df e8 18 88 f6 ff 0f
All code
========
   0:   1f                      (bad)
   1:   84 00                   test   %al,(%rax)
   3:   00 00                   add    %al,(%rax)
   5:   00 00                   add    %al,(%rax)
   7:   b8 f4 ff ff ff          mov    $0xfffffff4,%eax
   c:   c3                      retq
   d:   66 2e 0f 1f 84 00 00    nopw   %cs:0x0(%rax,%rax,1)
  14:   00 00 00
  17:   0f b7 05 a9 fb db 01    movzwl 0x1dbfba9(%rip),%eax        # 0x1dbfbc7
  1e:   0f b6 d4                movzbl %ah,%edx
  21:   31 d0                   xor    %edx,%eax
  23:   a8 fe                   test   $0xfe,%al
  25:   0f 85 3e fe ff ff       jne    0xfffffffffffffe69
  2b:*  0f 0b                   ud2             <-- trapping instruction
  2d:   66 2e 0f 1f 84 00 00    nopw   %cs:0x0(%rax,%rax,1)
  34:   00 00 00
  37:   48 89 df                mov    %rbx,%rdi
  3a:   e8 18 88 f6 ff          callq  0xfffffffffff68857
  3f:

Code starting with the faulting instruction
===========================================
   0:   0f 0b                   ud2
   2:   66 2e 0f 1f 84 00 00    nopw   %cs:0x0(%rax,%rax,1)
   9:   00 00 00
   c:   48 89 df                mov    %rbx,%rdi
   f:   e8 18 88 f6 ff          callq  0xfffffffffff6882c
  14:
[ 8048.406837] RIP __khugepaged_enter (mm/huge_memory.c:2059 mm/huge_memory.c:2075)
[ 8048.408525]  RSP <ffff8837bfcff8a0>


Thanks,
Sasha

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: mm: hangs in collapse_huge_page
  2015-04-30 22:17   ` Sasha Levin
@ 2015-04-30 22:24     ` Kirill A. Shutemov
  0 siblings, 0 replies; 8+ messages in thread
From: Kirill A. Shutemov @ 2015-04-30 22:24 UTC (permalink / raw)
  To: Sasha Levin; +Cc: Andrea Arcangeli, linux-mm, LKML, Dave Jones, Andrew Morton

On Thu, Apr 30, 2015 at 06:17:34PM -0400, Sasha Levin wrote:
> On 04/30/2014 11:42 AM, Kirill A. Shutemov wrote:
> > diff --git a/mm/huge_memory.c b/mm/huge_memory.c
> > index b4b1feba6472..1c6ace5207b9 100644
> > --- a/mm/huge_memory.c
> > +++ b/mm/huge_memory.c
> > @@ -1986,6 +1986,8 @@ static void insert_to_mm_slots_hash(struct mm_struct *mm,
> >  
> >  static inline int khugepaged_test_exit(struct mm_struct *mm)
> >  {
> > +       VM_BUG_ON(!rwsem_is_locked(&mm->mmap_sem) &&
> > +                       !spin_is_locked(&khugepaged_mm_lock));
> >         return atomic_read(&mm->mm_users) == 0;
> >  }
> 
> I've managed to hit this during testing:
> 
> [ 8048.304275] kernel BUG at mm/huge_memory.c:2060!
> [ 8048.305878] invalid opcode: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC KASAN
> [ 8048.307479] Modules linked in: quota_v2 quota_tree xfs libcrc32c x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel ast kvm ttm drm_kms_helper crct10dif_pclmul crc32_pclmul drm ghash_clmulni_intel aesni_
> intel aes_x86_64 lrw glue_helper ablk_helper cryptd joydev i2c_algo_bit sb_edac syscopyarea sysfillrect edac_core sysimgblt lpc_ich ipmi_si ipmi_msghandler ioatdma shpchp mac_hid btrfs xor mlx4_en vxlan raid6_pq
> hid_generic ixgbe mlx4_core usbhid hid dca megaraid_sas ahci ptp libahci pps_core mdio
> [ 8048.314422] CPU: 31 PID: 13065 Comm: thp01 Not tainted 4.1.0-rc1-next-20150430+ #8
> [ 8048.316215] Hardware name: Oracle Corporation OVCA X3-2             /ASSY,MOTHERBOARD,1U   , BIOS 17021300 06/19/2012
> [ 8048.318070] task: ffff8837ba9b3b40 ti: ffff8837bfcf8000 task.ti: ffff8837bfcf8000
> [ 8048.319941] RIP: __khugepaged_enter (mm/huge_memory.c:2059 mm/huge_memory.c:2075)
> [ 8048.321856] RSP: 0018:ffff8837bfcff8a0  EFLAGS: 00010246
> [ 8048.323752] RAX: 000000000000d800 RBX: ffff8837b8314b00 RCX: 0000000000000000
> [ 8048.325665] RDX: 00000000000000d8 RSI: 00000000000000fc RDI: ffff8837b8314ba8
> [ 8048.327570] RBP: ffff8837bfcff8e0 R08: ffff8837df1e5040 R09: ffffed06f4b701b8
> [ 8048.329486] R10: 000000002a82d01f R11: 1ffff106f82c0f77 R12: ffff8837a5b80d98
> [ 8048.331414] R13: ffff8837c6c58b80 R14: ffff8837c6c58bd0 R15: 0000000000000000
> [ 8048.333357] FS:  00007f238e593740(0000) GS:ffff8837df1c0000(0000) knlGS:0000000000000000
> [ 8048.335329] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 8048.337304] CR2: 00007f8a8d2c4740 CR3: 00000037c7c10000 CR4: 00000000000407e0
> [ 8048.339369] Stack:
> [ 8048.341343]  0000000000000000 00000007fffffffe ffff883700000001 ffff8837b8314b00
> [ 8048.343382]  00007fffffc00000 ffff8837c6c58b80 ffff8837c6c58bd0 0000000000000000
> [ 8048.345421]  ffff8837bfcff910 ffffffff815cfa60 ffff8837bfcff910 ffffffff81249cd3
> [ 8048.347473] Call Trace:
> [ 8048.349502] khugepaged_enter_vma_merge (include/linux/khugepaged.h:46 mm/huge_memory.c:2115)
> [ 8048.351584] ? up_write (kernel/locking/rwsem.h:9 kernel/locking/rwsem.c:93)
> [ 8048.353654] expand_downwards (mm/mmap.c:2278)
> [ 8048.355719] ? __mem_cgroup_count_vm_event (mm/memcontrol.c:1156)
> [ 8048.357791] handle_mm_fault (mm/memory.c:2673 mm/memory.c:3250 mm/memory.c:3371 mm/memory.c:3400)
> [ 8048.359886] ? follow_page_pte (mm/gup.c:48)
> [ 8048.361952] ? __pmd_alloc (mm/memory.c:3382)
> [ 8048.364020] ? _raw_spin_unlock (./arch/x86/include/asm/preempt.h:95 include/linux/spinlock_api_smp.h:154 kernel/locking/spinlock.c:183)
> [ 8048.366083] ? follow_page_pte (mm/gup.c:125)
> [ 8048.368139] ? follow_page_mask (mm/gup.c:209)
> [ 8048.370181] __get_user_pages (mm/gup.c:285 mm/gup.c:477)
> [ 8048.372214] ? follow_page_mask (mm/gup.c:420)
> [ 8048.374242] ? might_fault (./arch/x86/include/asm/current.h:14 mm/memory.c:3762)
> [ 8048.376269] get_user_pages (mm/gup.c:818)

We call get_user_pages() here without ->mmap_sem taken. It violates
get_user_pages() interface but should not cause a problem because we don't
have concurency for the mm yet -- it's exec path.

Not sure if we should correct it.

Hm. __bprm_mm_init() in the same exec path takes ->mmap_sem.

Any comments?

> [ 8048.378295] copy_strings.isra.20 (fs/exec.c:197 fs/exec.c:510)
> [ 8048.380392] ? count.isra.18.constprop.36 (fs/exec.c:454)
> [ 8048.382439] ? copy_strings_kernel (fs/exec.c:556)
> [ 8048.384464] do_execveat_common.isra.32 (fs/exec.c:1577)
> [ 8048.386469] ? do_execveat_common.isra.32 (include/linux/spinlock.h:312 fs/exec.c:1263 fs/exec.c:1518)
> [ 8048.388448] ? prepare_bprm_creds (fs/exec.c:1475)
> [ 8048.390395] ? kmem_cache_alloc (include/trace/events/kmem.h:53 mm/slub.c:2524)
> [ 8048.392309] ? getname_flags (fs/namei.c:135)
> [ 8048.394187] ? up_read (./arch/x86/include/asm/rwsem.h:156 kernel/locking/rwsem.c:81)
> [ 8048.396027] ? getname_flags (fs/namei.c:146)
> [ 8048.397869] SyS_execve (fs/exec.c:1701)
> [ 8048.399715] stub_execve (arch/x86/kernel/entry_64.S:510)
> [ 8048.401482] ? system_call_fastpath (arch/x86/kernel/entry_64.S:261)
> [ 8048.403207] Code: 1f 84 00 00 00 00 00 b8 f4 ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f b7 05 a9 fb db 01 0f b6 d4 31 d0 a8 fe 0f 85 3e fe ff ff <0f> 0b 66 2e 0f 1f 84 00 00 00 00 00 48 89 df e8 18 88 f6 ff 0f
> All code
> ========
>    0:   1f                      (bad)
>    1:   84 00                   test   %al,(%rax)
>    3:   00 00                   add    %al,(%rax)
>    5:   00 00                   add    %al,(%rax)
>    7:   b8 f4 ff ff ff          mov    $0xfffffff4,%eax
>    c:   c3                      retq
>    d:   66 2e 0f 1f 84 00 00    nopw   %cs:0x0(%rax,%rax,1)
>   14:   00 00 00
>   17:   0f b7 05 a9 fb db 01    movzwl 0x1dbfba9(%rip),%eax        # 0x1dbfbc7
>   1e:   0f b6 d4                movzbl %ah,%edx
>   21:   31 d0                   xor    %edx,%eax
>   23:   a8 fe                   test   $0xfe,%al
>   25:   0f 85 3e fe ff ff       jne    0xfffffffffffffe69
>   2b:*  0f 0b                   ud2             <-- trapping instruction
>   2d:   66 2e 0f 1f 84 00 00    nopw   %cs:0x0(%rax,%rax,1)
>   34:   00 00 00
>   37:   48 89 df                mov    %rbx,%rdi
>   3a:   e8 18 88 f6 ff          callq  0xfffffffffff68857
>   3f:
> 
> Code starting with the faulting instruction
> ===========================================
>    0:   0f 0b                   ud2
>    2:   66 2e 0f 1f 84 00 00    nopw   %cs:0x0(%rax,%rax,1)
>    9:   00 00 00
>    c:   48 89 df                mov    %rbx,%rdi
>    f:   e8 18 88 f6 ff          callq  0xfffffffffff6882c
>   14:
> [ 8048.406837] RIP __khugepaged_enter (mm/huge_memory.c:2059 mm/huge_memory.c:2075)
> [ 8048.408525]  RSP <ffff8837bfcff8a0>
> 
> 
> Thanks,
> Sasha
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/

-- 
 Kirill A. Shutemov

^ permalink raw reply	[flat|nested] 8+ messages in thread

end of thread, other threads:[~2015-04-30 22:24 UTC | newest]

Thread overview: 8+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2014-04-16  2:06 mm: hangs in collapse_huge_page Sasha Levin
2014-04-24 16:46 ` Sasha Levin
2014-04-30 15:42 ` Kirill A. Shutemov
2014-05-01 14:38   ` Hillf Danton
2014-05-11  0:34   ` Sasha Levin
2014-05-14 21:29     ` Kirill A. Shutemov
2015-04-30 22:17   ` Sasha Levin
2015-04-30 22:24     ` Kirill A. Shutemov

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).