Bug#822936: Occurs on Stretch
linux-image-4.9.0-4-686-pae 4.9.51-1
Oct 27 08:15:19 puar kernel: [26080.447922] INFO: rcu_sched
self-detected stall on CPU
Oct 27 08:15:19 puar kernel: [26080.447946] INFO: rcu_sched
self-detected stall on CPU
Oct 27 08:15:19 puar kernel: [26080.447964] 1-...: (1 GPs behind)
idle=c41/1/0 softirq=1143278/1143279 fqs=0
Oct 27 08:15:19 puar kernel: [26080.447968]
Oct 27 08:15:19 puar kernel: [26080.447976] (t=9226 jiffies g=487334
c=487333 q=1)
Oct 27 08:15:19 puar kernel: [26080.447988] rcu_sched kthread starved
for 9226 jiffies! g487334 c487333 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x1
Oct 27 08:15:19 puar kernel: [26080.447993] rcu_sched S
Oct 27 08:15:19 puar kernel: [26080.448001] 0 7 2 0x00000000
Oct 27 08:15:19 puar kernel: 00000000
Oct 27 08:15:19 puar kernel: [26080.448012] f300a100 f68b8800
f751bed4 c75a9e7e f751bebc c70d4cd7 c78b8280 0051bec4
Oct 27 08:15:19 puar kernel: [26080.448041] f7518db8 c7767680
f300a100 f79deac0 f75189c0 f751bee0 f75189c0 f79d8900
Oct 27 08:15:19 puar kernel: [26080.448069] f751bf00 f751bee0
c75aa3ae f79d8900 f751bf28 c75ad08f 00000002Call Trace:
Oct 27 08:15:19 puar kernel: [26080.448126] [<c75a9e7e>] ?
__schedule+0x25e/0x760
Oct 27 08:15:19 puar kernel: [26080.448144] [<c70d4cd7>] ?
lock_timer_base+0x67/0x80
Oct 27 08:15:19 puar kernel: [26080.448158] [<c75aa3ae>] ? schedule+0x2e/0x80
Oct 27 08:15:19 puar kernel: [26080.448172] [<c75ad08f>] ?
schedule_timeout+0x12f/0x300
Oct 27 08:15:19 puar kernel: [26080.448186] [<c70d5d40>] ?
del_timer_sync+0x50/0x50
Oct 27 08:15:19 puar kernel: [26080.448199] [<c70d0651>] ?
rcu_gp_kthread+0x4a1/0x7c0
Oct 27 08:15:19 puar kernel: [26080.448214] [<c7084314>] ? kthread+0xb4/0xd0
Oct 27 08:15:19 puar kernel: [26080.448225] [<c70d01b0>] ?
rcu_note_context_switch+0xf0/0xf0
Oct 27 08:15:19 puar kernel: [26080.448237] [<c7084260>] ?
kthread_park+0x50/0x50
Oct 27 08:15:19 puar kernel: [26080.448248] [<c75ae643>] ?
ret_from_fork+0x1b/0x28
Oct 27 08:15:19 puar kernel: [26080.448299] Task dump for CPU 0:
Oct 27 08:15:19 puar kernel: [26080.448307] swapper/0 R
Oct 27 08:15:19 puar kernel: [26080.448310] running task 0
0 0 0x00000000
Oct 27 08:15:19 puar kernel: c77c55f0
Oct 27 08:15:19 puar kernel: [26080.448327] c7761fbc 00000000
c776007b bc31007b 000000d8 c77c00e0 ffffff5e c7480944
Oct 27 08:15:19 puar kernel: [26080.448355] 00000060 00000246
00001667 bc2ca3cb 000017af 00000000 c77c54a0 00000004
Oct 27 08:15:19 puar kernel: [26080.448382] ff9d7fe0 bc314afc
000017af 00000000 ff9d7fe0 c77c54a0 c7761fe4Call Trace:
Oct 27 08:15:19 puar kernel: [26080.448435] [<c7480944>] ?
cpuidle_enter_state+0x134/0x330
Oct 27 08:15:19 puar kernel: [26080.448451] [<c70a9355>] ?
cpu_startup_entry+0x135/0x220
Oct 27 08:15:19 puar kernel: [26080.448467] [<c7803b53>] ?
start_kernel+0x39d/0x3b4
Oct 27 08:15:19 puar kernel: [26080.448473] Task dump for CPU 1:
Oct 27 08:15:19 puar kernel: [26080.448478] swapper/1 R
Oct 27 08:15:19 puar kernel: [26080.448481] running task 0
0 1 0x00000008
Oct 27 08:15:19 puar kernel: f7527dcc
Oct 27 08:15:19 puar kernel: [26080.448495] c7091941 c76b35df
00000000 00000000 00000001 00000008 c7782140 c7782140
Oct 27 08:15:19 puar kernel: [26080.448522] 00000001 f7527de4
c7166884 00000087 f79f3300 c7782140 c7782140 f7527e30
Oct 27 08:15:19 puar kernel: [26080.448550] c70d20e1 c76a9ed0
0000240a 00076fa6 00076fa5 00000001 603ea661Call Trace:
Oct 27 08:15:19 puar kernel: [26080.448593] [<c7091941>] ?
sched_show_task+0xf1/0x160
Oct 27 08:15:19 puar kernel: [26080.448612] [<c7166884>] ?
rcu_dump_cpu_stacks+0x79/0x95
Oct 27 08:15:19 puar kernel: [26080.448633] [<c70d20e1>] ?
rcu_check_callbacks+0x631/0x780
Oct 27 08:15:19 puar kernel: [26080.448652] [<c70d7748>] ?
update_process_times+0x28/0x50
Oct 27 08:15:19 puar kernel: [26080.448665] [<c70e8c86>] ?
tick_sched_handle.isra.11+0x26/0x60
Oct 27 08:15:19 puar kernel: [26080.448675] [<c70e8cfa>] ?
tick_sched_timer+0x3a/0x80
Oct 27 08:15:19 puar kernel: [26080.448688] [<c70d81df>] ?
__remove_hrtimer+0x3f/0x80
Oct 27 08:15:19 puar kernel: [26080.448700] [<c70d8400>] ?
__hrtimer_run_queues+0xc0/0x260
Oct 27 08:15:19 puar kernel: [26080.448712] [<c70e8cc0>] ?
tick_sched_handle.isra.11+0x60/0x60
Oct 27 08:15:19 puar kernel: [26080.448725] [<c70d8c23>] ?
hrtimer_interrupt+0x93/0x1a0
Oct 27 08:15:19 puar kernel: [26080.448742] [<c75afa63>] ?
smp_apic_timer_interrupt+0x33/0x50
Oct 27 08:15:19 puar kernel: [26080.448753] [<c75af178>] ?
apic_timer_interrupt+0x34/0x3c
Oct 27 08:15:19 puar kernel: [26080.448772] [<c7480944>] ?
cpuidle_enter_state+0x134/0x330
Oct 27 08:15:19 puar kernel: [26080.448787] [<c70a9355>] ?
cpu_startup_entry+0x135/0x220
Oct 27 08:15:19 puar kernel: [26080.448801] [<c70450f5>] ?
start_secondary+0x155/0x1b0
Oct 27 08:15:19 puar kernel: [26080.449772] 0-...: (1 ticks this
GP) idle=3e1/2/0 softirq=1245237/1245237 fqs=0
Oct 27 08:15:19 puar kernel: [26080.450190] (t=9227 jiffies
g=487334 c=487333 q=3)
Oct 27 08:15:19 puar kernel: [26080.450514] rcu_sched kthread starved
for 9227 jiffies! g487334 c487333 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x0
Oct 27 08:15:19 puar kernel: [26080.451087] rcu_sched R running
task 0 7 2 0x00000000
Oct 27 08:15:19 puar kernel: [26080.451109] 00000000 f300a100
f68b8800 f751bed4 c75a9e7e f751bebc c70d4cd7 c78b8280
Oct 27 08:15:19 puar kernel: [26080.451143] 0051bec4 f7518db8
c7767680 f300a100 f79deac0 f75189c0 f751bee0 f75189c0
Oct 27 08:15:19 puar kernel: [26080.451175] f79d8900 f79d8900
f751bee0 c70d5d39 f79ec900 f751bf28 c75ad08f c7782140
Oct 27 08:15:19 puar kernel: [26080.451205] Call Trace:
Oct 27 08:15:19 puar kernel: [26080.451240] [<c75a9e7e>] ?
__schedule+0x25e/0x760
Oct 27 08:15:19 puar kernel: [26080.451257] [<c70d4cd7>] ?
lock_timer_base+0x67/0x80
Oct 27 08:15:19 puar kernel: [26080.451271] [<c75aa3ae>] ? schedule+0x2e/0x80
Oct 27 08:15:19 puar kernel: [26080.451285] [<c75ad08f>] ?
schedule_timeout+0x12f/0x300
Oct 27 08:15:19 puar kernel: [26080.451298] [<c70d5d40>] ?
del_timer_sync+0x50/0x50
Oct 27 08:15:19 puar kernel: [26080.451311] [<c70d0651>] ?
rcu_gp_kthread+0x4a1/0x7c0
Oct 27 08:15:19 puar kernel: [26080.451326] [<c7084314>] ? kthread+0xb4/0xd0
Oct 27 08:15:19 puar kernel: [26080.451337] [<c70d01b0>] ?
rcu_note_context_switch+0xf0/0xf0
Oct 27 08:15:19 puar kernel: [26080.451349] [<c7084260>] ?
kthread_park+0x50/0x50
Oct 27 08:15:19 puar kernel: [26080.451360] [<c75ae643>] ?
ret_from_fork+0x1b/0x28
Oct 27 08:15:19 puar kernel: [26080.451399] Task dump for CPU 0:
Oct 27 08:15:19 puar kernel: [26080.451404] swapper/0 R running
task 0 0 0 0x00000008
Oct 27 08:15:19 puar kernel: [26080.451419] f742fe54 c7091941
c76b35df 00000000 00000000 00000000 00000008 c7782140
Oct 27 08:15:19 puar kernel: [26080.451446] c7782140 00000000
f742fe6c c7166884 00000087 f79df300 c7782140 c7782140
Oct 27 08:15:19 puar kernel: [26080.451473] f742feb8 c70d20e1
c76a9ed0 0000240b 00076fa6 00076fa5 00000003 f79deac0
Oct 27 08:15:19 puar kernel: [26080.451500] Call Trace:
Oct 27 08:15:19 puar kernel: [26080.451506] <IRQ>
Oct 27 08:15:19 puar kernel: [26080.451525] [<c7091941>] ?
sched_show_task+0xf1/0x160
Oct 27 08:15:19 puar kernel: [26080.451543] [<c7166884>] ?
rcu_dump_cpu_stacks+0x79/0x95
Oct 27 08:15:19 puar kernel: [26080.451555] [<c70d20e1>] ?
rcu_check_callbacks+0x631/0x780
Oct 27 08:15:19 puar kernel: [26080.451569] [<c7094f7a>] ?
account_process_tick+0x5a/0x150
Oct 27 08:15:19 puar kernel: [26080.451583] [<c70d7748>] ?
update_process_times+0x28/0x50
Oct 27 08:15:19 puar kernel: [26080.451596] [<c70e8c86>] ?
tick_sched_handle.isra.11+0x26/0x60
Oct 27 08:15:19 puar kernel: [26080.451606] [<c70e8cfa>] ?
tick_sched_timer+0x3a/0x80
Oct 27 08:15:19 puar kernel: [26080.451618] [<c70d81df>] ?
__remove_hrtimer+0x3f/0x80
Oct 27 08:15:19 puar kernel: [26080.451631] [<c70d8400>] ?
__hrtimer_run_queues+0xc0/0x260
Oct 27 08:15:19 puar kernel: [26080.451642] [<c70e8cc0>] ?
tick_sched_handle.isra.11+0x60/0x60
Oct 27 08:15:19 puar kernel: [26080.451656] [<c70d8c23>] ?
hrtimer_interrupt+0x93/0x1a0
Oct 27 08:15:19 puar kernel: [26080.451671] [<c7024d02>] ?
timer_interrupt+0x12/0x20
Oct 27 08:15:19 puar kernel: [26080.451687] [<c70c4ba8>] ?
__handle_irq_event_percpu+0x78/0x190
Oct 27 08:15:19 puar kernel: [26080.451700] [<c70c4ceb>] ?
handle_irq_event_percpu+0x2b/0x70
Oct 27 08:15:19 puar kernel: [26080.451713] [<c70c4d5f>] ?
handle_irq_event+0x2f/0x50
Oct 27 08:15:19 puar kernel: [26080.451724] [<c70c810d>] ?
handle_edge_irq+0x6d/0x120
Oct 27 08:15:19 puar kernel: [26080.451735] [<c70c80a0>] ?
handle_level_irq+0xe0/0xe0
Oct 27 08:15:19 puar kernel: [26080.451745] [<c7024844>] ? handle_irq+0x54/0x70
Oct 27 08:15:19 puar kernel: [26080.451749] <EOI>
Oct 27 08:15:19 puar kernel: [26080.451754] <IRQ>
Oct 27 08:15:19 puar kernel: [26080.451767] [<c75af9ac>] ? do_IRQ+0x3c/0xc0
Oct 27 08:15:19 puar kernel: [26080.451779] [<c70a8d25>] ?
swake_up_locked+0x25/0x30
Oct 27 08:15:19 puar kernel: [26080.451790] [<c75aee73>] ?
common_interrupt+0x33/0x38
Oct 27 08:15:19 puar kernel: [26080.451803] [<c75afb98>] ?
__do_softirq+0x58/0x240
Oct 27 08:15:19 puar kernel: [26080.451817] [<c75afb40>] ?
__irqentry_text_end+0x3/0x3
Oct 27 08:15:19 puar kernel: [26080.451828] [<c70247e8>] ?
do_softirq_own_stack+0x28/0x30
Oct 27 08:15:19 puar kernel: [26080.451828] <EOI>
Oct 27 08:15:19 puar kernel: [26080.451828] [<c706cc9d>] ? irq_exit+0xad/0xb0
Oct 27 08:15:19 puar kernel: [26080.451828] [<c75af9b5>] ? do_IRQ+0x45/0xc0
Oct 27 08:15:19 puar kernel: [26080.451828] [<c75aee73>] ?
common_interrupt+0x33/0x38
Oct 27 08:15:19 puar kernel: [26080.451828] [<c7480944>] ?
cpuidle_enter_state+0x134/0x330
Oct 27 08:15:19 puar kernel: [26080.451828] [<c70a9355>] ?
cpu_startup_entry+0x135/0x220
Oct 27 08:15:19 puar kernel: [26080.451828] [<c7803b53>] ?
start_kernel+0x39d/0x3b4
Oct 27 08:15:19 puar kernel: [26080.451828] Task dump for CPU 1:
Oct 27 08:15:19 puar kernel: [26080.451828] kworker/1:1 R running
task 0 11974 2 0x00000000
Oct 27 08:15:19 puar kernel: [26080.451828] Workqueue: events
output_poll_execute [drm_kms_helper]
Oct 27 08:15:19 puar kernel: [26080.451828] f90bf4e0 f690ca7c
f690c94c 0000001f f690ca7c f6cd0d80 f79f2640 f31c5f38
Oct 27 08:15:19 puar kernel: [26080.451828] c707ee21 f750cd78
f79f2ac0 f7520a00 f79f2ac0 f750c980 00000000 f79f8100
Oct 27 08:15:19 puar kernel: [26080.451828] 00000000 f79f2640
f6cd0d98 f6cd0d80 f79f2640 f31c5f64 c707f0a1 f79f2ac0
Oct 27 08:15:19 puar kernel: [26080.451828] Call Trace:
Oct 27 08:15:19 puar kernel: [26080.451828] [<c707ee21>] ?
process_one_work+0x141/0x380
Oct 27 08:15:19 puar kernel: [26080.451828] [<c707f0a1>] ?
worker_thread+0x41/0x460
Oct 27 08:15:19 puar kernel: [26080.451828] [<c7084314>] ? kthread+0xb4/0xd0
Oct 27 08:15:19 puar kernel: [26080.451828] [<c707f060>] ?
process_one_work+0x380/0x380
Oct 27 08:15:19 puar kernel: [26080.451828] [<c7084260>] ?
kthread_park+0x50/0x50
Oct 27 08:15:19 puar kernel: [26080.451828] [<c75ae643>] ?
ret_from_fork+0x1b/0x28
--
Jiann-Ming Su
"I have to decide between two equally frightening options.
If I wanted to do that, I'd vote." --Duckman
"The system's broke, Hank. The election baby has peed in
the bath water. You got to throw 'em both out." --Dale Gribble
"Those who vote decide nothing.
Those who count the votes decide everything.” --Joseph Stalin
Reply to: