Ftrace and its functions

brief introduction

Ftrace is a tracker of the kernel, which helps developers to check the operation of the kernel, so as to better analyze performance problems.

Ftrace can help us analyze kernel specific events, track dynamic kernel functions, call stacks and stack usage. It can also help us track delays, such as when interrupts are blocked, when preemptions are blocked, and how long after a process is awakened to start executing.

tracefs

First, you need to mount debugfs or tracefs of the system to a certain place. Almost all Linux distributions have debugfs/tracefs support enabled, so we don't need to recompile the kernel. On CentOS 7, debugfs is usually mounted to / sys/kernel/debug

There are many files in this directory. Here is an overview of the basic files.

$ ls
available_events            free_buffer               README               stack_max_size      tracing_cpumask
available_filter_functions  function_profile_enabled  saved_cmdlines       stack_trace         tracing_max_latency
available_tracers           instances                 saved_cmdlines_size  stack_trace_filter  tracing_on
buffer_size_kb              kprobe_events             set_event            trace               tracing_thresh
buffer_total_size_kb        kprobe_profile            set_ftrace_filter    trace_clock         uprobe_events
current_tracer              max_graph_depth           set_ftrace_notrace   trace_marker        uprobe_profile
dyn_ftrace_total_info       options                   set_ftrace_pid       trace_options
enabled_functions           per_cpu                   set_graph_function   trace_pipe
events                      printk_formats            snapshot             trace_stat

At the same time, you can use the trace CMD tool, which is more friendly.

Basic use

You can know which tracers are supported through available tracers.

$ cat available_tracers
blk function_graph wakeup_dl wakeup_rt wakeup function nop

Turn on trace for function.

$ echo function > current_tracer

trace-cmd  start -p function

View results

cat trace | head -n 15 Or use the command

$ trace-cmd show| head -15
# tracer: function
#
# entries-in-buffer/entries-written: 20705/20705   #P:1
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
       trace-cmd-6698  [000] .... 17131.903259: schedule <-do_exit
       rcu_sched-9     [000] .... 17131.903264: schedule <-schedule_timeout
     kworker/0:3-5306  [000] .... 17131.903269: schedule <-worker_thread
             zsh-4670  [000] .... 17131.903674: schedule <-pipe_wait

stop trace:

$ echo nop > current_tracer
$ cat trace
# tracer: nop
#
# entries-in-buffer/entries-written: 0/0   #P:1
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |

Use command:

trace-cmd start -p nop
$ trace-cmd show
# tracer: nop
#
# entries-in-buffer/entries-written: 0/0   #P:1
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |

function graph tracer

trace-cmd start -p function_graph
trace-cmd show
# tracer: function_graph
#
# CPU  DURATION                  FUNCTION CALLS
# |     |   |                     |   |   |   |
 0)               |  schedule() {
 ------------------------------------------
 0)   <...>-7236   =>   rcu_sch-9
 ------------------------------------------

 0)               |  schedule() {
 ------------------------------------------
 0)   rcu_sch-9    =>  kworker-5306
 ------------------------------------------

 0)               |  schedule() {
c

Track only specific function s

#Specify function
echo schedule > set_ftrace_filter
cat set_ftrace_filter
schedule

#No tracking
echo '!schedule' > set_ftrace_filter
//Or:
echo schedule > set_ftrace_notrace