Re: linux-next 20111025: warnings in rcu_idle_exit_common()/rcu_idle_enter_common()

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

On Mon, Oct 31, 2011 at 08:37:08PM +0800, Wu Fengguang wrote:
> On Mon, Oct 31, 2011 at 08:31:25PM +0800, Wu Fengguang wrote:
> > On Mon, Oct 31, 2011 at 07:41:42PM +0800, Wu Fengguang wrote:
> > > On Mon, Oct 31, 2011 at 06:43:25PM +0800, Wu Fengguang wrote:
> > > > On Mon, Oct 31, 2011 at 05:51:52PM +0800, Paul E. McKenney wrote:
> > > > > On Mon, Oct 31, 2011 at 04:26:34PM +0800, Wu Fengguang wrote:
> > > > > > Hi Paul,
> > > > > >
> > > > > > I got two warnings in rcutree.c. The last working kernels are
> > > > > > linux-next 20111014 and linux v3.1.
> > > > > 
> > > > > Interesting.  Could you please enable RCU event tracing at boot?
> > > > 
> > > > Sorry I cannot...possibly due to another ftrace bug.
> > > > 
> > > > > The RCU event tracing is at tracing/events/rcu/enable relative to
> > > > > the debugfs mount point at runtime, if that helps.
> > > > 
> > > > It's exactly that linux next 20111025 (comparing to 20111014) no
> > > > longer produces all the trace events that made me looking into the
> > > > dmesg and find the warning from RCU (rather than the expected warning
> > > > from ftrace).
> > > > 
> > > > The trace output is now:
> > > > 
> > > >         # tracer: nop
> > > >         #
> > > >         # WARNING: FUNCTION TRACING IS CORRUPTED
> > > >         #          MAY BE MISSING FUNCTION EVENTS
> > > >         #           TASK-PID    CPU#    TIMESTAMP  FUNCTION
> > > >         #              | |       |          |         |
> > > > (nothing more)
> > > 
> > > I checked the other test box and got the same warnings. Below is the
> > > full dmesg.
> > 
> > Here is another dmesg showing the warnings inside kvm.
> > 
> > btw, I turned on the ftrace self tests and it shows a warning, too.
> 
> The trace events magically show up after enabling the ftrace self
> tests. Here are some of them collected in the original test box.
> Hope it helps.

Indeed it does!

Peter, I have been using "idle_cpu(smp_processor_id()))" to verify that
I really am running in the context of the idle task when RCU believes
that the current CPU has gone idle.  This is apparently the wrong thing
to use, because it gives spurious warnings when bringing up the non-boot
CPUs on x86 under some configs -- the task running at that point appears
to be kworker/0:0 rather than an idle thread.

At other times I get the warning even though the trace-event system is
convinced that I am running in the context of an idle thread, for example,
as in the following trace output:

<idle>-0     [000]    29.985355: rcu_dyntick: Error on entry: not idle task 0

On the left, trace-events thinks that this is the idle task, but the
check idle_cpu(smp_processor_id())) says otherwise.

Help?

							Thanx, Paul