lkml.org 
[lkml]   [2017]   [Jan]   [6]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: INFO: rcu_sched self-detected stall on CPU
On Thu, Jan 05, 2017 at 07:32:45PM +0100, Enrico Mioso wrote:
> Here is a new trace in the meanwhile: reporting it in case it proves useful.
> Thank you very much for your help and patience.

This looks quite similar to the last one. So there appears to be some
consistency, which is reassuring. Maybe fewer rather than more bugs in
play here.

Thanx, Paul

> Enrico
> [34839.019680] INFO: rcu_sched self-detected stall on CPU
> [34839.019694] INFO: rcu_sched detected stalls on CPUs/tasks:
> [34839.019711] 0-...: (1 GPs behind) idle=3d7/1/0
> softirq=5887188/5887188 fqs=0 [34839.019713] [34839.019725] 0-...:
> (1 GPs behind) idle=3d7/1/0 softirq=5887188/5887188 fqs=0
> [34839.019727] [34839.019733] (t=39875 jiffies g=3086597 c=3086596
> q=1)
> [34839.019744] rcu_sched kthread starved for 39875 jiffies! g3086597 c3086596 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x1
> [34839.019751] (detected by 1, t=39875 jiffies, g=3086597, c=3086596, q=1)
> [34839.019755] Task dump for CPU 0:
> [34839.019758] rcu_sched S 0 7 2 0x00000000
> [34839.019768] swapper/0 R running task [34839.019774] Call
> Trace:
> [34839.019779] 0 0 0 0x00000008
> [34839.019783] Call Trace:
> [34839.019808] ? cpuidle_enter_state+0x16c/0x350
> [34839.019818] ? __schedule+0x155/0x650
> [34839.019831] ? _raw_spin_lock_irqsave+0x14/0x40
> [34839.019839] ? cpuidle_enter+0x14/0x20
> [34839.019850] ? call_cpuidle+0x21/0x40
> [34839.019857] schedule+0x2e/0x70
> [34839.019866] ? do_idle+0xd3/0x1b0
> [34839.019875] schedule_timeout+0x18f/0x350
> [34839.019885] ? cpu_startup_entry+0x65/0x70
> [34839.019894] ? del_timer_sync+0x60/0x60
> [34839.019904] ? rest_init+0x62/0x70
> [34839.019914] rcu_gp_kthread+0x575/0xce0
> [34839.019927] ? start_kernel+0x32c/0x342
> [34839.019935] ? force_qs_rnp+0x170/0x170
> [34839.019946] kthread+0xd6/0x110
> [34839.019954] ? i386_start_kernel+0x90/0x94
> [34839.019963] ? startup_32_smp+0x16b/0x16d
> [34839.019971] ? force_qs_rnp+0x170/0x170
> [34839.019981] ? kthread_create_on_node+0x30/0x30
> [34839.019991] rcu_sched kthread starved for 39875 jiffies! g3086597 c3086596 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x1
> [34839.019995] rcu_sched S
> [34839.020004] ret_from_fork+0x19/0x24
> [34839.020011] 0 7 2 0x00000000
> [34839.020015] Call Trace:
> [34839.020029] ? __schedule+0x155/0x650
> [34839.020032] Task dump for CPU 0:
> [34839.020036] swapper/0 R
> [34839.020046] ? _raw_spin_lock_irqsave+0x14/0x40
> [34839.020049] running task [34839.020057] schedule+0x2e/0x70
> [34839.020063] 0 0 0 0x00000008
> [34839.020071] schedule_timeout+0x18f/0x350
> [34839.020075] Call Trace:
> [34839.020083] ? del_timer_sync+0x60/0x60
> [34839.020096] rcu_gp_kthread+0x575/0xce0
> [34839.020098] <IRQ>
> [34839.020109] sched_show_task+0xf3/0x160
> [34839.020117] ? force_qs_rnp+0x170/0x170
> [34839.020126] kthread+0xd6/0x110
> [34839.020133] dump_cpu_task+0x37/0x40
> [34839.020143] ? force_qs_rnp+0x170/0x170
> [34839.020153] rcu_dump_cpu_stacks+0x79/0x95
> [34839.020164] ? kthread_create_on_node+0x30/0x30
> [34839.020172] rcu_check_callbacks+0x621/0x770
> [34839.020184] ret_from_fork+0x19/0x24
> [34839.020191] ? ttwu_do_activate+0x5f/0x70
> [34839.020203] update_process_times+0x28/0x50
> [34839.020215] tick_sched_handle.isra.11+0x2f/0x40
> [34839.020225] tick_sched_timer+0x3b/0x80
> [34839.020236] __hrtimer_run_queues+0xdb/0x2b0
> [34839.020247] ? tick_sched_do_timer+0x60/0x60
> [34839.020258] hrtimer_interrupt+0x8b/0x180
> [34839.020269] ? default_send_IPI_mask_logical+0x5f/0x80
> [34839.020281] tick_handle_oneshot_broadcast+0x14c/0x190
> [34839.020293] timer_interrupt+0x12/0x20
> [34839.020304] __handle_irq_event_percpu+0x78/0x190
> [34839.020316] ? add_interrupt_randomness+0x144/0x1a0
> [34839.020327] ? handle_level_irq+0xf0/0xf0
> [34839.020336] handle_irq_event_percpu+0x2c/0x70
> [34839.020346] handle_irq_event+0x27/0x40
> [34839.020356] handle_edge_irq+0x5d/0x120
> [34839.020366] handle_irq+0x9b/0xc0
> [34839.020370] </IRQ>
> [34839.020380] do_IRQ+0x3d/0xc0
> [34839.020393] common_interrupt+0x3a/0x40
> [34839.020405] EIP: cpuidle_enter_state+0x16c/0x350
> [34839.020411] EFLAGS: 00200246 CPU: 0
> [34839.020418] EAX: 00000000 EBX: f9c80a40 ECX: 4ebd61d5 EDX: 00000000
> [34839.020425] ESI: 4ebd61d5 EDI: f9c80a50 EBP: d568df2c ESP: d568defc
> [34839.020433] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
> [34839.020449] cpuidle_enter+0x14/0x20
> [34839.020459] call_cpuidle+0x21/0x40
> [34839.020468] do_idle+0xd3/0x1b0
> [34839.020478] cpu_startup_entry+0x65/0x70
> [34839.020488] rest_init+0x62/0x70
> [34839.020501] start_kernel+0x32c/0x342
> [34839.020511] i386_start_kernel+0x90/0x94
> [34839.020521] startup_32_smp+0x16b/0x16d
> [37701.023799] INFO: rcu_sched self-detected stall on CPU
> [37701.023830] 0-...: (2 GPs behind) idle=e63/1/0
> softirq=5891997/5891997 fqs=0 [37701.023833] INFO: rcu_sched
> detected stalls on CPUs/tasks:
> [37701.023837] (t=58299 jiffies g=3092717 c=3092716 q=0)
> [37701.023854] 0-...: (2 GPs behind) idle=e63/1/0
> softirq=5891997/5891997 fqs=0 [37701.023857] [37701.023867]
> rcu_sched kthread starved for 58299 jiffies! g3092717 c3092716 f0x0
> RCU_GP_WAIT_FQS(3) ->state=0x1
> [37701.023875] (detected by 1, t=58299 jiffies, g=3092717, c=3092716, q=0)
> [37701.023878] rcu_sched S 0 7 2 0x00000000
> [37701.023888] Task dump for CPU 0:
> [37701.023892] swapper/0 R
> [37701.023895] Call Trace:
> [37701.023898] running task 0 0 0 0x00000000
> [37701.023923] ? __schedule+0x155/0x650
> [37701.023935] ? lock_timer_base+0x68/0x80
> [37701.023937] Call Trace:
> [37701.023951] ? _raw_spin_lock_irqsave+0x14/0x40
> [37701.023962] ? cpuidle_enter_state+0x16c/0x350
> [37701.023973] schedule+0x2e/0x70
> [37701.023981] ? cpuidle_enter+0x14/0x20
> [37701.023991] ? call_cpuidle+0x21/0x40
> [37701.024000] schedule_timeout+0x18f/0x350
> [37701.024009] ? do_idle+0xd3/0x1b0
> [37701.024016] ? del_timer_sync+0x60/0x60
> [37701.024027] ? cpu_startup_entry+0x65/0x70
> [37701.024036] rcu_gp_kthread+0x575/0xce0
> [37701.024047] ? rest_init+0x62/0x70
> [37701.024055] ? force_qs_rnp+0x170/0x170
> [37701.024065] kthread+0xd6/0x110
> [37701.024076] ? start_kernel+0x32c/0x342
> [37701.024086] ? force_qs_rnp+0x170/0x170
> [37701.024094] ? i386_start_kernel+0x90/0x94
> [37701.024103] ? startup_32_smp+0x16b/0x16d
> [37701.024111] ? kthread_create_on_node+0x30/0x30
> [37701.024122] ret_from_fork+0x19/0x24
> [37701.024133] rcu_sched kthread starved for 58299 jiffies! g3092717 c3092716 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x1
> [37701.024137] rcu_sched S 0 7 2 0x00000000
> [37701.024147] Call Trace:
> [37701.024162] ? __schedule+0x155/0x650
> [37701.024165] Task dump for CPU 0:
> [37701.024169] swapper/0 R
> [37701.024178] ? lock_timer_base+0x68/0x80
> [37701.024181] running task [37701.024190] ?
> _raw_spin_lock_irqsave+0x14/0x40
> [37701.024197] 0 0 0 0x00000008
> [37701.024204] schedule+0x2e/0x70
> [37701.024207] Call Trace:
> [37701.024216] schedule_timeout+0x18f/0x350
> [37701.024221] <IRQ>
> [37701.024228] ? del_timer_sync+0x60/0x60
> [37701.024239] sched_show_task+0xf3/0x160
> [37701.024248] rcu_gp_kthread+0x575/0xce0
> [37701.024259] dump_cpu_task+0x37/0x40
> [37701.024267] ? force_qs_rnp+0x170/0x170
> [37701.024277] kthread+0xd6/0x110
> [37701.024287] rcu_dump_cpu_stacks+0x79/0x95
> [37701.024297] ? force_qs_rnp+0x170/0x170
> [37701.024305] rcu_check_callbacks+0x621/0x770
> [37701.024316] ? kthread_create_on_node+0x30/0x30
> [37701.024324] update_process_times+0x28/0x50
> [37701.024336] tick_sched_handle.isra.11+0x2f/0x40
> [37701.024345] ret_from_fork+0x19/0x24
> [37701.024356] tick_sched_timer+0x3b/0x80
> [37701.024368] __hrtimer_run_queues+0xdb/0x2b0
> [37701.024379] ? tick_sched_do_timer+0x60/0x60
> [37701.024389] hrtimer_interrupt+0x8b/0x180
> [37701.024400] ? default_send_IPI_mask_logical+0x5f/0x80
> [37701.024412] tick_handle_oneshot_broadcast+0x14c/0x190
> [37701.024425] timer_interrupt+0x12/0x20
> [37701.024436] __handle_irq_event_percpu+0x78/0x190
> [37701.024448] ? add_interrupt_randomness+0x144/0x1a0
> [37701.024459] ? handle_level_irq+0xf0/0xf0
> [37701.024469] handle_irq_event_percpu+0x2c/0x70
> [37701.024478] handle_irq_event+0x27/0x40
> [37701.024488] handle_edge_irq+0x5d/0x120
> [37701.024498] handle_irq+0x9b/0xc0
> [37701.024502] </IRQ>
> [37701.024512] do_IRQ+0x3d/0xc0
> [37701.024525] common_interrupt+0x3a/0x40
> [37701.024537] EIP: cpuidle_enter_state+0x16c/0x350
> [37701.024543] EFLAGS: 00200246 CPU: 0
> [37701.024550] EAX: 00000000 EBX: f9c80a40 ECX: 616f6a50 EDX: 00000000
> [37701.024558] ESI: 616f6a50 EDI: f9c80a50 EBP: d568df2c ESP: d568defc
> [37701.024565] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
> [37701.024581] cpuidle_enter+0x14/0x20
> [37701.024591] call_cpuidle+0x21/0x40
> [37701.024600] do_idle+0xd3/0x1b0
> [37701.024610] cpu_startup_entry+0x65/0x70
> [37701.024620] rest_init+0x62/0x70
> [37701.024632] start_kernel+0x32c/0x342
> [37701.024643] i386_start_kernel+0x90/0x94
> [37701.024652] startup_32_smp+0x16b/0x16d
>

\
 
 \ /
  Last update: 2017-01-06 08:49    [W:0.098 / U:0.108 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site