3.9. Using the ftrace Utility for Tracing Latencies
ftrace, which is used by developers to analyze and debug latency and performance issues that occur outside of user-space. The
ftraceutility has a variety of options that allow you to use the utility in a number of different ways. It can be used to trace context switches, measure the time it takes for a high-priority task to wake up, the length of time interrupts are disabled, or list all the kernel functions executed during a given period.
ftraceutility can be set up once the
tracevariant of the Red Hat Enterprise Linux for Real Time kernel is installed and in use.
Procedure 3.3. Using the
- In the
/sys/kernel/debug/tracing/directory, there is a file named
available_tracers. This file contains all the available tracers for
ftrace. To see the list of available tracers, use the
catcommand to view the contents of the file:
cat /sys/kernel/debug/tracing/available_tracersfunction_graph wakeup_rt wakeup preemptirqsoff preemptoff irqsoff function nopThe user interface for
ftraceis a series of files within
ftracefiles are also located in the
/sys/kernel/debug/tracing/directory. Enter it:
cd /sys/kernel/debug/tracingThe files in this directory can only be modified by the
rootuser, as enabling tracing can have an impact on the performance of the system.Ftrace Files
The main files within this directory are:
- The file that shows the output of a ftrace trace. This is really a snapshot of the trace in time, as it stops tracing as this file is read, and it does not consume the events read. That is, if the user disabled tracing and read this file, it will always report the same thing every time its read.
- Like "trace" but is used to read the trace live. It is a producer / consumer trace, where each read will consume the event that is read. But this can be used to see an active trace without stopping the trace as it is read.
- A list of ftrace tracers that have been compiled into the kernel.
- Enables or disables a ftrace tracer.
- A directory that contains events to trace and can be used to enable or disable events as well as set filters for the events.
- Disable and enable recording to the ftrace buffer. Disabling tracing via the
tracing_onfile does not disable the actual tracing that is happening inside the kernel. It only disables writing to the buffer. The work to do the trace still happens, but the data does not go anywhere.
Depending on how the kernel was configured, not all tracers may be available for a given kernel. For the Red Hat Enterprise Linux for Real Time kernels, the trace and debug kernels have different tracers than the production kernel does. This is because some of the tracers have a noticeable overhead when the tracer is configured into the kernel but not active. Those tracers are only enabled for the trace and debug kernels.
- One of the most widely applicable tracers. Traces the function calls within the kernel. Can cause noticeable overhead depending on the quantity of functions traced. Creates little overhead when not active.
function_graphtracer is designed to present results in a more visually appealing format. This tracer also traces the exit of the function, displaying a flow of function calls in the kernel.Note that this tracer has more overhead than the
functiontracer when enabled, but the same low overhead when disabled.
- A full CPU tracer that reports the activity happening across all CPUs. Records the time that it takes to wake up the highest priority task in the system, whether that task is a real time task or not. Recording the max time it takes to wake up a non real time task will hide the times it takes to wake up a real time task.
- A full CPU tracer that reports the activity happening across all CPUs. Records the time that it takes from the current highests priority task to wake up to the time it is scheduled. Only records the time for real time tasks.
- Traces the areas that disable pre-emption or interrupts, and records the maximum amount of time for which pre-emption or interrupts were disabled.
- Similar to the
preemptirqsofftracer but traces only the maximum interval for which pre-emption was disabled.
- Similar to the
preemptirqsofftracer but traces only the maximum interval for which interrupts were disabled.
- The default tracer. It does not provide any tracing facility itself, but as events may interleave into any tracer, the
noptracer is used for specific interest in tracing events.
- To manually start a tracing session, first select the tracer you wish to use from the list in
available_tracersand then use the
echocommand to insert the name of the tracer into
echo preemptoff > /sys/kernel/debug/tracing/current_tracer
- To check if
function_graphtracing is enabled, use the
catcommand to view the
/sys/kernel/debug/tracing/options/function-tracefile. A value of
1indicates that this is enabled, and
0indicates that it has been disabled.
cat /sys/kernel/debug/tracing/options/function-trace1By default,
function_graphtracing is enabled. To turn this feature on or off,
echothe appropriate value to the
echo 0 > /sys/kernel/debug/tracing/options/function-trace~]#
echo 1 > /sys/kernel/debug/tracing/options/function-trace
ImportantWhen using the
echocommand, ensure you place a space character in between the value and the
>character. At the shell prompt, using
0>, 1>, and 2>(without a space character) refers to standard input, standard output and standard error. Using them by mistake could result in unexpected trace output.The
function-traceoption is useful because tracing latencies with
preemptirqsoffand so on automatically enables function tracing, which may exaggerate the overhead.
- Adjust details and parameters of the tracers by changing the values for the various files in the
/debugfs/tracing/directory. Some examples are:The irqsoff, preemptoff, preempirqsoff, and wakeup tracers continuously monitor latencies. When they record a latency greater than the one recorded in
tracing_max_latencythe trace of that latency is recorded, and
tracing_max_latencyis updated to the new maximum time. In this way,
tracing_max_latencywill always show the highest recorded latency since it was last reset.To reset the maximum latency,
tracing_max_latencyfile. To see only latencies greater than a set amount,
echothe amount in microseconds:
echo 0 > /sys/kernel/debug/tracing/tracing_max_latencyWhen the tracing threshold is set, it overrides the maximum latency setting. When a latency is recorded that is greater than the threshold, it will be recorded regardless of the maximum latency. When reviewing the trace file, only the last recorded latency is shown.To set the threshold,
echothe number of microseconds above which latencies must be recorded:
echo 200 > /sys/kernel/debug/tracing/tracing_thresh
- View the trace logs:
- To store the trace logs, copy them to another file:
cat /sys/kernel/debug/tracing/trace > /tmp/lat_trace_log
- Function tracing can be filtered by altering the settings in the
/sys/kernel/debug/tracing/set_ftrace_filterfile. If no filters are specified in the file, all functions are traced. Use the
catto view the current filters:
- To change the filters,
echothe name of the function to be traced. The filter allows the use of a
*wildcard at the beginning or end of a search term.The
*wildcard can also be used at both the beginning and end of a word. For example:
*irq*will select all functions that contain
irqin the name. The wildcard cannot, however, be used inside a word.Encasing the search term and the wildcard character in double quotation marks ensures that the shell will not attempt to expand the search to the present working directory.Some examples of filters are:
- Trace only the
echo schedule > /sys/kernel/debug/tracing/set_ftrace_filter
- Trace all functions that end with
echo "*lock" > /sys/kernel/debug/tracing/set_ftrace_filter
- Trace all functions that start with
echo "spin_*" > /sys/kernel/debug/tracing/set_ftrace_filter
- Trace all functions with
cpuin the name:
echo "*cpu*" > /sys/kernel/debug/tracing/set_ftrace_filter
NoteIf you use a single
echocommand, it will override any existing value in the file. If you wish to append the value to the file, use