1RTLA-TIMERLAT-TOP(1) RTLA-TIMERLAT-TOP(1)
2
3
4
6 rtla-timerlat-top - Measures the operating system timer latency
7
9 rtla timerlat top [OPTIONS] ...
10
12 The rtla timerlat tool is an interface for the timerlat tracer. The
13 timerlat tracer dispatches a kernel thread per-cpu. These threads set a
14 periodic timer to wake themselves up and go back to sleep. After the
15 wakeup, they collect and generate useful information for the debugging
16 of operating system timer latency.
17
18 The timerlat tracer outputs information in two ways. It periodically
19 prints the timer latency at the timer IRQ handler and the Thread han‐
20 dler. It also enable the trace of the most relevant information via os‐
21 noise: tracepoints.
22
23 The rtla timerlat top displays a summary of the periodic output from
24 the timerlat tracer. It also provides information for each operating
25 system noise via the osnoise: tracepoints that can be seem with the op‐
26 tion -T.
27
29 -a, --auto us
30 Set the automatic trace mode. This mode sets some commonly used op‐
31 tions while debugging the system. It is equivalent to use -T us -s
32 us -t. By default, timerlat tracer uses FIFO:95 for timerlat
33 threads, thus equilavent to -P f:95.
34
35 -p, --period us
36 Set the timerlat tracer period in microseconds.
37
38 -i, --irq us
39 Stop trace if the IRQ latency is higher than the argument in us.
40
41 -T, --thread us
42 Stop trace if the Thread latency is higher than the argument in us.
43
44 -s, --stack us
45 Save the stack trace at the IRQ if a Thread latency is higher than
46 the argument in us.
47
48 --dma-latency us
49 Set the /dev/cpu_dma_latency to us, aiming to bound exit from
50 idle latencies. cyclictest sets this value to 0 by default, use
51 --dma-latency 0 to have similar results.
52
53 -u, --user-threads
54 Set timerlat to run without a workload, and then dispatches
55 user-space workloads to wait on the timerlat_fd. Once the workload
56 is awakes, it goes to sleep again adding so the measurement for the
57 kernel-to-user and user-to-kernel to the tracer output.
58
59 -q, --quiet
60 Print only a summary at the end of the session.
61
62 -c, --cpus cpu-list
63 Set the osnoise tracer to run the sample threads in the cpu-list.
64
65 -H, --house-keeping cpu-list
66 Run rtla control threads only on the given cpu-list.
67
68 -d, --duration time[s|m|h|d]
69 Set the duration of the session.
70
71 -D, --debug
72 Print debug info.
73
74 -t, --trace[=file]
75 Save the stopped trace to [file|osnoise_trace.txt].
76
77 -e, --event sys:event
78 Enable an event in the trace (-t) session. The argument can be a
79 specific event, e.g., -e sched:sched_switch, or all events of a sys‐
80 tem group, e.g., -e sched. Multiple -e are allowed. It is only ac‐
81 tive when -t or -a are set.
82
83 --filter <filter>
84 Filter the previous -e sys:event event with <filter>. For further
85 information about event filtering see
86 https://www.kernel.org/doc/html/latest/trace/events.html#event-filtering.
87
88 --trigger <trigger>
89 Enable a trace event trigger to the previous -e sys:event. If
90 the hist: trigger is activated, the output histogram will be au‐
91 tomatically saved to a file named system_event_hist.txt. For
92 example, the command:
93
94 rtla <command> <mode> -t -e osnoise:irq_noise --trig‐
95 ger="hist:key=desc,duration/1000:sort=desc,dura‐
96 tion/1000:vals=hitcount"
97
98 Will automatically save the content of the histogram associated
99 to osnoise:irq_noise event in osnoise_irq_noise_hist.txt.
100
101 For further information about event trigger see
102 https://www.kernel.org/doc/html/latest/trace/events.html#event-triggers.
103
104 -P, --priority o:prio|r:prio|f:prio|d:runtime:period
105 Set scheduling parameters to the osnoise tracer threads, the format
106 to set the priority are:
107
108 • o:prio - use SCHED_OTHER with prio;
109
110 • r:prio - use SCHED_RR with prio;
111
112 • f:prio - use SCHED_FIFO with prio;
113
114 • d:runtime[us|ms|s]:period[us|ms|s] - use SCHED_DEADLINE with run‐
115 time and period in nanoseconds.
116
117 -C, --cgroup[=cgroup]
118 Set a cgroup to the tracer's threads. If the -C option is passed
119 without arguments, the tracer's thread will inherit rtla's cgroup.
120 Otherwise, the threads will be placed on the cgroup passed to the
121 option.
122
123 -h, --help
124 Print help menu.
125
126 --dump-tasks
127 prints the task running on all CPUs if stop conditions are met (de‐
128 pends on !--no-aa)
129
130 --no-aa
131 disable auto-analysis, reducing rtla timerlat cpu usage
132
133 --aa-only us
134 Set stop tracing conditions and run without collecting and display‐
135 ing statistics. Print the auto-analysis if the system hits the stop
136 tracing condition. This option is useful to reduce rtla timerlat
137 CPU, enabling the debug without the overhead of collecting the sta‐
138 tistics.
139
141 In the example below, the timerlat tracer is dispatched in cpus 1-23 in
142 the automatic trace mode, instructing the tracer to stop if a 40 us la‐
143 tency or higher is found:
144
145 # timerlat -a 40 -c 1-23 -q
146 Timer Latency
147 0 00:00:12 | IRQ Timer Latency (us) | Thread Timer Latency (us)
148 CPU COUNT | cur min avg max | cur min avg max
149 1 #12322 | 0 0 1 15 | 10 3 9 31
150 2 #12322 | 3 0 1 12 | 10 3 9 23
151 3 #12322 | 1 0 1 21 | 8 2 8 34
152 4 #12322 | 1 0 1 17 | 10 2 11 33
153 5 #12322 | 0 0 1 12 | 8 3 8 25
154 6 #12322 | 1 0 1 14 | 16 3 11 35
155 7 #12322 | 0 0 1 14 | 9 2 8 29
156 8 #12322 | 1 0 1 22 | 9 3 9 34
157 9 #12322 | 0 0 1 14 | 8 2 8 24
158 10 #12322 | 1 0 0 12 | 9 3 8 24
159 11 #12322 | 0 0 0 15 | 6 2 7 29
160 12 #12321 | 1 0 0 13 | 5 3 8 23
161 13 #12319 | 0 0 1 14 | 9 3 9 26
162 14 #12321 | 1 0 0 13 | 6 2 8 24
163 15 #12321 | 1 0 1 15 | 12 3 11 27
164 16 #12318 | 0 0 1 13 | 7 3 10 24
165 17 #12319 | 0 0 1 13 | 11 3 9 25
166 18 #12318 | 0 0 0 12 | 8 2 8 20
167 19 #12319 | 0 0 1 18 | 10 2 9 28
168 20 #12317 | 0 0 0 20 | 9 3 8 34
169 21 #12318 | 0 0 0 13 | 8 3 8 28
170 22 #12319 | 0 0 1 11 | 8 3 10 22
171 23 #12320 | 28 0 1 28 | 41 3 11 41
172 rtla timerlat hit stop tracing
173 ## CPU 23 hit stop tracing, analyzing it ##
174 IRQ handler delay: 27.49 us (65.52 %)
175 IRQ latency: 28.13 us
176 Timerlat IRQ duration: 9.59 us (22.85 %)
177 Blocking thread: 3.79 us (9.03 %)
178 objtool:49256 3.79 us
179 Blocking thread stacktrace
180 -> timerlat_irq
181 -> __hrtimer_run_queues
182 -> hrtimer_interrupt
183 -> __sysvec_apic_timer_interrupt
184 -> sysvec_apic_timer_interrupt
185 -> asm_sysvec_apic_timer_interrupt
186 -> _raw_spin_unlock_irqrestore
187 -> cgroup_rstat_flush_locked
188 -> cgroup_rstat_flush_irqsafe
189 -> mem_cgroup_flush_stats
190 -> mem_cgroup_wb_stats
191 -> balance_dirty_pages
192 -> balance_dirty_pages_ratelimited_flags
193 -> btrfs_buffered_write
194 -> btrfs_do_write_iter
195 -> vfs_write
196 -> __x64_sys_pwrite64
197 -> do_syscall_64
198 -> entry_SYSCALL_64_after_hwframe
199 ------------------------------------------------------------------------
200 Thread latency: 41.96 us (100%)
201
202 The system has exit from idle latency!
203 Max timerlat IRQ latency from idle: 17.48 us in cpu 4
204 Saving trace to timerlat_trace.txt
205
206 In this case, the major factor was the delay suffered by the IRQ han‐
207 dler that handles timerlat wakeup: 65.52%. This can be caused by the
208 current thread masking interrupts, which can be seen in the blocking
209 thread stacktrace: the current thread (objtool:49256) disabled inter‐
210 rupts via raw spin lock operations inside mem cgroup, while doing write
211 syscall in a btrfs file system.
212
213 The raw trace is saved in the timerlat_trace.txt file for further
214 analysis.
215
216 Note that rtla timerlat was dispatched without changing timerlat tracer
217 threads' priority. That is generally not needed because these threads
218 have priority FIFO:95 by default, which is a common priority used by
219 real-time kernel developers to analyze scheduling delays.
220
221 SEE ALSO
222 rtla-timerlat(1), rtla-timerlat-hist(1)
223
224 timerlat tracer documentation: <‐
225 https://www.kernel.org/doc/html/latest/trace/timerlat-tracer.html>
226
227 AUTHOR
228 Written by Daniel Bristot de Oliveira <bristot@kernel.org>
229
231 Report bugs to <linux-kernel@vger.kernel.org> and <‐
232 linux-trace-devel@vger.kernel.org>
233
235 rtla is Free Software licensed under the GNU GPLv2
236
238 Copyright (C) 2021 Red Hat, Inc. Free use of this software is granted
239 under the terms of the GNU Public License (GPL).
240
241
242
243
244 RTLA-TIMERLAT-TOP(1)