Kernel: BUG: soft lockup - CPU#0 stuck for 22s! on many machines at the same time

Kernel: BUG: soft lockup - CPU#0 stuck for 22s! on many machines at the same time

[Stefan Priebe - Profihost AG]

Hello List,

while running Kernel 4.4.2 on the host and Kernel 4.1.18 in guests we're
seeing frequent hangs inside our guests.

This happens for all guests at the same time.

All of them show a trace + soft lockup while seeing no message at the host.

Is this a known bug? I expect this one inside the kernel kvm module as
it happens at the same minute on all guests.

Greets Stefan

Re: Kernel: BUG: soft lockup - CPU#0 stuck for 22s! on many machines at the same time

[Stefan Priebe]

Some of the guest machines also say:

[1450155.131037] INFO: rcu_sched detected stalls on CPUs/tasks: {} 
(detected by 1, t=60008 jiffies, g=109736865, c=109736864, q=0)
[1450155.131653] All QSes seen, last rcu_sched kthread activity 60005 
(5744764007-5744704002), jiffies_till_next_fqs=3, root ->qsmask 0x0
[1450155.131878] swapper/1       R  running task        0     0      1 
0x00080000
[1450155.132068]  ffffffff84c64040 ffff880331643d98 ffffffff840ac79f 
ffff880331657040
[1450155.132199]  ffffffff84c64040 ffff880331643e28 ffffffff840dc46f 
0000000000000000
[1450155.132331]  ffffffff84096364 ffff880331656240 0000000000000000 
ffff88032f660000
[1450155.132487] Call Trace:
[1450155.132953]  <IRQ>  [<ffffffff840ac79f>] sched_show_task+0xaf/0x120
[1450155.133134]  [<ffffffff840dc46f>] rcu_check_callbacks+0x7ff/0x810
[1450155.133252]  [<ffffffff84096364>] ? insert_work+0x74/0xc0
[1450155.133376]  [<ffffffff840e21b8>] update_process_times+0x38/0x70
[1450155.133491]  [<ffffffff840f1e1e>] tick_sched_handle.isra.14+0x2e/0x70
[1450155.133608]  [<ffffffff840f21eb>] tick_sched_timer+0x4b/0x80
[1450155.137916]  [<ffffffff840e2ab9>] __run_hrtimer+0x79/0x1c0
[1450155.139284]  [<ffffffff840f21a0>] ? tick_sched_do_timer+0x60/0x60
[1450155.140722]  [<ffffffff840e327b>] hrtimer_interrupt+0xfb/0x220
[1450155.142183]  [<ffffffff8404a18e>] ? kvm_clock_read+0x1e/0x20
[1450155.143502]  [<ffffffff8403e109>] local_apic_timer_interrupt+0x39/0x60
[1450155.144813]  [<ffffffff8403e605>] smp_apic_timer_interrupt+0x45/0x60
[1450155.146152]  [<ffffffff846a3dfe>] apic_timer_interrupt+0x6e/0x80
[1450155.147449]  <EOI>  [<ffffffff8404a566>] ? native_safe_halt+0x6/0x10
[1450155.148718]  [<ffffffff840d95d8>] ? rcu_eqs_enter+0x68/0x90
[1450155.150154]  [<ffffffff8400e8be>] default_idle+0x1e/0xc0
[1450155.151439]  [<ffffffff8400f2bf>] arch_cpu_idle+0xf/0x20
[1450155.152720]  [<ffffffff840c372c>] cpu_startup_entry+0x30c/0x3b0
[1450155.154031]  [<ffffffff8403c3e2>] start_secondary+0x182/0x1b0
[1450155.155301] rcu_sched kthread starved for 60005 jiffies!

Am 01.03.2016 um 11:58 schrieb Stefan Priebe - Profihost AG:
> Hello List,
>
> while running Kernel 4.4.2 on the host and Kernel 4.1.18 in guests we're
> seeing frequent hangs inside our guests.
>
> This happens for all guests at the same time.
>
> All of them show a trace + soft lockup while seeing no message at the host.
>
> Is this a known bug? I expect this one inside the kernel kvm module as
> it happens at the same minute on all guests.
>
> Greets Stefan
>

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

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

[Michael Roth]

Quoting Stefan Priebe - Profihost AG (2016-03-09 01:37:37)
> 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.

If you're using non-local storage my guess would be network/connectivity
issues causing guest-initiated I/O to timeout. Maybe throw some guests
with local storage on the same host and see if they also experience
the lockups or not. Also, unless this is known to be fixed upstream
and only a problem for a previous qemu release, you should Cc:
qemu-devel@nongnu.org instead of qemu-stable. This list
is mainly for backports and doesn't get much traffic beyond that.

> 
> 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
> 
> 

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

[Stefan Priebe - Profihost AG]

Am 18.03.2016 um 00:16 schrieb Michael Roth:
> Quoting Stefan Priebe - Profihost AG (2016-03-09 01:37:37)
>> 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.
> 
> If you're using non-local storage my guess would be network/connectivity
> issues causing guest-initiated I/O to timeout. Maybe throw some guests
> with local storage on the same host and see if they also experience
> the lockups or not.

The lockup happens on the host not inside the guests. The guests just
starrting getting laggy after the trace on the host happens. I've now
upgraded to 4.4.6 and have to wait if this happens again.

> Also, unless this is known to be fixed upstream
> and only a problem for a previous qemu release, you should Cc:
> qemu-devel@nongnu.org instead of qemu-stable. This list
> is mainly for backports and doesn't get much traffic beyond that.
Sorry and thanks.

Stefan

>>
>> 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
>>
>>
>