1. Patchew
  2. linux
  3. View series

[PATCH] tracing: tprobe-events: Fix to clean up tprobe correctly when module unload

Masami Hiramatsu (Google) posted 1 patch 11 months, 1 week ago
There is a newer version of this series
kernel/trace/trace_fprobe.c |   10 +++-------
1 file changed, 3 insertions(+), 7 deletions(-)
[PATCH] tracing: tprobe-events: Fix to clean up tprobe correctly when module unload
Posted by Masami Hiramatsu (Google) 11 months, 1 week ago 
From: Masami Hiramatsu (Google) <mhiramat@kernel.org>

When unloading module, the tprobe events are not correctly cleaned
up. Thus it becomes `fprobe-event` and never be enabled again even
if loading the same module again.

For example;

 # cd /sys/kernel/tracing
 # modprobe trace_events_sample
 # echo 't:my_tprobe foo_bar' >> dynamic_events
 # cat dynamic_events
t:tracepoints/my_tprobe foo_bar
 # rmmod trace_events_sample
 # cat dynamic_events
f:tracepoints/my_tprobe foo_bar

As you can see, the second time my_tprobe starts with 'f' instead
of 't'.

This cleans up (unregister) the tprobe events when module is
unloaded.

Fixes: 57a7e6de9e30 ("tracing/fprobe: Support raw tracepoints on future loaded modules")
Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
---
 kernel/trace/trace_fprobe.c |   10 +++-------
 1 file changed, 3 insertions(+), 7 deletions(-)

diff --git a/kernel/trace/trace_fprobe.c b/kernel/trace/trace_fprobe.c
index e27305d31fc5..d5fc0c5bf879 100644
--- a/kernel/trace/trace_fprobe.c
+++ b/kernel/trace/trace_fprobe.c
@@ -775,7 +775,7 @@ static void __unregister_trace_fprobe(struct trace_fprobe *tf)
 		if (trace_fprobe_is_tracepoint(tf)) {
 			tracepoint_probe_unregister(tf->tpoint,
 					tf->tpoint->probestub, NULL);
-			tf->tpoint = NULL;
+			tf->tpoint = TRACEPOINT_STUB;
 			tf->mod = NULL;
 		}
 	}
@@ -1007,12 +1007,8 @@ static int __tracepoint_probe_module_cb(struct notifier_block *self,
 				    trace_probe_is_enabled(&tf->tp))
 					reenable_trace_fprobe(tf);
 			}
-		} else if (val == MODULE_STATE_GOING && tp_mod->mod == tf->mod) {
-			tracepoint_probe_unregister(tf->tpoint,
-					tf->tpoint->probestub, NULL);
-			tf->tpoint = NULL;
-			tf->mod = NULL;
-		}
+		} else if (val == MODULE_STATE_GOING && tp_mod->mod == tf->mod)
+			__unregister_trace_fprobe(tf);
 	}
 	mutex_unlock(&event_mutex);
Re: [PATCH] tracing: tprobe-events: Fix to clean up tprobe correctly when module unload
Posted by Steven Rostedt 11 months, 1 week ago 
On Thu,  6 Mar 2025 15:21:44 +0900
"Masami Hiramatsu (Google)" <mhiramat@kernel.org> wrote:

> When unloading module, the tprobe events are not correctly cleaned
> up. Thus it becomes `fprobe-event` and never be enabled again even
> if loading the same module again.
> 
> For example;
> 
>  # cd /sys/kernel/tracing
>  # modprobe trace_events_sample
>  # echo 't:my_tprobe foo_bar' >> dynamic_events
>  # cat dynamic_events
> t:tracepoints/my_tprobe foo_bar
>  # rmmod trace_events_sample
>  # cat dynamic_events
> f:tracepoints/my_tprobe foo_bar
> 
> As you can see, the second time my_tprobe starts with 'f' instead
> of 't'.
> 
> This cleans up (unregister) the tprobe events when module is
> unloaded.

After applying this, I tried it out:

 # cd /sys/kernel/tracing
 # modprobe trace_events_sample
 # echo 't:my_tprobe foo_bar a=$arg1' > dynamic_events
 # echo 1 > events/tracepoints/enable
[wait]
 # echo 0 > events/tracepoints/enable
 # cat trace
# tracer: nop
#
# entries-in-buffer/entries-written: 13/13   #P:8
#
#                                _-----=> irqs-off/BH-disabled
#                               / _----=> need-resched
#                              | / _---=> hardirq/softirq
#                              || / _--=> preempt-depth
#                              ||| / _-=> migrate-disable
#                              |||| /     delay
#           TASK-PID     CPU#  |||||  TIMESTAMP  FUNCTION
#              | |         |   |||||     |         |
    event-sample-1041    [005] ...1.  1957.632897: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1958.656935: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1959.680883: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1960.704855: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1961.728977: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1962.751822: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1963.776834: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1964.800748: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1965.824788: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1966.848789: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1967.872902: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1968.896754: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1969.920737: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
 # rmmod trace_events_sample
 # cat trace
# tracer: nop
#
# entries-in-buffer/entries-written: 13/13   #P:8
#
#                                _-----=> irqs-off/BH-disabled
#                               / _----=> need-resched
#                              | / _---=> hardirq/softirq
#                              || / _--=> preempt-depth
#                              ||| / _-=> migrate-disable
#                              |||| /     delay
#           TASK-PID     CPU#  |||||  TIMESTAMP  FUNCTION
#              | |         |   |||||     |         |
    event-sample-1041    [005] ...1.  1957.632897: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1958.656935: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1959.680883: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1960.704855: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1961.728977: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1962.751822: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1963.776834: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1964.800748: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1965.824788: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1966.848789: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1967.872902: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1968.896754: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1969.920737: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186

 # modprobe trace_events_sample
 # echo 1 > events/tracepoints/enable
 # cat trace
# tracer: nop
#
# entries-in-buffer/entries-written: 13/13   #P:8
#
#                                _-----=> irqs-off/BH-disabled
#                               / _----=> need-resched
#                              | / _---=> hardirq/softirq
#                              || / _--=> preempt-depth
#                              ||| / _-=> migrate-disable
#                              |||| /     delay
#           TASK-PID     CPU#  |||||  TIMESTAMP  FUNCTION
#              | |         |   |||||     |         |
    event-sample-1041    [005] ...1.  1957.632897: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1958.656935: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1959.680883: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1960.704855: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1961.728977: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1962.751822: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1963.776834: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1964.800748: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1965.824788: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1966.848789: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1967.872902: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1968.896754: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
    event-sample-1041    [005] ...1.  1969.920737: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186

Tracing doesn't restart.

-- Steve
Re: [PATCH] tracing: tprobe-events: Fix to clean up tprobe correctly when module unload
Posted by Masami Hiramatsu (Google) 11 months ago 
On Fri, 7 Mar 2025 12:20:00 -0500
Steven Rostedt <rostedt@goodmis.org> wrote:

> On Thu,  6 Mar 2025 15:21:44 +0900
> "Masami Hiramatsu (Google)" <mhiramat@kernel.org> wrote:
> 
> > When unloading module, the tprobe events are not correctly cleaned
> > up. Thus it becomes `fprobe-event` and never be enabled again even
> > if loading the same module again.
> > 
> > For example;
> > 
> >  # cd /sys/kernel/tracing
> >  # modprobe trace_events_sample
> >  # echo 't:my_tprobe foo_bar' >> dynamic_events
> >  # cat dynamic_events
> > t:tracepoints/my_tprobe foo_bar
> >  # rmmod trace_events_sample
> >  # cat dynamic_events
> > f:tracepoints/my_tprobe foo_bar
> > 
> > As you can see, the second time my_tprobe starts with 'f' instead
> > of 't'.
> > 
> > This cleans up (unregister) the tprobe events when module is
> > unloaded.
> 
> After applying this, I tried it out:
> 
>  # cd /sys/kernel/tracing
>  # modprobe trace_events_sample
>  # echo 't:my_tprobe foo_bar a=$arg1' > dynamic_events
>  # echo 1 > events/tracepoints/enable
> [wait]
>  # echo 0 > events/tracepoints/enable
>  # cat trace
> # tracer: nop
> #
> # entries-in-buffer/entries-written: 13/13   #P:8
> #
> #                                _-----=> irqs-off/BH-disabled
> #                               / _----=> need-resched
> #                              | / _---=> hardirq/softirq
> #                              || / _--=> preempt-depth
> #                              ||| / _-=> migrate-disable
> #                              |||| /     delay
> #           TASK-PID     CPU#  |||||  TIMESTAMP  FUNCTION
> #              | |         |   |||||     |         |
>     event-sample-1041    [005] ...1.  1957.632897: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1958.656935: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1959.680883: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1960.704855: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1961.728977: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1962.751822: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1963.776834: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1964.800748: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1965.824788: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1966.848789: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1967.872902: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1968.896754: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1969.920737: my_tprobe: (__probestub_foo_bar+0x4/0x20 [trace_events_sample]) a=0xffffffffc006c186
>  # rmmod trace_events_sample
>  # cat trace
> # tracer: nop
> #
> # entries-in-buffer/entries-written: 13/13   #P:8
> #
> #                                _-----=> irqs-off/BH-disabled
> #                               / _----=> need-resched
> #                              | / _---=> hardirq/softirq
> #                              || / _--=> preempt-depth
> #                              ||| / _-=> migrate-disable
> #                              |||| /     delay
> #           TASK-PID     CPU#  |||||  TIMESTAMP  FUNCTION
> #              | |         |   |||||     |         |
>     event-sample-1041    [005] ...1.  1957.632897: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1958.656935: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1959.680883: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1960.704855: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1961.728977: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1962.751822: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1963.776834: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1964.800748: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1965.824788: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1966.848789: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1967.872902: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1968.896754: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1969.920737: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
> 
>  # modprobe trace_events_sample
>  # echo 1 > events/tracepoints/enable
>  # cat trace
> # tracer: nop
> #
> # entries-in-buffer/entries-written: 13/13   #P:8
> #
> #                                _-----=> irqs-off/BH-disabled
> #                               / _----=> need-resched
> #                              | / _---=> hardirq/softirq
> #                              || / _--=> preempt-depth
> #                              ||| / _-=> migrate-disable
> #                              |||| /     delay
> #           TASK-PID     CPU#  |||||  TIMESTAMP  FUNCTION
> #              | |         |   |||||     |         |
>     event-sample-1041    [005] ...1.  1957.632897: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1958.656935: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1959.680883: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1960.704855: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1961.728977: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1962.751822: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1963.776834: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1964.800748: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1965.824788: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1966.848789: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1967.872902: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1968.896754: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
>     event-sample-1041    [005] ...1.  1969.920737: my_tprobe: (0xffffffffc00620b4) a=0xffffffffc006c186
> 
> Tracing doesn't restart.

Ah, I see. __unregister_trace_fprobe() clean up fp.

static void __unregister_trace_fprobe(struct trace_fprobe *tf)
{
	if (trace_fprobe_is_registered(tf)) {
		unregister_fprobe(&tf->fp);
		memset(&tf->fp, 0, sizeof(tf->fp)); <---- this

This will cleanup the callbacks.

Let me update it.

Thanks!

> 
> -- Steve
> 


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

Patchew 2.1-devel-b67e4c2

© 2016 - 2026 Red Hat, Inc.