[PATCH 3/4] rtla/timerlat: Add example for BPF action program

Tomas Glozar posted 4 patches 3 months, 3 weeks ago
There is a newer version of this series
[PATCH 3/4] rtla/timerlat: Add example for BPF action program
Posted by Tomas Glozar 3 months, 3 weeks ago
Add an example BPF action program that prints the measured latency to
the tracefs buffer via bpf_printk().

Signed-off-by: Tomas Glozar <tglozar@redhat.com>
---
 tools/tracing/rtla/sample/timerlat_bpf_action.c | 16 ++++++++++++++++
 1 file changed, 16 insertions(+)
 create mode 100644 tools/tracing/rtla/sample/timerlat_bpf_action.c

diff --git a/tools/tracing/rtla/sample/timerlat_bpf_action.c b/tools/tracing/rtla/sample/timerlat_bpf_action.c
new file mode 100644
index 000000000000..ac1be049a848
--- /dev/null
+++ b/tools/tracing/rtla/sample/timerlat_bpf_action.c
@@ -0,0 +1,16 @@
+// SPDX-License-Identifier: GPL-2.0
+#include <linux/bpf.h>
+#include <bpf/bpf_tracing.h>
+
+char LICENSE[] SEC("license") = "GPL";
+
+struct trace_event_raw_timerlat_sample {
+	unsigned long long timer_latency;
+} __attribute__((preserve_access_index));
+
+SEC("tp/timerlat_action")
+int action_handler(struct trace_event_raw_timerlat_sample *tp_args)
+{
+	bpf_printk("Latency: %lld\n", tp_args->timer_latency);
+	return 0;
+}
-- 
2.51.0
Re: [PATCH 3/4] rtla/timerlat: Add example for BPF action program
Posted by Crystal Wood 3 months, 2 weeks ago
On Fri, 2025-10-17 at 16:46 +0200, Tomas Glozar wrote:
> Add an example BPF action program that prints the measured latency to
> the tracefs buffer via bpf_printk().
> 
> Signed-off-by: Tomas Glozar <tglozar@redhat.com>
> ---
>  tools/tracing/rtla/sample/timerlat_bpf_action.c | 16 ++++++++++++++++
>  1 file changed, 16 insertions(+)
>  create mode 100644 tools/tracing/rtla/sample/timerlat_bpf_action.c

We should have the makefile build this, and add a test that uses it.

-Crystal
Re: [PATCH 3/4] rtla/timerlat: Add example for BPF action program
Posted by Tomas Glozar 3 months, 2 weeks ago
po 20. 10. 2025 v 19:53 odesílatel Crystal Wood <crwood@redhat.com> napsal:
>
> We should have the makefile build this, and add a test that uses it.
>

I agree. I tried to use the example, but it would be also good to
check if the BPF program was actually executed.

That is hard to do reliably for the current example, as it writes into
the global tracefs instance, which might conflict with another user of
the same instance. I will write another BPF program that will create a
map instead, and a script that will check the map value via
--on-threshold in the test.

Tomas
Re: [PATCH 3/4] rtla/timerlat: Add example for BPF action program
Posted by Crystal Wood 3 months, 2 weeks ago
On Tue, 2025-10-21 at 16:54 +0200, Tomas Glozar wrote:
> po 20. 10. 2025 v 19:53 odesílatel Crystal Wood <crwood@redhat.com> napsal:
> > 
> > We should have the makefile build this, and add a test that uses it.
> > 
> 
> I agree. I tried to use the example, but it would be also good to
> check if the BPF program was actually executed.
> 
> That is hard to do reliably for the current example, as it writes into
> the global tracefs instance, which might conflict with another user of
> the same instance. I will write another BPF program that will create a
> map instead, and a script that will check the map value via
> --on-threshold in the test.

Huh, so I guess BPF is an exception to the "no generic printk to the
global trace instance except for debugging that generates a big boot
splat" rule?

Speaking of which, why doesn't trace_osnoise.c call
trace_array_init_printk() given that it uses trace_array_printk_buf()?

-Crystal
Re: [PATCH 3/4] rtla/timerlat: Add example for BPF action program
Posted by Steven Rostedt 3 months, 2 weeks ago
On Tue, 21 Oct 2025 10:58:06 -0500
Crystal Wood <crwood@redhat.com> wrote:

> Huh, so I guess BPF is an exception to the "no generic printk to the
> global trace instance except for debugging that generates a big boot
> splat" rule?

bpf_printk() is an event and not the generic trace_printk() that would
cause that splat. You can turn it off.

> 
> Speaking of which, why doesn't trace_osnoise.c call
> trace_array_init_printk() given that it uses trace_array_printk_buf()?

Note, trace_array_printk() (which trace_array_init_printk()) only works for
instances and does not print into the top level trace buffer.

-- Steve
Re: [PATCH 3/4] rtla/timerlat: Add example for BPF action program
Posted by Crystal Wood 3 months, 2 weeks ago
On Tue, 2025-10-21 at 13:02 -0400, Steven Rostedt wrote:
> On Tue, 21 Oct 2025 10:58:06 -0500
> Crystal Wood <crwood@redhat.com> wrote:
> 
> > Huh, so I guess BPF is an exception to the "no generic printk to the
> > global trace instance except for debugging that generates a big boot
> > splat" rule?
> 
> bpf_printk() is an event and not the generic trace_printk() that would
> cause that splat. You can turn it off.

Ah, I see.

> > Speaking of which, why doesn't trace_osnoise.c call
> > trace_array_init_printk() given that it uses trace_array_printk_buf()?
> 
> Note, trace_array_printk() (which trace_array_init_printk()) only works for
> instances and does not print into the top level trace buffer.

Yes, it's for instances, such as the ones rtla creates.

-Crystal
Re: [PATCH 3/4] rtla/timerlat: Add example for BPF action program
Posted by Tomas Glozar 3 months, 2 weeks ago
út 21. 10. 2025 v 19:32 odesílatel Crystal Wood <crwood@redhat.com> napsal:
>
> On Tue, 2025-10-21 at 13:02 -0400, Steven Rostedt wrote:
> >
> > Note, trace_array_printk() (which trace_array_init_printk()) only works for
> > instances and does not print into the top level trace buffer.
>
> Yes, it's for instances, such as the ones rtla creates.
>
> -Crystal
>

Right, it actually works with the trace instance, when set up properly:

[root@cs9 rtla]# ./rtla timerlat hist -T 1 -c 0 -e
bpf_trace:bpf_trace_printk --on-end trace --on-end shell,command='grep
bpf_trace_printk timerlat_trace.txt' --bpf-action
example/timerlat_bpf_action.o
# RTLA timerlat histogram
# Time unit is microseconds (us)
# Duration:   0 00:00:01
Index   IRQ-000   Thr-000   Usr-000
6             1         0         0
21            0         1         0
over:         0         0         0
count:        1         1         0
min:          6        21         -
avg:          6        21         -
max:          6        21         -
ALL:        IRQ       Thr       Usr
count:        1         1         0
min:          6        21         -
avg:          6        21         -
max:          6        21         -
 Saving trace to timerlat_trace.txt
    timerlatu/0-47791   [000] ...22 863353.286497: bpf_trace_printk:
Latency: 21282

Tomas