* Suspicious RCU usage at boot w/ arm ipi trace events?
@ 2015-06-17 0:21 John Stultz
2015-06-17 0:31 ` Paul E. McKenney
0 siblings, 1 reply; 9+ messages in thread
From: John Stultz @ 2015-06-17 0:21 UTC (permalink / raw)
To: Nicolas Pitre, Steven Rostedt; +Cc: lkml, Paul McKenney, Stephen Boyd
Not sure if I have the right folks on CC. Noticed this booting on a
apq8064 based system w/ 4.1-rc7 (plus a few patches that I believe are
unrelated).
[ 0.008796] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[ 0.009024] Setting up static identity map for 0x80208280 - 0x802082d8
[ 0.084781] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[ 0.085119]
[ 0.085139] ===============================
[ 0.085152] [ INFO: suspicious RCU usage. ]
[ 0.085168] 4.1.0-rc7-00033-gb5bed2f #153 Not tainted
[ 0.085180] -------------------------------
[ 0.085195] include/trace/events/ipi.h:68 suspicious
rcu_dereference_check() usage!
[ 0.085205]
[ 0.085205] other info that might help us debug this:
[ 0.085205]
[ 0.085220]
[ 0.085220] RCU used illegally from idle CPU!
[ 0.085220] rcu_scheduler_active = 1, debug_locks = 0
[ 0.085235] RCU used illegally from extended quiescent state!
[ 0.085247] no locks held by swapper/0/0.
[ 0.085256]
[ 0.085256] stack backtrace:
[ 0.085275] CPU: 0 PID: 0 Comm: swapper/0 Not tainted
4.1.0-rc7-00033-gb5bed2f #153
[ 0.085288] Hardware name: Qualcomm (Flattened Device Tree)
[ 0.085323] [<c0216b08>] (unwind_backtrace) from [<c02136e8>]
(show_stack+0x10/0x14)
[ 0.085348] [<c02136e8>] (show_stack) from [<c075e678>]
(dump_stack+0x70/0xbc)
[ 0.085369] [<c075e678>] (dump_stack) from [<c0215a80>]
(handle_IPI+0x428/0x604)
[ 0.085393] [<c0215a80>] (handle_IPI) from [<c020942c>]
(gic_handle_irq+0x54/0x5c)
[ 0.085423] [<c020942c>] (gic_handle_irq) from [<c0766604>]
(__irq_svc+0x44/0x7c)
[ 0.085436] Exception stack(0xc09f3f48 to 0xc09f3f90)
[ 0.085451] 3f40: 00000001 00000001 00000000
c09f73b8 c09f4528 c0a5de9c
[ 0.085468] 3f60: c076b4f0 00000000 00000000 c09ef108 c0a5cec1
00000001 00000000 c09f3f90
[ 0.085481] 3f80: c026bf60 c0210ab8 20000113 ffffffff
[ 0.085512] [<c0766604>] (__irq_svc) from [<c0210ab8>]
(arch_cpu_idle+0x20/0x3c)
[ 0.085549] [<c0210ab8>] (arch_cpu_idle) from [<c02647f0>]
(cpu_startup_entry+0x2c0/0x5dc)
[ 0.085576] [<c02647f0>] (cpu_startup_entry) from [<c099bc1c>]
(start_kernel+0x358/0x3c4)
[ 0.085600] [<c099bc1c>] (start_kernel) from [<8020807c>] (0x8020807c)
Let me know if there's any patches you'd like me to test, or if you'd
like config details.
thanks
-john
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: Suspicious RCU usage at boot w/ arm ipi trace events?
2015-06-17 0:21 Suspicious RCU usage at boot w/ arm ipi trace events? John Stultz
@ 2015-06-17 0:31 ` Paul E. McKenney
2015-06-17 0:41 ` Stephen Boyd
0 siblings, 1 reply; 9+ messages in thread
From: Paul E. McKenney @ 2015-06-17 0:31 UTC (permalink / raw)
To: John Stultz; +Cc: Nicolas Pitre, Steven Rostedt, lkml, Stephen Boyd
On Tue, Jun 16, 2015 at 05:21:59PM -0700, John Stultz wrote:
> Not sure if I have the right folks on CC. Noticed this booting on a
> apq8064 based system w/ 4.1-rc7 (plus a few patches that I believe are
> unrelated).
>
>
> [ 0.008796] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
> [ 0.009024] Setting up static identity map for 0x80208280 - 0x802082d8
> [ 0.084781] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
> [ 0.085119]
> [ 0.085139] ===============================
> [ 0.085152] [ INFO: suspicious RCU usage. ]
> [ 0.085168] 4.1.0-rc7-00033-gb5bed2f #153 Not tainted
> [ 0.085180] -------------------------------
> [ 0.085195] include/trace/events/ipi.h:68 suspicious
> rcu_dereference_check() usage!
> [ 0.085205]
> [ 0.085205] other info that might help us debug this:
> [ 0.085205]
> [ 0.085220]
> [ 0.085220] RCU used illegally from idle CPU!
> [ 0.085220] rcu_scheduler_active = 1, debug_locks = 0
> [ 0.085235] RCU used illegally from extended quiescent state!
> [ 0.085247] no locks held by swapper/0/0.
> [ 0.085256]
> [ 0.085256] stack backtrace:
> [ 0.085275] CPU: 0 PID: 0 Comm: swapper/0 Not tainted
> 4.1.0-rc7-00033-gb5bed2f #153
> [ 0.085288] Hardware name: Qualcomm (Flattened Device Tree)
> [ 0.085323] [<c0216b08>] (unwind_backtrace) from [<c02136e8>]
> (show_stack+0x10/0x14)
> [ 0.085348] [<c02136e8>] (show_stack) from [<c075e678>]
> (dump_stack+0x70/0xbc)
> [ 0.085369] [<c075e678>] (dump_stack) from [<c0215a80>]
> (handle_IPI+0x428/0x604)
> [ 0.085393] [<c0215a80>] (handle_IPI) from [<c020942c>]
> (gic_handle_irq+0x54/0x5c)
> [ 0.085423] [<c020942c>] (gic_handle_irq) from [<c0766604>]
> (__irq_svc+0x44/0x7c)
> [ 0.085436] Exception stack(0xc09f3f48 to 0xc09f3f90)
> [ 0.085451] 3f40: 00000001 00000001 00000000
> c09f73b8 c09f4528 c0a5de9c
> [ 0.085468] 3f60: c076b4f0 00000000 00000000 c09ef108 c0a5cec1
> 00000001 00000000 c09f3f90
> [ 0.085481] 3f80: c026bf60 c0210ab8 20000113 ffffffff
> [ 0.085512] [<c0766604>] (__irq_svc) from [<c0210ab8>]
> (arch_cpu_idle+0x20/0x3c)
> [ 0.085549] [<c0210ab8>] (arch_cpu_idle) from [<c02647f0>]
> (cpu_startup_entry+0x2c0/0x5dc)
> [ 0.085576] [<c02647f0>] (cpu_startup_entry) from [<c099bc1c>]
> (start_kernel+0x358/0x3c4)
> [ 0.085600] [<c099bc1c>] (start_kernel) from [<8020807c>] (0x8020807c)
>
>
> Let me know if there's any patches you'd like me to test, or if you'd
> like config details.
At first glance, looks like a failure to invoke irq_enter() from
__irq_svc(), gic_handle_irq(), or handle_IPI().
Thanx, Paul
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: Suspicious RCU usage at boot w/ arm ipi trace events?
2015-06-17 0:31 ` Paul E. McKenney
@ 2015-06-17 0:41 ` Stephen Boyd
2015-06-17 4:46 ` Paul E. McKenney
0 siblings, 1 reply; 9+ messages in thread
From: Stephen Boyd @ 2015-06-17 0:41 UTC (permalink / raw)
To: paulmck, John Stultz; +Cc: Nicolas Pitre, Steven Rostedt, lkml
On 06/16/2015 05:31 PM, Paul E. McKenney wrote:
> On Tue, Jun 16, 2015 at 05:21:59PM -0700, John Stultz wrote:
>> Not sure if I have the right folks on CC. Noticed this booting on a
>> apq8064 based system w/ 4.1-rc7 (plus a few patches that I believe are
>> unrelated).
>>
>>
>> [ 0.008796] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
>> [ 0.009024] Setting up static identity map for 0x80208280 - 0x802082d8
>> [ 0.084781] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
>> [ 0.085119]
>> [ 0.085139] ===============================
>> [ 0.085152] [ INFO: suspicious RCU usage. ]
>> [ 0.085168] 4.1.0-rc7-00033-gb5bed2f #153 Not tainted
>> [ 0.085180] -------------------------------
>> [ 0.085195] include/trace/events/ipi.h:68 suspicious
>> rcu_dereference_check() usage!
>> [ 0.085205]
>> [ 0.085205] other info that might help us debug this:
>> [ 0.085205]
>> [ 0.085220]
>> [ 0.085220] RCU used illegally from idle CPU!
>> [ 0.085220] rcu_scheduler_active = 1, debug_locks = 0
>> [ 0.085235] RCU used illegally from extended quiescent state!
>> [ 0.085247] no locks held by swapper/0/0.
>> [ 0.085256]
>> [ 0.085256] stack backtrace:
>> [ 0.085275] CPU: 0 PID: 0 Comm: swapper/0 Not tainted
>> 4.1.0-rc7-00033-gb5bed2f #153
>> [ 0.085288] Hardware name: Qualcomm (Flattened Device Tree)
>> [ 0.085323] [<c0216b08>] (unwind_backtrace) from [<c02136e8>]
>> (show_stack+0x10/0x14)
>> [ 0.085348] [<c02136e8>] (show_stack) from [<c075e678>]
>> (dump_stack+0x70/0xbc)
>> [ 0.085369] [<c075e678>] (dump_stack) from [<c0215a80>]
>> (handle_IPI+0x428/0x604)
>> [ 0.085393] [<c0215a80>] (handle_IPI) from [<c020942c>]
>> (gic_handle_irq+0x54/0x5c)
>> [ 0.085423] [<c020942c>] (gic_handle_irq) from [<c0766604>]
>> (__irq_svc+0x44/0x7c)
>> [ 0.085436] Exception stack(0xc09f3f48 to 0xc09f3f90)
>> [ 0.085451] 3f40: 00000001 00000001 00000000
>> c09f73b8 c09f4528 c0a5de9c
>> [ 0.085468] 3f60: c076b4f0 00000000 00000000 c09ef108 c0a5cec1
>> 00000001 00000000 c09f3f90
>> [ 0.085481] 3f80: c026bf60 c0210ab8 20000113 ffffffff
>> [ 0.085512] [<c0766604>] (__irq_svc) from [<c0210ab8>]
>> (arch_cpu_idle+0x20/0x3c)
>> [ 0.085549] [<c0210ab8>] (arch_cpu_idle) from [<c02647f0>]
>> (cpu_startup_entry+0x2c0/0x5dc)
>> [ 0.085576] [<c02647f0>] (cpu_startup_entry) from [<c099bc1c>]
>> (start_kernel+0x358/0x3c4)
>> [ 0.085600] [<c099bc1c>] (start_kernel) from [<8020807c>] (0x8020807c)
>>
>>
>> Let me know if there's any patches you'd like me to test, or if you'd
>> like config details.
> At first glance, looks like a failure to invoke irq_enter() from
> __irq_svc(), gic_handle_irq(), or handle_IPI().
>
> Thanx, Paul
>
The tracepoint 'trace_ipi_entry' in handle_IPI() is using RCU and we
haven't called irq_enter() yet at the point. Does this tracepoint need
to have _rcuidle() added to it?
--
Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum,
a Linux Foundation Collaborative Project
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: Suspicious RCU usage at boot w/ arm ipi trace events?
2015-06-17 0:41 ` Stephen Boyd
@ 2015-06-17 4:46 ` Paul E. McKenney
2015-06-18 1:49 ` Stephen Boyd
0 siblings, 1 reply; 9+ messages in thread
From: Paul E. McKenney @ 2015-06-17 4:46 UTC (permalink / raw)
To: Stephen Boyd; +Cc: John Stultz, Nicolas Pitre, Steven Rostedt, lkml
On Tue, Jun 16, 2015 at 05:41:29PM -0700, Stephen Boyd wrote:
> On 06/16/2015 05:31 PM, Paul E. McKenney wrote:
> > On Tue, Jun 16, 2015 at 05:21:59PM -0700, John Stultz wrote:
> >> Not sure if I have the right folks on CC. Noticed this booting on a
> >> apq8064 based system w/ 4.1-rc7 (plus a few patches that I believe are
> >> unrelated).
> >>
> >>
> >> [ 0.008796] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
> >> [ 0.009024] Setting up static identity map for 0x80208280 - 0x802082d8
> >> [ 0.084781] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
> >> [ 0.085119]
> >> [ 0.085139] ===============================
> >> [ 0.085152] [ INFO: suspicious RCU usage. ]
> >> [ 0.085168] 4.1.0-rc7-00033-gb5bed2f #153 Not tainted
> >> [ 0.085180] -------------------------------
> >> [ 0.085195] include/trace/events/ipi.h:68 suspicious
> >> rcu_dereference_check() usage!
> >> [ 0.085205]
> >> [ 0.085205] other info that might help us debug this:
> >> [ 0.085205]
> >> [ 0.085220]
> >> [ 0.085220] RCU used illegally from idle CPU!
> >> [ 0.085220] rcu_scheduler_active = 1, debug_locks = 0
> >> [ 0.085235] RCU used illegally from extended quiescent state!
> >> [ 0.085247] no locks held by swapper/0/0.
> >> [ 0.085256]
> >> [ 0.085256] stack backtrace:
> >> [ 0.085275] CPU: 0 PID: 0 Comm: swapper/0 Not tainted
> >> 4.1.0-rc7-00033-gb5bed2f #153
> >> [ 0.085288] Hardware name: Qualcomm (Flattened Device Tree)
> >> [ 0.085323] [<c0216b08>] (unwind_backtrace) from [<c02136e8>]
> >> (show_stack+0x10/0x14)
> >> [ 0.085348] [<c02136e8>] (show_stack) from [<c075e678>]
> >> (dump_stack+0x70/0xbc)
> >> [ 0.085369] [<c075e678>] (dump_stack) from [<c0215a80>]
> >> (handle_IPI+0x428/0x604)
> >> [ 0.085393] [<c0215a80>] (handle_IPI) from [<c020942c>]
> >> (gic_handle_irq+0x54/0x5c)
> >> [ 0.085423] [<c020942c>] (gic_handle_irq) from [<c0766604>]
> >> (__irq_svc+0x44/0x7c)
> >> [ 0.085436] Exception stack(0xc09f3f48 to 0xc09f3f90)
> >> [ 0.085451] 3f40: 00000001 00000001 00000000
> >> c09f73b8 c09f4528 c0a5de9c
> >> [ 0.085468] 3f60: c076b4f0 00000000 00000000 c09ef108 c0a5cec1
> >> 00000001 00000000 c09f3f90
> >> [ 0.085481] 3f80: c026bf60 c0210ab8 20000113 ffffffff
> >> [ 0.085512] [<c0766604>] (__irq_svc) from [<c0210ab8>]
> >> (arch_cpu_idle+0x20/0x3c)
> >> [ 0.085549] [<c0210ab8>] (arch_cpu_idle) from [<c02647f0>]
> >> (cpu_startup_entry+0x2c0/0x5dc)
> >> [ 0.085576] [<c02647f0>] (cpu_startup_entry) from [<c099bc1c>]
> >> (start_kernel+0x358/0x3c4)
> >> [ 0.085600] [<c099bc1c>] (start_kernel) from [<8020807c>] (0x8020807c)
> >>
> >>
> >> Let me know if there's any patches you'd like me to test, or if you'd
> >> like config details.
> > At first glance, looks like a failure to invoke irq_enter() from
> > __irq_svc(), gic_handle_irq(), or handle_IPI().
> >
> > Thanx, Paul
> >
>
> The tracepoint 'trace_ipi_entry' in handle_IPI() is using RCU and we
> haven't called irq_enter() yet at the point. Does this tracepoint need
> to have _rcuidle() added to it?
Yes, I believe that would fix this problem.
Thanx, Paul
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: Suspicious RCU usage at boot w/ arm ipi trace events?
2015-06-17 4:46 ` Paul E. McKenney
@ 2015-06-18 1:49 ` Stephen Boyd
2015-06-18 2:33 ` Paul E. McKenney
` (2 more replies)
0 siblings, 3 replies; 9+ messages in thread
From: Stephen Boyd @ 2015-06-18 1:49 UTC (permalink / raw)
To: paulmck; +Cc: John Stultz, Nicolas Pitre, Steven Rostedt, lkml
On 06/16/2015 09:46 PM, Paul E. McKenney wrote:
> On Tue, Jun 16, 2015 at 05:41:29PM -0700, Stephen Boyd wrote:
>>
>> The tracepoint 'trace_ipi_entry' in handle_IPI() is using RCU and we
>> haven't called irq_enter() yet at the point. Does this tracepoint need
>> to have _rcuidle() added to it?
> Yes, I believe that would fix this problem.
>
Ok... here's the patch. I see the problem on my device and applying this
patch fixes it.
----8<----
From: Stephen Boyd <sboyd@codeaurora.org>
Subject: [PATCH] ARM: smp: Silence suspicious RCU usage with ipi tracepoints
John Stultz reports an RCU splat on boot with ARM ipi trace
events enabled.
===============================
[ INFO: suspicious RCU usage. ]
4.1.0-rc7-00033-gb5bed2f #153 Not tainted
-------------------------------
include/trace/events/ipi.h:68 suspicious rcu_dereference_check() usage!
other info that might help us debug this:
RCU used illegally from idle CPU!
rcu_scheduler_active = 1, debug_locks = 0
RCU used illegally from extended quiescent state!
no locks held by swapper/0/0.
stack backtrace:
CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.1.0-rc7-00033-gb5bed2f #153
Hardware name: Qualcomm (Flattened Device Tree)
[<c0216b08>] (unwind_backtrace) from [<c02136e8>] (show_stack+0x10/0x14)
[<c02136e8>] (show_stack) from [<c075e678>] (dump_stack+0x70/0xbc)
[<c075e678>] (dump_stack) from [<c0215a80>] (handle_IPI+0x428/0x604)
[<c0215a80>] (handle_IPI) from [<c020942c>] (gic_handle_irq+0x54/0x5c)
[<c020942c>] (gic_handle_irq) from [<c0766604>] (__irq_svc+0x44/0x7c)
Exception stack(0xc09f3f48 to 0xc09f3f90)
3f40: 00000001 00000001 00000000 c09f73b8 c09f4528 c0a5de9c
3f60: c076b4f0 00000000 00000000 c09ef108 c0a5cec1 00000001 00000000 c09f3f90
3f80: c026bf60 c0210ab8 20000113 ffffffff
[<c0766604>] (__irq_svc) from [<c0210ab8>] (arch_cpu_idle+0x20/0x3c)
[<c0210ab8>] (arch_cpu_idle) from [<c02647f0>] (cpu_startup_entry+0x2c0/0x5dc)
[<c02647f0>] (cpu_startup_entry) from [<c099bc1c>] (start_kernel+0x358/0x3c4)
[<c099bc1c>] (start_kernel) from [<8020807c>] (0x8020807c)
At this point in the IPI handling path we haven't called
irq_enter() yet, so RCU doesn't know that we're about to exit
idle and properly warns that we're using RCU from an idle CPU.
Use trace_ipi_entry_rcuidle() instead of trace_ipi_entry() so
that RCU is informed about our exit from idle.
Reported-by: John Stultz <john.stultz@linaro.org>
Fixes: 365ec7b17327 "ARM: add IPI tracepoints"
Signed-off-by: Stephen Boyd <sboyd@codeaurora.org>
---
arch/arm/kernel/smp.c | 4 ++--
1 file changed, 2 insertions(+), 2 deletions(-)
diff --git a/arch/arm/kernel/smp.c b/arch/arm/kernel/smp.c
index 13a91d390832..03eb8a446dca 100644
--- a/arch/arm/kernel/smp.c
+++ b/arch/arm/kernel/smp.c
@@ -589,7 +589,7 @@ void handle_IPI(int ipinr, struct pt_regs *regs)
struct pt_regs *old_regs = set_irq_regs(regs);
if ((unsigned)ipinr < NR_IPI) {
- trace_ipi_entry(ipi_types[ipinr]);
+ trace_ipi_entry_rcuidle(ipi_types[ipinr]);
__inc_irq_stat(cpu, ipi_irqs[ipinr]);
}
@@ -648,7 +648,7 @@ void handle_IPI(int ipinr, struct pt_regs *regs)
}
if ((unsigned)ipinr < NR_IPI)
- trace_ipi_exit(ipi_types[ipinr]);
+ trace_ipi_exit_rcuidle(ipi_types[ipinr]);
set_irq_regs(old_regs);
}
--
Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum,
a Linux Foundation Collaborative Project
^ permalink raw reply related [flat|nested] 9+ messages in thread
* Re: Suspicious RCU usage at boot w/ arm ipi trace events?
2015-06-18 1:49 ` Stephen Boyd
@ 2015-06-18 2:33 ` Paul E. McKenney
2015-06-18 3:25 ` Steven Rostedt
2015-06-18 21:57 ` John Stultz
2 siblings, 0 replies; 9+ messages in thread
From: Paul E. McKenney @ 2015-06-18 2:33 UTC (permalink / raw)
To: Stephen Boyd; +Cc: John Stultz, Nicolas Pitre, Steven Rostedt, lkml
On Wed, Jun 17, 2015 at 06:49:38PM -0700, Stephen Boyd wrote:
> On 06/16/2015 09:46 PM, Paul E. McKenney wrote:
> > On Tue, Jun 16, 2015 at 05:41:29PM -0700, Stephen Boyd wrote:
> >>
> >> The tracepoint 'trace_ipi_entry' in handle_IPI() is using RCU and we
> >> haven't called irq_enter() yet at the point. Does this tracepoint need
> >> to have _rcuidle() added to it?
> > Yes, I believe that would fix this problem.
> >
>
> Ok... here's the patch. I see the problem on my device and applying this
> patch fixes it.
>
> ----8<----
>
> From: Stephen Boyd <sboyd@codeaurora.org>
> Subject: [PATCH] ARM: smp: Silence suspicious RCU usage with ipi tracepoints
>
> John Stultz reports an RCU splat on boot with ARM ipi trace
> events enabled.
>
> ===============================
> [ INFO: suspicious RCU usage. ]
> 4.1.0-rc7-00033-gb5bed2f #153 Not tainted
> -------------------------------
> include/trace/events/ipi.h:68 suspicious rcu_dereference_check() usage!
>
> other info that might help us debug this:
>
> RCU used illegally from idle CPU!
> rcu_scheduler_active = 1, debug_locks = 0
> RCU used illegally from extended quiescent state!
> no locks held by swapper/0/0.
>
> stack backtrace:
> CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.1.0-rc7-00033-gb5bed2f #153
> Hardware name: Qualcomm (Flattened Device Tree)
> [<c0216b08>] (unwind_backtrace) from [<c02136e8>] (show_stack+0x10/0x14)
> [<c02136e8>] (show_stack) from [<c075e678>] (dump_stack+0x70/0xbc)
> [<c075e678>] (dump_stack) from [<c0215a80>] (handle_IPI+0x428/0x604)
> [<c0215a80>] (handle_IPI) from [<c020942c>] (gic_handle_irq+0x54/0x5c)
> [<c020942c>] (gic_handle_irq) from [<c0766604>] (__irq_svc+0x44/0x7c)
> Exception stack(0xc09f3f48 to 0xc09f3f90)
> 3f40: 00000001 00000001 00000000 c09f73b8 c09f4528 c0a5de9c
> 3f60: c076b4f0 00000000 00000000 c09ef108 c0a5cec1 00000001 00000000 c09f3f90
> 3f80: c026bf60 c0210ab8 20000113 ffffffff
> [<c0766604>] (__irq_svc) from [<c0210ab8>] (arch_cpu_idle+0x20/0x3c)
> [<c0210ab8>] (arch_cpu_idle) from [<c02647f0>] (cpu_startup_entry+0x2c0/0x5dc)
> [<c02647f0>] (cpu_startup_entry) from [<c099bc1c>] (start_kernel+0x358/0x3c4)
> [<c099bc1c>] (start_kernel) from [<8020807c>] (0x8020807c)
>
> At this point in the IPI handling path we haven't called
> irq_enter() yet, so RCU doesn't know that we're about to exit
> idle and properly warns that we're using RCU from an idle CPU.
> Use trace_ipi_entry_rcuidle() instead of trace_ipi_entry() so
> that RCU is informed about our exit from idle.
>
> Reported-by: John Stultz <john.stultz@linaro.org>
> Fixes: 365ec7b17327 "ARM: add IPI tracepoints"
> Signed-off-by: Stephen Boyd <sboyd@codeaurora.org>
Reviewed-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
> ---
> arch/arm/kernel/smp.c | 4 ++--
> 1 file changed, 2 insertions(+), 2 deletions(-)
>
> diff --git a/arch/arm/kernel/smp.c b/arch/arm/kernel/smp.c
> index 13a91d390832..03eb8a446dca 100644
> --- a/arch/arm/kernel/smp.c
> +++ b/arch/arm/kernel/smp.c
> @@ -589,7 +589,7 @@ void handle_IPI(int ipinr, struct pt_regs *regs)
> struct pt_regs *old_regs = set_irq_regs(regs);
>
> if ((unsigned)ipinr < NR_IPI) {
> - trace_ipi_entry(ipi_types[ipinr]);
> + trace_ipi_entry_rcuidle(ipi_types[ipinr]);
> __inc_irq_stat(cpu, ipi_irqs[ipinr]);
> }
>
> @@ -648,7 +648,7 @@ void handle_IPI(int ipinr, struct pt_regs *regs)
> }
>
> if ((unsigned)ipinr < NR_IPI)
> - trace_ipi_exit(ipi_types[ipinr]);
> + trace_ipi_exit_rcuidle(ipi_types[ipinr]);
> set_irq_regs(old_regs);
> }
>
>
> --
> Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum,
> a Linux Foundation Collaborative Project
>
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: Suspicious RCU usage at boot w/ arm ipi trace events?
2015-06-18 1:49 ` Stephen Boyd
2015-06-18 2:33 ` Paul E. McKenney
@ 2015-06-18 3:25 ` Steven Rostedt
2015-06-18 21:57 ` John Stultz
2 siblings, 0 replies; 9+ messages in thread
From: Steven Rostedt @ 2015-06-18 3:25 UTC (permalink / raw)
To: Stephen Boyd; +Cc: paulmck, John Stultz, Nicolas Pitre, lkml
On Wed, 17 Jun 2015 18:49:38 -0700
Stephen Boyd <sboyd@codeaurora.org> wrote:
> From: Stephen Boyd <sboyd@codeaurora.org>
> Subject: [PATCH] ARM: smp: Silence suspicious RCU usage with ipi tracepoints
>
> John Stultz reports an RCU splat on boot with ARM ipi trace
> events enabled.
>
> ===============================
> [ INFO: suspicious RCU usage. ]
> 4.1.0-rc7-00033-gb5bed2f #153 Not tainted
> -------------------------------
> include/trace/events/ipi.h:68 suspicious rcu_dereference_check() usage!
>
> other info that might help us debug this:
>
> RCU used illegally from idle CPU!
> rcu_scheduler_active = 1, debug_locks = 0
> RCU used illegally from extended quiescent state!
> no locks held by swapper/0/0.
>
> stack backtrace:
> CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.1.0-rc7-00033-gb5bed2f #153
> Hardware name: Qualcomm (Flattened Device Tree)
> [<c0216b08>] (unwind_backtrace) from [<c02136e8>] (show_stack+0x10/0x14)
> [<c02136e8>] (show_stack) from [<c075e678>] (dump_stack+0x70/0xbc)
> [<c075e678>] (dump_stack) from [<c0215a80>] (handle_IPI+0x428/0x604)
> [<c0215a80>] (handle_IPI) from [<c020942c>] (gic_handle_irq+0x54/0x5c)
> [<c020942c>] (gic_handle_irq) from [<c0766604>] (__irq_svc+0x44/0x7c)
> Exception stack(0xc09f3f48 to 0xc09f3f90)
> 3f40: 00000001 00000001 00000000 c09f73b8 c09f4528 c0a5de9c
> 3f60: c076b4f0 00000000 00000000 c09ef108 c0a5cec1 00000001 00000000 c09f3f90
> 3f80: c026bf60 c0210ab8 20000113 ffffffff
> [<c0766604>] (__irq_svc) from [<c0210ab8>] (arch_cpu_idle+0x20/0x3c)
> [<c0210ab8>] (arch_cpu_idle) from [<c02647f0>] (cpu_startup_entry+0x2c0/0x5dc)
> [<c02647f0>] (cpu_startup_entry) from [<c099bc1c>] (start_kernel+0x358/0x3c4)
> [<c099bc1c>] (start_kernel) from [<8020807c>] (0x8020807c)
>
> At this point in the IPI handling path we haven't called
> irq_enter() yet, so RCU doesn't know that we're about to exit
> idle and properly warns that we're using RCU from an idle CPU.
> Use trace_ipi_entry_rcuidle() instead of trace_ipi_entry() so
> that RCU is informed about our exit from idle.
>
> Reported-by: John Stultz <john.stultz@linaro.org>
Acked-by: Steven Rostedt <rostedt@goodmis.org>
-- Steve
> Fixes: 365ec7b17327 "ARM: add IPI tracepoints"
> Signed-off-by: Stephen Boyd <sboyd@codeaurora.org>
> ---
> arch/arm/kernel/smp.c | 4 ++--
> 1 file changed, 2 insertions(+), 2 deletions(-)
>
> diff --git a/arch/arm/kernel/smp.c b/arch/arm/kernel/smp.c
> index 13a91d390832..03eb8a446dca 100644
> --- a/arch/arm/kernel/smp.c
> +++ b/arch/arm/kernel/smp.c
> @@ -589,7 +589,7 @@ void handle_IPI(int ipinr, struct pt_regs *regs)
> struct pt_regs *old_regs = set_irq_regs(regs);
>
> if ((unsigned)ipinr < NR_IPI) {
> - trace_ipi_entry(ipi_types[ipinr]);
> + trace_ipi_entry_rcuidle(ipi_types[ipinr]);
> __inc_irq_stat(cpu, ipi_irqs[ipinr]);
> }
>
> @@ -648,7 +648,7 @@ void handle_IPI(int ipinr, struct pt_regs *regs)
> }
>
> if ((unsigned)ipinr < NR_IPI)
> - trace_ipi_exit(ipi_types[ipinr]);
> + trace_ipi_exit_rcuidle(ipi_types[ipinr]);
> set_irq_regs(old_regs);
> }
>
>
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: Suspicious RCU usage at boot w/ arm ipi trace events?
2015-06-18 1:49 ` Stephen Boyd
2015-06-18 2:33 ` Paul E. McKenney
2015-06-18 3:25 ` Steven Rostedt
@ 2015-06-18 21:57 ` John Stultz
2015-06-19 18:49 ` Stephen Boyd
2 siblings, 1 reply; 9+ messages in thread
From: John Stultz @ 2015-06-18 21:57 UTC (permalink / raw)
To: Stephen Boyd; +Cc: Paul McKenney, Nicolas Pitre, Steven Rostedt, lkml
On Wed, Jun 17, 2015 at 6:49 PM, Stephen Boyd <sboyd@codeaurora.org> wrote:
> On 06/16/2015 09:46 PM, Paul E. McKenney wrote:
>> On Tue, Jun 16, 2015 at 05:41:29PM -0700, Stephen Boyd wrote:
>>>
>>> The tracepoint 'trace_ipi_entry' in handle_IPI() is using RCU and we
>>> haven't called irq_enter() yet at the point. Does this tracepoint need
>>> to have _rcuidle() added to it?
>> Yes, I believe that would fix this problem.
>>
>
> Ok... here's the patch. I see the problem on my device and applying this
> patch fixes it.
>
> ----8<----
>
> From: Stephen Boyd <sboyd@codeaurora.org>
> Subject: [PATCH] ARM: smp: Silence suspicious RCU usage with ipi tracepoints
>
> John Stultz reports an RCU splat on boot with ARM ipi trace
> events enabled.
>
> ===============================
> [ INFO: suspicious RCU usage. ]
> 4.1.0-rc7-00033-gb5bed2f #153 Not tainted
> -------------------------------
> include/trace/events/ipi.h:68 suspicious rcu_dereference_check() usage!
>
> other info that might help us debug this:
>
> RCU used illegally from idle CPU!
> rcu_scheduler_active = 1, debug_locks = 0
> RCU used illegally from extended quiescent state!
> no locks held by swapper/0/0.
>
> stack backtrace:
> CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.1.0-rc7-00033-gb5bed2f #153
> Hardware name: Qualcomm (Flattened Device Tree)
> [<c0216b08>] (unwind_backtrace) from [<c02136e8>] (show_stack+0x10/0x14)
> [<c02136e8>] (show_stack) from [<c075e678>] (dump_stack+0x70/0xbc)
> [<c075e678>] (dump_stack) from [<c0215a80>] (handle_IPI+0x428/0x604)
> [<c0215a80>] (handle_IPI) from [<c020942c>] (gic_handle_irq+0x54/0x5c)
> [<c020942c>] (gic_handle_irq) from [<c0766604>] (__irq_svc+0x44/0x7c)
> Exception stack(0xc09f3f48 to 0xc09f3f90)
> 3f40: 00000001 00000001 00000000 c09f73b8 c09f4528 c0a5de9c
> 3f60: c076b4f0 00000000 00000000 c09ef108 c0a5cec1 00000001 00000000 c09f3f90
> 3f80: c026bf60 c0210ab8 20000113 ffffffff
> [<c0766604>] (__irq_svc) from [<c0210ab8>] (arch_cpu_idle+0x20/0x3c)
> [<c0210ab8>] (arch_cpu_idle) from [<c02647f0>] (cpu_startup_entry+0x2c0/0x5dc)
> [<c02647f0>] (cpu_startup_entry) from [<c099bc1c>] (start_kernel+0x358/0x3c4)
> [<c099bc1c>] (start_kernel) from [<8020807c>] (0x8020807c)
>
> At this point in the IPI handling path we haven't called
> irq_enter() yet, so RCU doesn't know that we're about to exit
> idle and properly warns that we're using RCU from an idle CPU.
> Use trace_ipi_entry_rcuidle() instead of trace_ipi_entry() so
> that RCU is informed about our exit from idle.
>
> Reported-by: John Stultz <john.stultz@linaro.org>
> Fixes: 365ec7b17327 "ARM: add IPI tracepoints"
> Signed-off-by: Stephen Boyd <sboyd@codeaurora.org>
> ---
> arch/arm/kernel/smp.c | 4 ++--
> 1 file changed, 2 insertions(+), 2 deletions(-)
>
> diff --git a/arch/arm/kernel/smp.c b/arch/arm/kernel/smp.c
> index 13a91d390832..03eb8a446dca 100644
> --- a/arch/arm/kernel/smp.c
> +++ b/arch/arm/kernel/smp.c
> @@ -589,7 +589,7 @@ void handle_IPI(int ipinr, struct pt_regs *regs)
> struct pt_regs *old_regs = set_irq_regs(regs);
>
> if ((unsigned)ipinr < NR_IPI) {
> - trace_ipi_entry(ipi_types[ipinr]);
> + trace_ipi_entry_rcuidle(ipi_types[ipinr]);
> __inc_irq_stat(cpu, ipi_irqs[ipinr]);
> }
>
> @@ -648,7 +648,7 @@ void handle_IPI(int ipinr, struct pt_regs *regs)
> }
>
> if ((unsigned)ipinr < NR_IPI)
> - trace_ipi_exit(ipi_types[ipinr]);
> + trace_ipi_exit_rcuidle(ipi_types[ipinr]);
> set_irq_regs(old_regs);
> }
>
Tested-by: John Stultz <john.stultz@linaro.org>
Thanks for fixing this up!
-john
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: Suspicious RCU usage at boot w/ arm ipi trace events?
2015-06-18 21:57 ` John Stultz
@ 2015-06-19 18:49 ` Stephen Boyd
0 siblings, 0 replies; 9+ messages in thread
From: Stephen Boyd @ 2015-06-19 18:49 UTC (permalink / raw)
To: John Stultz; +Cc: Paul McKenney, Nicolas Pitre, Steven Rostedt, lkml
On 06/18, John Stultz wrote:
> On Wed, Jun 17, 2015 at 6:49 PM, Stephen Boyd <sboyd@codeaurora.org> wrote:
> > On 06/16/2015 09:46 PM, Paul E. McKenney wrote:
> >> On Tue, Jun 16, 2015 at 05:41:29PM -0700, Stephen Boyd wrote:
> >>>
> >>> The tracepoint 'trace_ipi_entry' in handle_IPI() is using RCU and we
> >>> haven't called irq_enter() yet at the point. Does this tracepoint need
> >>> to have _rcuidle() added to it?
> >> Yes, I believe that would fix this problem.
> >>
> >
> > Ok... here's the patch. I see the problem on my device and applying this
> > patch fixes it.
> >
> > ----8<----
> >
> > From: Stephen Boyd <sboyd@codeaurora.org>
> > Subject: [PATCH] ARM: smp: Silence suspicious RCU usage with ipi tracepoints
> >
> > John Stultz reports an RCU splat on boot with ARM ipi trace
> > events enabled.
> >
> > ===============================
> > [ INFO: suspicious RCU usage. ]
> > 4.1.0-rc7-00033-gb5bed2f #153 Not tainted
> > -------------------------------
> > include/trace/events/ipi.h:68 suspicious rcu_dereference_check() usage!
> >
> > other info that might help us debug this:
> >
> > RCU used illegally from idle CPU!
> > rcu_scheduler_active = 1, debug_locks = 0
> > RCU used illegally from extended quiescent state!
> > no locks held by swapper/0/0.
> >
> > stack backtrace:
> > CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.1.0-rc7-00033-gb5bed2f #153
> > Hardware name: Qualcomm (Flattened Device Tree)
> > [<c0216b08>] (unwind_backtrace) from [<c02136e8>] (show_stack+0x10/0x14)
> > [<c02136e8>] (show_stack) from [<c075e678>] (dump_stack+0x70/0xbc)
> > [<c075e678>] (dump_stack) from [<c0215a80>] (handle_IPI+0x428/0x604)
> > [<c0215a80>] (handle_IPI) from [<c020942c>] (gic_handle_irq+0x54/0x5c)
> > [<c020942c>] (gic_handle_irq) from [<c0766604>] (__irq_svc+0x44/0x7c)
> > Exception stack(0xc09f3f48 to 0xc09f3f90)
> > 3f40: 00000001 00000001 00000000 c09f73b8 c09f4528 c0a5de9c
> > 3f60: c076b4f0 00000000 00000000 c09ef108 c0a5cec1 00000001 00000000 c09f3f90
> > 3f80: c026bf60 c0210ab8 20000113 ffffffff
> > [<c0766604>] (__irq_svc) from [<c0210ab8>] (arch_cpu_idle+0x20/0x3c)
> > [<c0210ab8>] (arch_cpu_idle) from [<c02647f0>] (cpu_startup_entry+0x2c0/0x5dc)
> > [<c02647f0>] (cpu_startup_entry) from [<c099bc1c>] (start_kernel+0x358/0x3c4)
> > [<c099bc1c>] (start_kernel) from [<8020807c>] (0x8020807c)
> >
> > At this point in the IPI handling path we haven't called
> > irq_enter() yet, so RCU doesn't know that we're about to exit
> > idle and properly warns that we're using RCU from an idle CPU.
> > Use trace_ipi_entry_rcuidle() instead of trace_ipi_entry() so
> > that RCU is informed about our exit from idle.
> >
> > Reported-by: John Stultz <john.stultz@linaro.org>
> > Fixes: 365ec7b17327 "ARM: add IPI tracepoints"
> > Signed-off-by: Stephen Boyd <sboyd@codeaurora.org>
> > ---
> > arch/arm/kernel/smp.c | 4 ++--
> > 1 file changed, 2 insertions(+), 2 deletions(-)
> >
> > diff --git a/arch/arm/kernel/smp.c b/arch/arm/kernel/smp.c
> > index 13a91d390832..03eb8a446dca 100644
> > --- a/arch/arm/kernel/smp.c
> > +++ b/arch/arm/kernel/smp.c
> > @@ -589,7 +589,7 @@ void handle_IPI(int ipinr, struct pt_regs *regs)
> > struct pt_regs *old_regs = set_irq_regs(regs);
> >
> > if ((unsigned)ipinr < NR_IPI) {
> > - trace_ipi_entry(ipi_types[ipinr]);
> > + trace_ipi_entry_rcuidle(ipi_types[ipinr]);
> > __inc_irq_stat(cpu, ipi_irqs[ipinr]);
> > }
> >
> > @@ -648,7 +648,7 @@ void handle_IPI(int ipinr, struct pt_regs *regs)
> > }
> >
> > if ((unsigned)ipinr < NR_IPI)
> > - trace_ipi_exit(ipi_types[ipinr]);
> > + trace_ipi_exit_rcuidle(ipi_types[ipinr]);
> > set_irq_regs(old_regs);
> > }
> >
>
> Tested-by: John Stultz <john.stultz@linaro.org>
>
> Thanks for fixing this up!
Thanks. I'll throw it into the patch tracker. I'll send the same
patch for arm64 because I assume it's also broken there.
--
Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum,
a Linux Foundation Collaborative Project
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
Please read the FAQ at http://www.tux.org/lkml/
^ permalink raw reply [flat|nested] 9+ messages in thread
end of thread, other threads:[~2015-06-19 18:50 UTC | newest]
Thread overview: 9+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2015-06-17 0:21 Suspicious RCU usage at boot w/ arm ipi trace events? John Stultz
2015-06-17 0:31 ` Paul E. McKenney
2015-06-17 0:41 ` Stephen Boyd
2015-06-17 4:46 ` Paul E. McKenney
2015-06-18 1:49 ` Stephen Boyd
2015-06-18 2:33 ` Paul E. McKenney
2015-06-18 3:25 ` Steven Rostedt
2015-06-18 21:57 ` John Stultz
2015-06-19 18:49 ` Stephen Boyd
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.