[Qemu-stable] high i/o waits and 100% khugepaged with 4.4.4

[Stefan Priebe - Profihost AG]

Hello list,

while running vanilla 4.4.4 in guest and host.

I'm seeing pretty often 50% I/O waits while doing no disk I/O (storage
isn't even local) and 100% khugepaged. Guests are very laggy.

Example traces from guests:
[34578.974225] INFO: rcu_sched self-detected stall on CPU
[34578.974435]  0-...: (1 ticks this GP) idle=6d3/140000000000001/0
softirq=1100707/1100707 fqs=0
[34578.974570]   (t=64960 jiffies g=1097919 c=1097918 q=0)
[34578.974693] rcu_sched kthread starved for 64960 jiffies! g1097919
c1097918 f0x0 s3 ->state=0x1
[34578.974861] Task dump for CPU 0:
[34578.974970] mysqld          R  running task        0  7782   6301
0x00080000
[34578.975111]  ffffffffb4c54980 ffff88013fc03d68 ffffffffb40aeeaf
0000000000000000
[34578.975257]  ffffffffb4c54980 ffff88013fc03d88 ffffffffb40b177d
0000000000000087
[34578.975395]  0000000000000000 ffff88013fc03db8 ffffffffb40da823
ffff88013fc15f80
[34578.975529] Call Trace:
[34578.975617]  <IRQ>  [<ffffffffb40aeeaf>] sched_show_task+0xaf/0x110
[34578.975782]  [<ffffffffb40b177d>] dump_cpu_task+0x3d/0x50
[34578.975927]  [<ffffffffb40da823>] rcu_dump_cpu_stacks+0x83/0xb0
[34578.976074]  [<ffffffffb40de9db>] rcu_check_callbacks+0x51b/0x7e0
[34578.976208]  [<ffffffffb40eb79c>] ? update_wall_time+0x23c/0x660
[34578.976331]  [<ffffffffb40cac51>] ?
__raw_callee_save___pv_queued_spin_unlock+0x11/0x20
[34578.976466]  [<ffffffffb40f39f0>] ? tick_nohz_handler+0xa0/0xa0
[34578.976586]  [<ffffffffb40e4978>] update_process_times+0x38/0x70
[34578.976701]  [<ffffffffb40f348e>] tick_sched_handle.isra.15+0x2e/0x70
[34578.976827]  [<ffffffffb40f3a38>] tick_sched_timer+0x48/0x80
[34578.976955]  [<ffffffffb40e51d3>] __hrtimer_run_queues+0xf3/0x260
[34578.977072]  [<ffffffffb40e59c8>] hrtimer_interrupt+0xa8/0x1a0
[34578.977197]  [<ffffffffb403da59>] local_apic_timer_interrupt+0x39/0x60
[34578.977328]  [<ffffffffb403e465>] smp_apic_timer_interrupt+0x45/0x60
[34578.977482]  [<ffffffffb46b19a7>] apic_timer_interrupt+0x87/0x90
[34578.977601]  <EOI>
[34592.724028] hrtimer: interrupt took 5213197 ns
[119322.536307] INFO: rcu_sched detected stalls on CPUs/tasks:
[119322.536550]         1-...: (2804647 GPs behind) idle=1f0/0/0 softirq=7/8 
fqs=0
[119322.536785]         (detected by 0, t=85017 jiffies, g=3903684, c=3903683, 
q=0)
[119322.536932] Task dump for CPU 1:
[119322.537052] httpd           R  running task        0  3007      1
0x00080008
[119322.537213]  ffffffffb46ac94c ffff8800baa0b888 ffffffffb40e56d4
000000000000db00
[119322.537362]  ffff8800baa0c000 00000000000f423f ffff8800baa0b8c0
00000000000f423f
[119322.537533]  0000000000000000 ffff8800baa0b8a8 ffffffffb40e57dd
0000000000000000
[119322.541018] Call Trace:
[119322.542498]  [<ffffffffb46ac94c>] ? __schedule+0x34c/0x9a1
[119322.543969]  [<ffffffffb40e56d4>] ? hrtimer_try_to_cancel+0x24/0x110
[119322.545487]  [<ffffffffb40e57dd>] ? hrtimer_cancel+0x1d/0x30
[119322.560265]  [<ffffffffb46afd8c>] ?
schedule_hrtimeout_range_clock+0xbc/0x140
[119322.561573]  [<ffffffffb40e4c20>] ? update_rmtp+0x70/0x70
[119322.563051]  [<ffffffffb46afd80>] ?
schedule_hrtimeout_range_clock+0xb0/0x140
[119322.564621]  [<ffffffffb46afe23>] ? schedule_hrtimeout_range+0x13/0x20
[119322.566140]  [<ffffffffb41dc349>] ? poll_schedule_timeout+0x49/0x70
[119322.567643]  [<ffffffffb41dce0e>] ? do_select+0x71e/0x800
[119322.569121]  [<ffffffffb4159d2f>] ? __alloc_pages_nodemask+0x12f/0x240
[119322.570669]  [<ffffffffb40cac51>] ?
__raw_callee_save___pv_queued_spin_unlock+0x11/0x20
[119322.595353]  [<ffffffffb43d8958>] ? find_next_bit+0x18/0x20
[119322.596828]  [<ffffffffb43c3d90>] ? cpumask_any_but+0x30/0x40
[119322.598271]  [<ffffffffb40566b5>] ? flush_tlb_page+0x45/0xa0
[119322.599732]  [<ffffffffb40cac51>] ?
__raw_callee_save___pv_queued_spin_unlock+0x11/0x20
[119322.601260]  [<ffffffffb41dd0c7>] ? core_sys_select+0x1d7/0x2e0
[119322.602647]  [<ffffffffb4084b24>] ? wait_consider_task+0xe4/0xaf0
[119322.604431]  [<ffffffffb40cac51>] ?
__raw_callee_save___pv_queued_spin_unlock+0x11/0x20
[119322.605956]  [<ffffffffb404b58e>] ? kvm_clock_read+0x1e/0x20
[119322.607397]  [<ffffffffb404b599>] ? kvm_clock_get_cycles+0x9/0x10
[119322.608926]  [<ffffffffb40ea94e>] ? ktime_get_ts64+0x4e/0xf0
[119322.610355]  [<ffffffffb41dc6ce>] ? poll_select_set_timeout+0x6e/0x90
[119322.611806]  [<ffffffffb41dd284>] ? SyS_select+0xb4/0x100
[119322.613379]  [<ffffffffb46b0c6e>] ? entry_SYSCALL_64_fastpath+0x12/0x71
[119322.616261] rcu_sched kthread starved for 85017 jiffies! g3903684
c3903683 f0x0 s3 ->state=0x1
[122912.736848] INFO: rcu_sched detected stalls on CPUs/tasks:
[122912.740498]         1-...: (0 ticks this GP) idle=692/0/0 softirq=23/23 
fqs=0
[122912.741872]         (detected by 0, t=78530 jiffies, g=4046836, c=4046835, 
q=0)
[122912.742965] Task dump for CPU 1:
[122912.743852] swapper/1       R  running task        0     0      1
0x00080000
[122912.744782]  7fffffffffffffff ffff88013abd3e58 ffffffffb4d2c4e0
0000000000000000
[122912.745722]  0000000000000000 ffff88013abd0000 ffffffffb40db815
ffff88013abd3e88
[122912.746673]  ffffffffb400f7be ffffffffb4d2c4e0 0000000000000000
ffff88013abd3e98
[122912.747608] Call Trace:
[122912.778023]  [<ffffffffb40db815>] ?
rcu_eqs_enter_common.isra.44+0x45/0x70
[122912.779562]  [<ffffffffb400f7be>] ? default_idle+0x1e/0xe0
[122912.780551]  [<ffffffffb400fe5f>] ? arch_cpu_idle+0xf/0x20
[122912.782185]  [<ffffffffb40c4672>] ? default_idle_call+0x32/0x40
[122912.783894]  [<ffffffffb40c48f8>] ? cpu_startup_entry+0x278/0x350
[122912.785521]  [<ffffffffb40f08bc>] ?
clockevents_register_device+0xdc/0x140
[122912.787265]  [<ffffffffb403c280>] ? start_secondary+0x150/0x180
[122912.799987] rcu_sched kthread starved for 78530 jiffies! g4046836
c4046835 f0x0 s3 ->state=0x1
[134835.866122] INFO: rcu_sched detected stalls on CPUs/tasks:
[134835.870001]         (detected by 0, t=102857 jiffies, g=4534359, c=4534358,
q=0)
[134835.898377] All QSes seen, last rcu_sched kthread activity 92217
(4429503836-4429411619), jiffies_till_next_fqs=3, root ->qsmask 0x0
[134835.903445] postimap.pl     R  running task        0 21675  21551
0x00080000
[134835.905545]  ffffffffb4c54980 ffff88013fc03db8 ffffffffb40aeeaf
ffff88013fc15f80
[134835.910218]  ffffffffb4c54980 ffff88013fc03e38 ffffffffb40dec96
0000000000000000
[134835.914329]  ffffffffb40eb79c 0000000000000000 0000000000453057
ffff88013fc15f80
[134835.921559] Call Trace:
[134835.933856]  <IRQ>  [<ffffffffb40aeeaf>] sched_show_task+0xaf/0x110
[134835.935565]  [<ffffffffb40dec96>] rcu_check_callbacks+0x7d6/0x7e0
[134835.937192]  [<ffffffffb40eb79c>] ? update_wall_time+0x23c/0x660
[134835.968907]  [<ffffffffb40f39f0>] ? tick_nohz_handler+0xa0/0xa0
[134835.970542]  [<ffffffffb40e4978>] update_process_times+0x38/0x70
[134835.972226]  [<ffffffffb40f348e>] tick_sched_handle.isra.15+0x2e/0x70
[134835.974367]  [<ffffffffb40f3a38>] tick_sched_timer+0x48/0x80
[134835.975954]  [<ffffffffb40e51d3>] __hrtimer_run_queues+0xf3/0x260
[134835.977576]  [<ffffffffb40e59c8>] hrtimer_interrupt+0xa8/0x1a0
[134835.979197]  [<ffffffffb403da59>] local_apic_timer_interrupt+0x39/0x60
[134835.981159]  [<ffffffffb403e465>] smp_apic_timer_interrupt+0x45/0x60
[134835.982764]  [<ffffffffb46b19a7>] apic_timer_interrupt+0x87/0x90
[134835.984254]  <EOI>  [<ffffffffb43d079a>] ? copy_page+0xa/0x10
[134835.985880]  [<ffffffffb417d5cc>] ? wp_page_copy.isra.56+0xec/0x4d0
[134835.987472]  [<ffffffffb40cac51>] ?
__raw_callee_save___pv_queued_spin_unlock+0x11/0x20
[134835.989087]  [<ffffffffb417e619>] do_wp_page+0x99/0x630
[134835.990678]  [<ffffffffb418b9f9>] ? page_add_new_anon_rmap+0x89/0xf0
[134836.005064]  [<ffffffffb40cac51>] ?
__raw_callee_save___pv_queued_spin_unlock+0x11/0x20
[134836.006713]  [<ffffffffb4180c54>] __handle_mm_fault+0xb54/0x11f0
[134836.008325]  [<ffffffffb41813cf>] handle_mm_fault+0xdf/0x180
[134836.009925]  [<ffffffffb404f324>] __do_page_fault+0x164/0x380
[134836.011379]  [<ffffffffb404f650>] trace_do_page_fault+0x50/0x140
[134836.012951]  [<ffffffffb414ebe5>] ? __context_tracking_exit+0x15/0xc0
[134836.015158]  [<ffffffffb404b14e>] do_async_page_fault+0x1e/0xc0
[134836.016894]  [<ffffffffb400261f>] ? enter_from_user_mode+0x1f/0x50
[134836.018691]  [<ffffffffb46b2b28>] async_page_fault+0x28/0x30
[134836.020359] rcu_sched kthread starved for 92217 jiffies! g4534359
c4534358 f0x2 s3 ->state=0x100
[137471.816832] INFO: rcu_sched detected stalls on CPUs/tasks:
[137471.857390]         (detected by 0, t=85069 jiffies, g=4627783, c=4627782, 
q=0)
[137471.859052] All QSes seen, last rcu_sched kthread activity 85069
(4432139793-4432054724), jiffies_till_next_fqs=3, root ->qsmask 0x0
[137471.862446] httpd           R  running task        0  3007      1
0x00080000
[137471.864229]  ffffffffb4c54980 ffff88013fc03db8 ffffffffb40aeeaf
ffff88013fc15f80
[137471.866044]  ffffffffb4c54980 ffff88013fc03e38 ffffffffb40dec96
0000000000000000
[137471.882408]  ffffffffb40eb79c 0000000000000000 0000000000469d47
ffff88013fc15f80
[137471.884110] Call Trace:
[137471.885795]  <IRQ>  [<ffffffffb40aeeaf>] sched_show_task+0xaf/0x110
[137471.888522]  [<ffffffffb40dec96>] rcu_check_callbacks+0x7d6/0x7e0
[137471.890338]  [<ffffffffb40eb79c>] ? update_wall_time+0x23c/0x660
[137471.892050]  [<ffffffffb40f39f0>] ? tick_nohz_handler+0xa0/0xa0
[137471.893864]  [<ffffffffb40e4978>] update_process_times+0x38/0x70
[137471.895762]  [<ffffffffb40f348e>] tick_sched_handle.isra.15+0x2e/0x70
[137471.898501]  [<ffffffffb40f3a38>] tick_sched_timer+0x48/0x80
[137471.920446]  [<ffffffffb40e51d3>] __hrtimer_run_queues+0xf3/0x260
[137471.922108]  [<ffffffffb40e59c8>] hrtimer_interrupt+0xa8/0x1a0
[137471.923962]  [<ffffffffb403da59>] local_apic_timer_interrupt+0x39/0x60
[137471.926198]  [<ffffffffb403e465>] smp_apic_timer_interrupt+0x45/0x60
[137471.928561]  [<ffffffffb46b19a7>] apic_timer_interrupt+0x87/0x90
[137471.930448]  <EOI>
[137471.930494] rcu_sched kthread starved for 85069 jiffies! g4627783
c4627782 f0x2 s3 ->state=0x0
[167969.408935] INFO: rcu_sched detected stalls on CPUs/tasks:
[167969.413404]         (detected by 0, t=96556 jiffies, g=5879146, c=5879145, 
q=0)
[167969.414996] All QSes seen, last rcu_sched kthread activity 96556
(4462637574-4462541018), jiffies_till_next_fqs=3, root ->qsmask 0x0
[167969.418087] errorlogs.pl    R  running task        0 28042  27632
0x00080008
[167969.420832]  ffffffffb4c54980 ffff88013fc03db8 ffffffffb40aeeaf
ffff88013fc15f80
[167969.422695]  ffffffffb4c54980 ffff88013fc03e38 ffffffffb40dec96
0000000000000000
[167969.424535]  ffffffffb40eb79c 0000000000000000 000000000059b56a
ffff88013fc15f80
[167969.426385] Call Trace:
[167969.447415]  <IRQ>  [<ffffffffb40aeeaf>] sched_show_task+0xaf/0x110
[167969.449630]  [<ffffffffb40dec96>] rcu_check_callbacks+0x7d6/0x7e0
[167969.451648]  [<ffffffffb40eb79c>] ? update_wall_time+0x23c/0x660
[167969.453370]  [<ffffffffb40f39f0>] ? tick_nohz_handler+0xa0/0xa0
[167969.455248]  [<ffffffffb40e4978>] update_process_times+0x38/0x70
[167969.506267]  [<ffffffffb40f348e>] tick_sched_handle.isra.15+0x2e/0x70
[167969.508297]  [<ffffffffb40f3a38>] tick_sched_timer+0x48/0x80
[167969.510087]  [<ffffffffb40e51d3>] __hrtimer_run_queues+0xf3/0x260
[167969.511933]  [<ffffffffb40e59c8>] hrtimer_interrupt+0xa8/0x1a0
[167969.514086]  [<ffffffffb403da59>] local_apic_timer_interrupt+0x39/0x60
[167969.516147]  [<ffffffffb403e465>] smp_apic_timer_interrupt+0x45/0x60
[167969.518207]  [<ffffffffb46b19a7>] apic_timer_interrupt+0x87/0x90
[167969.520245]  <EOI>  [<ffffffffb407e45f>] ?
exit_to_usermode_loop+0x35/0x95
[167969.521974]  [<ffffffffb400298c>] prepare_exit_to_usermode+0x2c/0x40
[167969.529171]  [<ffffffffb46b172a>] retint_user+0x8/0x13
[167969.541963] rcu_sched kthread starved for 96556 jiffies! g5879146
c5879145 f0x2 s3 ->state=0x0
[168305.292972] INFO: rcu_sched detected stalls on CPUs/tasks:
[168305.296690]         1-...: (3688 GPs behind) idle=779/140000000000001/0
softirq=53/54 fqs=148
[168305.298696]         (detected by 0, t=108507 jiffies, g=5882834, c=5882833,
q=0)
[168305.300470] Task dump for CPU 1:
[168305.302430] cache           R  running task        0 28352   8202
0x00080000
[168305.332720]  ffffffffb40db815 0000000000000001 ffff880078600000
ffff880078603ec8
[168305.334690]  0000000000000001 00007faac90fc000 00007faac90fc000
00007faac90fb000
[168305.336768]  ffffffffb40db88a ffff880078603ef8 ffffffffb40de21e
ffff880078603f18
[168305.338859] Call Trace:
[168305.344683]  [<ffffffffb40db815>] ?
rcu_eqs_enter_common.isra.44+0x45/0x70
[168305.346720]  [<ffffffffb40db88a>] ? rcu_eqs_enter.isra.45+0x4a/0x50
[168305.349834]  [<ffffffffb40de21e>] ? rcu_user_enter+0xe/0x10
[168305.351878]  [<ffffffffb414ed3c>] ? __context_tracking_enter+0x5c/0x100
[168305.353859]  [<ffffffffb4002985>] ? prepare_exit_to_usermode+0x25/0x40
[168305.356386]  [<ffffffffb46b0dcc>] ? int_ret_from_sys_call+0x25/0x8f
[168305.358407] rcu_sched kthread starved for 108063 jiffies! g5882834
c5882833 f0x0 s3 ->state=0x0
[168415.226802] INFO: rcu_sched self-detected stall on CPU
[168415.232744]         0-...: (1 ticks this GP) idle=ed5/140000000000001/0
softirq=5900968/5900968 fqs=0
[168415.234596]          (t=74832 jiffies g=5884663 c=5884662 q=0)
[168415.236529] rcu_sched kthread starved for 74832 jiffies! g5884663
c5884662 f0x0 s3 ->state=0x1
[168415.263182] Task dump for CPU 0:
[168415.265311] mysqld          R  running task        0  7782   6301
0x00080000
[168415.267510]  ffffffffb4c54980 ffff88013fc03d68 ffffffffb40aeeaf
0000000000000000
[168415.269905]  ffffffffb4c54980 ffff88013fc03d88 ffffffffb40b177d
0000000000000087
[168415.271675]  0000000000000000 ffff88013fc03db8 ffffffffb40da823
ffff88013fc15f80
[168415.273493] Call Trace:
[168415.275222]  <IRQ>  [<ffffffffb40aeeaf>] sched_show_task+0xaf/0x110
[168415.277104]  [<ffffffffb40b177d>] dump_cpu_task+0x3d/0x50
[168415.278945]  [<ffffffffb40da823>] rcu_dump_cpu_stacks+0x83/0xb0
[168415.280790]  [<ffffffffb40de9db>] rcu_check_callbacks+0x51b/0x7e0
[168415.286748]  [<ffffffffb40eb79c>] ? update_wall_time+0x23c/0x660
[168415.288463]  [<ffffffffb40cac51>] ?
__raw_callee_save___pv_queued_spin_unlock+0x11/0x20
[168415.290221]  [<ffffffffb40f39f0>] ? tick_nohz_handler+0xa0/0xa0
[168415.292032]  [<ffffffffb40e4978>] update_process_times+0x38/0x70
[168415.293965]  [<ffffffffb40f348e>] tick_sched_handle.isra.15+0x2e/0x70
[168415.319215]  [<ffffffffb40f3a38>] tick_sched_timer+0x48/0x80
[168415.321025]  [<ffffffffb40e51d3>] __hrtimer_run_queues+0xf3/0x260
[168415.322646]  [<ffffffffb40e59c8>] hrtimer_interrupt+0xa8/0x1a0
[168415.324319]  [<ffffffffb403da59>] local_apic_timer_interrupt+0x39/0x60
[168415.326172]  [<ffffffffb403e465>] smp_apic_timer_interrupt+0x45/0x60
[168415.328087]  [<ffffffffb46b19a7>] apic_timer_interrupt+0x87/0x90
[168415.342099]  <EOI>
[174655.145591] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 23s!
[kworker/0:1:34]
[174664.287031] Modules linked in: netconsole ipt_REJECT nf_reject_ipv4
xt_multiport iptable_filter ip_tables x_tables i2c_piix4 i2c_core
virtio_balloon shpchp button btrfs xor raid6_pq usbhid sg ata_generic
sd_mod floppy virtio_net virtio_scsi uhci_hcd ehci_hcd ata_piix usbcore
usb_common virtio_pci
[174664.291943] CPU: 0 PID: 34 Comm: kworker/0:1 Not tainted 4.4.4+4-ph #1
[174664.293948] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS rel-1.8.2-0-g33fbe13 by qemu-project.org 04/01/2014
[174664.296103] Workqueue: events nohz_kick_work_fn
[174664.298210] task: ffff8800bb97a500 ti: ffff8800bb9ac000 task.ti:
ffff8800bb9ac000
[174664.300258] RIP: 0010:[<ffffffffb40f916e>]  [<ffffffffb40f916e>]
smp_call_function_single+0x7e/0x110
[174664.302703] RSP: 0018:ffff8800bb9afd38  EFLAGS: 00000202
[174664.304796] RAX: 0000000000000001 RBX: 0000000000000001 RCX:
0000000000000000
[174664.306927] RDX: 0000000000000000 RSI: ffff88013fc16500 RDI:
0000000000000001
[174664.309005] RBP: ffff8800bb9afd78 R08: ffffffffb4d2c4e0 R09:
0000000000000000
[174664.311108] R10: 0000000000000001 R11: 0000000000000000 R12:
ffffffffb40f3410
[174664.313172] R13: 0000000000000000 R14: 0000000000000000 R15:
ffff88013b0055f8
[174664.315215] FS:  0000000000000000(0000) GS:ffff88013fc00000(0000)
knlGS:0000000000000000
[174664.317272] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[174664.319437] CR2: 00007f8d31bca140 CR3: 0000000067ca8000 CR4:
00000000001406f0
[174664.321582] Stack:
[174664.323333]  ffff8800bb9afdc8 ffff8800bb9afdc0 0000000000000000
0000000000000000
[174664.325303]  0000000000000000 0000000000000003 0000000000000000
ffffffffb40f3410
[174664.327245]  ffff8800bb9afdc8 ffffffffb40f94fb ffff880000000001
0000000000000000
[174664.329093] Call Trace:
[174664.330918]  [<ffffffffb40f3410>] ? nohz_full_kick_work_func+0x10/0x10
[174664.332761]  [<ffffffffb40f94fb>] smp_call_function_many+0x21b/0x260
[174664.334577]  [<ffffffffb40f41bb>] tick_nohz_full_kick_all+0x2b/0x40
[174664.336347]  [<ffffffffb40e82de>] nohz_kick_work_fn+0xe/0x10
[174664.338128]  [<ffffffffb409a6ad>] process_one_work+0x14d/0x3e0
[174664.339878]  [<ffffffffb409aa9a>] worker_thread+0x11a/0x440
[174664.341728]  [<ffffffffb46ac94c>] ? __schedule+0x34c/0x9a1
[174664.343471]  [<ffffffffb409a980>] ? process_scheduled_works+0x40/0x40
[174664.345282]  [<ffffffffb40a0b49>] kthread+0xc9/0xe0
[174664.347052]  [<ffffffffb40a0a80>] ? kthread_stop+0x100/0x100
[174664.348722]  [<ffffffffb46b0fcf>] ret_from_fork+0x3f/0x70
[174664.350407]  [<ffffffffb40a0a80>] ? kthread_stop+0x100/0x100
[174664.352117] Code: c0 74 0c 9c 58 0f 1f 44 00 00 f6 c4 02 74 62 85 c9
75 39 48 c7 c6 00 65 01 00 65 48 03 35 b3 0f f1 4b 8b 46 18 a8 01 74 09
f3 90 <8b> 46 18 a8 01 75 f7 83 4e 18 01 48 89 d1 89 df 4c 89 e2 e8 2a
[174673.096580] INFO: rcu_sched detected stalls on CPUs/tasks:
[174673.097711]         1-...: (3024 GPs behind) idle=0d3/140000000000000/0
softirq=100/102 fqs=410
[174673.098797]         (detected by 0, t=60016 jiffies, g=6158787, c=6158786, 
q=0)
[174673.099890] Task dump for CPU 1:
[174673.100977] cache           R  running task        0  4867   8202
0x0008000c
[174673.102094]  ffff8800787c8f00 ffff88002ad17ee8 ffffffffb404f324
00007ffc57ac18d0
[174673.103229]  0000000000000002 ffff8800787c8f68 0000005500000000
ffff880032e02e34
[174673.104370]  ffff88002ad17f58 0000000000000007 00007fc6ebffe6c8
0000000000000001
[174673.105516] Call Trace:
[174673.106649]  [<ffffffffb404f324>] ? __do_page_fault+0x164/0x380
[174673.107784]  [<ffffffffb404f650>] ? trace_do_page_fault+0x50/0x140
[174673.108917]  [<ffffffffb414ec38>] ? __context_tracking_exit+0x68/0xc0
[174673.110018]  [<ffffffffb404b14e>] ? do_async_page_fault+0x1e/0xc0
[174673.111090]  [<ffffffffb400261f>] ? enter_from_user_mode+0x1f/0x50
[174673.112129]  [<ffffffffb46b2b28>] ? async_page_fault+0x28/0x30
[174673.113159] rcu_sched kthread starved for 41595 jiffies! g6158787
c6158786 f0x0 s3 ->state=0x0
[177010.777871] INFO: rcu_sched detected stalls on CPUs/tasks:
[177010.779917]         (detected by 1, t=95835 jiffies, g=6209468, c=6209467, 
q=0)
[177010.780936] All QSes seen, last rcu_sched kthread activity 93300
(4471678997-4471585697), jiffies_till_next_fqs=3, root ->qsmask 0x0
[177010.782969] swapper/1       R  running task        0     0      1
0x00080000
[177010.784008]  ffffffffb4c54980 ffff88013fd03db8 ffffffffb40aeeaf
ffff88013fd15f80
[177010.785071]  ffffffffb4c54980 ffff88013fd03e38 ffffffffb40dec96
0000000000000000
[177010.786126]  0000000000000002 0000000000000000 00000000005ebfbc
ffff88013fd15f80
[177010.787187] Call Trace:
[177010.788232]  <IRQ>  [<ffffffffb40aeeaf>] sched_show_task+0xaf/0x110
[177010.789329]  [<ffffffffb40dec96>] rcu_check_callbacks+0x7d6/0x7e0
[177010.790388]  [<ffffffffb40f39f0>] ? tick_nohz_handler+0xa0/0xa0
[177013.928795]  [<ffffffffb40e4978>] update_process_times+0x38/0x70
[177013.930670]  [<ffffffffb40f348e>] tick_sched_handle.isra.15+0x2e/0x70
[177013.932532]  [<ffffffffb40f3a38>] tick_sched_timer+0x48/0x80
[177013.934239]  [<ffffffffb40e51d3>] __hrtimer_run_queues+0xf3/0x260
[177013.935939]  [<ffffffffb40e59c8>] hrtimer_interrupt+0xa8/0x1a0
[177013.937650]  [<ffffffffb403da59>] local_apic_timer_interrupt+0x39/0x60
[177013.939272]  [<ffffffffb403e465>] smp_apic_timer_interrupt+0x45/0x60
[177013.940950]  [<ffffffffb46b19a7>] apic_timer_interrupt+0x87/0x90
[177013.942545]  <EOI>  [<ffffffffb404b936>] ? native_safe_halt+0x6/0x10
[177013.944211]  [<ffffffffb40db815>] ?
rcu_eqs_enter_common.isra.44+0x45/0x70
[177013.945831]  [<ffffffffb400f7be>] default_idle+0x1e/0xe0
[177013.947604]  [<ffffffffb400fe5f>] arch_cpu_idle+0xf/0x20
[177013.949723]  [<ffffffffb40c4672>] default_idle_call+0x32/0x40
[177013.951523]  [<ffffffffb40c48f8>] cpu_startup_entry+0x278/0x350
[177013.953365]  [<ffffffffb40f08bc>] ?
clockevents_register_device+0xdc/0x140
[177013.955637]  [<ffffffffb403c280>] start_secondary+0x150/0x180
[177013.957552] rcu_sched kthread starved for 93300 jiffies! g6209468
c6209467 f0x2 s3 ->state=0x100
[180287.076703] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 22s!
[mysqld:7909]
[180287.078785] Modules linked in: netconsole ipt_REJECT nf_reject_ipv4
xt_multiport iptable_filter ip_tables x_tables i2c_piix4 i2c_core
virtio_balloon shpchp button btrfs xor raid6_pq usbhid sg ata_generic
sd_mod floppy virtio_net virtio_scsi uhci_hcd ehci_hcd ata_piix usbcore
usb_common virtio_pci
[180287.082177] CPU: 0 PID: 7909 Comm: mysqld Tainted: G             L
4.4.4+4-ph #1
[180287.083252] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS rel-1.8.2-0-g33fbe13 by qemu-project.org 04/01/2014
[180287.084361] task: ffff88008108ca00 ti: ffff880093ec0000 task.ti:
ffff880093ec0000
[180287.085473] RIP: 0010:[<ffffffffb40f91aa>]  [<ffffffffb40f91aa>]
smp_call_function_single+0xba/0x110
[180287.086627] RSP: 0018:ffff880093ec3c08  EFLAGS: 00000202
[180287.087746] RAX: 0000000000000000 RBX: 0000000000000001 RCX:
0000000000000830
[180287.088872] RDX: 0000000000000001 RSI: 0000000000000002 RDI:
0000000000000292
[180287.089978] RBP: ffff880093ec3c48 R08: 0000000000000002 R09:
0000000000000000
[180287.091075] R10: 0000000000000000 R11: 0000000000000246 R12:
ffffffffb4056200
[180287.092174] R13: ffff880093ec3cb0 R14: 0000000000000000 R15:
ffff88003798f3d8
[180287.093271] FS:  00007efff4a12700(0000) GS:ffff88013fc00000(0000)
knlGS:0000000000000000
[180287.094385] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[180287.095500] CR2: 00007effee4b9648 CR3: 00000000374eb000 CR4:
00000000001406f0
[180287.096633] Stack:
[180287.097737]  ffff880093ec3c68 ffffffffb41ff693 0000000000000000
ffffffffb4056200
[180287.098871]  ffff880093ec3cb0 0000000000000003 0000000000000001
ffffffffb4056200
[180287.099991]  ffff880093ec3c98 ffffffffb40f94fb 0000000000000001
0000000000000000
[180287.101082] Call Trace:
[180287.102137]  [<ffffffffb41ff693>] ? generic_write_end+0x83/0xb0
[180287.103198]  [<ffffffffb4056200>] ? do_flush_tlb_all+0x50/0x50
[180287.104239]  [<ffffffffb4056200>] ? do_flush_tlb_all+0x50/0x50
[180287.105274]  [<ffffffffb40f94fb>] smp_call_function_many+0x21b/0x260
[180287.106301]  [<ffffffffb40563d5>] native_flush_tlb_others+0x45/0xb0
[180287.107316]  [<ffffffffb4056573>] flush_tlb_mm_range+0x73/0x170
[180287.108330]  [<ffffffffb417cf9b>] tlb_flush_mmu_tlbonly+0xbb/0xf0
[180287.109332]  [<ffffffffb417dad6>] tlb_flush_mmu+0x16/0x30
[180287.110325]  [<ffffffffb417db04>] tlb_finish_mmu+0x14/0x40
[180287.111313]  [<ffffffffb417fda3>] zap_page_range+0xc3/0x100
[180287.112306]  [<ffffffffb43307fe>] ? xfs_file_write_iter+0x9e/0x160
[180287.113301]  [<ffffffffb4191f23>] SyS_madvise+0x1d3/0x750
[180287.114297]  [<ffffffffb414ebe5>] ? __context_tracking_exit+0x15/0xc0
[180287.115295]  [<ffffffffb4002711>] ?
syscall_trace_enter_phase1+0xc1/0x110
[180287.116304]  [<ffffffffb46b0c6e>] entry_SYSCALL_64_fastpath+0x12/0x71
[180287.117299] Code: 89 e2 e8 2a fe ff ff 48 83 c4 30 5b 41 5c 5d c3 48
8d 75 d0 48 89 d1 89 df 4c 89 e2 e8 10 fe ff ff 8b 55 e8 83 e2 01 74 de
f3 90 <8b> 55 e8 83 e2 01 75 f6 eb d2 8b 05 1e bd e8 00 85 c0 75 94 80
[184001.330633] INFO: rcu_sched detected stalls on CPUs/tasks:
[184001.334236]         (detected by 0, t=69401 jiffies, g=6441059, c=6441058, 
q=0)
[184001.336284] All QSes seen, last rcu_sched kthread activity 61291
(4478669591-4478608300), jiffies_till_next_fqs=3, root ->qsmask 0x0
[184001.340892] qpsmtpd-prefork R  running task        0  8115      1
0x00080008
[184001.405216]  ffffffffb4c54980 ffff88013fc03db8 ffffffffb40aeeaf
ffff88013fc15f80
[184001.407315]  ffffffffb4c54980 ffff88013fc03e38 ffffffffb40dec96
0000000000000000
[184001.409349]  ffffffffb40eb79c 0000000000000000 0000000000624863
ffff88013fc15f80
[184001.411426] Call Trace:
[184001.414412]  <IRQ>  [<ffffffffb40aeeaf>] sched_show_task+0xaf/0x110
[184001.417144]  [<ffffffffb40dec96>] rcu_check_callbacks+0x7d6/0x7e0
[184001.419168]  [<ffffffffb40eb79c>] ? update_wall_time+0x23c/0x660
[184001.421118]  [<ffffffffb40f39f0>] ? tick_nohz_handler+0xa0/0xa0
[184001.426614]  [<ffffffffb40e4978>] update_process_times+0x38/0x70
[184001.428529]  [<ffffffffb40f348e>] tick_sched_handle.isra.15+0x2e/0x70
[184001.430329]  [<ffffffffb40f3a38>] tick_sched_timer+0x48/0x80
[184001.432138]  [<ffffffffb40e51d3>] __hrtimer_run_queues+0xf3/0x260
[184001.434904]  [<ffffffffb40e59c8>] hrtimer_interrupt+0xa8/0x1a0
[184001.436684]  [<ffffffffb403da59>] local_apic_timer_interrupt+0x39/0x60
[184001.438394]  [<ffffffffb403e465>] smp_apic_timer_interrupt+0x45/0x60
[184001.440226]  [<ffffffffb46b19a7>] apic_timer_interrupt+0x87/0x90
[184001.441957]  <EOI>  [<ffffffffb407e45f>] ?
exit_to_usermode_loop+0x35/0x95
[184001.443841]  [<ffffffffb400298c>] prepare_exit_to_usermode+0x2c/0x40
[184001.445525]  [<ffffffffb46b172a>] retint_user+0x8/0x13
[184001.453298] rcu_sched kthread starved for 61291 jiffies! g6441059
c6441058 f0x2 s3 ->state=0x0
[184826.350576] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 31s!
[imap-login:4977]
[184826.355131] Modules linked in: netconsole ipt_REJECT nf_reject_ipv4
xt_multiport iptable_filter ip_tables x_tables i2c_piix4 i2c_core
virtio_balloon shpchp button btrfs xor raid6_pq usbhid sg ata_generic
sd_mod floppy virtio_net virtio_scsi uhci_hcd ehci_hcd ata_piix usbcore
usb_common virtio_pci
[184826.382655] CPU: 0 PID: 4977 Comm: imap-login Tainted: G
 L  4.4.4+4-ph #1
[184826.384775] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS rel-1.8.2-0-g33fbe13 by qemu-project.org 04/01/2014
[184826.386927] task: ffff8800ae8a4a00 ti: ffff880037940000 task.ti:
ffff880037940000
[184826.389028] RIP: 0010:[<ffffffffb407e45f>]  [<ffffffffb407e45f>]
exit_to_usermode_loop+0x35/0x95
[184826.391300] RSP: 0000:ffff880037943f18  EFLAGS: 00000286
[184826.393373] RAX: 0000000000000096 RBX: 0000000000080008 RCX:
ffffffffb4c0f4c0
[184826.395266] RDX: ffff88013fc0ca70 RSI: 0000000000080008 RDI:
ffff880037943f58
[184826.397055] RBP: ffff880037943f38 R08: ffff88013fc153f8 R09:
ffff8800ae8a4a00
[184826.398805] R10: 0000000005dd1c00 R11: 0000000000000000 R12:
ffff880037943f58
[184826.401053] R13: ffff880037940000 R14: ffff8800ae8a4a00 R15:
0000559d76dfdc18
[184826.402906] FS:  00007f7dbee94700(0000) GS:ffff88013fc00000(0000)
knlGS:0000000000000000
[184826.404987] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[184826.406973] CR2: ffffffffff600400 CR3: 00000000378e1000 CR4:
00000000001406f0
[184826.408879] Stack:
[184826.411567]  0000559d76f214b0 0000000000000003 00007f7dbea7dc50
0000000000000000
[184826.413434]  ffff880037943f48 ffffffffb400298c 0000000000000003
ffffffffb46b172a
[184826.415575]  0000559d76dfdc18 0000000000000000 00007f7dbea7dc50
0000000000000003
[184826.417425] Call Trace:
[184826.419262]  [<ffffffffb400298c>] prepare_exit_to_usermode+0x2c/0x40
[184826.423694]  [<ffffffffb46b172a>] retint_user+0x8/0x13
[184826.425828] Code: 56 65 4c 8b 34 25 80 ad 00 00 41 55 65 4c 8b 2c 25
84 28 01 00 41 54 49 81 ed 00 40 00 00 49 89 fc 53 89 f3 fb 66 0f 1f 44
00 00 <f6> c3 08 74 05 e8 e7 eb 62 00 f6 c3 04 74 08 4c 89 e7 e8 5a 6d
[184972.665760] INFO: rcu_sched detected stalls on CPUs/tasks:
[184972.669324]         (detected by 0, t=61041 jiffies, g=6465105, c=6465104, 
q=0)
[184972.671231] All QSes seen, last rcu_sched kthread activity 49624
(4479640932-4479591308), jiffies_till_next_fqs=3, root ->qsmask 0x0
[184972.675288] qpsmtpd p:25 wa R  running task        0 29491   8090
0x00080008
[184972.677441]  ffffffffb4c54980 ffff88013fc03db8 ffffffffb40aeeaf
ffff88013fc15f80
[184972.679540]  ffffffffb4c54980 ffff88013fc03e38 ffffffffb40dec96
0000000000000000
[184972.681497]  ffffffffb40eb79c 0000000000000000 000000000062a651
ffff88013fc15f80
[184972.683562] Call Trace:
[184972.685581]  <IRQ>  [<ffffffffb40aeeaf>] sched_show_task+0xaf/0x110
[184972.692341]  [<ffffffffb40dec96>] rcu_check_callbacks+0x7d6/0x7e0
[184972.694446]  [<ffffffffb40eb79c>] ? update_wall_time+0x23c/0x660
[184972.696634]  [<ffffffffb40f39f0>] ? tick_nohz_handler+0xa0/0xa0
[184972.698784]  [<ffffffffb40e4978>] update_process_times+0x38/0x70
[184972.700997]  [<ffffffffb40f348e>] tick_sched_handle.isra.15+0x2e/0x70
[184972.703128]  [<ffffffffb40f3a38>] tick_sched_timer+0x48/0x80
[184972.705399]  [<ffffffffb40e51d3>] __hrtimer_run_queues+0xf3/0x260
[184972.707370]  [<ffffffffb40e59c8>] hrtimer_interrupt+0xa8/0x1a0
[184972.711724]  [<ffffffffb403da59>] local_apic_timer_interrupt+0x39/0x60
[184972.713779]  [<ffffffffb403e465>] smp_apic_timer_interrupt+0x45/0x60
[184972.716056]  [<ffffffffb46b19a7>] apic_timer_interrupt+0x87/0x90
[184972.743139]  <EOI>  [<ffffffffb407e45f>] ?
exit_to_usermode_loop+0x35/0x95
[184972.745322]  [<ffffffffb400298c>] prepare_exit_to_usermode+0x2c/0x40
[184972.751738]  [<ffffffffb46b172a>] retint_user+0x8/0x13
[184972.753678] rcu_sched kthread starved for 49624 jiffies! g6465105
c6465104 f0x2 s3 ->state=0x0
[185128.047621] INFO: rcu_sched detected stalls on CPUs/tasks:
[185128.049719]         (detected by 0, t=85222 jiffies, g=6467929, c=6467928, 
q=0)
[185128.051563] All QSes seen, last rcu_sched kthread activity 85222
(4479796314-4479711092), jiffies_till_next_fqs=3, root ->qsmask 0x0
[185128.055036] mysql           R  running task        0 19050  19048
0x00080008
[185128.056631]  ffffffffb4c54980 ffff88013fc03db8 ffffffffb40aeeaf
ffff88013fc15f80
[185128.058237]  ffffffffb4c54980 ffff88013fc03e38 ffffffffb40dec96
0000000000000000
[185128.060195]  ffffffffb40eb79c 0000000000000000 000000000062b159
ffff88013fc15f80
[185128.061831] Call Trace:
[185128.063904]  <IRQ>  [<ffffffffb40aeeaf>] sched_show_task+0xaf/0x110
[185128.065776]  [<ffffffffb40dec96>] rcu_check_callbacks+0x7d6/0x7e0
[185128.067589]  [<ffffffffb40eb79c>] ? update_wall_time+0x23c/0x660
[185128.069405]  [<ffffffffb40f39f0>] ? tick_nohz_handler+0xa0/0xa0
[185128.071114]  [<ffffffffb40e4978>] update_process_times+0x38/0x70
[185128.074093]  [<ffffffffb40f348e>] tick_sched_handle.isra.15+0x2e/0x70
[185128.075843]  [<ffffffffb40f3a38>] tick_sched_timer+0x48/0x80
[185128.077920]  [<ffffffffb40e51d3>] __hrtimer_run_queues+0xf3/0x260
[185128.079691]  [<ffffffffb40e59c8>] hrtimer_interrupt+0xa8/0x1a0
[185128.081439]  [<ffffffffb403da59>] local_apic_timer_interrupt+0x39/0x60
[185128.083531]  [<ffffffffb403e465>] smp_apic_timer_interrupt+0x45/0x60
[185128.085297]  [<ffffffffb46b19a7>] apic_timer_interrupt+0x87/0x90
[185128.086948]  <EOI>  [<ffffffffb43d079a>] ? copy_page+0xa/0x10
[185128.088700]  [<ffffffffb417d5cc>] ? wp_page_copy.isra.56+0xec/0x4d0
[185128.090368]  [<ffffffffb40cac51>] ?
__raw_callee_save___pv_queued_spin_unlock+0x11/0x20
[185128.092195]  [<ffffffffb417e619>] do_wp_page+0x99/0x630
[185128.093803]  [<ffffffffb43d8958>] ? find_next_bit+0x18/0x20
[185128.095414]  [<ffffffffb4180c54>] __handle_mm_fault+0xb54/0x11f0
[185128.097168]  [<ffffffffb41813cf>] handle_mm_fault+0xdf/0x180
[185128.098605]  [<ffffffffb404f324>] __do_page_fault+0x164/0x380
[185128.100193]  [<ffffffffb404f650>] trace_do_page_fault+0x50/0x140
[185128.101897]  [<ffffffffb414ebe5>] ? __context_tracking_exit+0x15/0xc0
[185128.103613]  [<ffffffffb404b14e>] do_async_page_fault+0x1e/0xc0
[185128.105325]  [<ffffffffb400261f>] ? enter_from_user_mode+0x1f/0x50
[185128.106806]  [<ffffffffb46b2b28>] async_page_fault+0x28/0x30
[185128.108273] rcu_sched kthread starved for 85222 jiffies! g6467929
c6467928 f0x2 s3 ->state=0x0
[185726.121092] INFO: rcu_sched detected stalls on CPUs/tasks:
[185726.124251]         1-...: (7056 GPs behind) idle=7e8/0/0 softirq=359/360
fqs=0
[185726.125772]         (detected by 0, t=72077 jiffies, g=6481102, c=6481101, 
q=0)
[185726.127205] Task dump for CPU 1:
[185726.128616] authscanclient  R  running task        0  2707      1
0x00080008
[185726.130063]  ffffffffb46ac94c ffff88013abc8000 ffff8800b9f30000
000000000000db00
[185726.131523]  ffff8800b8e8c000 ffff8800b9f30000 ffff8800b8e8bd70
ffff8800b8e8bd18
[185726.192287]  ffffc9000071b480 ffff8800b8e8bc68 ffffffffb46ad089
ffff8800b8e8bd18
[185726.193938] Call Trace:
[185726.195660]  [<ffffffffb46ad089>] schedule+0x39/0x80
[185726.197354]  [<ffffffffb40f5461>] futex_wait_queue_me+0xd1/0x130
[185726.199311]  [<ffffffffb40cac51>] ?
__raw_callee_save___pv_queued_spin_unlock+0x11/0x20
[185726.201194]  [<ffffffffb40f6755>] futex_wait+0x195/0x2b0
[185726.202837]  [<ffffffffb40e4c20>] ? update_rmtp+0x70/0x70
[185726.204395]  [<ffffffffb40f543f>] ? futex_wait_queue_me+0xaf/0x130
[185726.206142]  [<ffffffffb40f8285>] do_futex+0x115/0x520
[185726.207831]  [<ffffffffb40cac51>] ?
__raw_callee_save___pv_queued_spin_unlock+0x11/0x20
[185726.209641]  [<ffffffffb40b28af>] ? vtime_account_user+0x5f/0x70
[185726.211280]  [<ffffffffb40f8728>] SyS_futex+0x98/0x1a0
[185726.212963]  [<ffffffffb400261f>] ? enter_from_user_mode+0x1f/0x50
[185726.214639]  [<ffffffffb46b0c6e>] entry_SYSCALL_64_fastpath+0x12/0x71
[185726.216332] rcu_sched kthread starved for 72077 jiffies! g6481102
c6481101 f0x0 s3 ->state=0x1
[185847.242124] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 22s!
[kworker/0:1:34]
[185847.243092] Modules linked in: netconsole ipt_REJECT nf_reject_ipv4
xt_multiport iptable_filter ip_tables x_tables i2c_piix4 i2c_core
virtio_balloon shpchp button btrfs xor raid6_pq usbhid sg ata_generic
sd_mod floppy virtio_net virtio_scsi uhci_hcd ehci_hcd ata_piix usbcore
usb_common virtio_pci
[185847.246197] CPU: 0 PID: 34 Comm: kworker/0:1 Tainted: G
L  4.4.4+4-ph #1
[185847.247198] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS rel-1.8.2-0-g33fbe13 by qemu-project.org 04/01/2014
[185847.248248] Workqueue: events nohz_kick_work_fn
[185847.249299] task: ffff8800bb97a500 ti: ffff8800bb9ac000 task.ti:
ffff8800bb9ac000
[185847.250361] RIP: 0010:[<ffffffffb40f916e>]  [<ffffffffb40f916e>]
smp_call_function_single+0x7e/0x110
[185847.251455] RSP: 0018:ffff8800bb9afd38  EFLAGS: 00000202
[185847.252538] RAX: 0000000000000001 RBX: 0000000000000001 RCX:
0000000000000000
[185847.253632] RDX: 0000000000000000 RSI: ffff88013fc16500 RDI:
0000000000000001
[185847.254723] RBP: ffff8800bb9afd78 R08: ffffffffb4d2c4e0 R09:
0000000000000000
[185847.255801] R10: 0000000000000001 R11: 0000000000000000 R12:
ffffffffb40f3410
[185847.256877] R13: 0000000000000000 R14: 0000000000000000 R15:
ffff88013b0055f8
[185847.257939] FS:  0000000000000000(0000) GS:ffff88013fc00000(0000)
knlGS:0000000000000000
[185847.259021] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[185847.260098] CR2: ffffffffff600400 CR3: 0000000078673000 CR4:
00000000001406f0
[185847.261193] Stack:
[185847.262274]  ffff8800bb9afdc8 ffff8800bb9afdc0 0000000000000000
0000000000000000
[185847.263400]  0000000000000000 0000000000000003 0000000000000000
ffffffffb40f3410
[185847.264540]  ffff8800bb9afdc8 ffffffffb40f94fb ffff880000000001
0000000000000000
[185847.265680] Call Trace:
[185847.266794]  [<ffffffffb40f3410>] ? nohz_full_kick_work_func+0x10/0x10
[185847.267930]  [<ffffffffb40f94fb>] smp_call_function_many+0x21b/0x260
[185847.269059]  [<ffffffffb40f41bb>] tick_nohz_full_kick_all+0x2b/0x40
[185847.270162]  [<ffffffffb40e82de>] nohz_kick_work_fn+0xe/0x10
[185847.271259]  [<ffffffffb409a6ad>] process_one_work+0x14d/0x3e0
[185847.272362]  [<ffffffffb409aa9a>] worker_thread+0x11a/0x440
[185847.273440]  [<ffffffffb46ac94c>] ? __schedule+0x34c/0x9a1
[185847.274518]  [<ffffffffb409a980>] ? process_scheduled_works+0x40/0x40
[185847.275587]  [<ffffffffb40a0b49>] kthread+0xc9/0xe0
[185847.276646]  [<ffffffffb40a0a80>] ? kthread_stop+0x100/0x100
[185847.277719]  [<ffffffffb46b0fcf>] ret_from_fork+0x3f/0x70
[185847.278768]  [<ffffffffb40a0a80>] ? kthread_stop+0x100/0x100
[185847.279813] Code: c0 74 0c 9c 58 0f 1f 44 00 00 f6 c4 02 74 62 85 c9
75 39 48 c7 c6 00 65 01 00 65 48 03 35 b3 0f f1 4b 8b 46 18 a8 01 74 09
f3 90 <8b> 46 18 a8 01 75 f7 83 4e 18 01 48 89 d1 89 df 4c 89 e2 e8 2a
[185875.069239] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 22s!
[kworker/0:1:34]
[185875.070388] Modules linked in: netconsole ipt_REJECT nf_reject_ipv4
xt_multiport iptable_filter ip_tables x_tables i2c_piix4 i2c_core
virtio_balloon shpchp button btrfs xor raid6_pq usbhid sg ata_generic
sd_mod floppy virtio_net virtio_scsi uhci_hcd ehci_hcd ata_piix usbcore
usb_common virtio_pci
[185875.073948] CPU: 0 PID: 34 Comm: kworker/0:1 Tainted: G
L  4.4.4+4-ph #1
[185875.075133] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS rel-1.8.2-0-g33fbe13 by qemu-project.org 04/01/2014
[185875.076353] Workqueue: events nohz_kick_work_fn
[185875.077567] task: ffff8800bb97a500 ti: ffff8800bb9ac000 task.ti:
ffff8800bb9ac000
[185875.078802] RIP: 0010:[<ffffffffc03a2b53>]  [<ffffffffc03a2b53>]
virtnet_receive+0x2c3/0x890 [virtio_net]
[185875.080078] RSP: 0018:ffff88013fc03d88  EFLAGS: 00010246
[185875.081322] RAX: ffff880093c33000 RBX: ffff880093c33005 RCX:
ffff8800b9d90000
[185875.082565] RDX: ffff8800baa517c0 RSI: 0000000000000064 RDI:
ffff8800baa52000
[185875.083780] RBP: ffff88013fc03e18 R08: 0000000000000048 R09:
0000000000000000
[185875.084963] R10: 0000000000000022 R11: 000077ff80000000 R12:
ffff8800b9c47808
[185875.086120] R13: 0000000000000040 R14: 000077ff80000000 R15:
ffff8800b9c47800
[185875.087261] FS:  0000000000000000(0000) GS:ffff88013fc00000(0000)
knlGS:0000000000000000
[185875.088385] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[185875.089487] CR2: ffffffffff600400 CR3: 0000000078673000 CR4:
00000000001406f0
[185875.090590] Stack:
[185875.091662]  0000000100000000 0000000000000000 ffff88013b005000
0000000000000000
[185875.092759]  ffff8800b9c47808 ffff880093c33000 ffff8800baa51000
0000000000000040
[185875.093859]  ffff8800baa517c0 ffff88013fc1d638 000000010b10949d
0000004800000048
[185875.094956] Call Trace:
[185875.096035]  <IRQ>
[185875.096050]  [<ffffffffc03a3148>] virtnet_poll+0x28/0x90 [virtio_net]
[185875.098206]  [<ffffffffb456d79d>] net_rx_action+0x14d/0x340
[185875.099296]  [<ffffffffc03a3707>] ? skb_recv_done+0x47/0x50 [virtio_net]
[185875.100388]  [<ffffffffb408741c>] __do_softirq+0xdc/0x2d0
[185875.101464]  [<ffffffffb40cac51>] ?
__raw_callee_save___pv_queued_spin_unlock+0x11/0x20
[185875.102546]  [<ffffffffb40878d5>] irq_exit+0x105/0x110
[185875.103615]  [<ffffffffb4007495>] do_IRQ+0x65/0xf0
[185875.104675]  [<ffffffffb40f3410>] ? nohz_full_kick_work_func+0x10/0x10
[185875.105738]  [<ffffffffb46b1707>] common_interrupt+0x87/0x87
[185875.106790]  <EOI>
[185875.106803]  [<ffffffffb40f3410>] ? nohz_full_kick_work_func+0x10/0x10
[185875.108878]  [<ffffffffb40f916e>] ? smp_call_function_single+0x7e/0x110
[185875.109931]  [<ffffffffb40f3410>] ? nohz_full_kick_work_func+0x10/0x10
[185875.110984]  [<ffffffffb40f94fb>] smp_call_function_many+0x21b/0x260
[185875.112037]  [<ffffffffb40f41bb>] tick_nohz_full_kick_all+0x2b/0x40
[185875.113090]  [<ffffffffb40e82de>] nohz_kick_work_fn+0xe/0x10
[185875.114143]  [<ffffffffb409a6ad>] process_one_work+0x14d/0x3e0
[185875.115194]  [<ffffffffb409aa9a>] worker_thread+0x11a/0x440
[185875.116242]  [<ffffffffb46ac94c>] ? __schedule+0x34c/0x9a1
[185875.117297]  [<ffffffffb409a980>] ? process_scheduled_works+0x40/0x40
[185875.118354]  [<ffffffffb40a0b49>] kthread+0xc9/0xe0
[185875.119405]  [<ffffffffb40a0a80>] ? kthread_stop+0x100/0x100
[185875.120437]  [<ffffffffb46b0fcf>] ret_from_fork+0x3f/0x70
[185877.142523]  [<ffffffffb40a0a80>] ? kthread_stop+0x100/0x100
[185877.143599] Code: 5c 41 5d 41 5e 41 5f 5d c3 44 89 c6 48 89 df 29 c6
e8 e2 93 1b f4 e9 81 fe ff ff 48 89 d8 4d 89 f3 44 89 45 cc 30 c0 48 89
45 98 <44> 0f b7 60 0a b8 00 00 00 80 48 03 45 98 4c 0f 42 1d a7 c4 86
[186553.525454] INFO: rcu_sched detected stalls on CPUs/tasks:
[186553.528512]         1-...: (2153 GPs behind) idle=3c1/140000000000000/0
softirq=383/383 fqs=17
[186553.530296]         (detected by 0, t=67656 jiffies, g=6494354, c=6494353, 
q=0)
[186553.531990] Task dump for CPU 1:
[186553.533527] php5.2          R  running task        0 21137  27635
0x00080008
[186553.575828]  ffff880139c3ad00 ffff880037547ee8 ffffffffb404f324
3b6c6d756f264c3e
[186553.590500]  0000000000000002 ffff880139c3ad68 0000005500000000
ffff8800b9eb8934
[186553.601241]  ffff880037547f58 0000000000000006 0000000005363000
0000000001cccab8
[186553.613959] Call Trace:
[186553.636746]  [<ffffffffb404f324>] ? __do_page_fault+0x164/0x380
[186553.646399]  [<ffffffffb404f650>] ? trace_do_page_fault+0x50/0x140
[186553.654689]  [<ffffffffb414ec38>] ? __context_tracking_exit+0x68/0xc0
[186553.662718]  [<ffffffffb404b14e>] ? do_async_page_fault+0x1e/0xc0
[186553.672492]  [<ffffffffb400261f>] ? enter_from_user_mode+0x1f/0x50
[186553.683275]  [<ffffffffb46b2b28>] ? async_page_fault+0x28/0x30
[186553.690594] rcu_sched kthread starved for 50945 jiffies! g6494354
c6494353 f0x0 s3 ->state=0x1
[188039.072001] INFO: rcu_sched detected stalls on CPUs/tasks:
[188039.075029]         (detected by 0, t=90920 jiffies, g=6539663, c=6539662, 
q=0)
[188039.076660] All QSes seen, last rcu_sched kthread activity 89756
(4482707356-4482617600), jiffies_till_next_fqs=3, root ->qsmask 0x0
[188039.079895] mysqld          R  running task        0  7782   6301
0x00080008
[188039.082958]  ffffffffb4c54980 ffff88013fc03db8 ffffffffb40aeeaf
ffff88013fc15f80
[188039.084671]  ffffffffb4c54980 ffff88013fc03e38 ffffffffb40dec96
0000000000000000
[188039.086311]  ffffffffb40eb79c 0000000000000000 000000000063c98f
ffff88013fc15f80
[188039.088044] Call Trace:
[188039.089728]  <IRQ>  [<ffffffffb40aeeaf>] sched_show_task+0xaf/0x110
[188039.092059]  [<ffffffffb40dec96>] rcu_check_callbacks+0x7d6/0x7e0
[188039.093791]  [<ffffffffb40eb79c>] ? update_wall_time+0x23c/0x660
[188039.095400]  [<ffffffffb40f39f0>] ? tick_nohz_handler+0xa0/0xa0
[188039.097160]  [<ffffffffb40e4978>] update_process_times+0x38/0x70
[188039.098755]  [<ffffffffb40f348e>] tick_sched_handle.isra.15+0x2e/0x70
[188039.100967]  [<ffffffffb40f3a38>] tick_sched_timer+0x48/0x80
[188039.102576]  [<ffffffffb40e51d3>] __hrtimer_run_queues+0xf3/0x260
[188039.104213]  [<ffffffffb40e59c8>] hrtimer_interrupt+0xa8/0x1a0
[188039.105881]  [<ffffffffb403da59>] local_apic_timer_interrupt+0x39/0x60
[188039.107455]  [<ffffffffb403e465>] smp_apic_timer_interrupt+0x45/0x60
[188039.109586]  [<ffffffffb46b19a7>] apic_timer_interrupt+0x87/0x90
[188039.111306]  <EOI>  [<ffffffffb407e45f>] ?
exit_to_usermode_loop+0x35/0x95
[188039.112936]  [<ffffffffb400298c>] prepare_exit_to_usermode+0x2c/0x40
[188039.114591]  [<ffffffffb46b172a>] retint_user+0x8/0x13
[188039.116249] rcu_sched kthread starved for 89756 jiffies! g6539663
c6539662 f0x2 s3 ->state=0x0


Greets,
Stefan