[PATCH 0/2] tracing: tprobe-events: Fixes for tprobe events

Masami Hiramatsu (Google) posted 2 patches 1 month, 1 week ago
kernel/trace/trace_fprobe.c |    7 ++++++-
1 file changed, 6 insertions(+), 1 deletion(-)
[PATCH 0/2] tracing: tprobe-events: Fixes for tprobe events
Posted by Masami Hiramatsu (Google) 1 month, 1 week ago
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>
Re: [PATCH 0/2] tracing: tprobe-events: Fixes for tprobe events
Posted by Beau Belgrave 1 month, 1 week ago
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>
Re: [PATCH 0/2] tracing: tprobe-events: Fixes for tprobe events
Posted by Masami Hiramatsu (Google) 1 month, 1 week ago
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>