On Tue, Jan 24, 2023 at 06:39:12PM +0000, Mark Rutland
wrote:> On Tue, Jan 24, 2023 at 05:30:29PM +0000, Mark Rutland wrote:
> > On Tue, Jan 24, 2023 at 04:34:23PM +0000, Mark Rutland wrote:
> > > Hi Peter,
> > >
> > > On Mon, Jan 23, 2023 at 09:50:09PM +0100, Peter Zijlstra wrote:
> > > > 0-day robot reported graph-tracing made the cpuidle-vs-rcu
rework go splat.
> > >
> > > Do you have a link toe the splat somewhere?
> > >
> > > I'm assuming that this is partially generic, and I'd like
to make sure I test
> > > the right thing on arm64. I'll throw my usual lockdep options
at the ftrace
> > > selftests...
> >
> > Hmm... with the tip sched/core branch, with or without this series
applied atop
> > I see a couple of splats which I don't see with v6.2-rc1 (which
seems to be
> > entirely clean). I'm not seeing any other splats.
> >
> > I can trigger those reliably with the 'toplevel-enable.tc'
ftrace test:
> >
> > ./ftracetest test.d/event/toplevel-enable.tc
> >
> > Splats below; I'll dig into this a bit more tomorrow.
> >
> > [ 65.729252] ------------[ cut here ]------------
> > [ 65.730397] WARNING: CPU: 3 PID: 1162 at
include/trace/events/preemptirq.h:55 trace_preempt_on+0x68/0x70
>
> The line number here is a bit inscrutible, but a bisect led me down to
commit
>
> 408b961146be4c1a ("tracing: WARN on rcuidle")
>
> ... and it appears this must be the RCUIDLE_COND() warning that adds, and
that
> seems to be because trace_preempt_on() calls
trace_preempt_enable_rcuidle():
>
> | void trace_preempt_on(unsigned long a0, unsigned long a1)
> | {
> | if (!in_nmi())
> | trace_preempt_enable_rcuidle(a0, a1);
> | tracer_preempt_on(a0, a1);
> | }
>
> It looks like that tracing is dependend upon CONFIG_TRACE_PREEMPT_TOGGLE,
and I
> have that because I enabled CONFIG_PREEMPT_TRACER. I reckon the same should
> happen on x86 with CONFIG_PREEMPT_TRACER=y.
>
> IIUC we'll need to clean up that trace_.*_rcuidle() usage too, but
I'm not
> entirely sure how to do that.
tip/sched/core contains the following patch addressing this:
---
commit 9aedeaed6fc6fe8452b9b8225e95cc2b8631ff91
Author: Peter Zijlstra <peterz at infradead.org>
Date: Thu Jan 12 20:43:49 2023 +0100
tracing, hardirq: No moar _rcuidle() tracing
Robot reported that trace_hardirqs_{on,off}() tickle the forbidden
_rcuidle() tracepoint through local_irq_{en,dis}able().
For 'sane' configs, these calls will only happen with RCU enabled
and
as such can use the regular tracepoint. This also means it's possible
to trace them from NMI context again.
Reported-by: kernel test robot <lkp at intel.com>
Signed-off-by: Peter Zijlstra (Intel) <peterz at infradead.org>
Signed-off-by: Ingo Molnar <mingo at kernel.org>
Link: https://lore.kernel.org/r/20230112195541.477416709 at infradead.org
diff --git a/kernel/trace/trace_preemptirq.c b/kernel/trace/trace_preemptirq.c
index 629f2854e12b..f992444a0b1f 100644
--- a/kernel/trace/trace_preemptirq.c
+++ b/kernel/trace/trace_preemptirq.c
@@ -19,6 +19,20 @@
/* Per-cpu variable to prevent redundant calls when IRQs already off */
static DEFINE_PER_CPU(int, tracing_irq_cpu);
+/*
+ * Use regular trace points on architectures that implement noinstr
+ * tooling: these calls will only happen with RCU enabled, which can
+ * use a regular tracepoint.
+ *
+ * On older architectures, use the rcuidle tracing methods (which
+ * aren't NMI-safe - so exclude NMI contexts):
+ */
+#ifdef CONFIG_ARCH_WANTS_NO_INSTR
+#define trace(point) trace_##point
+#else
+#define trace(point) if (!in_nmi()) trace_##point##_rcuidle
+#endif
+
/*
* Like trace_hardirqs_on() but without the lockdep invocation. This is
* used in the low level entry code where the ordering vs. RCU is important
@@ -28,8 +42,7 @@ static DEFINE_PER_CPU(int, tracing_irq_cpu);
void trace_hardirqs_on_prepare(void)
{
if (this_cpu_read(tracing_irq_cpu)) {
- if (!in_nmi())
- trace_irq_enable(CALLER_ADDR0, CALLER_ADDR1);
+ trace(irq_enable)(CALLER_ADDR0, CALLER_ADDR1);
tracer_hardirqs_on(CALLER_ADDR0, CALLER_ADDR1);
this_cpu_write(tracing_irq_cpu, 0);
}
@@ -40,8 +53,7 @@ NOKPROBE_SYMBOL(trace_hardirqs_on_prepare);
void trace_hardirqs_on(void)
{
if (this_cpu_read(tracing_irq_cpu)) {
- if (!in_nmi())
- trace_irq_enable_rcuidle(CALLER_ADDR0, CALLER_ADDR1);
+ trace(irq_enable)(CALLER_ADDR0, CALLER_ADDR1);
tracer_hardirqs_on(CALLER_ADDR0, CALLER_ADDR1);
this_cpu_write(tracing_irq_cpu, 0);
}
@@ -63,8 +75,7 @@ void trace_hardirqs_off_finish(void)
if (!this_cpu_read(tracing_irq_cpu)) {
this_cpu_write(tracing_irq_cpu, 1);
tracer_hardirqs_off(CALLER_ADDR0, CALLER_ADDR1);
- if (!in_nmi())
- trace_irq_disable(CALLER_ADDR0, CALLER_ADDR1);
+ trace(irq_disable)(CALLER_ADDR0, CALLER_ADDR1);
}
}
@@ -78,8 +89,7 @@ void trace_hardirqs_off(void)
if (!this_cpu_read(tracing_irq_cpu)) {
this_cpu_write(tracing_irq_cpu, 1);
tracer_hardirqs_off(CALLER_ADDR0, CALLER_ADDR1);
- if (!in_nmi())
- trace_irq_disable_rcuidle(CALLER_ADDR0, CALLER_ADDR1);
+ trace(irq_disable)(CALLER_ADDR0, CALLER_ADDR1);
}
}
EXPORT_SYMBOL(trace_hardirqs_off);