* Re: RCU_USER_QS traces.
2012-10-04 14:41 RCU_USER_QS traces Dave Jones
@ 2012-10-04 15:46 ` Paul E. McKenney
2012-10-05 12:36 ` Frederic Weisbecker
1 sibling, 0 replies; 4+ messages in thread
From: Paul E. McKenney @ 2012-10-04 15:46 UTC (permalink / raw)
To: Dave Jones, Frederic Weisbecker, linux-kernel
On Thu, Oct 04, 2012 at 10:41:06AM -0400, Dave Jones wrote:
> > We have CONFIG_RCU_USER_QS that is a specific case. It's an intermediate state
> > before we implement a true CONFIG_NO_HZ_FULL. But the option is useless on its
> > own for users. Worse, it introduces a real overhead. OTOH we want it to be upstream
> > to make the development of full tickless feature more incremental.
>
> I couldn't resist trying it.. Did these get reported yet ?
News to me... Thank you for the testing!
And yes, please do not enable CONFIG_RCU_USER_QS in your distro. ;-)
Thanx, Paul
> WARNING: at kernel/rcutree.c:377 rcu_eqs_enter+0x93/0xa0()
> Pid: 0, comm: swapper/1 Not tainted 3.6.0+ #24
> Call Trace:
> [<ffffffff810678af>] warn_slowpath_common+0x7f/0xc0
> [<ffffffff8106790a>] warn_slowpath_null+0x1a/0x20
> [<ffffffff8111a383>] rcu_eqs_enter+0x93/0xa0
> [<ffffffff8111af0b>] rcu_idle_enter+0x2b/0x70
> [<ffffffff8102460f>] cpu_idle+0xbf/0x140
> [<ffffffff816ad18d>] start_secondary+0x252/0x254
>
> WARNING: at kernel/rcutree.c:352 rcu_eqs_enter_common.isra.37+0x1c6/0x1e0()
> Pid: 0, comm: swapper/1 Tainted: G W 3.6.0+ #24
> Call Trace:
> [<ffffffff810678af>] warn_slowpath_common+0x7f/0xc0
> [<ffffffff8106790a>] warn_slowpath_null+0x1a/0x20
> [<ffffffff8111a2d6>] rcu_eqs_enter_common.isra.37+0x1c6/0x1e0
> [<ffffffff8111a355>] rcu_eqs_enter+0x65/0xa0
> [<ffffffff8111af0b>] rcu_idle_enter+0x2b/0x70
> [<ffffffff8102460f>] cpu_idle+0xbf/0x140
> [<ffffffff816ad18d>] start_secondary+0x252/0x254
>
> WARNING: at kernel/rcutree.c:539 rcu_eqs_exit+0x99/0xb0()
> Pid: 0, comm: swapper/1 Tainted: G W 3.6.0+ #24
> Call Trace:
> [<ffffffff810678af>] warn_slowpath_common+0x7f/0xc0
> [<ffffffff8106790a>] warn_slowpath_null+0x1a/0x20
> [<ffffffff8111a0f9>] rcu_eqs_exit+0x99/0xb0
> [<ffffffff8111ae9b>] rcu_idle_exit+0x2b/0x70
> [<ffffffff8102461e>] cpu_idle+0xce/0x140
> [<ffffffff816ad18d>] start_secondary+0x252/0x254
>
> WARNING: at kernel/rcutree.c:513 rcu_eqs_exit_common.isra.35+0xd4/0xe0()
> Pid: 0, comm: swapper/1 Tainted: G W 3.6.0+ #24
> Call Trace:
> [<ffffffff810678af>] warn_slowpath_common+0x7f/0xc0
> [<ffffffff8106790a>] warn_slowpath_null+0x1a/0x20
> [<ffffffff8111a054>] rcu_eqs_exit_common.isra.35+0xd4/0xe0
> [<ffffffff8111a0bc>] rcu_eqs_exit+0x5c/0xb0
> [<ffffffff8111ae9b>] rcu_idle_exit+0x2b/0x70
> [<ffffffff8102461e>] cpu_idle+0xce/0x140
> [<ffffffff816ad18d>] start_secondary+0x252/0x254
>
> Dave
>
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: RCU_USER_QS traces.
2012-10-04 14:41 RCU_USER_QS traces Dave Jones
2012-10-04 15:46 ` Paul E. McKenney
@ 2012-10-05 12:36 ` Frederic Weisbecker
2012-10-05 20:00 ` Dave Jones
1 sibling, 1 reply; 4+ messages in thread
From: Frederic Weisbecker @ 2012-10-05 12:36 UTC (permalink / raw)
To: Dave Jones, Paul E. McKenney, linux-kernel
On Thu, Oct 04, 2012 at 10:41:06AM -0400, Dave Jones wrote:
> > We have CONFIG_RCU_USER_QS that is a specific case. It's an intermediate state
> > before we implement a true CONFIG_NO_HZ_FULL. But the option is useless on its
> > own for users. Worse, it introduces a real overhead. OTOH we want it to be upstream
> > to make the development of full tickless feature more incremental.
>
> I couldn't resist trying it.. Did these get reported yet ?
Hi Dave,
Thanks for this report. I need to find the source of the issue.
If you don't mind, could you please apply the following patch? You'll also
need to enable:
- CONFIG_EVENT_TRACING and CONFIG_RCU_TRACE
And you also need this boot parameter:
- trace_event=rcu_dyntick
Thanks a lot!
---
>From 824f2ef855597d6dd263bb363727e4585db88ca3 Mon Sep 17 00:00:00 2001
From: Frederic Weisbecker <fweisbec@gmail.com>
Date: Thu, 4 Oct 2012 17:30:36 +0200
Subject: [PATCH] rcu: Dump rcu traces and stacktraces on dynticks warnings
Temp patch for debugging.
Signed-off-by: Frederic Weisbecker <fweisbec@gmail.com>
---
kernel/rcutree.c | 38 ++++++++++++++++++++++++--------------
1 files changed, 24 insertions(+), 14 deletions(-)
diff --git a/kernel/rcutree.c b/kernel/rcutree.c
index 4fb2376..1bc96fd 100644
--- a/kernel/rcutree.c
+++ b/kernel/rcutree.c
@@ -59,6 +59,12 @@
#include "rcu.h"
+#define trace_rcu_dyntick_stacktrace(...) { \
+ trace_rcu_dyntick(__VA_ARGS__); \
+ trace_dump_stack();\
+}
+
+
/* Data structures. */
static struct lock_class_key rcu_node_class[RCU_NUM_LVLS];
@@ -334,11 +340,11 @@ static struct rcu_node *rcu_get_root(struct rcu_state *rsp)
static void rcu_eqs_enter_common(struct rcu_dynticks *rdtp, long long oldval,
bool user)
{
- trace_rcu_dyntick("Start", oldval, 0);
+ trace_rcu_dyntick_stacktrace("Start", oldval, 0);
if (!user && !is_idle_task(current)) {
struct task_struct *idle = idle_task(smp_processor_id());
- trace_rcu_dyntick("Error on entry: not idle task", oldval, 0);
+ trace_rcu_dyntick_stacktrace("Error on entry: not idle task", oldval, 0);
ftrace_dump(DUMP_ORIG);
WARN_ONCE(1, "Current pid: %d comm: %s / Idle pid: %d comm: %s",
current->pid, current->comm,
@@ -349,7 +355,8 @@ static void rcu_eqs_enter_common(struct rcu_dynticks *rdtp, long long oldval,
smp_mb__before_atomic_inc(); /* See above. */
atomic_inc(&rdtp->dynticks);
smp_mb__after_atomic_inc(); /* Force ordering with next sojourn. */
- WARN_ON_ONCE(atomic_read(&rdtp->dynticks) & 0x1);
+ if (WARN_ON_ONCE(atomic_read(&rdtp->dynticks) & 0x1))
+ ftrace_dump(DUMP_ORIG);
/*
* It is illegal to enter an extended quiescent state while
@@ -374,7 +381,8 @@ static void rcu_eqs_enter(bool user)
rdtp = &__get_cpu_var(rcu_dynticks);
oldval = rdtp->dynticks_nesting;
- WARN_ON_ONCE((oldval & DYNTICK_TASK_NEST_MASK) == 0);
+ if (WARN_ON_ONCE((oldval & DYNTICK_TASK_NEST_MASK) == 0))
+ ftrace_dump(DUMP_ORIG);
if ((oldval & DYNTICK_TASK_NEST_MASK) == DYNTICK_TASK_NEST_VALUE)
rdtp->dynticks_nesting = 0;
else
@@ -489,9 +497,9 @@ void rcu_irq_exit(void)
oldval = rdtp->dynticks_nesting;
rdtp->dynticks_nesting--;
WARN_ON_ONCE(rdtp->dynticks_nesting < 0);
- if (rdtp->dynticks_nesting)
- trace_rcu_dyntick("--=", oldval, rdtp->dynticks_nesting);
- else
+ if (rdtp->dynticks_nesting) {
+ trace_rcu_dyntick_stacktrace("--=", oldval, rdtp->dynticks_nesting);
+ } else
rcu_eqs_enter_common(rdtp, oldval, true);
local_irq_restore(flags);
}
@@ -510,13 +518,14 @@ static void rcu_eqs_exit_common(struct rcu_dynticks *rdtp, long long oldval,
atomic_inc(&rdtp->dynticks);
/* CPUs seeing atomic_inc() must see later RCU read-side crit sects */
smp_mb__after_atomic_inc(); /* See above. */
- WARN_ON_ONCE(!(atomic_read(&rdtp->dynticks) & 0x1));
+ if (WARN_ON_ONCE(!(atomic_read(&rdtp->dynticks) & 0x1)))
+ ftrace_dump(DUMP_ORIG);
rcu_cleanup_after_idle(smp_processor_id());
- trace_rcu_dyntick("End", oldval, rdtp->dynticks_nesting);
+ trace_rcu_dyntick_stacktrace("End", oldval, rdtp->dynticks_nesting);
if (!user && !is_idle_task(current)) {
struct task_struct *idle = idle_task(smp_processor_id());
- trace_rcu_dyntick("Error on exit: not idle task",
+ trace_rcu_dyntick_stacktrace("Error on exit: not idle task",
oldval, rdtp->dynticks_nesting);
ftrace_dump(DUMP_ORIG);
WARN_ONCE(1, "Current pid: %d comm: %s / Idle pid: %d comm: %s",
@@ -536,7 +545,8 @@ static void rcu_eqs_exit(bool user)
rdtp = &__get_cpu_var(rcu_dynticks);
oldval = rdtp->dynticks_nesting;
- WARN_ON_ONCE(oldval < 0);
+ if (WARN_ON_ONCE(oldval < 0))
+ ftrace_dump(DUMP_ORIG);
if (oldval & DYNTICK_TASK_NEST_MASK)
rdtp->dynticks_nesting += DYNTICK_TASK_NEST_VALUE;
else
@@ -650,9 +660,9 @@ void rcu_irq_enter(void)
oldval = rdtp->dynticks_nesting;
rdtp->dynticks_nesting++;
WARN_ON_ONCE(rdtp->dynticks_nesting == 0);
- if (oldval)
- trace_rcu_dyntick("++=", oldval, rdtp->dynticks_nesting);
- else
+ if (oldval) {
+ trace_rcu_dyntick_stacktrace("++=", oldval, rdtp->dynticks_nesting);
+ } else
rcu_eqs_exit_common(rdtp, oldval, true);
local_irq_restore(flags);
}
--
1.7.1
^ permalink raw reply related [flat|nested] 4+ messages in thread