From: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Add 'add_remove_wprobe.tc' testcase for testing wprobe event that
tests adding and removing operations of the wprobe event.
Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
---
Changes in v5:
- Enable CONFIG_WPROBE_EVENTS in config for ftrace selftest
---
tools/testing/selftests/ftrace/config | 1
.../ftrace/test.d/dynevent/add_remove_wprobe.tc | 68 ++++++++++++++++++++
2 files changed, 69 insertions(+)
create mode 100644 tools/testing/selftests/ftrace/test.d/dynevent/add_remove_wprobe.tc
diff --git a/tools/testing/selftests/ftrace/config b/tools/testing/selftests/ftrace/config
index 544de0db5f58..d2f503722020 100644
--- a/tools/testing/selftests/ftrace/config
+++ b/tools/testing/selftests/ftrace/config
@@ -27,3 +27,4 @@ CONFIG_STACK_TRACER=y
CONFIG_TRACER_SNAPSHOT=y
CONFIG_UPROBES=y
CONFIG_UPROBE_EVENTS=y
+CONFIG_WPROBE_EVENTS=y
diff --git a/tools/testing/selftests/ftrace/test.d/dynevent/add_remove_wprobe.tc b/tools/testing/selftests/ftrace/test.d/dynevent/add_remove_wprobe.tc
new file mode 100644
index 000000000000..20774c7f69f8
--- /dev/null
+++ b/tools/testing/selftests/ftrace/test.d/dynevent/add_remove_wprobe.tc
@@ -0,0 +1,68 @@
+#!/bin/sh
+# SPDX-License-Identifier: GPL-2.0
+# description: Generic dynamic event - add/remove wprobe events
+# requires: dynamic_events "w[:[<group>/][<event>]] [r|w|rw]@<addr>[:<len>]":README
+
+echo 0 > events/enable
+echo > dynamic_events
+
+# Use jiffies as a variable that is frequently written to.
+TARGET=jiffies
+
+echo "w:my_wprobe w@$TARGET" >> dynamic_events
+
+grep -q my_wprobe dynamic_events
+if [ $? -ne 0 ]; then
+ echo "Failed to create wprobe event"
+ exit_fail
+fi
+
+test -d events/wprobes/my_wprobe
+if [ $? -ne 0 ]; then
+ echo "Failed to create wprobe event directory"
+ exit_fail
+fi
+
+echo 1 > events/wprobes/my_wprobe/enable
+
+# Check if the event is enabled
+cat events/wprobes/my_wprobe/enable | grep -q 1
+if [ $? -ne 0 ]; then
+ echo "Failed to enable wprobe event"
+ exit_fail
+fi
+
+# Let some time pass to trigger the breakpoint
+sleep 1
+
+# Check if we got any trace output
+if !grep -q my_wprobe trace; then
+ echo "wprobe event was not triggered"
+fi
+
+echo 0 > events/wprobes/my_wprobe/enable
+
+# Check if the event is disabled
+cat events/wprobes/my_wprobe/enable | grep -q 0
+if [ $? -ne 0 ]; then
+ echo "Failed to disable wprobe event"
+ exit_fail
+fi
+
+echo "-:my_wprobe" >> dynamic_events
+
+! grep -q my_wprobe dynamic_events
+if [ $? -ne 0 ]; then
+ echo "Failed to remove wprobe event"
+ exit_fail
+fi
+
+! test -d events/wprobes/my_wprobe
+if [ $? -ne 0 ]; then
+ echo "Failed to remove wprobe event directory"
+ exit_fail
+fi
+
+clear_trace
+
+exit 0On Tue, Sep 23, 2025 at 10:17:47AM +0900, Masami Hiramatsu (Google) wrote: > From: Masami Hiramatsu (Google) <mhiramat@kernel.org> > > Add 'add_remove_wprobe.tc' testcase for testing wprobe event that > tests adding and removing operations of the wprobe event. Since this series has landed in -next we've been seeing hangs on a range of arm64 platforms running the ftrace tests, it looks like it's all of them. Unfortunately the systems lock up with no output as soon as they start trying to do something with wprobes: # ok 19 Generic dynamic event - add/remove kprobe events # ok 20 Generic dynamic event - add/remove synthetic events # ok 21 Generic dynamic event - add/remove tracepoint probe events # ok 22 Generic dynamic event - add/remove tracepoint probe events on module # ok 23 Generic dynamic event - add/remove/test uprobe events the next test being add_remove_wprobe.tc, which doesn't seem to complete. Full log (for what little it's worth): https://lava.sirena.org.uk/scheduler/job/2000440#L1860 I turned on -vvv logging and that generated the rather spectacularly more verbose: https://lava.sirena.org.uk/scheduler/job/2000676/log_file/plain (in a somewhat processed format unfortunately.). Looking at that log I do notice a bunch of "unexpected operators" reported by the shell, these systems are running dash not bash, though that doesn't seem related. It looks like the script hangs in reset_trigger_file while grepping the trigger files rather than actually trying to do the test. Sorry about the delay in reporting this.
On Fri, 24 Oct 2025 22:31:06 +0100 Mark Brown <broonie@kernel.org> wrote: > On Tue, Sep 23, 2025 at 10:17:47AM +0900, Masami Hiramatsu (Google) wrote: > > From: Masami Hiramatsu (Google) <mhiramat@kernel.org> > > > > Add 'add_remove_wprobe.tc' testcase for testing wprobe event that > > tests adding and removing operations of the wprobe event. > > Since this series has landed in -next we've been seeing hangs on a range > of arm64 platforms running the ftrace tests, it looks like it's all of > them. Unfortunately the systems lock up with no output as soon as they > start trying to do something with wprobes: > > # ok 19 Generic dynamic event - add/remove kprobe events > # ok 20 Generic dynamic event - add/remove synthetic events > # ok 21 Generic dynamic event - add/remove tracepoint probe events > # ok 22 Generic dynamic event - add/remove tracepoint probe events on module > # ok 23 Generic dynamic event - add/remove/test uprobe events > > the next test being add_remove_wprobe.tc, which doesn't seem to > complete. Full log (for what little it's worth): > > https://lava.sirena.org.uk/scheduler/job/2000440#L1860 > > I turned on -vvv logging and that generated the rather spectacularly > more verbose: > > https://lava.sirena.org.uk/scheduler/job/2000676/log_file/plain > > (in a somewhat processed format unfortunately.). Looking at that log I > do notice a bunch of "unexpected operators" reported by the shell, these > systems are running dash not bash, though that doesn't seem related. It > looks like the script hangs in reset_trigger_file while grepping the > trigger files rather than actually trying to do the test. > > Sorry about the delay in reporting this. OK, eventually, I confirmed it is stopped on enabling wprobe + . /mnt/ftrace/test.d/dynevent/add_remove_wprobe.tc + echo 0 + echo + TARGET=jiffies + echo 'w:my_wprobe w@jiffies' + grep -q my_wprobe dynamic_events + '[' 0 -ne 0 ] + test -d events/wprobes/my_wprobe + '[' 0 -ne 0 ] + echo 1 I also confirmed: ~ # cd /sys/kernel/tracing/ /sys/kernel/tracing # echo 'w:my_wprobe w@jiffies' >> dynamic_events /sys/kernel/tracing # echo 1 > events/wprobes/my_wprobe/enable Freeze the machine. Thank you, -- Masami Hiramatsu (Google) <mhiramat@kernel.org>
On Mon, 27 Oct 2025 22:43:47 +0900 Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote: > On Fri, 24 Oct 2025 22:31:06 +0100 > Mark Brown <broonie@kernel.org> wrote: > > > On Tue, Sep 23, 2025 at 10:17:47AM +0900, Masami Hiramatsu (Google) wrote: > > > From: Masami Hiramatsu (Google) <mhiramat@kernel.org> > > > > > > Add 'add_remove_wprobe.tc' testcase for testing wprobe event that > > > tests adding and removing operations of the wprobe event. > > > > Since this series has landed in -next we've been seeing hangs on a range > > of arm64 platforms running the ftrace tests, it looks like it's all of > > them. Unfortunately the systems lock up with no output as soon as they > > start trying to do something with wprobes: > > > > # ok 19 Generic dynamic event - add/remove kprobe events > > # ok 20 Generic dynamic event - add/remove synthetic events > > # ok 21 Generic dynamic event - add/remove tracepoint probe events > > # ok 22 Generic dynamic event - add/remove tracepoint probe events on module > > # ok 23 Generic dynamic event - add/remove/test uprobe events > > > > the next test being add_remove_wprobe.tc, which doesn't seem to > > complete. Full log (for what little it's worth): > > > > https://lava.sirena.org.uk/scheduler/job/2000440#L1860 > > > > I turned on -vvv logging and that generated the rather spectacularly > > more verbose: > > > > https://lava.sirena.org.uk/scheduler/job/2000676/log_file/plain > > > > (in a somewhat processed format unfortunately.). Looking at that log I > > do notice a bunch of "unexpected operators" reported by the shell, these > > systems are running dash not bash, though that doesn't seem related. It > > looks like the script hangs in reset_trigger_file while grepping the > > trigger files rather than actually trying to do the test. > > > > Sorry about the delay in reporting this. > > OK, eventually, I confirmed it is stopped on enabling wprobe > > + . /mnt/ftrace/test.d/dynevent/add_remove_wprobe.tc > + echo 0 > + echo > + TARGET=jiffies > + echo 'w:my_wprobe w@jiffies' > + grep -q my_wprobe dynamic_events > + '[' 0 -ne 0 ] > + test -d events/wprobes/my_wprobe > + '[' 0 -ne 0 ] > + echo 1 > Interestingly, this stops in the cpu_function_call(). It does not call __perf_install_in_context(). ~ # cd /sys/kernel/tracing/ /sys/kernel/tracing # echo 'w:my_wprobe w@jiffies' >> dynamic_events /sys/kernel/tracing # echo 1 > events/wprobes/my_wprobe/enable [ 54.942288] trace_wprobe: enable_trace_wprobe called [ 54.945306] trace_wprobe: trying to register wprobes [ 54.947367] trace_wprobe: __register_trace_wprobe called [ 54.949586] trace_wprobe: registering wprobe at addr: 0xffffb6ce429fb200, len: 4, type: 2 [ 54.951639] Creating wide hw breakpoint on CPU 0 [ 54.966390] Creating kernel counter on CPU 0 for event type 5 [ 54.967758] perf_install_in_context: event 00000000736da1d9 ctx 000000005d4db900 cpu 0 [ 54.972015] perf_install_in_context2: event 00000000736da1d9 ctx set to 000000005d4db900 [ 54.976697] cpu_function_call: calling function on CPU 0, func: __perf_install_in_context+0x0/0x2c8 What happen if the cpu calls function on itself by smp_call_function_single() on arm64? smp_call_function_single(this_cpu, remote_function, &data, 1); Thank you, -- Masami Hiramatsu (Google) <mhiramat@kernel.org>
On Tue, 28 Oct 2025 08:42:22 +0900
Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote:
> ~ # cd /sys/kernel/tracing/
> /sys/kernel/tracing # echo 'w:my_wprobe w@jiffies' >> dynamic_events
> /sys/kernel/tracing # echo 1 > events/wprobes/my_wprobe/enable
> [ 54.942288] trace_wprobe: enable_trace_wprobe called
> [ 54.945306] trace_wprobe: trying to register wprobes
> [ 54.947367] trace_wprobe: __register_trace_wprobe called
> [ 54.949586] trace_wprobe: registering wprobe at addr: 0xffffb6ce429fb200, len: 4, type: 2
> [ 54.951639] Creating wide hw breakpoint on CPU 0
> [ 54.966390] Creating kernel counter on CPU 0 for event type 5
> [ 54.967758] perf_install_in_context: event 00000000736da1d9 ctx 000000005d4db900 cpu 0
> [ 54.972015] perf_install_in_context2: event 00000000736da1d9 ctx set to 000000005d4db900
> [ 54.976697] cpu_function_call: calling function on CPU 0, func: __perf_install_in_context+0x0/0x2c8
>
> What happen if the cpu calls function on itself by
> smp_call_function_single() on arm64?
>
> smp_call_function_single(this_cpu, remote_function, &data, 1);
Sorry, that was printk buffering issue. I used trace_printk() instead
and persistent ring buffer[1] to trace it.
[1] https://docs.kernel.org/trace/debugging.html#persistent-buffers-across-boots
~ # echo 1 > /sys/kernel/tracing/instances/boot_map/options/trace_printk_dest
~ # echo 'w:my_wprobe w@jiffies' >> /sys/kernel/tracing/dynamic_events
~ # echo 1 > /sys/kernel/tracing/events/wprobes/my_wprobe/enable
QEMU 8.2.2 monitor - type 'help' for more information
(qemu) system_reset
...
~ # cat /sys/kernel/tracing/instances/boot_map/trace
# tracer: nop
#
# entries-in-buffer/entries-written: 16/16 #P:1
#
# _-----=> irqs-off/BH-disabled
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / _-=> migrate-disable
# |||| / delay
# TASK-PID CPU# ||||| TIMESTAMP FUNCTION
# | | | ||||| | |
<...>-63 [000] ..... 21.065038: register_wide_hw_breakpoint: Creating wide hw breakpoint on CPU 0
<...>-63 [000] ..... 21.079678: perf_event_create_kernel_counter: Creating kernel counter on CPU 0 for event type 5
<...>-63 [000] ..... 21.080051: perf_install_in_context: perf_install_in_context: event 000000000b3ac4d3 ctx 00000000097d6337 cpu 0
<...>-63 [000] ..... 21.080140: perf_install_in_context: perf_install_in_context2: event 000000000b3ac4d3 ctx set to 00000000097d6337
<...>-63 [000] ..... 21.080939: cpu_function_call: cpu_function_call: calling function on CPU 0, func: __perf_install_in_context+0x0/0x2f0
<...>-63 [000] ..... 21.080966: smp_call_function_single: smp_call_function_single: calling function on CPU 0, func: remote_function+0x0/0x78, wait=1
<...>-63 [000] ...1. 21.080973: smp_call_function_single: smp_call_function_single: running on CPU 0, call CPU 0
<...>-63 [000] ...1. 21.081099: smp_call_function_single: smp_call_function_single: checking for potential deadlock conditions
<...>-63 [000] ...1. 21.081259: generic_exec_single: generic_exec_single: preparing to call function on CPU 0, func: remote_function+0x0/0x78
<...>-63 [000] ...1. 21.081269: generic_exec_single: Executing smp_call_function_single on self CPU 0, func: remote_function+0x0/0x78
<...>-63 [000] d..1. 21.081289: csd_do_func: csd_do_func: CPU 0 executing func remote_function+0x0/0x78
<...>-63 [000] d..1. 21.081429: __perf_install_in_context: __perf_install_in_context: event 000000000b3ac4d3 ctx 00000000097d6337
<...>-63 [000] d..2. 21.083211: hw_breakpoint_control: hw_breakpoint_control: ops=0
<...>-63 [000] d..1. 21.084191: __perf_install_in_context: __perf_install_in_context: event 000000000b3ac4d3 done, ret=0
<...>-63 [000] d..1. 21.084237: csd_do_func: csd_do_func: CPU 0 finished func remote_function+0x0/0x78
<...>-63 [000] d..1. 21.084243: generic_exec_single: Finished csd_lock_record(NULL)
~ #
So the last message is right before the local_irq_restore() in
generic_exec_single().
static int generic_exec_single(int cpu, call_single_data_t *csd)
{
...
csd_lock_record(csd);
csd_unlock(csd);
local_irq_save(flags);
csd_do_func(func, info, NULL);
csd_lock_record(NULL);
trace_printk("Finished csd_lock_record(NULL)\n"); <-
local_irq_restore(flags);
return 0;
Actually, I added another trace_printk() right after generic_exec_single().
err = generic_exec_single(cpu, csd);
trace_printk("generic_exec_single returned %d for CPU %d, func: %pS\n",
err, cpu, func);
This means after setting the hw_breakpoint, when enabing the IRQ,
the machine is frozen - but qemu is running busy.
Can we specify the kernel memory address to HW breakpoint on arm64?
Thank you,
--
Masami Hiramatsu (Google) <mhiramat@kernel.org>
On Tue, 28 Oct 2025 10:55:49 +0900
Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote:
> On Tue, 28 Oct 2025 08:42:22 +0900
> Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote:
>
> > ~ # cd /sys/kernel/tracing/
> > /sys/kernel/tracing # echo 'w:my_wprobe w@jiffies' >> dynamic_events
> > /sys/kernel/tracing # echo 1 > events/wprobes/my_wprobe/enable
> > [ 54.942288] trace_wprobe: enable_trace_wprobe called
> > [ 54.945306] trace_wprobe: trying to register wprobes
> > [ 54.947367] trace_wprobe: __register_trace_wprobe called
> > [ 54.949586] trace_wprobe: registering wprobe at addr: 0xffffb6ce429fb200, len: 4, type: 2
> > [ 54.951639] Creating wide hw breakpoint on CPU 0
> > [ 54.966390] Creating kernel counter on CPU 0 for event type 5
> > [ 54.967758] perf_install_in_context: event 00000000736da1d9 ctx 000000005d4db900 cpu 0
> > [ 54.972015] perf_install_in_context2: event 00000000736da1d9 ctx set to 000000005d4db900
> > [ 54.976697] cpu_function_call: calling function on CPU 0, func: __perf_install_in_context+0x0/0x2c8
> >
> > What happen if the cpu calls function on itself by
> > smp_call_function_single() on arm64?
> >
> > smp_call_function_single(this_cpu, remote_function, &data, 1);
>
> Sorry, that was printk buffering issue. I used trace_printk() instead
> and persistent ring buffer[1] to trace it.
>
> [1] https://docs.kernel.org/trace/debugging.html#persistent-buffers-across-boots
>
> ~ # echo 1 > /sys/kernel/tracing/instances/boot_map/options/trace_printk_dest
> ~ # echo 'w:my_wprobe w@jiffies' >> /sys/kernel/tracing/dynamic_events
> ~ # echo 1 > /sys/kernel/tracing/events/wprobes/my_wprobe/enable
> QEMU 8.2.2 monitor - type 'help' for more information
> (qemu) system_reset
> ...
>
> ~ # cat /sys/kernel/tracing/instances/boot_map/trace
> # tracer: nop
> #
> # entries-in-buffer/entries-written: 16/16 #P:1
> #
> # _-----=> irqs-off/BH-disabled
> # / _----=> need-resched
> # | / _---=> hardirq/softirq
> # || / _--=> preempt-depth
> # ||| / _-=> migrate-disable
> # |||| / delay
> # TASK-PID CPU# ||||| TIMESTAMP FUNCTION
> # | | | ||||| | |
> <...>-63 [000] ..... 21.065038: register_wide_hw_breakpoint: Creating wide hw breakpoint on CPU 0
> <...>-63 [000] ..... 21.079678: perf_event_create_kernel_counter: Creating kernel counter on CPU 0 for event type 5
> <...>-63 [000] ..... 21.080051: perf_install_in_context: perf_install_in_context: event 000000000b3ac4d3 ctx 00000000097d6337 cpu 0
> <...>-63 [000] ..... 21.080140: perf_install_in_context: perf_install_in_context2: event 000000000b3ac4d3 ctx set to 00000000097d6337
> <...>-63 [000] ..... 21.080939: cpu_function_call: cpu_function_call: calling function on CPU 0, func: __perf_install_in_context+0x0/0x2f0
> <...>-63 [000] ..... 21.080966: smp_call_function_single: smp_call_function_single: calling function on CPU 0, func: remote_function+0x0/0x78, wait=1
> <...>-63 [000] ...1. 21.080973: smp_call_function_single: smp_call_function_single: running on CPU 0, call CPU 0
> <...>-63 [000] ...1. 21.081099: smp_call_function_single: smp_call_function_single: checking for potential deadlock conditions
> <...>-63 [000] ...1. 21.081259: generic_exec_single: generic_exec_single: preparing to call function on CPU 0, func: remote_function+0x0/0x78
> <...>-63 [000] ...1. 21.081269: generic_exec_single: Executing smp_call_function_single on self CPU 0, func: remote_function+0x0/0x78
> <...>-63 [000] d..1. 21.081289: csd_do_func: csd_do_func: CPU 0 executing func remote_function+0x0/0x78
> <...>-63 [000] d..1. 21.081429: __perf_install_in_context: __perf_install_in_context: event 000000000b3ac4d3 ctx 00000000097d6337
> <...>-63 [000] d..2. 21.083211: hw_breakpoint_control: hw_breakpoint_control: ops=0
> <...>-63 [000] d..1. 21.084191: __perf_install_in_context: __perf_install_in_context: event 000000000b3ac4d3 done, ret=0
> <...>-63 [000] d..1. 21.084237: csd_do_func: csd_do_func: CPU 0 finished func remote_function+0x0/0x78
> <...>-63 [000] d..1. 21.084243: generic_exec_single: Finished csd_lock_record(NULL)
> ~ #
>
>
> So the last message is right before the local_irq_restore() in
> generic_exec_single().
>
> static int generic_exec_single(int cpu, call_single_data_t *csd)
> {
> ...
> csd_lock_record(csd);
> csd_unlock(csd);
> local_irq_save(flags);
> csd_do_func(func, info, NULL);
> csd_lock_record(NULL);
> trace_printk("Finished csd_lock_record(NULL)\n"); <-
> local_irq_restore(flags);
> return 0;
>
> Actually, I added another trace_printk() right after generic_exec_single().
>
> err = generic_exec_single(cpu, csd);
> trace_printk("generic_exec_single returned %d for CPU %d, func: %pS\n",
> err, cpu, func);
>
> This means after setting the hw_breakpoint, when enabing the IRQ,
> the machine is frozen - but qemu is running busy.
>
> Can we specify the kernel memory address to HW breakpoint on arm64?
Hmm, it seems that jiffies related things are updated frequently
and it may cause interrupt storm or infinit recursive call.
Basically, I think it should be temporarily disabled so that the
interrupt does not occur during the extension of the HWBP interrupt,
but I wonder how this works in arm64?
If you know the path, you may be able to prohibit access to the
related variables. But that maybe more difficult than SWBP like
kprobes. Maybe this should add at least taint flag.
Thank you,
>
> Thank you,
> --
> Masami Hiramatsu (Google) <mhiramat@kernel.org>
--
Masami Hiramatsu (Google) <mhiramat@kernel.org>
On Wed, 29 Oct 2025 00:42:19 +0900
Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote:
> On Tue, 28 Oct 2025 10:55:49 +0900
> Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote:
>
> > On Tue, 28 Oct 2025 08:42:22 +0900
> > Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote:
> >
> > > ~ # cd /sys/kernel/tracing/
> > > /sys/kernel/tracing # echo 'w:my_wprobe w@jiffies' >> dynamic_events
> > > /sys/kernel/tracing # echo 1 > events/wprobes/my_wprobe/enable
> > > [ 54.942288] trace_wprobe: enable_trace_wprobe called
> > > [ 54.945306] trace_wprobe: trying to register wprobes
> > > [ 54.947367] trace_wprobe: __register_trace_wprobe called
> > > [ 54.949586] trace_wprobe: registering wprobe at addr: 0xffffb6ce429fb200, len: 4, type: 2
> > > [ 54.951639] Creating wide hw breakpoint on CPU 0
> > > [ 54.966390] Creating kernel counter on CPU 0 for event type 5
> > > [ 54.967758] perf_install_in_context: event 00000000736da1d9 ctx 000000005d4db900 cpu 0
> > > [ 54.972015] perf_install_in_context2: event 00000000736da1d9 ctx set to 000000005d4db900
> > > [ 54.976697] cpu_function_call: calling function on CPU 0, func: __perf_install_in_context+0x0/0x2c8
> > >
> > > What happen if the cpu calls function on itself by
> > > smp_call_function_single() on arm64?
> > >
> > > smp_call_function_single(this_cpu, remote_function, &data, 1);
> >
> > Sorry, that was printk buffering issue. I used trace_printk() instead
> > and persistent ring buffer[1] to trace it.
> >
> > [1] https://docs.kernel.org/trace/debugging.html#persistent-buffers-across-boots
> >
> > ~ # echo 1 > /sys/kernel/tracing/instances/boot_map/options/trace_printk_dest
> > ~ # echo 'w:my_wprobe w@jiffies' >> /sys/kernel/tracing/dynamic_events
> > ~ # echo 1 > /sys/kernel/tracing/events/wprobes/my_wprobe/enable
> > QEMU 8.2.2 monitor - type 'help' for more information
> > (qemu) system_reset
> > ...
> >
> > ~ # cat /sys/kernel/tracing/instances/boot_map/trace
> > # tracer: nop
> > #
> > # entries-in-buffer/entries-written: 16/16 #P:1
> > #
> > # _-----=> irqs-off/BH-disabled
> > # / _----=> need-resched
> > # | / _---=> hardirq/softirq
> > # || / _--=> preempt-depth
> > # ||| / _-=> migrate-disable
> > # |||| / delay
> > # TASK-PID CPU# ||||| TIMESTAMP FUNCTION
> > # | | | ||||| | |
> > <...>-63 [000] ..... 21.065038: register_wide_hw_breakpoint: Creating wide hw breakpoint on CPU 0
> > <...>-63 [000] ..... 21.079678: perf_event_create_kernel_counter: Creating kernel counter on CPU 0 for event type 5
> > <...>-63 [000] ..... 21.080051: perf_install_in_context: perf_install_in_context: event 000000000b3ac4d3 ctx 00000000097d6337 cpu 0
> > <...>-63 [000] ..... 21.080140: perf_install_in_context: perf_install_in_context2: event 000000000b3ac4d3 ctx set to 00000000097d6337
> > <...>-63 [000] ..... 21.080939: cpu_function_call: cpu_function_call: calling function on CPU 0, func: __perf_install_in_context+0x0/0x2f0
> > <...>-63 [000] ..... 21.080966: smp_call_function_single: smp_call_function_single: calling function on CPU 0, func: remote_function+0x0/0x78, wait=1
> > <...>-63 [000] ...1. 21.080973: smp_call_function_single: smp_call_function_single: running on CPU 0, call CPU 0
> > <...>-63 [000] ...1. 21.081099: smp_call_function_single: smp_call_function_single: checking for potential deadlock conditions
> > <...>-63 [000] ...1. 21.081259: generic_exec_single: generic_exec_single: preparing to call function on CPU 0, func: remote_function+0x0/0x78
> > <...>-63 [000] ...1. 21.081269: generic_exec_single: Executing smp_call_function_single on self CPU 0, func: remote_function+0x0/0x78
> > <...>-63 [000] d..1. 21.081289: csd_do_func: csd_do_func: CPU 0 executing func remote_function+0x0/0x78
> > <...>-63 [000] d..1. 21.081429: __perf_install_in_context: __perf_install_in_context: event 000000000b3ac4d3 ctx 00000000097d6337
> > <...>-63 [000] d..2. 21.083211: hw_breakpoint_control: hw_breakpoint_control: ops=0
> > <...>-63 [000] d..1. 21.084191: __perf_install_in_context: __perf_install_in_context: event 000000000b3ac4d3 done, ret=0
> > <...>-63 [000] d..1. 21.084237: csd_do_func: csd_do_func: CPU 0 finished func remote_function+0x0/0x78
> > <...>-63 [000] d..1. 21.084243: generic_exec_single: Finished csd_lock_record(NULL)
> > ~ #
> >
> >
> > So the last message is right before the local_irq_restore() in
> > generic_exec_single().
> >
> > static int generic_exec_single(int cpu, call_single_data_t *csd)
> > {
> > ...
> > csd_lock_record(csd);
> > csd_unlock(csd);
> > local_irq_save(flags);
> > csd_do_func(func, info, NULL);
> > csd_lock_record(NULL);
> > trace_printk("Finished csd_lock_record(NULL)\n"); <-
> > local_irq_restore(flags);
> > return 0;
> >
> > Actually, I added another trace_printk() right after generic_exec_single().
> >
> > err = generic_exec_single(cpu, csd);
> > trace_printk("generic_exec_single returned %d for CPU %d, func: %pS\n",
> > err, cpu, func);
> >
> > This means after setting the hw_breakpoint, when enabing the IRQ,
> > the machine is frozen - but qemu is running busy.
> >
> > Can we specify the kernel memory address to HW breakpoint on arm64?
>
> Hmm, it seems that jiffies related things are updated frequently
> and it may cause interrupt storm or infinit recursive call.
I added another trace_printk() in el1_watchpt(). It seems el1_watchpt()
takes too long and there is no time to do any other things.
(Note the interval shown below is only within the el1_watchpt function,
and in reality various processes (save/restore registers etc) for
exception handling will be inserted before and after.)
kworker/u32:3-75 [001] d.h2. 43.216706: el1_watchpt: FAR=0xjiffies+0x0/0x40, ESR=0xd6000062, WP index=0, n
est=0
kworker/u32:3-75 [001] d.h2. 43.216750: el1_watchpt: returning to EL1: nest=0
kworker/u32:3-75 [001] d.h2. 43.216816: el1_watchpt: FAR=0xjiffies+0x0/0x40, ESR=0xd6000062, WP index=0, n
est=0
kworker/u32:3-75 [001] d.h2. 43.216860: el1_watchpt: returning to EL1: nest=0
kworker/u32:3-75 [001] d.h2. 43.216927: el1_watchpt: FAR=0xjiffies+0x0/0x40, ESR=0xd6000062, WP index=0, n
est=0
kworker/u32:3-75 [001] d.h2. 43.216971: el1_watchpt: returning to EL1: nest=0
kworker/u32:3-75 [001] d.h2. 43.217058: el1_watchpt: FAR=0xjiffies+0x0/0x40, ESR=0xd6000062, WP index=0, n
est=0
kworker/u32:3-75 [001] d.h2. 43.217106: el1_watchpt: returning to EL1: nest=0
kworker/u32:3-75 [001] d.h2. 43.217175: el1_watchpt: FAR=0xjiffies+0x0/0x40, ESR=0xd6000062, WP index=0, n
est=0
kworker/u32:3-75 [001] d.h2. 43.217219: el1_watchpt: returning to EL1: nest=0
So watching any variables which is frequently updated will
almost freeze the system. Hmmm, the handler should check the
interval and if it is too frequently, it should disable the
wprobe.
Thank you,
--
Masami Hiramatsu (Google) <mhiramat@kernel.org>
On Wed, 29 Oct 2025 11:43:17 +0900 Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote: > > Hmm, it seems that jiffies related things are updated frequently > > and it may cause interrupt storm or infinit recursive call. > > I added another trace_printk() in el1_watchpt(). It seems el1_watchpt() > takes too long and there is no time to do any other things. > (Note the interval shown below is only within the el1_watchpt function, > and in reality various processes (save/restore registers etc) for > exception handling will be inserted before and after.) Forget about this. I found the root cause. The x86 watchpoint exception happens after the instruction is executed, the arm64 happens before. Thus what we need is to emulate or do single step the hooked instruction and restart from the next instruction from the watchpoint exception on arm64. I thought hw_breakpoint does that, but doesn't. Should we do this in do_watchpoint() or in user_handler? Thank you, -- Masami Hiramatsu (Google) <mhiramat@kernel.org>
On Wed, 29 Oct 2025 17:20:04 +0900
Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote:
> On Wed, 29 Oct 2025 11:43:17 +0900
> Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote:
>
> > > Hmm, it seems that jiffies related things are updated frequently
> > > and it may cause interrupt storm or infinit recursive call.
> >
> > I added another trace_printk() in el1_watchpt(). It seems el1_watchpt()
> > takes too long and there is no time to do any other things.
> > (Note the interval shown below is only within the el1_watchpt function,
> > and in reality various processes (save/restore registers etc) for
> > exception handling will be inserted before and after.)
>
> Forget about this. I found the root cause. The x86 watchpoint exception
> happens after the instruction is executed, the arm64 happens before.
>
> Thus what we need is to emulate or do single step the hooked instruction
> and restart from the next instruction from the watchpoint exception on
> arm64. I thought hw_breakpoint does that, but doesn't. Should we do this
> in do_watchpoint() or in user_handler?
There is a single step execution code but only for default overflow_handlers.
This is a bit strange becuase other users can not set it up outside of
the arch dependent code. Even if it can, it is simply redundant.
So I made changes below which allow users to set its own custom handler is
compatible with perf default overflow handlers.
I confirmed this works on both arm and arm64.
diff --git a/arch/arm64/kernel/hw_breakpoint.c b/arch/arm64/kernel/hw_breakpoint.c
index ab76b36dce82..e12ec95b471e 100644
--- a/arch/arm64/kernel/hw_breakpoint.c
+++ b/arch/arm64/kernel/hw_breakpoint.c
@@ -632,6 +632,7 @@ void do_breakpoint(unsigned long esr, struct pt_regs *regs)
addr = instruction_pointer(regs);
debug_info = ¤t->thread.debug;
+ trace_printk("breakpoint exception at address: 0x%lx\n", addr);
for (i = 0; i < core_num_brps; ++i) {
rcu_read_lock();
@@ -661,6 +662,7 @@ void do_breakpoint(unsigned long esr, struct pt_regs *regs)
rcu_read_unlock();
}
+ trace_printk("breakpoint handling complete, step=%d\n", step);
if (!step)
return;
diff --git a/include/linux/perf_event.h b/include/linux/perf_event.h
index fd1d91017b99..40dd897e26b0 100644
--- a/include/linux/perf_event.h
+++ b/include/linux/perf_event.h
@@ -902,6 +902,7 @@ struct perf_event {
u64 (*clock)(void);
perf_overflow_handler_t overflow_handler;
void *overflow_handler_context;
+ bool default_overflow_compatible;
struct bpf_prog *prog;
u64 bpf_cookie;
@@ -1505,13 +1506,7 @@ extern int perf_event_output(struct perf_event *event,
static inline bool
is_default_overflow_handler(struct perf_event *event)
{
- perf_overflow_handler_t overflow_handler = event->overflow_handler;
-
- if (likely(overflow_handler == perf_event_output_forward))
- return true;
- if (unlikely(overflow_handler == perf_event_output_backward))
- return true;
- return false;
+ return event->default_overflow_compatible;
}
extern void
diff --git a/kernel/events/core.c b/kernel/events/core.c
index 177e57c1a362..6bbbde82cb21 100644
--- a/kernel/events/core.c
+++ b/kernel/events/core.c
@@ -12946,9 +12946,11 @@ perf_event_alloc(struct perf_event_attr *attr, int cpu,
} else if (is_write_backward(event)){
event->overflow_handler = perf_event_output_backward;
event->overflow_handler_context = NULL;
+ event->default_overflow_compatible = true;
} else {
event->overflow_handler = perf_event_output_forward;
event->overflow_handler_context = NULL;
+ event->default_overflow_compatible = true;
}
perf_event__state_init(event);
diff --git a/kernel/trace/trace_wprobe.c b/kernel/trace/trace_wprobe.c
index 98605b207f43..f2c2f26fd668 100644
--- a/kernel/trace/trace_wprobe.c
+++ b/kernel/trace/trace_wprobe.c
@@ -163,6 +163,8 @@ static void wprobe_perf_handler(struct perf_event *bp,
static int __register_trace_wprobe(struct trace_wprobe *tw)
{
struct perf_event_attr attr;
+ struct perf_event *bp;
+ int cpu;
if (tw->bp_event)
return -EINVAL;
@@ -179,6 +181,11 @@ static int __register_trace_wprobe(struct trace_wprobe *tw)
tw->bp_event = NULL;
return ret;
}
+ /* Mark wprobe_perf_handler is compatible with default one. */
+ for_each_online_cpu(cpu) {
+ bp = per_cpu(*tw->bp_event, cpu);
+ bp->default_overflow_compatible = true;
+ }
return 0;
}
--
Masami Hiramatsu (Google) <mhiramat@kernel.org>
On Thu, Oct 30, 2025 at 09:09:52AM +0900, Masami Hiramatsu wrote: > Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote: > There is a single step execution code but only for default overflow_handlers. > This is a bit strange becuase other users can not set it up outside of > the arch dependent code. Even if it can, it is simply redundant. > So I made changes below which allow users to set its own custom handler is > compatible with perf default overflow handlers. > I confirmed this works on both arm and arm64. I think everyone who knows this code is really snowed under at the minute - can I suggest posting this as a fix for now? This is still broken on arm64, we'll need a fix (or to disable the feature on the affected arches) one way or another for v6.19.
On Wed, 12 Nov 2025 12:15:03 +0000 Mark Brown <broonie@kernel.org> wrote: > On Thu, Oct 30, 2025 at 09:09:52AM +0900, Masami Hiramatsu wrote: > > Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote: > > > There is a single step execution code but only for default overflow_handlers. > > This is a bit strange becuase other users can not set it up outside of > > the arch dependent code. Even if it can, it is simply redundant. > > > So I made changes below which allow users to set its own custom handler is > > compatible with perf default overflow handlers. > > I confirmed this works on both arm and arm64. > > I think everyone who knows this code is really snowed under at the > minute - can I suggest posting this as a fix for now? This is still > broken on arm64, we'll need a fix (or to disable the feature on the > affected arches) one way or another for v6.19. Sorry, let me drop it from for-next soon. Thanks, -- Masami Hiramatsu (Google) <mhiramat@kernel.org>
On Fri, 24 Oct 2025 22:31:06 +0100 Mark Brown <broonie@kernel.org> wrote: > On Tue, Sep 23, 2025 at 10:17:47AM +0900, Masami Hiramatsu (Google) wrote: > > From: Masami Hiramatsu (Google) <mhiramat@kernel.org> > > > > Add 'add_remove_wprobe.tc' testcase for testing wprobe event that > > tests adding and removing operations of the wprobe event. > > Since this series has landed in -next we've been seeing hangs on a range > of arm64 platforms running the ftrace tests, it looks like it's all of > them. Unfortunately the systems lock up with no output as soon as they > start trying to do something with wprobes: Oh, thanks for reporting! > > # ok 19 Generic dynamic event - add/remove kprobe events > # ok 20 Generic dynamic event - add/remove synthetic events > # ok 21 Generic dynamic event - add/remove tracepoint probe events > # ok 22 Generic dynamic event - add/remove tracepoint probe events on module > # ok 23 Generic dynamic event - add/remove/test uprobe events OK, let me check. > > the next test being add_remove_wprobe.tc, which doesn't seem to > complete. Full log (for what little it's worth): > > https://lava.sirena.org.uk/scheduler/job/2000440#L1860 > > I turned on -vvv logging and that generated the rather spectacularly > more verbose: > > https://lava.sirena.org.uk/scheduler/job/2000676/log_file/plain > > (in a somewhat processed format unfortunately.). Looking at that log I > do notice a bunch of "unexpected operators" reported by the shell, these > systems are running dash not bash, though that doesn't seem related. It > looks like the script hangs in reset_trigger_file while grepping the > trigger files rather than actually trying to do the test. Yeah, it seems do nothing on wprobe. Let me check why it happens. Thanks! > > Sorry about the delay in reporting this. -- Masami Hiramatsu (Google) <mhiramat@kernel.org>
© 2016 - 2025 Red Hat, Inc.