RTLA-TIMERLAT-TOP(1)

RTLA-TIMERLAT-TOP(1) 💅

okay bestie, this page is from the General Commands Manual, and it's literally called rtla-timerlat-top — no cap. It's giving “measure the operating system timer latency” energy, and we're gonna walk through it together. ✨

✨ NAME ✨

• rtla-timerlat-top — Measures the operating system timer latency. 🕰️💖

🌸 SYNOPSIS 🌸

rtla timerlat top [OPTIONS] ...

💖 DESCRIPTION 💖

The rtla timerlat tool is an interface for the timerlat tracer. The timerlat tracer dispatches a kernel thread per-cpu — yes, one for each CPU, she's thorough. 💅 These threads set a periodic timer to wake themselves up and go back to sleep. After the wakeup, they collect and generate useful information for the debugging of operating system timer latency. That's the whole point, bestie. 🎀

The timerlat tracer outputs information in two ways. It periodically prints the timer latency at the timer IRQ handler and the Thread handler. It also enables the trace of the most relevant information via osnoise: tracepoints. Two lanes, same iconic data. ✨

The rtla timerlat tool sets the options of the timerlat tracer and collects and displays a summary of the results. By default, the collection is done synchronously in kernel space using a dedicated BPF program attached to the timerlat tracer. 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 got a backup plan, she's prepared. 💅

The rtla timerlat top displays a summary of the periodic output from the timerlat tracer. It also provides information for each operating system noise via the osnoise: tracepoints that can be seen with the option -T. That -T is the VIP pass, iykyk. 👑

---

✨ OPTIONS ✨

okay bestie, this is the part where we go through literally every single knob you can turn. there are a LOT. grab a snack 🍓

• -a, --auto us — turns on the automatic trace mode, which is giving "I set up all the sensible stuff for you" energy. it flips on a bunch of commonly used options for when you're debugging the system, and it's exactly equivalent to using -T us -s us -t. also heads up: 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, in microseconds.
• -i, --irq us — stops the trace if the IRQ latency goes higher than the argument you gave, in us.
• -T, --thread us — stops the trace if the Thread latency goes higher than the argument you gave, in us.
• -s, --stack us — saves the stack trace at the IRQ if a Thread latency goes higher than the argument, in us.
• -t, --trace [file] — saves the stopped trace to [file|timerlat_trace.txt]. so if you don't hand it a filename, it defaults to timerlat_trace.txt. 💾
• --dma-latency us — sets /dev/cpu_dma_latency to us, aiming to bound exit-from-idle latencies. fun fact: cyclictest sets this value to 0 by default, so use --dma-latency 0 if you want similar results.
• --deepest-idle-state n — disables idle states higher than n for the CPUs that are running timerlat threads, which reduces exit-from-idle latencies. if n is -1, all idle states get disabled. on exit from timerlat, the idle state setting is restored to whatever it was originally before timerlat ran. 🧚

heads up: this one requires rtla to be built with libcpupower.

• -k, --kernel-threads — use timerlat kernel-space threads, in contrast to -u.
• -u, --user-threads — sets timerlat to run without a workload, and then dispatches user-space workloads to wait on the timerlat_fd. once the workload is awakened, it goes back to sleep again, which adds the kernel-to-user and user-to-kernel measurement to the tracer output. --user-threads will be used unless you specify -k.
• -U, --user-load — sets timerlat to run without workload, just waiting for you to dispatch a per-cpu task that waits for a new period on the tracing/osnoise/per_cpu/cpu$ID/timerlat_fd. wanna see what user-load code looks like? 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 is exceeded. very main character.

the BPF program has to be a valid ELF file 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 timerlat sample data.

there's an example in tools/tracing/rtla/example/timerlat_bpf_action.c, which demonstrates how to make a BPF program that prints latency info using bpf_trace_printk() when a threshold is exceeded.

note: BPF actions require BPF support to actually be available. if BPF isn't available or is disabled, the tool falls back to tracefs mode and BPF actions are not supported.

• --stack-format format — adjusts the format of the stack trace that gets 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.
  • full — print the entire stack trace, including unknown addresses.

for unknown addresses, the raw pointer is 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.

this option may be used with any non-negative argument, including zero — and zero will align threads so they all wake up at the exact same time. synced up, slay. ✨

• -q, --quiet — print only a summary at the end of the session. minimalism era.
• -c, --cpus cpu-list — tells the timerlat top tracer to run the sample threads on the cpu-list. by default, the timerlat top tracer runs the sample threads on all CPUs.
• -H, --house-keeping cpu-list — run rtla control threads only on the given cpu-list. if you omit it, rtla will attempt to auto-migrate its main thread to any CPU that isn't running any workload threads. 🏠
• -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. 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 is 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 with the osnoise:irq_noise event into 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 top tracer threads. the format for setting 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. iykyk 📚

• -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 between workload types. user workloads created by rtla will inherit rtla's cgroup. kernel workloads get assigned the root cgroup.

• --warm-up s — after starting the workload, let it run for s seconds before collecting data, so the system can warm up. any statistical data generated during warm-up is discarded. 🫶
• --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, as specified by -a/--auto, -i/--irq, or -T/--thread.

multiple --on-threshold actions may be specified, 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.

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 — continue tracing after actions are executed, instead of stopping.

example:

$ rtla timerlat top -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. 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 is disabled. 😭

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

multiple --on-end actions can be specified, 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 top -d 5s --on-end trace

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

• -h, --help — print the help menu.
• --dump-tasks — prints the task running on all CPUs if stop conditions are met (depends on !--no-aa).
• --no-aa — disable auto-analysis, which reduces rtla timerlat CPU usage.
• --aa-only us — sets stop tracing conditions and runs without collecting and displaying statistics. prints the auto-analysis if the system hits the stop tracing condition. this option is useful for reducing rtla timerlat CPU, letting you debug without the overhead of collecting the statistics. 🦋

🌸 EXAMPLE 🌸

okay bestie, storytime, because this example is chef's kiss 💖 In the one below, the timerlat tracer gets yeeted onto cpus 1-23 in the automatic trace mode, and it's told to stop if it finds a latency of 40 us or higher:

          # timerlat -a 40 -c 1-23 -q
                                             Timer Latency
            0 00:00:12   |          IRQ Timer Latency (us)        |         Thread Timer Latency (us)
          CPU COUNT      |      cur       min       avg       max |      cur       min       avg       max
            1 #12322     |        0         0         1        15 |       10         3         9        31
            2 #12322     |        3         0         1        12 |       10         3         9        23
            3 #12322     |        1         0         1        21 |        8         2         8        34
            4 #12322     |        1         0         1        17 |       10         2        11        33
            5 #12322     |        0         0         1        12 |        8         3         8        25
            6 #12322     |        1         0         1        14 |       16         3        11        35
            7 #12322     |        0         0         1        14 |        9         2         8        29
            8 #12322     |        1         0         1        22 |        9         3         9        34
            9 #12322     |        0         0         1        14 |        8         2         8        24
           10 #12322     |        1         0         0        12 |        9         3         8        24
           11 #12322     |        0         0         0        15 |        6         2         7        29
           12 #12321     |        1         0         0        13 |        5         3         8        23
           13 #12319     |        0         0         1        14 |        9         3         9        26
           14 #12321     |        1         0         0        13 |        6         2         8        24
           15 #12321     |        1         0         1        15 |       12         3        11        27
           16 #12318     |        0         0         1        13 |        7         3        10        24
           17 #12319     |        0         0         1        13 |       11         3         9        25
           18 #12318     |        0         0         0        12 |        8         2         8        20
           19 #12319     |        0         0         1        18 |       10         2         9        28
           20 #12317     |        0         0         0        20 |        9         3         8        34
           21 #12318     |        0         0         0        13 |        8         3         8        28
           22 #12319     |        0         0         1        11 |        8         3        10        22
           23 #12320     |       28         0         1        28 |       41         3        11        41
          rtla timerlat hit stop tracing
          ## CPU 23 hit stop tracing, analyzing it ##
          IRQ handler delay:                                        27.49 us (65.52 %)
          IRQ latency:                                              28.13 us
          Timerlat IRQ duration:                                     9.59 us (22.85 %)
          Blocking thread:                                           3.79 us (9.03 %)
                                 objtool:49256                       3.79 us
            Blocking thread stacktrace
                        -> timerlat_irq
                        -> __hrtimer_run_queues
                        -> hrtimer_interrupt
                        -> __sysvec_apic_timer_interrupt
                        -> sysvec_apic_timer_interrupt
                        -> asm_sysvec_apic_timer_interrupt
                        -> _raw_spin_unlock_irqrestore
                        -> cgroup_rstat_flush_locked
                        -> cgroup_rstat_flush_irqsafe
                        -> mem_cgroup_flush_stats
                        -> mem_cgroup_wb_stats
                        -> balance_dirty_pages
                        -> balance_dirty_pages_ratelimited_flags
                        -> btrfs_buffered_write
                        -> btrfs_do_write_iter
                        -> vfs_write
                        -> __x64_sys_pwrite64
                        -> do_syscall_64
                        -> entry_SYSCALL_64_after_hwframe
          ------------------------------------------------------------------------
            Thread latency:                                          41.96 us (100%)

          The system has exit from idle latency!
            Max timerlat IRQ latency from idle: 17.48 us in cpu 4
          Saving trace to timerlat_trace.txt

so in this case, the major factor was the delay suffered by the IRQ handler that handles timerlat wakeup: 65.52%. That can be caused by the current thread masking interrupts, which you can literally see in the blocking thread stacktrace: the current thread (objtool:49256) disabled interrupts via raw spin lock operations inside mem cgroup, while doing write syscall in a btrfs file system. the way it's all right there in the trace 😭💅

The raw trace is saved in the timerlat_trace.txt file for further analysis. keep it, love it, it's your receipt 🧾✨

Note that rtla timerlat was dispatched without changing timerlat tracer threads' priority. That is generally not needed because these threads have priority FIFO:95 by default, which is a common priority used by real-time kernel developers to analyze scheduling delays.

---

👀 SEE ALSO 👀

• rtla-timerlat(1), rtla-timerlat-hist(1)

Timerlat tracer <https://docs.kernel.org/trace/timerlat-tracer.html>

---

✍️ AUTHOR ✍️

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

---

🛑 SIGINT BEHAVIOR 🛑 (the "pls chill" rules)

On the first SIGINT, RTLA exits after collecting all outstanding samples up to the point of receiving the signal. it's giving polite, it's giving finishing your sentence 🎀

When receiving more than one SIGINT, RTLA discards any outstanding samples, and exits while displaying only samples that have already been processed. okay so you pressed it twice, that's on you bestie 💀

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. For example, a SIGINT received after duration expired but samples have not been processed yet will drop any outstanding samples.

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. lowkey important fr fr 🫶

---

🚪 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> >

---

📜 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).

---

and that's a wrap on the whole page, bestie!! 🦋✨ this was RTLA-TIMERLAT-TOP(1) — that's the source/manpage name sitting right at the bottom, and no cap, you now know more about timerlat top than like 99% of people. slay, go measure some latencies, and remember: if it's >40 us, that's not a vibe, that's a bug 💅👑🌸