From: "Paul E. McKenney" <paulmck@linux.vnet.ibm.com>
To: Enrico Mioso <mrkiko.rs@gmail.com>
Cc: Steven Rostedt <rostedt@goodmis.org>,
linux-kernel@vger.kernel.org,
Josh Triplett <josh@joshtriplett.org>,
Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Subject: Re: INFO: rcu_sched self-detected stall on CPU
Date: Thu, 5 Jan 2017 23:48:28 -0800 [thread overview]
Message-ID: <20170106074828.GF3800@linux.vnet.ibm.com> (raw)
In-Reply-To: <alpine.LNX.2.20.1701051931520.2497@localhost.localdomain>
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
>
prev parent reply other threads:[~2017-01-06 7:48 UTC|newest]
Thread overview: 9+ messages / expand[flat|nested] mbox.gz Atom feed top
2017-01-04 9:58 INFO: rcu_sched self-detected stall on CPU Enrico Mioso
2017-01-04 13:46 ` Paul E. McKenney
2017-01-04 14:16 ` Steven Rostedt
2017-01-04 15:35 ` Enrico Mioso
2017-01-04 16:17 ` Paul E. McKenney
2017-01-04 20:59 ` Enrico Mioso
2017-01-06 7:47 ` Paul E. McKenney
2017-01-05 18:32 ` Enrico Mioso
2017-01-06 7:48 ` Paul E. McKenney [this message]
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20170106074828.GF3800@linux.vnet.ibm.com \
--to=paulmck@linux.vnet.ibm.com \
--cc=josh@joshtriplett.org \
--cc=linux-kernel@vger.kernel.org \
--cc=mathieu.desnoyers@efficios.com \
--cc=mrkiko.rs@gmail.com \
--cc=rostedt@goodmis.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox