What is ftrace and how do I use it?

Solution Verified - Updated

Environment

  • Red Hat Enterprise Linux 9
  • Red Hat Enterprise Linux 8
  • Red Hat Enterprise Linux 7
  • Red Hat Enterprise Linux 6
  • ftrace

Issue

  • What is ftrace and how do I use it?
  • How to enabled ftrace for tracing?

Resolution

  • ftrace is an internal tracer of the Linux kernel designed to help out developers and designers of systems to find what is going on inside the kernel.

Kconfig for the ftrace:

# grep TRACER /boot/config-4.18.0-60.el8.x86_64 
CONFIG_NOP_TRACER=y
CONFIG_HAVE_FUNCTION_TRACER=y
CONFIG_HAVE_FUNCTION_GRAPH_TRACER=y
CONFIG_TRACER_MAX_TRACE=y
CONFIG_CONTEXT_SWITCH_TRACER=y
CONFIG_GENERIC_TRACER=y
CONFIG_FUNCTION_TRACER=y
CONFIG_FUNCTION_GRAPH_TRACER=y
# CONFIG_IRQSOFF_TRACER is not set
CONFIG_SCHED_TRACER=y
CONFIG_HWLAT_TRACER=y
CONFIG_TRACER_SNAPSHOT=y
# CONFIG_TRACER_SNAPSHOT_PER_CPU_SWAP is not set
CONFIG_STACK_TRACER=y

  • It can be used for debugging or analyzing latencies and performance issues that take place outside of user-space. Although ftrace is typically considered the function tracer, it is really a framework of several assorted tracing utilities. 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.

  • The interface for ftrace resides in the debugfs file system in the 'tracing' directory.

How to use ftrace?

The Debug File System

  • Check if debugfs is mounted on the system.
# findmnt -t debugfs
TARGET            SOURCE  FSTYPE  OPTIONS
/sys/kernel/debug debugfs debugfs rw,relatime,seclabel

# mount | grep ^debugfs
debugfs on /sys/kernel/debug type debugfs (rw,relatime,seclabel)

Note: If debugfs is not mounted then mount the debugfs using the following command.

# mount -t debugfs nodev /sys/kernel/debug

The sysctl parameter ftrace_enabled

  • Check if sysctl parameter ftrace_enabled is enabled.
# sysctl -a | grep kernel.ftrace_enabled
kernel.ftrace_enabled = 1

Note: If sysctl parameter ftrace_enabled is not enabled then enable it using the following command.

# echo "kernel.ftrace_enabled = 1" >> /etc/sysctl.conf
# sysctl -a

The tracing directory /sys/kernel/debug/tracing

  • The tracing directory /sys/kernel/debug/tracing contains control and output files of ftrace.
# ll /sys/kernel/debug/tracing/
total 0
-r--r--r--.  1 root root 0 Feb 15 15:45 available_events
-r--r--r--.  1 root root 0 Feb 15 15:45 available_filter_functions
-r--r--r--.  1 root root 0 Feb 15 15:45 available_tracers
-rw-r--r--.  1 root root 0 Feb 15 15:45 buffer_size_kb
-r--r--r--.  1 root root 0 Feb 15 15:45 buffer_total_size_kb
-rw-r--r--.  1 root root 0 Feb 15 15:48 current_tracer
-r--r--r--.  1 root root 0 Feb 15 15:45 dyn_ftrace_total_info
-r--r--r--.  1 root root 0 Feb 15 15:45 enabled_functions
drwxr-xr-x. 84 root root 0 Feb 15 15:45 events
--w-------.  1 root root 0 Feb 15 15:45 free_buffer
-rw-r--r--.  1 root root 0 Feb 15 15:45 function_profile_enabled
drwxr-xr-x.  2 root root 0 Feb 15 15:45 hwlat_detector
drwxr-xr-x.  2 root root 0 Feb 15 15:45 instances
-rw-r--r--.  1 root root 0 Feb 15 15:45 kprobe_events
-r--r--r--.  1 root root 0 Feb 15 15:45 kprobe_profile
-rw-r--r--.  1 root root 0 Feb 15 15:48 max_graph_depth
drwxr-xr-x.  2 root root 0 Feb 15 15:45 options
drwxr-xr-x. 14 root root 0 Feb 15 15:45 per_cpu
-r--r--r--.  1 root root 0 Feb 15 15:45 printk_formats
-r--r--r--.  1 root root 0 Feb 15 15:45 README
-r--r--r--.  1 root root 0 Feb 15 15:45 saved_cmdlines
-rw-r--r--.  1 root root 0 Feb 15 15:45 saved_cmdlines_size
-r--r--r--.  1 root root 0 Feb 15 15:45 saved_tgids
-rw-r--r--.  1 root root 0 Feb 15 15:45 set_event
-rw-r--r--.  1 root root 0 Feb 15 15:45 set_event_pid
-rw-r--r--.  1 root root 0 Feb 15 15:48 set_ftrace_filter
-rw-r--r--.  1 root root 0 Feb 15 15:48 set_ftrace_notrace
-rw-r--r--.  1 root root 0 Feb 15 15:48 set_ftrace_pid
-rw-r--r--.  1 root root 0 Feb 15 15:48 set_graph_function
-rw-r--r--.  1 root root 0 Feb 15 15:48 set_graph_notrace
-rw-r--r--.  1 root root 0 Feb 15 15:45 snapshot
-rw-r--r--.  1 root root 0 Feb 15 15:45 stack_max_size
-r--r--r--.  1 root root 0 Feb 15 15:45 stack_trace
-rw-r--r--.  1 root root 0 Feb 15 15:45 stack_trace_filter
-rw-r--r--.  1 root root 0 Feb 15 15:45 synthetic_events
-r--r--r--.  1 root root 0 Feb 15 15:45 timestamp_mode
-rw-r--r--.  1 root root 0 Feb 15 15:48 trace
-rw-r--r--.  1 root root 0 Feb 15 15:45 trace_clock
--w--w----.  1 root root 0 Feb 15 15:45 trace_marker
--w--w----.  1 root root 0 Feb 15 15:45 trace_marker_raw
-rw-r--r--.  1 root root 0 Feb 15 15:45 trace_options
-r--r--r--.  1 root root 0 Feb 15 15:45 trace_pipe
drwxr-xr-x.  2 root root 0 Feb 15 15:45 trace_stat
-rw-r--r--.  1 root root 0 Feb 15 15:48 tracing_cpumask
-rw-r--r--.  1 root root 0 Feb 15 15:45 tracing_max_latency
-rw-r--r--.  1 root root 0 Feb 15 15:48 tracing_on
-rw-r--r--.  1 root root 0 Feb 15 15:45 tracing_thresh
-rw-r--r--.  1 root root 0 Feb 15 15:45 uprobe_events
-r--r--r--.  1 root root 0 Feb 15 15:45 uprobe_profile

Note: These files can only be modified by root user, as enabling tracing can have an impact on the performance of the system.

  • Open the file current_tracer to check the current tracer in use.
# cat /sys/kernel/debug/tracing/current_tracer
nop
  • Open the file available_tracers to check all the available tracers.
# cat /sys/kernel/debug/tracing/available_tracers
hwlat blk function_graph wakeup_dl wakeup_rt wakeup function nop

New tracers available in RHEL 9 timerlat & osnoise

# cat /sys/kernel/debug/tracing/available_tracers
timerlat osnoise hwlat blk function_graph wakeup_dl wakeup_rt wakeup function nop
  • To set one of the available tracers:
# echo function > /sys/kernel/debug/tracing/current_tracer
  • To verify the current tracer:
# cat /sys/kernel/debug/tracing/current_tracer
function
  • To enable tracing:
# echo 1 > /sys/kernel/debug/tracing/tracing_on

# cat /sys/kernel/debug/tracing/tracing_on
1
  • Open trace file to check the trace buffer.
# head -n 20 /sys/kernel/debug/tracing/trace
# tracer: function
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
            bash-17690 [003] .... 70881.737248: _cond_resched <-__do_page_fault
            bash-17690 [003] .... 70881.737248: rcu_all_qs <-_cond_resched
            bash-17690 [003] .... 70881.737248: find_vma <-__do_page_fault
            bash-17690 [003] .... 70881.737248: vmacache_find <-find_vma
            bash-17690 [003] .... 70881.737249: handle_mm_fault <-__do_page_fault
            bash-17690 [003] .... 70881.737249: mem_cgroup_from_task <-handle_mm_fault
            bash-17690 [003] .... 70881.737249: __handle_mm_fault <-handle_mm_fault
            bash-17690 [003] .... 70881.737249: handle_pte_fault <-__handle_mm_fault
            bash-17690 [003] .... 70881.737250: pmd_devmap_trans_unstable <-handle_pte_fault
            bash-17690 [003] .... 70881.737250: alloc_pages_vma <-handle_pte_fault
            bash-17690 [003] .... 70881.737250: __get_vma_policy <-alloc_pages_vma
  • To disable tracing:
# echo 0 > /sys/kernel/debug/tracing/tracing_on

# cat /sys/kernel/debug/tracing/tracing_on
0
  • To clear the trace buffer.
# echo > /sys/kernel/debug/tracing/trace

# cat /sys/kernel/debug/tracing/trace
# tracer: function
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
  • Refer the kernel documentation or README file of ftrace to get detail information about each of files present inside the directory /sys/kernel/debug/tracing/ and how to use them for debugging.

Kernel Documentation:

# cat /usr/share/doc/kernel-doc-<kernel-version>/Documentation/trace/ftrace.txt

Ftrace README:

# cat /sys/kernel/debug/tracing/README

Red Hat Product documentation:

https://access.redhat.com/documentation/en-us/red_hat_enterprise_linux/6/html/developer_guide/ftrace

https://access.redhat.com/documentation/en-us/red_hat_enterprise_linux_for_real_time/7/html/tuning_guide/using_the_ftrace_utility_for_tracing_latencies

https://access.redhat.com/documentation/en-us/red_hat_enterprise_linux_for_real_time/7/html/tuning_guide/appe-detailed_description_of_ftrace

https://access.redhat.com/documentation/en-us/red_hat_enterprise_linux_for_real_time/8/html/optimizing_rhel_8_for_real_time_for_low_latency_operation/assembly_using-the-ftrace-utility-to-trace-latencies_optimizing-rhel8-for-real-time-for-low-latency-operation
SBR
Product(s)
Components
Category
Tags

This solution is part of Red Hat’s fast-track publication program, providing a huge library of solutions that Red Hat engineers have created while supporting our customers. To give you the knowledge you need the instant it becomes available, these articles may be presented in a raw and unedited form.