.\" Man page generated from reStructuredText. . . .nr rst2man-indent-level 0 . .de1 rstReportMargin \\$1 \\n[an-margin] level \\n[rst2man-indent-level] level margin: \\n[rst2man-indent\\n[rst2man-indent-level]] - \\n[rst2man-indent0] \\n[rst2man-indent1] \\n[rst2man-indent2] .. .de1 INDENT .\" .rstReportMargin pre: . RS \\$1 . nr rst2man-indent\\n[rst2man-indent-level] \\n[an-margin] . nr rst2man-indent-level +1 .\" .rstReportMargin post: .. .de UNINDENT . RE .\" indent \\n[an-margin] .\" old: \\n[rst2man-indent\\n[rst2man-indent-level]] .nr rst2man-indent-level -1 .\" new: \\n[rst2man-indent\\n[rst2man-indent-level]] .in \\n[rst2man-indent\\n[rst2man-indent-level]]u .. .TH "RTLA-TIMERLAT-TOP" 1 "" "" .SH NAME rtla-timerlat-top \- Measures the operating system timer latency .SH SYNOPSIS .sp \fBrtla timerlat top\fP [\fIOPTIONS\fP] ... .SH DESCRIPTION .sp The \fBrtla timerlat\fP tool is an interface for the \fItimerlat\fP tracer. The \fItimerlat\fP tracer dispatches a kernel thread per\-cpu. 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. .sp The \fItimerlat\fP tracer outputs information in two ways. It periodically prints the timer latency at the timer \fIIRQ\fP handler and the \fIThread\fP handler. It also enable the trace of the most relevant information via \fBosnoise:\fP tracepoints. .sp The \fBrtla timerlat top\fP displays a summary of the periodic output from the \fItimerlat\fP tracer. It also provides information for each operating system noise via the \fBosnoise:\fP tracepoints that can be seem with the option \fB\-T\fP\&. .SH OPTIONS .sp \fB\-a\fP, \fB\-\-auto\fP \fIus\fP .INDENT 0.0 .INDENT 3.5 Set the automatic trace mode. This mode sets some commonly used options while debugging the system. It is equivalent to use \fB\-T\fP \fIus\fP \fB\-s\fP \fIus\fP \fB\-t\fP\&. By default, \fItimerlat\fP tracer uses FIFO:95 for \fItimerlat\fP threads, thus equilavent to \fB\-P\fP \fIf:95\fP\&. .UNINDENT .UNINDENT .sp \fB\-p\fP, \fB\-\-period\fP \fIus\fP .INDENT 0.0 .INDENT 3.5 Set the \fItimerlat\fP tracer period in microseconds. .UNINDENT .UNINDENT .sp \fB\-i\fP, \fB\-\-irq\fP \fIus\fP .INDENT 0.0 .INDENT 3.5 Stop trace if the \fIIRQ\fP latency is higher than the argument in us. .UNINDENT .UNINDENT .sp \fB\-T\fP, \fB\-\-thread\fP \fIus\fP .INDENT 0.0 .INDENT 3.5 Stop trace if the \fIThread\fP latency is higher than the argument in us. .UNINDENT .UNINDENT .sp \fB\-s\fP, \fB\-\-stack\fP \fIus\fP .INDENT 0.0 .INDENT 3.5 Save the stack trace at the \fIIRQ\fP if a \fIThread\fP latency is higher than the argument in us. .UNINDENT .UNINDENT .INDENT 0.0 .TP .B \fB\-\-dma\-latency\fP \fIus\fP Set the /dev/cpu_dma_latency to \fIus\fP, aiming to bound exit from idle latencies. \fIcyclictest\fP sets this value to \fI0\fP by default, use \fB\-\-dma\-latency\fP \fI0\fP to have similar results. .UNINDENT .sp \fB\-u\fP, \fB\-\-user\-threads\fP .INDENT 0.0 .INDENT 3.5 Set timerlat to run without a workload, and then dispatches user\-space workloads to wait on the timerlat_fd. Once the workload is awakes, it goes to sleep again adding so the measurement for the kernel\-to\-user and user\-to\-kernel to the tracer output. .UNINDENT .UNINDENT .sp \fB\-q\fP, \fB\-\-quiet\fP .INDENT 0.0 .INDENT 3.5 Print only a summary at the end of the session. .UNINDENT .UNINDENT .sp \fB\-c\fP, \fB\-\-cpus\fP \fIcpu\-list\fP .INDENT 0.0 .INDENT 3.5 Set the osnoise tracer to run the sample threads in the cpu\-list. .UNINDENT .UNINDENT .sp \fB\-H\fP, \fB\-\-house\-keeping\fP \fIcpu\-list\fP .INDENT 0.0 .INDENT 3.5 Run rtla control threads only on the given cpu\-list. .UNINDENT .UNINDENT .sp \fB\-d\fP, \fB\-\-duration\fP \fItime[s|m|h|d]\fP .INDENT 0.0 .INDENT 3.5 Set the duration of the session. .UNINDENT .UNINDENT .sp \fB\-D\fP, \fB\-\-debug\fP .INDENT 0.0 .INDENT 3.5 Print debug info. .UNINDENT .UNINDENT .sp \fB\-t\fP, \fB\-\-trace\fP[\fI=file\fP] .INDENT 0.0 .INDENT 3.5 Save the stopped trace to [\fIfile|osnoise_trace.txt\fP]. .UNINDENT .UNINDENT .sp \fB\-e\fP, \fB\-\-event\fP \fIsys:event\fP .INDENT 0.0 .INDENT 3.5 Enable an event in the trace (\fB\-t\fP) session. The argument can be a specific event, e.g., \fB\-e\fP \fIsched:sched_switch\fP, or all events of a system group, e.g., \fB\-e\fP \fIsched\fP\&. Multiple \fB\-e\fP are allowed. It is only active when \fB\-t\fP or \fB\-a\fP are set. .UNINDENT .UNINDENT .sp \fB\-\-filter\fP \fI\fP .INDENT 0.0 .INDENT 3.5 Filter the previous \fB\-e\fP \fIsys:event\fP event with \fI\fP\&. For further information about event filtering see \fI\%https://www.kernel.org/doc/html/latest/trace/events.html#event\-filtering\fP\&. .UNINDENT .UNINDENT .INDENT 0.0 .TP .B \fB\-\-trigger\fP \fI\fP Enable a trace event trigger to the previous \fB\-e\fP \fIsys:event\fP\&. If the \fIhist:\fP trigger is activated, the output histogram will be automatically saved to a file named \fIsystem_event_hist.txt\fP\&. For example, the command: .sp rtla \-t \-e osnoise:irq_noise \-\-trigger=\(dqhist:key=desc,duration/1000:sort=desc,duration/1000:vals=hitcount\(dq .sp Will automatically save the content of the histogram associated to \fIosnoise:irq_noise\fP event in \fIosnoise_irq_noise_hist.txt\fP\&. .sp For further information about event trigger see \fI\%https://www.kernel.org/doc/html/latest/trace/events.html#event\-triggers\fP\&. .UNINDENT .sp \fB\-P\fP, \fB\-\-priority\fP \fIo:prio|r:prio|f:prio|d:runtime:period\fP .INDENT 0.0 .INDENT 3.5 Set scheduling parameters to the osnoise tracer threads, the format to set the priority are: .INDENT 0.0 .IP \(bu 2 \fIo:prio\fP \- use SCHED_OTHER with \fIprio\fP; .IP \(bu 2 \fIr:prio\fP \- use SCHED_RR with \fIprio\fP; .IP \(bu 2 \fIf:prio\fP \- use SCHED_FIFO with \fIprio\fP; .IP \(bu 2 \fId:runtime[us|ms|s]:period[us|ms|s]\fP \- use SCHED_DEADLINE with \fIruntime\fP and \fIperiod\fP in nanoseconds. .UNINDENT .UNINDENT .UNINDENT .sp \fB\-C\fP, \fB\-\-cgroup\fP[\fI=cgroup\fP] .INDENT 0.0 .INDENT 3.5 Set a \fIcgroup\fP to the tracer\(aqs threads. If the \fB\-C\fP option is passed without arguments, the tracer\(aqs thread will inherit \fBrtla\fP\(aqs \fIcgroup\fP\&. Otherwise, the threads will be placed on the \fIcgroup\fP passed to the option. .UNINDENT .UNINDENT .sp \fB\-h\fP, \fB\-\-help\fP .INDENT 0.0 .INDENT 3.5 Print help menu. .UNINDENT .UNINDENT .sp \fB\-\-dump\-tasks\fP .INDENT 0.0 .INDENT 3.5 prints the task running on all CPUs if stop conditions are met (depends on !\-\-no\-aa) .UNINDENT .UNINDENT .sp \fB\-\-no\-aa\fP .INDENT 0.0 .INDENT 3.5 disable auto\-analysis, reducing rtla timerlat cpu usage .UNINDENT .UNINDENT .sp \fB\-\-aa\-only\fP \fIus\fP .INDENT 0.0 .INDENT 3.5 Set stop tracing conditions and run without collecting and displaying statistics. Print the auto\-analysis if the system hits the stop tracing condition. This option is useful to reduce rtla timerlat CPU, enabling the debug without the overhead of collecting the statistics. .UNINDENT .UNINDENT .SH EXAMPLE .sp In the example below, the timerlat tracer is dispatched in cpus \fI1\-23\fP in the automatic trace mode, instructing the tracer to stop if a \fI40 us\fP latency or higher is found: .INDENT 0.0 .INDENT 3.5 .sp .EX # 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 .EE .UNINDENT .UNINDENT .sp In this case, the major factor was the delay suffered by the \fIIRQ handler\fP that handles \fBtimerlat\fP wakeup: \fI65.52%\fP\&. This can be caused by the current thread masking interrupts, which can be seen in the blocking thread stacktrace: the current thread (\fIobjtool:49256\fP) disabled interrupts via \fIraw spin lock\fP operations inside mem cgroup, while doing write syscall in a btrfs file system. .sp The raw trace is saved in the \fBtimerlat_trace.txt\fP file for further analysis. .sp Note that \fBrtla timerlat\fP was dispatched without changing \fItimerlat\fP tracer threads\(aq priority. That is generally not needed because these threads have priority \fIFIFO:95\fP by default, which is a common priority used by real\-time kernel developers to analyze scheduling delays. .SS SEE ALSO .sp \fBrtla\-timerlat\fP(1), \fBrtla\-timerlat\-hist\fP(1) .sp \fItimerlat\fP tracer documentation: <\fI\%https://www.kernel.org/doc/html/latest/trace/timerlat\-tracer.html\fP> .SS AUTHOR .sp Written by Daniel Bristot de Oliveira <\fI\%bristot@kernel.org\fP> .SH REPORTING BUGS .sp Report bugs to <\fI\%linux\-kernel@vger.kernel.org\fP> and <\fI\%linux\-trace\-devel@vger.kernel.org\fP> .SH LICENSE .sp \fBrtla\fP is Free Software licensed under the GNU GPLv2 .SH COPYING .sp Copyright (C) 2021 Red Hat, Inc. Free use of this software is granted under the terms of the GNU Public License (GPL). .\" Generated by docutils manpage writer. .