2024-02-28 18:29:15

by Steven Rostedt

Subject: [PATCH] tracepoints: Use WARN() and not WARN_ON() for warnings

From: "Steven Rostedt (Google)" <[email protected]>

There are two WARN_ON*() warnings in tracepoint.h that deal with RCU
usage. But when they trigger, especially from using a TRACE_EVENT()
macro, the information is not very helpful and is confusing:

------------[ cut here ]------------
WARNING: CPU: 0 PID: 0 at include/trace/events/lock.h:24 lock_acquire+0x2b2/0x2d0

Where the above warning takes you to:

TRACE_EVENT(lock_acquire, <<<--- line 24 in lock.h

TP_PROTO(struct lockdep_map *lock, unsigned int subclass,
int trylock, int read, int check,
struct lockdep_map *next_lock, unsigned long ip),
[..]

Change the WARN_ON_ONCE() to WARN_ONCE() and add a string that allows
someone to search for exactly where the bug happened.

Reported-by: Borislav Petkov <[email protected]>
Signed-off-by: Steven Rostedt (Google) <[email protected]>
---
include/linux/tracepoint.h | 6 ++++--
1 file changed, 4 insertions(+), 2 deletions(-)

diff --git a/include/linux/tracepoint.h b/include/linux/tracepoint.h
index 88c0ba623ee6..689b6d71590e 100644
--- a/include/linux/tracepoint.h
+++ b/include/linux/tracepoint.h
@@ -199,7 +199,8 @@ static inline struct tracepoint *tracepoint_ptr_deref(tracepoint_ptr_t *p)
if (!(cond)) \
return; \
\
- if (WARN_ON_ONCE(RCUIDLE_COND(rcuidle))) \
+ if (WARN_ONCE(RCUIDLE_COND(rcuidle), \
+ "Bad RCU usage for tracepoint")) \
return; \
\
/* keep srcu and sched-rcu usage consistent */ \
@@ -259,7 +260,8 @@ static inline struct tracepoint *tracepoint_ptr_deref(tracepoint_ptr_t *p)
TP_ARGS(args), \
TP_CONDITION(cond), 0); \
if (IS_ENABLED(CONFIG_LOCKDEP) && (cond)) { \
- WARN_ON_ONCE(!rcu_is_watching()); \
+ WARN_ONCE(!rcu_is_watching(), \
+ "RCU not watching for tracepoint"); \
} \
} \
__DECLARE_TRACE_RCU(name, PARAMS(proto), PARAMS(args), \
--
2.43.0

2024-02-28 18:32:54

by Borislav Petkov

Subject: Re: [PATCH] tracepoints: Use WARN() and not WARN_ON() for warnings

On Wed, Feb 28, 2024 at 01:31:12PM -0500, Steven Rostedt wrote:
> From: "Steven Rostedt (Google)" <[email protected]>
>
> There are two WARN_ON*() warnings in tracepoint.h that deal with RCU
> usage. But when they trigger, especially from using a TRACE_EVENT()
> macro, the information is not very helpful and is confusing:
>
> ------------[ cut here ]------------
> WARNING: CPU: 0 PID: 0 at include/trace/events/lock.h:24 lock_acquire+0x2b2/0x2d0
>
> Where the above warning takes you to:
>
> TRACE_EVENT(lock_acquire, <<<--- line 24 in lock.h
>
> TP_PROTO(struct lockdep_map *lock, unsigned int subclass,
> int trylock, int read, int check,
> struct lockdep_map *next_lock, unsigned long ip),
> [..]
>
> Change the WARN_ON_ONCE() to WARN_ONCE() and add a string that allows
> someone to search for exactly where the bug happened.
>
> Reported-by: Borislav Petkov <[email protected]>
> Signed-off-by: Steven Rostedt (Google) <[email protected]>
> ---
> include/linux/tracepoint.h | 6 ++++--
> 1 file changed, 4 insertions(+), 2 deletions(-)

Tested-by: Borislav Petkov (AMD) <[email protected]>

meaning: tested that it really fires:

[ 1.196008] Running RCU Tasks wait API self tests
[ 1.200227] ------------[ cut here ]------------
[ 1.203899] RCU not watching for tracepoint
[ 1.203899] WARNING: CPU: 0 PID: 0 at include/trace/events/lock.h:24 lock_acquire+0x2d3/0x300
..

Thx.

--
Regards/Gruss,
Boris.

https://people.kernel.org/tglx/notes-about-netiquette

2024-02-28 18:57:14

by Paul E. McKenney

Subject: Re: [PATCH] tracepoints: Use WARN() and not WARN_ON() for warnings

On Wed, Feb 28, 2024 at 01:31:12PM -0500, Steven Rostedt wrote:
> From: "Steven Rostedt (Google)" <[email protected]>
>
> There are two WARN_ON*() warnings in tracepoint.h that deal with RCU
> usage. But when they trigger, especially from using a TRACE_EVENT()
> macro, the information is not very helpful and is confusing:
>
> ------------[ cut here ]------------
> WARNING: CPU: 0 PID: 0 at include/trace/events/lock.h:24 lock_acquire+0x2b2/0x2d0
>
> Where the above warning takes you to:
>
> TRACE_EVENT(lock_acquire, <<<--- line 24 in lock.h
>
> TP_PROTO(struct lockdep_map *lock, unsigned int subclass,
> int trylock, int read, int check,
> struct lockdep_map *next_lock, unsigned long ip),
> [..]
>
> Change the WARN_ON_ONCE() to WARN_ONCE() and add a string that allows
> someone to search for exactly where the bug happened.
>
> Reported-by: Borislav Petkov <[email protected]>
> Signed-off-by: Steven Rostedt (Google) <[email protected]>

Reviewed-by: Paul E. McKenney <[email protected]>

> ---
> include/linux/tracepoint.h | 6 ++++--
> 1 file changed, 4 insertions(+), 2 deletions(-)
>
> diff --git a/include/linux/tracepoint.h b/include/linux/tracepoint.h
> index 88c0ba623ee6..689b6d71590e 100644
> --- a/include/linux/tracepoint.h
> +++ b/include/linux/tracepoint.h
> @@ -199,7 +199,8 @@ static inline struct tracepoint *tracepoint_ptr_deref(tracepoint_ptr_t *p)
> if (!(cond)) \
> return; \
> \
> - if (WARN_ON_ONCE(RCUIDLE_COND(rcuidle))) \
> + if (WARN_ONCE(RCUIDLE_COND(rcuidle), \
> + "Bad RCU usage for tracepoint")) \
> return; \
> \
> /* keep srcu and sched-rcu usage consistent */ \
> @@ -259,7 +260,8 @@ static inline struct tracepoint *tracepoint_ptr_deref(tracepoint_ptr_t *p)
> TP_ARGS(args), \
> TP_CONDITION(cond), 0); \
> if (IS_ENABLED(CONFIG_LOCKDEP) && (cond)) { \
> - WARN_ON_ONCE(!rcu_is_watching()); \
> + WARN_ONCE(!rcu_is_watching(), \
> + "RCU not watching for tracepoint"); \
> } \
> } \
> __DECLARE_TRACE_RCU(name, PARAMS(proto), PARAMS(args), \
> --
> 2.43.0
>