linux-trace-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [PATCH 0/2] tracing: tprobe-events: Fixes for tprobe events
@ 2025-11-06 16:52 Masami Hiramatsu (Google)
  2025-11-06 16:52 ` [PATCH 1/2] tracing: tprobe-events: Fix to register tracepoint correctly Masami Hiramatsu (Google)
                   ` (2 more replies)
  0 siblings, 3 replies; 5+ messages in thread
From: Masami Hiramatsu (Google) @ 2025-11-06 16:52 UTC (permalink / raw)
  To: Steven Rostedt, Beau Belgrave
  Cc: Masami Hiramatsu, Mathieu Desnoyers, linux-kernel,
	linux-trace-kernel

Hi,

Beau reported tprobe example in the document does not work on 6.17
kernel.

---
echo "t sched_switch preempt prev_pid=prev->pid next_pid=next->pid" > /sys/kernel/tracing/dynamic_events
echo 1 > /sys/kernel/tracing/events/tracepoints/sched_switch/enable
cat /sys/kernel/tracing/trace_pipe
---

It seems that the tracepoint callback is not correctly set. So I tried
to trace the actual function calls and the local variables.
(I need to enable CONFIG_KPROBE_EVENTS_ON_NOTRACE for tracing ftrace
code itself.)

With the below commands, I got some probe definitions for debug:

 $ perf probe -k vmlinux -D "tracepoint_user_find_get name:string"
 $ perf probe -k vmlinux -D '__regsiter_tracepoint_fprobe:13 tuser tuser->tpoint'
 $ perf probe -k vmlinux -D 'register_fprobe_ips addrs[1]'
 $ perf probe -k vmlinux -D 'register_fprobe_ips%return ret=$retval'
 $ perf probe -k vmlinux -D '__regsiter_tracepoint_fprobe tf->tprobe'
 $ perf probe -k vmlinux -D 'tracepoint_probe_register_prio_may_exist tp'
 $ perf probe -k vmlinux -D 'tracepoint_probe_register_prio_may_exist%return ret=$retval'
 $ perf probe -k vmlinux -D '__tracepoint_user_init name:string'

And run below commands on the machine:

-----
 $ cat > /sys/kernel/tracing/dynamic_events << EOF
p:probe/tracepoint_user_find_get enable_trace_fprobe+271 name_string=+0(%bp):string
p:probe/regsiter_tracepoint_fprobe_L13 enable_trace_fprobe+692 tuser=%r13 tpoint=+24(%r13)
p:probe/regsiter_tracepoint_fprobe_L13_1 enable_trace_fprobe+685 tuser=%r13 tpoint=+24(%r13)
p:probe/register_fprobe_ips register_fprobe_ips+0 addrs=+8(%si):u64
r:probe/register_fprobe_ips__return register_fprobe_ips+0 ret=\$retval
p:probe/regsiter_tracepoint_fprobe enable_trace_fprobe+247 tprobe=+80(-96(%r14)):u8
p:probe/tracepoint_probe_register_prio_may_exist tracepoint_probe_register_prio_may_exist+0 tp=%di
r:probe/tracepoint_probe_register_prio_may_exist__return tracepoint_probe_register_prio_may_exist+0 ret=\$retval
p:probe/tracepoint_user_init enable_trace_fprobe+440 name_string=+0(%bp):string
EOF
 $ echo 1 > /sys/kernel/tracing/events/probe/enable

 $ echo "t sched_switch preempt prev_pid=prev->pid next_pid=next->pid" >> /sys/kernel/tracing/dynamic_events
 $ echo 1 > /sys/kernel/tracing/events/tracepoints/sched_switch/enable
 $ cat /sys/kernel/tracing/trace
-----

And I got below trace data:

-----
#           TASK-PID     CPU#  |||||  TIMESTAMP  FUNCTION
#              | |         |   |||||     |         |
              sh-107     [005] ..Zff     7.290496: regsiter_tracepoint_fprobe: (enable_trace_fprobe+0xf7/0x3a0) tprobe=0
              sh-107     [005] ..Zff     7.290547: tracepoint_user_find_get: (enable_trace_fprobe+0x10f/0x3a0) name_string="sched_switch"
              sh-107     [005] ..Zff     7.290680: tracepoint_user_init: (enable_trace_fprobe+0x1b8/0x3a0) name_string="sched_switch"
              sh-107     [005] ..Zff     7.290727: regsiter_tracepoint_fprobe_L13_1: (enable_trace_fprobe+0x2ad/0x3a0) tuser=0xffff88800538b280 tpoint=0xffffffff82a4ac10
              sh-107     [005] ..Zff     7.290730: regsiter_tracepoint_fprobe_L13: (enable_trace_fprobe+0x2b4/0x3a0) tuser=0xffff88800538b280 tpoint=0xffffffff82a4ac10
              sh-107     [005] ..Zff     7.290735: register_fprobe_ips: (register_fprobe_ips+0x4/0x310) addrs=18446612682157410880
              sh-107     [005] .....     7.311345: register_fprobe_ips__return: (enable_trace_fprobe+0x2f6/0x3a0 <- register_fprobe_ips) ret=0
-----

No tracepoint_probe_register_prio_may_exist event is recorded, but 
tracepoint_user_init and regsiter_tracepoint_fprobe_L13_1 (call-site
of tracepoint_user_init()) are recorded and `tuser` and `tpoint`
are not NULL or error.

This means when the tprobe is enabled, the register_tracepoint_fprobe()
eventually calls tracepoint_user_init() correctly. However, it does not
call tracepoint_probe_register_prio_may_exist() to register tracepoint
callback. So the bug is inside tracepoint_user_init(), not NULL return
path.

-----
static struct tracepoint_user *__tracepoint_user_init(const char *name, struct tracepoint *tpoint)
{
	struct tracepoint_user *tuser __free(tuser_free) = NULL;
	int ret;

	tuser = kzalloc(sizeof(*tuser), GFP_KERNEL);
	if (!tuser)
		return NULL;
	tuser->name = kstrdup(name, GFP_KERNEL);
	if (!tuser->name)
		return NULL;

	if (tpoint) {
		ret = tracepoint_user_register(tuser); /* forgot to set tuser->tpoint */
		if (ret)
			return ERR_PTR(ret);
	}
-----

And found it forgot to set tuser->tpoint before calling
tracepoint_user_register() which calls
tracepoint_probe_register_prio_may_exist(tuser->tpoint).
To fix that, I just moved the tuser->tpoint setting line
right before tracepoint_user_register() call [1/2].

I also found another issue when I switched enable and disable[2/2].

I hope this report will help someone to do similar debug by tracing.

Thank you,

---

Masami Hiramatsu (Google) (2):
      tracing: tprobe-events: Fix to register tracepoint correctly
      tracing: tprobe-events: Fix to put tracepoint_user when disable the tprobe


 kernel/trace/trace_fprobe.c |    7 ++++++-
 1 file changed, 6 insertions(+), 1 deletion(-)

--
Masami Hiramatsu (Google) <mhiramat@kernel.org>

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

* [PATCH 1/2] tracing: tprobe-events: Fix to register tracepoint correctly
  2025-11-06 16:52 [PATCH 0/2] tracing: tprobe-events: Fixes for tprobe events Masami Hiramatsu (Google)
@ 2025-11-06 16:52 ` Masami Hiramatsu (Google)
  2025-11-06 16:52 ` [PATCH 2/2] tracing: tprobe-events: Fix to put tracepoint_user when disable the tprobe Masami Hiramatsu (Google)
  2025-11-06 17:55 ` [PATCH 0/2] tracing: tprobe-events: Fixes for tprobe events Beau Belgrave
  2 siblings, 0 replies; 5+ messages in thread
From: Masami Hiramatsu (Google) @ 2025-11-06 16:52 UTC (permalink / raw)
  To: Steven Rostedt, Beau Belgrave
  Cc: Masami Hiramatsu, Mathieu Desnoyers, linux-kernel,
	linux-trace-kernel

From: Masami Hiramatsu (Google) <mhiramat@kernel.org>

Since __tracepoint_user_init() calls tracepoint_user_register() without
initializing tuser->tpoint with given tracpoint, it does not register
tracepoint stub function as callback correctly, and tprobe does not work.

Initializing tuser->tpoint correctly before tracepoint_user_register()
so that it sets up tracepoint callback.

I confirmed below example works fine again.

echo "t sched_switch preempt prev_pid=prev->pid next_pid=next->pid" > /sys/kernel/tracing/dynamic_events
echo 1 > /sys/kernel/tracing/events/tracepoints/sched_switch/enable
cat /sys/kernel/tracing/trace_pipe

Fixes: 2867495dea86 ("tracing: tprobe-events: Register tracepoint when enable tprobe event")
Reported-by: Beau Belgrave <beaub@linux.microsoft.com>
Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
---
 kernel/trace/trace_fprobe.c |    3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/kernel/trace/trace_fprobe.c b/kernel/trace/trace_fprobe.c
index b36ade43d4b3..d4e78d1ace12 100644
--- a/kernel/trace/trace_fprobe.c
+++ b/kernel/trace/trace_fprobe.c
@@ -106,13 +106,14 @@ static struct tracepoint_user *__tracepoint_user_init(const char *name, struct t
 	if (!tuser->name)
 		return NULL;
 
+	/* Register tracepoint if it is loaded. */
 	if (tpoint) {
+		tuser->tpoint = tpoint;
 		ret = tracepoint_user_register(tuser);
 		if (ret)
 			return ERR_PTR(ret);
 	}
 
-	tuser->tpoint = tpoint;
 	tuser->refcount = 1;
 	INIT_LIST_HEAD(&tuser->list);
 	list_add(&tuser->list, &tracepoint_user_list);


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

* [PATCH 2/2] tracing: tprobe-events: Fix to put tracepoint_user when disable the tprobe
  2025-11-06 16:52 [PATCH 0/2] tracing: tprobe-events: Fixes for tprobe events Masami Hiramatsu (Google)
  2025-11-06 16:52 ` [PATCH 1/2] tracing: tprobe-events: Fix to register tracepoint correctly Masami Hiramatsu (Google)
@ 2025-11-06 16:52 ` Masami Hiramatsu (Google)
  2025-11-06 17:55 ` [PATCH 0/2] tracing: tprobe-events: Fixes for tprobe events Beau Belgrave
  2 siblings, 0 replies; 5+ messages in thread
From: Masami Hiramatsu (Google) @ 2025-11-06 16:52 UTC (permalink / raw)
  To: Steven Rostedt, Beau Belgrave
  Cc: Masami Hiramatsu, Mathieu Desnoyers, linux-kernel,
	linux-trace-kernel

From: Masami Hiramatsu (Google) <mhiramat@kernel.org>

__unregister_trace_fprobe() checks tf->tuser to put it when removing
tprobe. However, disable_trace_fprobe() does not use it and only calls
unregister_fprobe(). Thus it forgets to disable tracepoint_user.

If the trace_fprobe has tuser, put it for unregistering the tracepoint
callbacks when disabling tprobe correctly.

Fixes: 2867495dea86 ("tracing: tprobe-events: Register tracepoint when enable tprobe event")
Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
---
 kernel/trace/trace_fprobe.c |    4 ++++
 1 file changed, 4 insertions(+)

diff --git a/kernel/trace/trace_fprobe.c b/kernel/trace/trace_fprobe.c
index d4e78d1ace12..62420eec677f 100644
--- a/kernel/trace/trace_fprobe.c
+++ b/kernel/trace/trace_fprobe.c
@@ -1512,6 +1512,10 @@ static int disable_trace_fprobe(struct trace_event_call *call,
 	if (!trace_probe_is_enabled(tp)) {
 		list_for_each_entry(tf, trace_probe_probe_list(tp), tp.list) {
 			unregister_fprobe(&tf->fp);
+			if (tf->tuser) {
+				tracepoint_user_put(tf->tuser);
+				tf->tuser = NULL;
+			}
 		}
 	}
 


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

* Re: [PATCH 0/2] tracing: tprobe-events: Fixes for tprobe events
  2025-11-06 16:52 [PATCH 0/2] tracing: tprobe-events: Fixes for tprobe events Masami Hiramatsu (Google)
  2025-11-06 16:52 ` [PATCH 1/2] tracing: tprobe-events: Fix to register tracepoint correctly Masami Hiramatsu (Google)
  2025-11-06 16:52 ` [PATCH 2/2] tracing: tprobe-events: Fix to put tracepoint_user when disable the tprobe Masami Hiramatsu (Google)
@ 2025-11-06 17:55 ` Beau Belgrave
  2025-11-06 22:28   ` Masami Hiramatsu
  2 siblings, 1 reply; 5+ messages in thread
From: Beau Belgrave @ 2025-11-06 17:55 UTC (permalink / raw)
  To: Masami Hiramatsu (Google)
  Cc: Steven Rostedt, Mathieu Desnoyers, linux-kernel,
	linux-trace-kernel

On Fri, Nov 07, 2025 at 01:52:05AM +0900, Masami Hiramatsu (Google) wrote:
> Hi,
> 
> Beau reported tprobe example in the document does not work on 6.17
> kernel.
> 

Thanks! I've applied this series locally and tested this. Everything
works well in our environment.

> 
> And found it forgot to set tuser->tpoint before calling
> tracepoint_user_register() which calls
> tracepoint_probe_register_prio_may_exist(tuser->tpoint).
> To fix that, I just moved the tuser->tpoint setting line
> right before tracepoint_user_register() call [1/2].
> 
> I also found another issue when I switched enable and disable[2/2].
> 

Thanks! I've validated no bad dmesg, etc. and can delete the tprobe
without issues after we disable it.

> I hope this report will help someone to do similar debug by tracing.
> 

I will reference this, it's very useful.

For the series:
Tested-by: Beau Belgrave <beaub@linux.microsoft.com>
Reviewed-by: Beau Belgrave <beaub@linux.microsoft.com>

Thanks,
-Beau
> Thank you,
> 
> ---
> 
> Masami Hiramatsu (Google) (2):
>       tracing: tprobe-events: Fix to register tracepoint correctly
>       tracing: tprobe-events: Fix to put tracepoint_user when disable the tprobe
> 
> 
>  kernel/trace/trace_fprobe.c |    7 ++++++-
>  1 file changed, 6 insertions(+), 1 deletion(-)
> 
> --
> Masami Hiramatsu (Google) <mhiramat@kernel.org>

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

* Re: [PATCH 0/2] tracing: tprobe-events: Fixes for tprobe events
  2025-11-06 17:55 ` [PATCH 0/2] tracing: tprobe-events: Fixes for tprobe events Beau Belgrave
@ 2025-11-06 22:28   ` Masami Hiramatsu
  0 siblings, 0 replies; 5+ messages in thread
From: Masami Hiramatsu @ 2025-11-06 22:28 UTC (permalink / raw)
  To: Beau Belgrave
  Cc: Steven Rostedt, Mathieu Desnoyers, linux-kernel,
	linux-trace-kernel

On Thu, 6 Nov 2025 17:55:13 +0000
Beau Belgrave <beaub@linux.microsoft.com> wrote:

> On Fri, Nov 07, 2025 at 01:52:05AM +0900, Masami Hiramatsu (Google) wrote:
> > Hi,
> > 
> > Beau reported tprobe example in the document does not work on 6.17
> > kernel.
> > 
> 
> Thanks! I've applied this series locally and tested this. Everything
> works well in our environment.

Great!

> 
> > 
> > And found it forgot to set tuser->tpoint before calling
> > tracepoint_user_register() which calls
> > tracepoint_probe_register_prio_may_exist(tuser->tpoint).
> > To fix that, I just moved the tuser->tpoint setting line
> > right before tracepoint_user_register() call [1/2].
> > 
> > I also found another issue when I switched enable and disable[2/2].
> > 
> 
> Thanks! I've validated no bad dmesg, etc. and can delete the tprobe
> without issues after we disable it.
> 
> > I hope this report will help someone to do similar debug by tracing.
> > 
> 
> I will reference this, it's very useful.
> 
> For the series:
> Tested-by: Beau Belgrave <beaub@linux.microsoft.com>
> Reviewed-by: Beau Belgrave <beaub@linux.microsoft.com>

Thanks!


> 
> Thanks,
> -Beau
> > Thank you,
> > 
> > ---
> > 
> > Masami Hiramatsu (Google) (2):
> >       tracing: tprobe-events: Fix to register tracepoint correctly
> >       tracing: tprobe-events: Fix to put tracepoint_user when disable the tprobe
> > 
> > 
> >  kernel/trace/trace_fprobe.c |    7 ++++++-
> >  1 file changed, 6 insertions(+), 1 deletion(-)
> > 
> > --
> > Masami Hiramatsu (Google) <mhiramat@kernel.org>


-- 
Masami Hiramatsu (Google) <mhiramat@kernel.org>

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

end of thread, other threads:[~2025-11-06 22:28 UTC | newest]

Thread overview: 5+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2025-11-06 16:52 [PATCH 0/2] tracing: tprobe-events: Fixes for tprobe events Masami Hiramatsu (Google)
2025-11-06 16:52 ` [PATCH 1/2] tracing: tprobe-events: Fix to register tracepoint correctly Masami Hiramatsu (Google)
2025-11-06 16:52 ` [PATCH 2/2] tracing: tprobe-events: Fix to put tracepoint_user when disable the tprobe Masami Hiramatsu (Google)
2025-11-06 17:55 ` [PATCH 0/2] tracing: tprobe-events: Fixes for tprobe events Beau Belgrave
2025-11-06 22:28   ` Masami Hiramatsu

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