Chapter 11. Measuring scheduling latency using timerlat in RHEL for Real Time

The rtla-timerlat tool is an interface for the timerlat tracer. The timerlat tracer finds sources of wake-up latencies for real-time threads. The timerlat tracer creates a kernel thread per CPU with a real-time priority and these threads set a periodic timer to wake up and go back to sleep. On a wake up, timerlat finds and collects information, which is useful to debug operating system timer latencies. The timerlat tracer generates an output and prints the following two lines at every activation:

  • The timerlat tracer periodically prints the timer latency seen at timer interrupt requests (IRQs) handler. This is the first output seen at the hardirq context before a thread activation.
  • The second output is the timer latency of a thread. The ACTIVATION ID field displays the interrupt requests (IRQs) performance to its respective thread execution.

11.1. Configuring the timerlat tracer to measure scheduling latency

You can configure the timerlat tracer by adding timerlat in the curret_tracer file of the tracing system. The current_tracer file is generally mounted in the /sys/kernel/tracing directory. The timerlat tracer measures the interrupt requests (IRQs) and saves the trace output for analysis when a thread latency is more than 100 microseconds.

Procedure

  1. List the current tracer: 

    # cat /sys/kernel/tracing/current_tracer
nop

    The no operations (nop) is the default tracer.

  2. Add the timerlat tracer in the current_tracer file of the tracing system: 

    # cd /sys/kernel/tracing/
# echo timerlat > current_tracer

  3. Generate a tracing output: 

    # cat trace
# tracer: timerlat

Verification

  • Enter the following command to check if timerlat is enabled as the current tracer: 

    # cat /sys/kernel/tracing/current_tracer
  timerlat

11.2. The timerlat tracer options

The timerlat tracer is built on top of osnoise tracer. Therefore, you can set the options in the /osnoise/config directory to trace and capture information for thread scheduling latencies.

timerlat options

cpus
Sets CPUs for a timerlat thread to execute on.
timerlat_period_us
Sets the duration period of the timerlat thread in microseconds.
stop_tracing_us
Stops the system tracing if a timer latency at the irq context is more than the configured value. Writing 0 disables this option.
stop_tracing_total_us
Stops the system tracing if the total noise is more than the configured value. Writing 0 disables this option.
print_stack
Saves the stack of the interrupt requests (IRQs) occurrence. The stack saves the IRQs occurrence after the thread context event, or if the IRQs handler is more than the configured value.

11.3. Measuring timer latency with rtla-timerlat-top

The rtla-timerlat-top tracer displays a summary of the periodic output from the timerlat tracer. The tracer output also provides information about each operating system noise and events, such as osnoise, and tracepoints. You can view this information by using the -t option.

Procedure

  • To measure timer latency: 

    # rtla timerlat top -s 30 -T 30 -t

11.4. The rtla timerlat top tracer options

By using the rtla timerlat top --help command, you can view the help usage on options for the rtla-timerlat-top tracer.

timerlat-top-tracer options

-p, --period us
Sets the timerlat tracer period in microseconds.
-i, --irq us
Stops the trace if the interrupt requests (IRQs) latency is more than the argument in microseconds.
-T, --thread us
Stops the trace if the thread latency is more than the argument in microseconds.
-t, --trace
Saves the stopped trace to the timerlat_trace.txt file.
-s, --stack us
Saves the stack trace at the interrupt requests (IRQs), if a thread latency is more than the argument.