linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* RCU_USER_QS traces.
@ 2012-10-04 14:41 Dave Jones
  2012-10-04 15:46 ` Paul E. McKenney
  2012-10-05 12:36 ` Frederic Weisbecker
  0 siblings, 2 replies; 4+ messages in thread
From: Dave Jones @ 2012-10-04 14:41 UTC (permalink / raw)
  To: Frederic Weisbecker; +Cc: Paul E. McKenney, linux-kernel

 > 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 ?


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
  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

* Re: RCU_USER_QS traces.
  2012-10-05 12:36 ` Frederic Weisbecker
@ 2012-10-05 20:00   ` Dave Jones
  0 siblings, 0 replies; 4+ messages in thread
From: Dave Jones @ 2012-10-05 20:00 UTC (permalink / raw)
  To: Frederic Weisbecker; +Cc: Paul E. McKenney, linux-kernel

On Fri, Oct 05, 2012 at 02:36:19PM +0200, Frederic Weisbecker wrote:
 > 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!

Hrmph, it seems to have gone into hiding. I can't reproduce it any more.
If it shows about again, I'll get back to you.

	Dave 

^ permalink raw reply	[flat|nested] 4+ messages in thread

end of thread, other threads:[~2012-10-05 20:00 UTC | newest]

Thread overview: 4+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
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

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).