Re: [PATCH v2 11/11] lockdep,trace: Expose tracepoints

From: peterz@infradead.org
To: Guenter Roeck <linux@roeck-us.net>
Cc: linux-kernel@vger.kernel.org, mingo@kernel.org, will@kernel.org,
	npiggin@gmail.com, elver@google.com, jgross@suse.com,
	paulmck@kernel.org, rostedt@goodmis.org, rjw@rjwysocki.net,
	joel@joelfernandes.org, svens@linux.ibm.com, tglx@linutronix.de
Subject: Re: [PATCH v2 11/11] lockdep,trace: Expose tracepoints
Date: Wed, 2 Sep 2020 09:24:32 +0200	[thread overview]
Message-ID: <20200902072432.GI2674@hirez.programming.kicks-ass.net> (raw)
In-Reply-To: <20200902035146.GA45826@roeck-us.net>

On Tue, Sep 01, 2020 at 08:51:46PM -0700, Guenter Roeck wrote:
> On Fri, Aug 21, 2020 at 10:47:49AM +0200, Peter Zijlstra wrote:
> > The lockdep tracepoints are under the lockdep recursion counter, this
> > has a bunch of nasty side effects:
> > 
> >  - TRACE_IRQFLAGS doesn't work across the entire tracepoint
> > 
> >  - RCU-lockdep doesn't see the tracepoints either, hiding numerous
> >    "suspicious RCU usage" warnings.
> > 
> > Pull the trace_lock_*() tracepoints completely out from under the
> > lockdep recursion handling and completely rely on the trace level
> > recusion handling -- also, tracing *SHOULD* not be taking locks in any
> > case.
> > 
> 
> Wonder what is worse - the problem or its fix. This patch results in
> a number of WARNING backtraces for several archtectures/platforms.
> Reverting it fixes the problems.

Without all this there was a recursion that could crash. But yes,
tedious.

OTOH the warnings are about real bugs that were pre-existing, we now see
them and can fix them.

I'll reply to ARM separately, but let's have a peek at s390.

> s390:
> 
> [   19.490586] =============================
> [   19.490752] WARNING: suspicious RCU usage
> [   19.490921] 5.9.0-rc3 #1 Not tainted
> [   19.491086] -----------------------------
> [   19.491253] include/trace/events/lock.h:37 suspicious rcu_dereference_check() usage!

> [   19.493147]  [<00000000001d5de2>] lock_acquire+0x41a/0x498
> [   19.493320]  [<0000000000103b72>] enabled_wait+0xca/0x198
> [   19.493493]  [<0000000000103f80>] arch_cpu_idle+0x20/0x38

Does this help?

---

diff --git a/arch/s390/kernel/idle.c b/arch/s390/kernel/idle.c
index c73f50649e7e..f7f1e64e0d98 100644
--- a/arch/s390/kernel/idle.c
+++ b/arch/s390/kernel/idle.c
@@ -39,14 +39,13 @@ void enabled_wait(void)
 	local_irq_restore(flags);
 
 	/* Account time spent with enabled wait psw loaded as idle time. */
-	/* XXX seqcount has tracepoints that require RCU */
-	write_seqcount_begin(&idle->seqcount);
+	raw_write_seqcount_begin(&idle->seqcount);
 	idle_time = idle->clock_idle_exit - idle->clock_idle_enter;
 	idle->clock_idle_enter = idle->clock_idle_exit = 0ULL;
 	idle->idle_time += idle_time;
 	idle->idle_count++;
 	account_idle_time(cputime_to_nsecs(idle_time));
-	write_seqcount_end(&idle->seqcount);
+	raw_write_seqcount_end(&idle->seqcount);
 }
 NOKPROBE_SYMBOL(enabled_wait);
 
