RTLA-TIMERLAT-HIST(1)

🎀 rtla-timerlat-hist 🎀

okay bestie, welcome to the rtla-timerlat-hist page — it lives in the General Commands Manual section of your friendly neighbourhood man setup, and it's all about histograms of the operating system timer latency. yes. we're measuring vibes of the kernel's timer. iconic behavior honestly. 💅

---

✨ NAME ✨

rtla-timerlat-hist — Histograms of the operating system timer latency

---

🌈 SYNOPSIS 🌈

rtla timerlat hist [OPTIONS] ...

like. that's it. that's the summoning ritual. 🪄

---

💖 DESCRIPTION 💖

so the rtla timerlat tool is basically the bestie-interface for the timerlat tracer. and what does that tracer do? it dispatches a kernel thread per-cpu. every single one of those threads sets a periodic timer so it can wake itself up and then immediately go back to sleep — which is, honestly, such a mood 😭. and after the wakeup, they collect and generate useful information for the debugging of operating system timer latency. like, they're doing the work so you don't have to. obsessed.

---

now, the timerlat tracer spills the tea in two different ways:

• it periodically prints the timer latency at the timer IRQ handler and the Thread handler 🕐
• and it also enables the trace of the most relevant information via osnoise: tracepoints ✨

---

and here's where rtla timerlat shows up: it sets the options of the timerlat tracer and then collects and displays a summary of the results. main character energy fr fr. 👑

by default? the collection happens synchronously in kernel space using a dedicated BPF program that gets attached to the timerlat tracer. but — and this is the important part — if either BPF or the osnoise:timerlat_sample tracepoint it attaches to is unavailable, the rtla timerlat tool falls back to using tracefs to process the data asynchronously in user space. so it's giving plan B, but make it functional. 🫶

---

and finally, the star of this particular show: rtla timerlat hist displays a histogram of each tracer event occurrence. 📊✨

it uses the periodic information, and heads up bestie — the osnoise: tracepoints are enabled when using the -T option. so if you want those, you gotta ask for them. no cap. 💅

---

to be continued, don't go anywhere… 🦋

✨ OPTIONS ✨

okay bestie, buckle UP, this is the part where rtla timerlat hist lets you customize literally everything 💅 every flag, every default, all of it. no skimming allowed.

• -a, --auto us — turns on automatic trace mode, which is the "just make it work" mode: it flips on a bunch of commonly-used options while you're debugging the system. It's the same as typing -T us -s us -t. oh and btw, by default the timerlat tracer uses FIFO:95 for timerlat threads, so this is also equivalent to -P f:95. 🫶
• -p, --period us — sets the timerlat tracer period, measured in microseconds.
• -i, --irq us — stops the trace if the IRQ latency goes higher than the argument (in us). like, "we're done here" energy.
• -T, --thread us — stops the trace if the Thread latency goes higher than the argument (in us).
• -s, --stack us — saves the stack trace at the IRQ if a Thread latency is higher than the argument (in us). receipts, basically 📸
• -t, --trace [file] — saves the stopped trace to [file|timerlat_trace.txt]. if you don't hand it a filename it just goes to timerlat_trace.txt, iconic default behavior.
• --dma-latency us — sets the /dev/cpu_dma_latency to us, trying to bound how long the system takes to exit from idle latencies. fun fact: cyclictest sets this value to 0 by default, so use --dma-latency 0 if you want similar results to that.
• --deepest-idle-state n — disables idle states higher than n for the cpus that are running timerlat threads, which cuts down on exit-from-idle latencies. if n is -1, ALL idle states get disabled, no cap. and when timerlat exits, the idle state setting gets restored to whatever it was originally before you ran timerlat — so it cleans up after itself, we love that 🌸

heads up bestie: this one requires rtla to be built with libcpupower. no libcpupower, no vibe.

• -k, --kernel-threads — uses timerlat kernel-space threads, in contrast to -u.
• -u, --user-threads — sets timerlat to run without a workload, and instead dispatches user-space workloads to wait on the timerlat_fd. once the workload gets awakened, it goes back to sleep again, which adds the measurement for the kernel-to-user and user-to-kernel transitions to the tracer output. and lowkey important: --user-threads will be used unless the user specifies -k.
• -U, --user-load — sets timerlat to run without a workload, just waiting for the user to dispatch a per-cpu task that waits for a new period on the tracing/osnoise/per_cpu/cpu$ID/timerlat_fd. wanna see an example of user-load code? check linux/tools/rtla/example/timerlat_load.py 🐍
• --bpf-action bpf-program — loads a BPF program from an ELF file and executes it whenever a latency threshold gets exceeded. very main character.

The BPF program has to be a valid ELF file that's loadable with libbpf. It must contain a function named action_handler, stored in an ELF section with the tp_ prefix. That prefix is what libbpf uses to set the BPF program type to BPF_PROG_TYPE_TRACEPOINT.

The program receives a struct trace_event_raw_timerlat_sample parameter containing the timerlat sample data.

There's an example in tools/tracing/rtla/example/timerlat_bpf_action.c. That example shows how to build a BPF program that prints latency info using bpf_trace_printk() when a threshold is exceeded. ✨

Note: BPF actions need BPF support to be available. If BPF isn't available or it's disabled, the tool falls back to tracefs mode and BPF actions are not supported. so don't come crying to me 😭

• --stack-format format — tweaks the format of the stack trace printed during auto-analysis.

The supported values for format are:

• truncate — print the stack trace up to the first unknown address (this is the default).
• skip — skip unknown addresses entirely, bye 👋
• full — print the entire stack trace, unknown addresses and all.

And for unknown addresses, the raw pointer gets printed.

• -A, --aligned us — aligns the wake-up of timerlat threads to a set offset in microseconds.

The alignment gets applied when the threads wake up at the start of tracing, while the timer for the first cycle is armed. Each thread sets its timer to the wake-up time of the previous thread plus the alignment.

You can use this with any non-negative argument, including zero — and zero aligns the threads so they all wake up at the same time. synchronized slay 🎀

• -b, --bucket-size N — sets the histogram bucket size (default 1).
• -E, --entries N — sets the number of entries of the histogram (default 256).
• --no-header — do not print the header.
• --no-summary — do not print the summary.
• --no-index — do not print the index.
• --with-zeros — prints zero-only entries. yeah, the empty ones. some people want them 🤷‍♀️
• -c, --cpus cpu-list — tells the timerlat hist tracer to run the sample threads on the cpu-list.

By default, the timerlat hist tracer runs the sample threads on all CPUs.

• -H, --house-keeping cpu-list — runs rtla control threads only on the given cpu-list.

If you omit it, rtla will try to auto-migrate its main thread to any CPU that isn't running any workload threads. it just wants its own lil corner 🦋

• -d, --duration time[s|m|h|d] — sets the duration of the session.
• -D, --debug — prints debug info.
• -e, --event sys:event — enables an event in the trace (-t) session. the argument can be a specific event, like -e sched:sched_switch, or all events of a system group, like -e sched. multiple -e are allowed. note that it's only active when -t or -a are set.
• --filter <filter> — filters the previous -e sys:event event with <filter>. for more info about event filtering, see <https://www.kernel.org/doc/html/latest/trace/events.html#event-filtering>.
• --trigger <trigger> — enables a trace event trigger to the previous -e sys:event. if the hist: trigger gets activated, the output histogram will automatically be saved to a file named system_event_hist.txt. for example, this command:

rtla <command> <mode> -t -e osnoise:irq_noise
--trigger="hist:key=desc,duration/1000:sort=desc,duration/1000:vals=hitcount"

will automatically save the content of the histogram associated to the osnoise:irq_noise event in osnoise_irq_noise_hist.txt.

for more info about event triggers, see <https://www.kernel.org/doc/html/latest/trace/events.html#event-triggers>.

• -P, --priority o:prio|r:prio|f:prio|d:runtime:period — sets the scheduling parameters for the timerlat hist tracer threads. the format for setting the priority is:
  • o:prio — use SCHED_OTHER with prio;
  • r:prio — use SCHED_RR with prio;
  • f:prio — use SCHED_FIFO with prio;
  • d:runtime[us|ms|s]:period[us|ms|s] — use SCHED_DEADLINE with runtime and period in nanoseconds.

If it's not set, tracer threads keep their default priority. For rtla user threads, it's set to SCHED_FIFO with priority 95. For kernel threads, go check the osnoise and timerlat tracer documentation for your running kernel version 👑

• -C, --cgroup [cgroup] — sets a cgroup for the tracer's threads. if you pass -C without arguments, the tracer's thread will inherit rtla's cgroup. otherwise, the threads get placed on the cgroup you passed to the option.

If it's not set, the behavior differs depending on workload type: user workloads created by rtla will inherit rtla's cgroup, while kernel workloads get assigned the root cgroup.

• --warm-up s — after starting the workload, lets it run for s seconds before starting to collect data, so the system can warm up. any statistical data generated during warm-up gets discarded. we stretch first, then we measure 💅
• --trace-buffer-size kB — sets the per-cpu trace buffer size in kB for the tracing output.

If it's not set, the default tracefs buffer size is used.

• --on-threshold action — defines an action to be executed when tracing is stopped on a latency threshold specified by -a/--auto, -i/--irq, or -T/--thread.

You can specify multiple --on-threshold actions, and they'll be executed in the order you provide them. If any action fails, the subsequent actions in the list will not be executed. one goes down, they all go down 💀

The supported actions are:

• trace[,file=<filename>]

Saves trace output, optionally taking a filename. This is an alternative to -t/--trace. Note that unlike -t/--trace, specifying this multiple times will result in the trace being saved multiple times.

• signal,num=<sig>,pid=<pid>

Sends a signal to a process. parent might be specified in place of pid to target the parent process of rtla.

• shell,command=<command>

Executes a shell command.

• continue

Continues tracing after the actions are executed instead of stopping.

Example:

$ rtla timerlat hist -T 20 --on-threshold trace --on-threshold
shell,command="grep ipi_send timerlat_trace.txt" --on-threshold
signal,num=2,pid=parent

This will save a trace with the default filename timerlat_trace.txt, print its lines that contain the text ipi_send on standard output, and send signal 2 (SIGINT) to the parent process.

Performance Considerations:

For time-sensitive actions, it's recommended to run rtla timerlat with BPF support and RT priority. And note that, due to implementational limitations, actions might be delayed up to one second after tracing is stopped if BPF mode isn't available or it's disabled. yeah, one whole second. plan accordingly bestie 😭

• --on-end action — defines an action to be executed at the end of tracing.

You can specify multiple --on-end actions, and they'll be executed in the order you provide them. If any action fails, the subsequent actions in the list will not be executed.

See the documentation for --on-threshold for the list of supported actions, with the exception that continue has no effect here.

Example:

$ rtla timerlat hist -d 5s --on-end trace

This runs rtla with the default options, and saves trace output at the end.

• -h, --help — prints the help menu.
• --dump-tasks — prints the task running on all CPUs if stop conditions are met (this depends on !--no-aa).
• --no-aa — disables auto-analysis, which reduces rtla timerlat cpu usage.

🎀 EXAMPLE 🎀

okay bestie, here's the whole vibe in action. In the example below, rtla timerlat hist is set to run for 10 minutes, on the cpus 0-4, skipping zero only lines. Also, rtla timerlat hist will change the priority of the timerlat threads to run under SCHED_DEADLINE priority, with a 100us runtime every 1ms period. That 1ms period is also passed to the timerlat tracer. Auto-analysis is disabled to reduce overhead.

[root@alien ~]# timerlat hist -d 10m -c 0-4 -P d:100us:1ms -p 1000 --no-aa
# RTLA timerlat histogram
# Time unit is microseconds (us)
# Duration:   0 00:10:00
Index   IRQ-000   Thr-000   IRQ-001   Thr-001   IRQ-002   Thr-002   IRQ-003   Thr-003   IRQ-004   Thr-004
0        276489         0    206089         0    466018         0    481102         0    205546         0
1        318327     35487    388149     30024     94531     48382     83082     71078    388026     55730
2          3282    122584      4019    126527     28231    109012     23311     89309      4568     98739
3           940     11815       837      9863      6209     16227      6895     17196       910      9780
4           444     17287       424     11574      2097     38443      2169     36736       462     13476
5           206     43291       255     25581      1223    101908      1304    101137       236     28913
6           132    101501        96     64584       635    213774       757    215471        99     73453
7            74    169347        65    124758       350     57466       441     53639        69    148573
8            53     85183        31    156751       229      9052       306      9026        39    139907
9            22     10387        12     42762       161      2554       225      2689        19     26192
10           13      1898         8      5770       114      1247       128      1405        13      3772
11            9       560         9       924        71       686        76       765         8       713
12            4       256         2       360        50       411        64       474         3       278
13            2       167         2       172        43       256        53       350         4       180
14            1        88         1       116        15       198        42       223         0       115
15            2        63         3        94        11       139        20       150         0        58
16            2        37         0        56         5        78        10       102         0        39
17            0        18         0        28         4        57         8        80         0        15
18            0         8         0        17         2        50         6        56         0        12
19            0         9         0         5         0        19         0        48         0        18
20            0         4         0         8         0        11         2        27         0         4
21            0         2         0         3         1         9         1        18         0         6
22            0         1         0         3         1         7         0         3         0         5
23            0         2         0         4         0         2         0         7         0         2
24            0         2         0         2         1         3         0         3         0         5
25            0         0         0         1         0         1         0         1         0         3
26            0         1         0         0         0         2         0         2         0         0
27            0         0         0         3         0         1         0         0         0         1
28            0         0         0         3         0         0         0         1         0         0
29            0         0         0         2         0         2         0         1         0         3
30            0         1         0         0         0         0         0         0         0         0
31            0         1         0         0         0         0         0         2         0         2
32            0         0         0         1         0         2         0         0         0         0
33            0         0         0         2         0         0         0         0         0         1
34            0         0         0         0         0         0         0         0         0         2
35            0         1         0         1         0         0         0         0         0         1
36            0         1         0         0         0         1         0         1         0         0
37            0         0         0         1         0         0         0         0         0         0
40            0         0         0         0         0         1         0         1         0         0
41            0         0         0         0         0         0         0         0         0         1
42            0         0         0         0         0         0         0         0         0         1
44            0         0         0         0         0         1         0         0         0         0
46            0         0         0         0         0         0         0         1         0         0
47            0         0         0         0         0         0         0         0         0         1
50            0         0         0         0         0         0         0         0         0         1
54            0         0         0         1         0         0         0         0         0         0
58            0         0         0         1         0         0         0         0         0         0
over:         0         0         0         0         0         0         0         0         0         0
count:   600002    600002    600002    600002    600002    600002    600002    600002    600002    600002
min:          0         1         0         1         0         1         0         1         0         1
avg:          0         5         0         5         0         4         0         4         0         5
max:         16        36        15        58        24        44        21        46        13        50

look at those numbers go 😭 she's WORKING.

---

🌈 SEE ALSO 🌈

• rtla-timerlat(1)
• rtla-timerlat-top(1)
• Timerlat tracer <https://docs.kernel.org/trace/timerlat-tracer.html>

---

✨ AUTHOR ✨

Written by Daniel Bristot de Oliveira < <bristot@kernel.org> >

periodt, thank you king 💖

---

💅 SIGINT BEHAVIOR 💅

okay so this part actually matters, bestie, pay attention:

• On the first SIGINT, RTLA exits after collecting all outstanding samples up to the point of receiving the signal.
• When receiving more than one SIGINT, RTLA discards any outstanding samples, and exits while displaying only samples that have already been processed.
• If SIGINT is received during RTLA cleanup, RTLA exits immediately via the default signal handler.

Note: For the purpose of SIGINT behavior, the expiry of duration specified via the -d/--duration option is treated as equivalent to receiving a SIGINT. So like, a SIGINT received after duration expired but samples have not been processed yet will drop any outstanding samples. no cap.

Also note that when using the timerlat tool in BPF mode, samples are processed in-kernel; RTLA only copies them out to display them to the user. A second SIGINT does not affect in-kernel sample aggregation.

---

👑 EXIT STATUS 👑

• 0 — Passed: the test did not hit the stop tracing condition 🎉
• 1 — Error: invalid argument 😭
• 2 — Failed: the test hit the stop tracing condition 💀
• 129 — Help: either user requested help or incorrect option was specified 🙈

---

🫶 REPORTING BUGS 🫶

Report bugs to < <linux-kernel@vger.kernel.org> > and < <linux-trace-devel@vger.kernel.org> >

(fr fr, they want to hear from you, don't be shy)

---

💜 LICENSE 💜

rtla is Free Software licensed under the GNU GPLv2

---

🌸 COPYING 🌸

Copyright (C) 2021 Red Hat, Inc. Free use of this software is granted under the terms of the GNU Public License (GPL).

---

that's the whole page bestie, you made it to the end 🦋 and if you ever need to double-check what you just read, it's all filed under RTLA-TIMERLAT-HIST(1) — go be the main character of your own tracing session 💖✨