Linux-ARM-Kernel Archive on lore.kernel.org
 help / color / mirror / Atom feed
* Re: [for-next][PATCH 04/15] tracepoint: Add lockdep rcu_is_watching() check to trace_##name##_enabled()
       [not found] ` <20260522143525.551205135@kernel.org>
@ 2026-06-30 17:39   ` Geert Uytterhoeven
  2026-06-30 19:53     ` Steven Rostedt
  0 siblings, 1 reply; 4+ messages in thread
From: Geert Uytterhoeven @ 2026-06-30 17:39 UTC (permalink / raw)
  To: Steven Rostedt, David Carlier
  Cc: linux-kernel, Masami Hiramatsu, Mark Rutland, Mathieu Desnoyers,
	Andrew Morton, Vineeth Pillai (Google), Peter Zijlstra, Linux ARM,
	Linux-Renesas

Hi Steven, David,

On Fri, 22 May 2026 at 16:35, Steven Rostedt <rostedt@kernel.org> wrote:
> From: David Carlier <devnexen@gmail.com>
>
> The trace_##name##_enabled() static call branch is used when work needs to
> be done for a tracepoint. It allows that work to be skipped when the
> tracepoint is not active and still uses the static_branch() of the
> tracepoint to keep performance.
>
> Tracepoints themselves require being called in "RCU watching" locations
> otherwise races can occur that corrupts things. In order to make sure
> lockdep triggers at tracepoint locations, the lockdep checks are added to
> the tracepoint calling location and trigger even if the tracepoint is not
> enabled. This is done because a poorly placed tracepoint may never be
> detected if it is never enabled when lockdep is enabled.
>
> As trace_##name##_enabled() also prevents the lockdep checks when the
> tracepoint is disabled add lockdep checks to that as well so that if one
> is placed in a location that RCU is not watching, it will trigger a
> lockdep splat even when the tracepoint is not enabled.
>
> Cc: Vineeth Pillai (Google) <vineeth@bitbyteword.org>
> Cc: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
> Cc: Masami Hiramatsu <mhiramat@kernel.org>
> Cc: Peter Zijlstra <peterz@infradead.org>
> Link: https://patch.msgid.link/20260430144159.10985-1-devnexen@gmail.com
> Signed-off-by: David Carlier <devnexen@gmail.com>
> [ Updated the change log ]
> Signed-off-by: Steven Rostedt <rostedt@goodmis.org>

Thanks for your patch, which is now commit 9764e731ef6abacd
("tracepoint: Add lockdep rcu_is_watching() check to
trace_##name##_enabled()") in v7.2-rc1.

This is causing multiple warnings during system suspend on Renesas
SH-Mobile AG5, R-Car H1. and R-Car M2-W:

     PM: suspend entry (deep)
    -Filesystems sync: 0.018 seconds
    +Filesystems sync: 0.027 seconds
     Freezing user space processes
     Freezing user space processes completed (elapsed 0.001 seconds)
     OOM killer disabled.
     Freezing remaining freezable tasks
     Freezing remaining freezable tasks completed (elapsed 0.001 seconds)
    -PM: suspend devices took 0.110 seconds
    +------------[ cut here ]------------
    +WARNING: include/trace/events/preemptirq.h:36 at
trace_irq_disable_enabled+0x3c/0x64, CPU#0: swapper/0/0
    +------------[ cut here ]------------
    +RCU not watching for tracepoint
    +Modules linked in:
    +WARNING: include/trace/events/preemptirq.h:40 at
trace_irq_enable_enabled+0x3c/0x64, CPU#1: swapper/1/0
    +
    +RCU not watching for tracepoint
    +CPU: 0 UID: 0 PID: 0 Comm: swapper/0 Not tainted
7.1.0-rc4-koelsch-00006-g9764e731ef6a #2337 VOLUNTARY
    +Hardware name: Generic R-Car Gen2 (Flattened Device Tree)
    +Call trace:
    + unwind_backtrace from show_stack+0x10/0x14
    + show_stack from dump_stack_lvl+0x7c/0xb0
    + dump_stack_lvl from __warn+0x98/0x27c
    + __warn from warn_slowpath_fmt+0xc0/0x124
    + warn_slowpath_fmt from trace_irq_disable_enabled+0x3c/0x64
    + trace_irq_disable_enabled from trace_hardirqs_off+0x6c/0xb0
    + trace_hardirqs_off from __irq_svc+0x48/0xac
    +Exception stack(0xc1401f20 to 0xc1401f68)
    +1f20: c027a764 effb0e88 00000000 00000001 c140b080 c027a764
c140801c c140b080
    +1f40: c1407fe0 00000000 c140801c 00000000 fffffff8 c1401f70
c0b35980 c0b359d8
    +1f60: 20000113 ffffffff
    + __irq_svc from cpu_idle_poll+0x114/0x130
    + cpu_idle_poll from do_idle+0xb8/0x268
    + do_idle from cpu_startup_entry+0x28/0x2c
    + cpu_startup_entry from rest_init+0x150/0x178
    + rest_init from start_kernel+0x634/0x6d8
    +irq event stamp: 19112
    +Modules linked in:
    +hardirqs last  enabled at (19111): [<c0b35adc>]
default_idle_call+0xe8/0x104
    +
    +hardirqs last disabled at (19112): [<c0200b88>] __irq_svc+0x48/0xac
    +CPU: 1 UID: 0 PID: 0 Comm: swapper/1 Not tainted
7.1.0-rc4-koelsch-00006-g9764e731ef6a #2337 VOLUNTARY
    +Hardware name: Generic R-Car Gen2 (Flattened Device Tree)
    +Call trace:
    + unwind_backtrace from show_stack+0x10/0x14
    + show_stack from dump_stack_lvl+0x7c/0xb0
    + dump_stack_lvl from __warn+0x98/0x27c
    + __warn from warn_slowpath_fmt+0xc0/0x124
    + warn_slowpath_fmt from trace_irq_enable_enabled+0x3c/0x64
    + trace_irq_enable_enabled from trace_hardirqs_on+0x40/0xbc
    + trace_hardirqs_on from __irq_svc+0x94/0xac
    +Exception stack(0xf0865f48 to 0xf0865f90)
    +5f40:                   c027a764 effc2e88 00000000 00000001
c227cec0 c027a764
    +5f60: c140801c c227cec0 c1407fe0 413fc0f2 c140801c 00000000
fffffff8 f0865f98
    +5f80: c0b35980 c0b35988 20000013 ffffffff
    + __irq_svc from cpu_idle_poll+0xc4/0x130
    + cpu_idle_poll from do_idle+0xb8/0x268
    + do_idle from cpu_startup_entry+0x28/0x2c
    + cpu_startup_entry from secondary_start_kernel+0xdc/0xf0
    + secondary_start_kernel from 0x4020f094
    +irq event stamp: 27461
    +softirqs last  enabled at (19008): [<c02341ec>] handle_softirqs+0x174/0x3e4
    +hardirqs last  enabled at (27461): [<c027a7d0>] do_idle+0x124/0x268
    +softirqs last disabled at (18991): [<c0234a84>] __irq_exit_rcu+0xf0/0x194
    +hardirqs last disabled at (27460): [<c027a734>] do_idle+0x88/0x268
    +---[ end trace 0000000000000000 ]---
    +softirqs last  enabled at (27438): [<c02341ec>] handle_softirqs+0x174/0x3e4
    +softirqs last disabled at (27425): [<c0234a84>] __irq_exit_rcu+0xf0/0x194
    +---[ end trace 0000000000000000 ]---
    +PM: suspend devices took 0.380 seconds
     Disabling non-boot CPUs ...

Other Renesas ARM32 platforms I tried (R-Mobile A1, RZ/A1H, RZ/A2M)
are unafffected, perhaps because they are not SMP?
All Renesas ARM64 platforms I tried (R-Car Gen3/4) are also unaffected.

Reverting the commit fixes the issue.

Do you have a clue?
Thanks!

> --- a/include/linux/tracepoint.h
> +++ b/include/linux/tracepoint.h
> @@ -293,6 +293,10 @@ static inline struct tracepoint *tracepoint_ptr_deref(tracepoint_ptr_t *p)
>         static inline bool                                              \
>         trace_##name##_enabled(void)                                    \
>         {                                                               \
> +               if (IS_ENABLED(CONFIG_LOCKDEP)) {                       \
> +                       WARN_ONCE(!rcu_is_watching(),                   \
> +                                 "RCU not watching for tracepoint");   \
> +               }                                                       \
>                 return static_branch_unlikely(&__tracepoint_##name.key);\
>         }

Gr{oetje,eeting}s,

                        Geert

-- 
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- geert@linux-m68k.org

In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
                                -- Linus Torvalds


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

* Re: [for-next][PATCH 04/15] tracepoint: Add lockdep rcu_is_watching() check to trace_##name##_enabled()
  2026-06-30 17:39   ` [for-next][PATCH 04/15] tracepoint: Add lockdep rcu_is_watching() check to trace_##name##_enabled() Geert Uytterhoeven
@ 2026-06-30 19:53     ` Steven Rostedt
  2026-07-01  9:24       ` Geert Uytterhoeven
  0 siblings, 1 reply; 4+ messages in thread
From: Steven Rostedt @ 2026-06-30 19:53 UTC (permalink / raw)
  To: Geert Uytterhoeven
  Cc: David Carlier, linux-kernel, Masami Hiramatsu, Mark Rutland,
	Mathieu Desnoyers, Andrew Morton, Vineeth Pillai (Google),
	Peter Zijlstra, Linux ARM, Linux-Renesas

On Tue, 30 Jun 2026 19:39:02 +0200
Geert Uytterhoeven <geert@linux-m68k.org> wrote:

> Other Renesas ARM32 platforms I tried (R-Mobile A1, RZ/A1H, RZ/A2M)
> are unafffected, perhaps because they are not SMP?
> All Renesas ARM64 platforms I tried (R-Car Gen3/4) are also unaffected.
> 
> Reverting the commit fixes the issue.
> 
> Do you have a clue?

Yes, it means the code was buggy before the commit. The commit will trigger
warnings in places that have issues. Before the commit, the buggy code was
never caught.

It's like enabling KASAN and finding code that has use-after-free.
Disabling KASAN is not the fix.

Tracepoints are managed by using RCU. There's places that RCU is turned
off, meaning a tracepoint in one of those locations can be triggered when
RCU is not active which may have a use-after-free semantic when the
tracepoint is enabled.

Tracepoints hidden by trace_#tracepoint#_enabled() are not caught when RCU
is disabled and the tracepoint is not active. This commit makes these
locations trigger even when the tracepoint is not active.

One way to find out if this is an existing bug or not, could you enable the
preemptirq tracepoints and run the tests again with the commit reverted?

  echo 1 >  /sys/kernel/tracing/events/preemptirq/enable

This will enable the events that are hidden without the commit. If it
triggers when enabled, it shows the commit found a bug.

If you get the same errors, the bug isn't with the commit in question, it's
with the tracepoints being called during suspend/resume. We will need to
fix that if that's the case.

-- Steve


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

* Re: [for-next][PATCH 04/15] tracepoint: Add lockdep rcu_is_watching() check to trace_##name##_enabled()
  2026-06-30 19:53     ` Steven Rostedt
@ 2026-07-01  9:24       ` Geert Uytterhoeven
  2026-07-01 17:11         ` Steven Rostedt
  0 siblings, 1 reply; 4+ messages in thread
From: Geert Uytterhoeven @ 2026-07-01  9:24 UTC (permalink / raw)
  To: Steven Rostedt
  Cc: David Carlier, linux-kernel, Masami Hiramatsu, Mark Rutland,
	Mathieu Desnoyers, Andrew Morton, Vineeth Pillai (Google),
	Peter Zijlstra, Linux ARM, Linux-Renesas

Hi Steven,

On Tue, 30 Jun 2026 at 21:53, Steven Rostedt <rostedt@kernel.org> wrote:
> On Tue, 30 Jun 2026 19:39:02 +0200
> Geert Uytterhoeven <geert@linux-m68k.org> wrote:
> > Other Renesas ARM32 platforms I tried (R-Mobile A1, RZ/A1H, RZ/A2M)
> > are unafffected, perhaps because they are not SMP?
> > All Renesas ARM64 platforms I tried (R-Car Gen3/4) are also unaffected.
> >
> > Reverting the commit fixes the issue.
> >
> > Do you have a clue?
>
> Yes, it means the code was buggy before the commit. The commit will trigger
> warnings in places that have issues. Before the commit, the buggy code was
> never caught.
>
> It's like enabling KASAN and finding code that has use-after-free.
> Disabling KASAN is not the fix.
>
> Tracepoints are managed by using RCU. There's places that RCU is turned
> off, meaning a tracepoint in one of those locations can be triggered when
> RCU is not active which may have a use-after-free semantic when the
> tracepoint is enabled.
>
> Tracepoints hidden by trace_#tracepoint#_enabled() are not caught when RCU
> is disabled and the tracepoint is not active. This commit makes these
> locations trigger even when the tracepoint is not active.

Sorry, my wording could indeed be better: this commit probably does not
"cause" the issue, but merely exposes it.

> One way to find out if this is an existing bug or not, could you enable the
> preemptirq tracepoints and run the tests again with the commit reverted?
>
>   echo 1 >  /sys/kernel/tracing/events/preemptirq/enable
>
> This will enable the events that are hidden without the commit. If it
> triggers when enabled, it shows the commit found a bug.
>
> If you get the same errors, the bug isn't with the commit in question, it's
> with the tracepoints being called during suspend/resume. We will need to
> fix that if that's the case.

Thanks, it does not trigger with the commit reverted and the "echo 1 > ...".

Gr{oetje,eeting}s,

                        Geert

-- 
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- geert@linux-m68k.org

In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
                                -- Linus Torvalds


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

* Re: [for-next][PATCH 04/15] tracepoint: Add lockdep rcu_is_watching() check to trace_##name##_enabled()
  2026-07-01  9:24       ` Geert Uytterhoeven
@ 2026-07-01 17:11         ` Steven Rostedt
  0 siblings, 0 replies; 4+ messages in thread
From: Steven Rostedt @ 2026-07-01 17:11 UTC (permalink / raw)
  To: Geert Uytterhoeven
  Cc: David Carlier, linux-kernel, Masami Hiramatsu, Mark Rutland,
	Mathieu Desnoyers, Andrew Morton, Vineeth Pillai (Google),
	Peter Zijlstra, Linux ARM, Linux-Renesas

On Wed, 1 Jul 2026 11:24:31 +0200
Geert Uytterhoeven <geert@linux-m68k.org> wrote:

> Thanks, it does not trigger with the commit reverted and the "echo 1 > ...".

Ah found the issue;

#define trace(point, args)                                      \
        do {                                                    \
                if (trace_##point##_enabled()) {                \
                        bool exit_rcu = false;                  \
                        if (in_nmi())                           \
                                break;                          \
                        if (!IS_ENABLED(CONFIG_TINY_RCU) &&     \
                            is_idle_task(current)) {            \
                                ct_irq_enter();                 \
                                exit_rcu = true;                \
                        }                                       \
                        trace_##point(args);                    \
                        if (exit_rcu)                           \
                                ct_irq_exit();                  \
                }                                               \
        } while (0)
#endif

The code within the enabled() call checks if RCU is watching, and if
not, it makes it watch. So yeah, this is a special case.

The following patch should fix the issue:

diff --git a/include/linux/tracepoint.h b/include/linux/tracepoint.h
index 4a0c36f40fe2..e0d838c9ce93 100644
--- a/include/linux/tracepoint.h
+++ b/include/linux/tracepoint.h
@@ -292,13 +292,18 @@ static inline struct tracepoint *tracepoint_ptr_deref(tracepoint_ptr_t *p)
 	{								\
 	}								\
 	static inline bool						\
+	__trace_##name##_enabled(void)					\
+	{								\
+		return static_branch_unlikely(&__tracepoint_##name.key);\
+	}								\
+	static inline bool						\
 	trace_##name##_enabled(void)					\
 	{								\
 		if (IS_ENABLED(CONFIG_LOCKDEP)) {			\
 			WARN_ONCE(!rcu_is_watching(),			\
 				  "RCU not watching for tracepoint");	\
 		}							\
-		return static_branch_unlikely(&__tracepoint_##name.key);\
+		return __trace_##name##_enabled();			\
 	}
 
 #define __DECLARE_TRACE(name, proto, args, cond, data_proto)			\
@@ -457,6 +462,11 @@ static inline struct tracepoint *tracepoint_ptr_deref(tracepoint_ptr_t *p)
 	{								\
 	}								\
 	static inline bool						\
+	__trace_##name##_enabled(void)					\
+	{								\
+		return false;						\
+	}								\
+	static inline bool						\
 	trace_##name##_enabled(void)					\
 	{								\
 		return false;						\
diff --git a/kernel/trace/trace_preemptirq.c b/kernel/trace/trace_preemptirq.c
index 0c42b15c3800..b63e3558948f 100644
--- a/kernel/trace/trace_preemptirq.c
+++ b/kernel/trace/trace_preemptirq.c
@@ -30,7 +30,7 @@
 #else
 #define trace(point, args)					\
 	do {							\
-		if (trace_##point##_enabled()) {		\
+		if (__trace_##point##_enabled()) {		\
 			bool exit_rcu = false;			\
 			if (in_nmi())				\
 				break;				\


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

end of thread, other threads:[~2026-07-01 17:12 UTC | newest]

Thread overview: 4+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
     [not found] <20260522143508.298439732@kernel.org>
     [not found] ` <20260522143525.551205135@kernel.org>
2026-06-30 17:39   ` [for-next][PATCH 04/15] tracepoint: Add lockdep rcu_is_watching() check to trace_##name##_enabled() Geert Uytterhoeven
2026-06-30 19:53     ` Steven Rostedt
2026-07-01  9:24       ` Geert Uytterhoeven
2026-07-01 17:11         ` Steven Rostedt

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox