動態追蹤技術：trace your kernel Functions!

Ftrace是一個設計用來幫助開發者和設計者監視內核的追蹤器，可用於調試或分析延遲以及性能問題。ftrace令人印象最深刻的是作為一個function tracer，內核函數調用、耗時等情況一覽無餘。另外，ftrace最常見的用途是事件追蹤，通過內核是成百上千的靜態事件點，看到系統內核的哪些部分在運行。實際上，ftrace更是一個追蹤框架，它具備豐富工具集：延遲跟蹤檢查、何時發生中斷、任務的啟用、禁用及搶佔等。在ftrace的基線版本之上，還有很多第三方提供的開源工具，用於簡化操作或者提供數據可視化等擴展應用。

一、Introduction

Developer(s): Steven Rostedt(RedHat) and others

Initial release: October 9, 2008;

Operating system: Linux （merged into the Linux kernel mainline in kernel version 2.6.27）

Type: Kernel extension

License: GNU GPL

Website: www.kernel.org/doc/Documentation/trace

二、ABC

在使用ftrace之前，需要確認調試目錄是否已經掛載，默認目錄：/sys/kernel/debug/ 。

debugfs是Linux內核中一種特殊的文件系統，非常易用、基於RAM，專門設計用於調試。（since version 2.6.10-rc3，https://en.wikipedia.org/wiki/Debugfs)。

mount -t debugfs none /sys/kernel/debugn或者指定到自己的目錄nmkdir /debugnmount -t debugfs nodev /debugn

掛載之後會自動創建如下文件：

/sys/kernel/debug# ls -lrtndrwxr-xr-x. 2 root root 0 12月 28 17:24 x86ndrwxr-xr-x. 3 root root 0 12月 28 17:24 boot_paramsndrwxr-xr-x. 34 root root 0 12月 28 17:24 bdin-r--r--r--. 1 root root 0 12月 28 17:24 gpiondrwxr-xr-x. 3 root root 0 12月 28 17:24 usbndrwxr-xr-x. 4 root root 0 12月 28 17:24 xenndrwxr-xr-x. 6 root root 0 12月 28 17:24 tracingndrwxr-xr-x. 2 root root 0 12月 28 17:24 extfragndrwxr-xr-x. 2 root root 0 12月 28 17:24 dynamic_debugndrwxr-xr-x. 2 root root 0 12月 28 17:24 hidn-rw-r--r--. 1 root root 0 12月 28 17:24 sched_featuresndrwxr-xr-x. 2 root root 0 12月 28 17:24 mcendrwxr-xr-x. 2 root root 0 12月 28 17:24 kprobesn-r--r--r--. 1 root root 0 12月 28 17:24 vmmemctln/sys/kernel/debug/tracing# ls -lrtn-rw-r--r--. 1 root root 0 12月 28 17:24 tracing_threshn-rw-r--r--. 1 root root 0 12月 28 17:24 tracing_onn-rw-r--r--. 1 root root 0 12月 28 17:24 tracing_max_latencyn-rw-r--r--. 1 root root 0 12月 28 17:24 tracing_enabledn-rw-r--r--. 1 root root 0 12月 28 17:24 tracing_cpumaskndrwxr-xr-x. 2 root root 0 12月 28 17:24 trace_statn-r--r--r--. 1 root root 0 12月 28 17:24 trace_pipen-rw-r--r--. 1 root root 0 12月 28 17:24 trace_optionsn--w--w----. 1 root root 0 12月 28 17:24 trace_markern-rw-r--r--. 1 root root 0 12月 28 17:24 trace_clockn-rw-r--r--. 1 root root 0 12月 28 17:24 tracen-rw-r--r--. 1 root root 0 12月 28 17:24 sysprof_sample_periodn-r--r--r--. 1 root root 0 12月 28 17:24 set_graph_functionn-rw-r--r--. 1 root root 0 12月 28 17:24 set_ftrace_pidn-rw-r--r--. 1 root root 0 12月 28 17:24 set_ftrace_notracen-r--r--r--. 1 root root 0 12月 28 17:24 saved_cmdlinesn-r--r--r--. 1 root root 0 12月 28 17:24 READMEndrwxr-xr-x. 2 root root 0 12月 28 17:24 optionsn-rw-r--r--. 1 root root 0 12月 28 17:24 function_profile_enabledn-r--r--r--. 1 root root 0 12月 28 17:24 dyn_ftrace_total_infon-rw-r--r--. 1 root root 0 12月 28 17:24 buffer_size_kbn-r--r--r--. 1 root root 0 12月 28 17:24 available_tracersn-r--r--r--. 1 root root 0 12月 28 17:24 available_filter_functionsn-rw-r--r--. 1 root root 0 12月 28 17:24 set_eventn-r--r--r--. 1 root root 0 12月 28 17:24 printk_formatsndrwxr-xr-x. 34 root root 0 12月 28 17:24 per_cpundrwxr-xr-x. 24 root root 0 12月 28 17:24 eventsn-r--r--r--. 1 root root 0 12月 28 17:24 available_eventsn-r--r--r--. 1 root root 0 12月 28 17:24 kprobe_profilen-rw-r--r--. 1 root root 0 12月 28 17:24 kprobe_eventsn-r--r--r--. 1 root root 0 12月 28 17:24 stack_tracen-rw-r--r--. 1 root root 0 12月 28 17:24 stack_max_sizen-rw-r--r--. 1 root root 0 5月 31 11:50 current_tracern-rwxr-xr-x. 1 root root 0 5月 31 11:57 set_ftrace_filtern

三、BASIC

1. Function tracer

以Function tracer為例，結果存儲在 trace，該文件類似一張報表，該表將顯示 4 列信息。首先是進程信息，包括進程名和PID ；第二列是CPU；第三列是時間戳；第四列是函數信息，預設情況下，這裡將顯示內核函數名以及它的上一層調用函數。

cd /sys/kernel/debug/tracingnecho function > current_tracerncat tracenn# tracer: functionn#n# TASK-PID CPU# TIMESTAMP FUNCTIONn# | | | ngmond-6684 [004] 13285965.088308: _spin_lock <-hrtimer_interruptngmond-6684 [004] 13285965.088308: ktime_get_update_offsets <-hrtimer_interruptngmond-6684 [004] 13285965.088309: __run_hrtimer <-hrtimer_interruptngmond-6684 [004] 13285965.088309: __remove_hrtimer <-__run_hrtimerngmond-6684 [004] 13285965.088309: tick_sched_timer <-__run_hrtimerngmond-6684 [004] 13285965.088309: ktime_get <-tick_sched_timerngmond-6684 [004] 13285965.088310: tick_do_update_jiffies64 <-tick_sched_timerngmond-6684 [004] 13285965.088310: update_process_times <-tick_sched_timern

2. Function graph tracer

Function graph tracer 和 function tracer 類似，但輸出為函數調用圖，更加容易閱讀：

# tracer: function_graphn#n# TIME CPU DURATION FUNCTION CALLSn# | | | | | | | |n 21) ==========> |n 21) | smp_apic_timer_interrupt() {n 31) ==========> |n 31) | smp_apic_timer_interrupt() {n 8) | smp_apic_timer_interrupt() {n 11) 2.598 us | native_apic_mem_write();n 18) 3.106 us | native_apic_mem_write();n 30) ==========> |n 30) | smp_apic_timer_interrupt() {n 3) 3.590 us | native_apic_mem_write();n 22) 2.944 us | native_apic_mem_write();n 7) 3.392 us | native_apic_mem_write();n 17) ==========> |n 17) | smp_apic_timer_interrupt() {n 27) ==========> |n 27) | smp_apic_timer_interrupt() {n 16) ==========> |n 16) | smp_apic_timer_interrupt() {n

http://og2061b3n.bkt.clouddn.com/DTrace_ftrace_tracers.png

四、體系結構

Ftrace有兩大組成部分，framework和一系列的tracer 。每個tracer完成不同的功能，它們統一由framework管理。 ftrace 的trace信息保存在ring buffer中，由framework負責管理。Framework 利用debugfs建立tracing目錄，並提供了一系列的控制文件。

http://og2061b3n.bkt.clouddn.com/DTrace_ftrace_arch.png

ftrace is a dynamic tracing system. 當你開始「ftracing」一個內核函數的時候，該函數的代碼實際上就已經發生變化了。內核將在程序集中插入一些額外的指令，使得函數調用時可以隨時通知追蹤程序。

WARNNING:使用ftrace追蹤內核將有可能對系統性能產生影響，追蹤的函數越多，開銷越大。

使用者必須提前做好準備工作，生產環境必須謹慎使用。

#cat available_tracers //查看支持的tracersnblk kmemtrace function_graph wakeup_rt wakeup function sysprof sched_switch initcall nopn

五、Useful Tools

1. trace-cmd

trace-cmd是一個非常有用的Ftrace命令行工具。

sudo apt-get install trace-cmdn或者ngit clone git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/trace-cmd.gitn

使用方法：

sudo trace-cmd record --help #helpnsudo trace-cmd record -p function -P 123456 #record for PIDnsudo trace-cmd record -p function -l do_page_fault #record for functionn plugin functionnHit Ctrl^C to stop recordingn

trace.dat

$ sudo trace-cmd reportn chrome-15144 [000] 11446.466121: function: do_page_faultn chrome-15144 [000] 11446.467910: function: do_page_faultn chrome-15144 [000] 11446.469174: function: do_page_faultn chrome-15144 [000] 11446.474225: function: do_page_faultn chrome-15144 [000] 11446.474386: function: do_page_faultn chrome-15144 [000] 11446.478768: function: do_page_faultn CompositorTileW-15154 [001] 11446.480172: function: do_page_faultn chrome-1830 [003] 11446.486696: function: do_page_faultn CompositorTileW-15154 [001] 11446.488983: function: do_page_faultn CompositorTileW-15154 [001] 11446.489034: function: do_page_faultn CompositorTileW-15154 [001] 11446.489045: function: do_page_faultn

在很有情況下不能使用函數追蹤，需要依賴 事件追蹤 的支持，例如：

# cat available_events //查看支持的事件類型npower:power_startnpower:power_frequencynpower:power_endnnsched:sched_kthread_stopnsched:sched_kthread_stop_retnsched:sched_wait_tasknsched:sched_wakeupnsched:sched_wakeup_newnsched:sched_switchnsched:sched_migrate_tasknsched:sched_process_freensched:sched_process_exitnsched:sched_process_waitnsched:sched_process_forknsched:sched_stat_waitnsched:sched_stat_sleepnsched:sched_stat_iowaitnsched:sched_stat_runtimennsudo trace-cmd record -e sched:sched_switchnsudo trace-cmd reportn

輸出如下：

16169.624862: Chrome_ChildIOT:24817 [112] S ==> chrome:15144 [120]n16169.624992: chrome:15144 [120] S ==> swapper/3:0 [120]n16169.625202: swapper/3:0 [120] R ==> Chrome_ChildIOT:24817 [112]n16169.625251: Chrome_ChildIOT:24817 [112] R ==> chrome:1561 [112]n16169.625437: chrome:1561 [112] S ==> chrome:15144 [120]n

切換路徑：PID 24817 -> 15144 -> kernel -> 24817 -> 1561 -> 15114。

2. perf-tools

perf-tools 是性能調試大神Brendan Gregg開發的一個工具包，提供了很多強大的功能，例如：

iosnoop: 磁碟I/O分析詳細包括延遲

iolatency: 磁碟I/O分析概要(柱狀圖)

execsnoop: 追蹤進程exec()

opensnoop: 追蹤open()系統調用，包含文件名

killsnoop: 追蹤kill()信號（進程和信號詳細）

代碼下載：brendangregg/perf-tools

# ./execsnoop //顯示新進程和參數：nTracing exec()s. Ctrl-C to end.n PID PPID ARGSn 22898 22004 man lsn 22905 22898 preconv -e UTF-8n 22908 22898 pager -sn 22907 22898 nroff -mandoc -rLL=164n -rLT=164n -Tutf8n 22906 22898 tbln 22911 22910 locale charmapn 22912 22907 groff -mtty-char -Tutf8 -mandoc -rLL=164n -rLT=164nn 22913 22912 troff -mtty-char -mandoc -rLL=164n -rLT=164n -Tutf8n 22914 22912 grottynnn# ./iolatency -Q //測量設備I/O延遲nTracing block I/O. Output every 1 seconds. Ctrl-C to end.n >=(ms) .. <(ms) : I/O |Distribution |n 0 -> 1 : 1913 |######################################|n 1 -> 2 : 438 |######### |n 2 -> 4 : 100 |## |n 4 -> 8 : 145 |### |n 8 -> 16 : 43 |# |n 16 -> 32 : 43 |# |n 32 -> 64 : 1 |# |n[...]n

六、可視化工具:KernelShark

KernelShark是trace-cmd的前端工具，提供了對trace.dat的可視化分析（Graph View 、List View、Simple and Advance filtering）。

https://static.lwn.net/images/2011/ks-success-zoom-task.png
推薦閱讀：