lkml.org 
[lkml]   [2013]   [May]   [23]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: WARNING: at kernel/rcutree.c:388 rcu_eqs_enter
On Wed, May 22, 2013 at 02:51:29AM -0700, Paul E. McKenney wrote:

> trace: Allow idle-safe tracepoints to be called from irq
>
> __DECLARE_TRACE_RCU() currently creates an _rcuidle() tracepoint which
> may safely be invoked from what RCU considers to be an idle CPU.
> However, these _rcuidle() tracepoints may -not- be invoked from the
> handler of an irq taken from idle, because rcu_idle_enter() zeroes
> RCU's nesting-level counter, so that the rcu_irq_exit() returning to
> idle will trigger a WARN_ON_ONCE().
>
> This commit therefore substitutes rcu_irq_enter() for rcu_idle_exit()
> and rcu_irq_exit() for rcu_idle_enter() in order to make the _rcuidle()
> tracepoints usable from irq handlers as well as from process context.
>
> Reported-by: Dave Jones <davej@redhat.com>
> Signed-off-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
> Cc: Steven Rostedt <rostedt@goodmis.org>
>
> diff --git a/include/linux/tracepoint.h b/include/linux/tracepoint.h
> index 2f322c3..f8e084d 100644
> --- a/include/linux/tracepoint.h
> +++ b/include/linux/tracepoint.h
> @@ -145,8 +145,8 @@ static inline void tracepoint_synchronize_unregister(void)
> TP_PROTO(data_proto), \
> TP_ARGS(data_args), \
> TP_CONDITION(cond), \
> - rcu_idle_exit(), \
> - rcu_idle_enter()); \
> + rcu_irq_enter(), \
> + rcu_irq_exit()); \
> }
> #else
> #define __DECLARE_TRACE_RCU(name, proto, args, cond, data_proto, data_args)

This stops the "WARNING: at kernel/context_tracking.c:55 user_enter+0xb5/0xd0()"
but I still see..


[ 363.399348] ===============================
[ 363.400617] [ INFO: suspicious RCU usage. ]
[ 363.401880] 3.10.0-rc2+ #31 Not tainted
[ 363.403210] -------------------------------
[ 363.403787] include/linux/rcupdate.h:771 rcu_read_lock() used illegally while idle!
[ 363.403831]
other info that might help us debug this:

[ 363.403880]
RCU used illegally from idle CPU!
rcu_scheduler_active = 1, debug_locks = 0
[ 363.403942] RCU used illegally from extended quiescent state!
[ 363.403976] 2 locks held by trinity-child0/27319:
[ 363.404006] #0: (&rq->lock){-.-.-.}, at: [<ffffffff816e91bf>] __schedule+0xef/0x9c0
[ 363.404076] #1: (rcu_read_lock){.+.+..}, at: [<ffffffff810a5605>] cpuacct_charge+0x5/0x1f0
[ 363.404146]
stack backtrace:
[ 363.404176] CPU: 1 PID: 27319 Comm: trinity-child0 Not tainted 3.10.0-rc2+ #31
[ 363.405536] 0000000000000000 ffff880208ddfcf8 ffffffff816e2a5b ffff880208ddfd28
[ 363.406835] ffffffff810b5917 ffff880243362568 00000000003c3c18 ffff880243362520
[ 363.408140] 0000000000000001 ffff880208ddfd60 ffffffff810a5785 ffffffff810a5605
[ 363.409451] Call Trace:
[ 363.410726] [<ffffffff816e2a5b>] dump_stack+0x19/0x1b
[ 363.412005] [<ffffffff810b5917>] lockdep_rcu_suspicious+0xe7/0x120
[ 363.413281] [<ffffffff810a5785>] cpuacct_charge+0x185/0x1f0
[ 363.414543] [<ffffffff810a5605>] ? cpuacct_charge+0x5/0x1f0
[ 363.415793] [<ffffffff8109607c>] update_curr+0xec/0x250
[ 363.417035] [<ffffffff810975a8>] put_prev_task_fair+0x228/0x480
[ 363.418273] [<ffffffff816e9236>] __schedule+0x166/0x9c0
[ 363.419497] [<ffffffff816e9ee4>] preempt_schedule+0x44/0x60
[ 363.420717] [<ffffffff816e9fb0>] ? __cond_resched_softirq+0x60/0x60
[ 363.421940] [<ffffffff816ebfa4>] ? retint_careful+0x12/0x2e
[ 363.423155] [<ffffffff8110e2b3>] ftrace_ops_control_func+0x1d3/0x210
[ 363.424373] [<ffffffff816f3a40>] ftrace_call+0x5/0x2f
[ 363.425577] [<ffffffff816ebf9d>] ? retint_careful+0xb/0x2e
[ 363.426784] [<ffffffff816e9fb5>] ? schedule_user+0x5/0x70
[ 363.427988] [<ffffffff816e9fb5>] ? schedule_user+0x5/0x70
[ 363.429184] [<ffffffff816ebfa4>] ? retint_careful+0x12/0x2e

I'll try Steve's patch on top next.

Dave



\
 
 \ /
  Last update: 2013-05-23 18:22    [W:0.054 / U:0.104 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site