利用ftrace进行内核性能分析

在内核层面上分析事件有很多的工具：SystemTap、ktap、Sysdig、LTTNG 等等，你也可以在网络上找到关于这些工具的大量介绍文章和资料。

而对于使用 Linux 原生机制去跟踪系统事件以及检索/分析故障信息的方面的资料却很少找的到。这就是 ftrace，它是添加到内核中的第一款跟踪工具，今天我们来看一下它都能做什么.

ftrace 是 Function Trace 的简写，但它能做的远不止这些：它可以跟踪上下文切换、测量进程阻塞时间、计算高优先级任务的活动时间等等。

ftrace 是由 Steven Rostedt 开发的，从 2008 年发布的内核 2.6.27 中开始就内置了。这是为记录数据提供的一个调试 Ring 缓冲区的框架。这些数据由集成到内核中的跟踪程序来采集。

ftrace 工作在 debugfs 文件系统上，在大多数现代 Linux 发行版中都默认挂载了。要开始使用 ftrace，你将进入到 sys/kernel/debug/tracing 目录（仅对 root 用户可用）：

第一步:确认机器已经挂载debugfs

第二步: 查看系统当前支持的tracer

root@czl-VirtualBox:/sys/kernel/debug/tracing# cat available_tracers 
hwlat blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop
root@czl-VirtualBox:/sys/kernel/debug/tracing# 

第三步:设置其中一个tracer:

echo wakeup_rt >current_tracer 
echo 1 > tracing_on
echo 0 > tracing_on

在echo 1和 echo 0中间停留片刻,等待ftrace将ringbuffer填充

之后执行如下命令查看结果:

cat trace

root@czl-VirtualBox:/sys/kernel/debug/tracing# cat trace
# tracer: wakeup_rt
#
# wakeup_rt latency trace v1.1.5 on 5.4.0-81-generic
# --------------------------------------------------------------------
# latency: 112 us, #154/154, CPU#0 | (M:desktop VP:0, KP:0, SP:0 HP:0 #P:1)
#    -----------------
#    | task: migration/0-12 (uid:0 nice:0 policy:1 rt_prio:99)
#    -----------------
#
#                    _------=> CPU#            
#                   / _-----=> irqs-off        
#                  | / _----=> need-resched    
#                  || / _---=> hardirq/softirq 
#                  ||| / _--=> preempt-depth   
#                  |||| /     delay            
#  cmd     pid     ||||| time  |   caller      
#     \   /        |||||  \    |   /         
  <idle>-0         0dNh.    1us+:        0:120:R   + [000]      12:  0:R migration/0
  <idle>-0         0dNh.   20us : <stack trace>
 => __trace_stack
 => probe_wakeup
 => ttwu_do_wakeup
 => ttwu_do_activate
 => try_to_wake_up
 => wake_up_q
 => cpu_stop_queue_work
 => stop_one_cpu_nowait
 => watchdog_timer_fn
 => __hrtimer_run_queues
 => hrtimer_interrupt
 => smp_apic_timer_interrupt
 => apic_timer_interrupt
 => mwait_idle
 => arch_cpu_idle
 => default_idle_call
 => do_idle
 => cpu_startup_entry
 => rest_init
 => arch_call_rest_init
 => start_kernel
 => x86_64_start_reservations
 => x86_64_start_kernel
 => secondary_startup_64
  <idle>-0         0dNh.   21us : ttwu_do_activate <-try_to_wake_up
  <idle>-0         0dNh.   21us : _raw_spin_unlock_irqrestore <-try_to_wake_up
  <idle>-0         0dNh.   22us : ktime_get <-watchdog_timer_fn
  <idle>-0         0dNh.   22us : hrtimer_forward <-watchdog_timer_fn
  <idle>-0         0dNh.   23us : _raw_spin_lock_irq <-__hrtimer_run_queues
  <idle>-0         0dNh.   23us : enqueue_hrtimer <-__hrtimer_run_queues
  <idle>-0         0dNh.   26us : __remove_hrtimer <-__hrtimer_run_queues
  <idle>-0         0dNh.   27us : _raw_spin_unlock_irqrestore <-__hrtimer_run_queues
  <idle>-0         0dNh.   27us : tick_sched_timer <-__hrtimer_run_queues
  <idle>-0         0dNh.   28us : ktime_get <-tick_sched_timer
  <idle>-0         0dNh.   28us : tick_sched_do_timer <-tick_sched_timer
  <idle>-0         0dNh.   29us : tick_do_update_jiffies64.part.14 <-tick_sched_do_timer
  <idle>-0         0dNh.   29us : _raw_spin_lock <-tick_do_update_jiffies64.part.14
  <idle>-0         0dNh.   29us : do_timer <-tick_do_update_jiffies64.part.14
  <idle>-0         0dNh.   30us : calc_global_load <-do_timer
  <idle>-0         0dNh.   30us : update