Re: Suspicious RCU usage at boot w/ arm ipi trace events?

["Paul E. McKenney" <paulmck@linux.vnet.ibm.com>]

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