[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: [Qemu-stable] high i/o waits and 100% khugepaged with 4.4.4
|
From: |
Michael Roth |
|
Subject: |
Re: [Qemu-stable] high i/o waits and 100% khugepaged with 4.4.4 |
|
Date: |
Thu, 17 Mar 2016 18:16:45 -0500 |
|
User-agent: |
alot/0.3.6 |
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:
address@hidden 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
>
>