動(dòng)態(tài)追蹤技術(shù)(二)：trace your kernel Functions!

Ftrace是一個(gè)設(shè)計(jì)用來幫助開發(fā)者和設(shè)計(jì)者監(jiān)視內(nèi)核的追蹤器矫膨，可用于調(diào)試或分析延遲以及性能問題响逢。ftrace令人印象最深刻的是作為一個(gè)function tracer躺同，內(nèi)核函數(shù)調(diào)用、耗時(shí)等情況一覽無余士聪。另外，ftrace最常見的用途是事件追蹤猛蔽，通過內(nèi)核是成百上千的靜態(tài)事件點(diǎn)剥悟，看到系統(tǒng)內(nèi)核的哪些部分在運(yùn)行。實(shí)際上曼库，ftrace更是一個(gè)追蹤框架区岗，它具備豐富工具集：延遲跟蹤檢查、何時(shí)發(fā)生中斷毁枯、任務(wù)的啟用慈缔、禁用及搶占等。在ftrace的基線版本之上种玛，還有很多第三方提供的開源工具胀糜，用于簡化操作或者提供數(shù)據(jù)可視化等擴(kuò)展應(yīng)用。

一蒂誉、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之前，需要確認(rèn)調(diào)試目錄是否已經(jīng)掛載右锨，默認(rèn)目錄：/sys/kernel/debug/ 括堤。

debugfs是Linux內(nèi)核中一種特殊的文件系統(tǒng)，非常易用绍移、基于RAM悄窃，專門設(shè)計(jì)用于調(diào)試。（since version 2.6.10-rc3蹂窖，https://en.wikipedia.org/wiki/Debugfs)轧抗。

mount -t debugfs none /sys/kernel/debug
或者指定到自己的目錄
mkdir /debug
mount -t debugfs nodev /debug

掛載之后會(huì)自動(dòng)創(chuàng)建如下文件：

/sys/kernel/debug# ls -lrt
drwxr-xr-x.  2 root root 0 12月 28 17:24 x86
drwxr-xr-x.  3 root root 0 12月 28 17:24 boot_params
drwxr-xr-x. 34 root root 0 12月 28 17:24 bdi
-r--r--r--.  1 root root 0 12月 28 17:24 gpio
drwxr-xr-x.  3 root root 0 12月 28 17:24 usb
drwxr-xr-x.  4 root root 0 12月 28 17:24 xen
drwxr-xr-x.  6 root root 0 12月 28 17:24 tracing
drwxr-xr-x.  2 root root 0 12月 28 17:24 extfrag
drwxr-xr-x.  2 root root 0 12月 28 17:24 dynamic_debug
drwxr-xr-x.  2 root root 0 12月 28 17:24 hid
-rw-r--r--.  1 root root 0 12月 28 17:24 sched_features
drwxr-xr-x.  2 root root 0 12月 28 17:24 mce
drwxr-xr-x.  2 root root 0 12月 28 17:24 kprobes
-r--r--r--.  1 root root 0 12月 28 17:24 vmmemctl
/sys/kernel/debug/tracing# ls -lrt
-rw-r--r--.  1 root root 0 12月 28 17:24 tracing_thresh
-rw-r--r--.  1 root root 0 12月 28 17:24 tracing_on
-rw-r--r--.  1 root root 0 12月 28 17:24 tracing_max_latency
-rw-r--r--.  1 root root 0 12月 28 17:24 tracing_enabled
-rw-r--r--.  1 root root 0 12月 28 17:24 tracing_cpumask
drwxr-xr-x.  2 root root 0 12月 28 17:24 trace_stat
-r--r--r--.  1 root root 0 12月 28 17:24 trace_pipe
-rw-r--r--.  1 root root 0 12月 28 17:24 trace_options
--w--w----.  1 root root 0 12月 28 17:24 trace_marker
-rw-r--r--.  1 root root 0 12月 28 17:24 trace_clock
-rw-r--r--.  1 root root 0 12月 28 17:24 trace
-rw-r--r--.  1 root root 0 12月 28 17:24 sysprof_sample_period
-r--r--r--.  1 root root 0 12月 28 17:24 set_graph_function
-rw-r--r--.  1 root root 0 12月 28 17:24 set_ftrace_pid
-rw-r--r--.  1 root root 0 12月 28 17:24 set_ftrace_notrace
-r--r--r--.  1 root root 0 12月 28 17:24 saved_cmdlines
-r--r--r--.  1 root root 0 12月 28 17:24 README
drwxr-xr-x.  2 root root 0 12月 28 17:24 options
-rw-r--r--.  1 root root 0 12月 28 17:24 function_profile_enabled
-r--r--r--.  1 root root 0 12月 28 17:24 dyn_ftrace_total_info
-rw-r--r--.  1 root root 0 12月 28 17:24 buffer_size_kb
-r--r--r--.  1 root root 0 12月 28 17:24 available_tracers
-r--r--r--.  1 root root 0 12月 28 17:24 available_filter_functions
-rw-r--r--.  1 root root 0 12月 28 17:24 set_event
-r--r--r--.  1 root root 0 12月 28 17:24 printk_formats
drwxr-xr-x. 34 root root 0 12月 28 17:24 per_cpu
drwxr-xr-x. 24 root root 0 12月 28 17:24 events
-r--r--r--.  1 root root 0 12月 28 17:24 available_events
-r--r--r--.  1 root root 0 12月 28 17:24 kprobe_profile
-rw-r--r--.  1 root root 0 12月 28 17:24 kprobe_events
-r--r--r--.  1 root root 0 12月 28 17:24 stack_trace
-rw-r--r--.  1 root root 0 12月 28 17:24 stack_max_size
-rw-r--r--.  1 root root 0 5月  31 11:50 current_tracer
-rwxr-xr-x.  1 root root 0 5月  31 11:57 set_ftrace_filter

三、BASIC

1. Function tracer

以Function tracer為例瞬测，結(jié)果存儲(chǔ)在 trace横媚，該文件類似一張報(bào)表纠炮，該表將顯示 4 列信息。首先是進(jìn)程信息灯蝴，包括進(jìn)程名和PID 恢口；第二列是CPU；第三列是時(shí)間戳穷躁；第四列是函數(shù)信息耕肩，缺省情況下，這里將顯示內(nèi)核函數(shù)名以及它的上一層調(diào)用函數(shù)问潭。

cd /sys/kernel/debug/tracing
echo function > current_tracer
cat trace

# tracer: function
#
#  TASK-PID   CPU#  TIMESTAMP        FUNCTION
#   |  |       |  
gmond-6684  [004] 13285965.088308: _spin_lock <-hrtimer_interrupt
gmond-6684  [004] 13285965.088308: ktime_get_update_offsets <-hrtimer_interrupt
gmond-6684  [004] 13285965.088309: __run_hrtimer <-hrtimer_interrupt
gmond-6684  [004] 13285965.088309: __remove_hrtimer <-__run_hrtimer
gmond-6684  [004] 13285965.088309: tick_sched_timer <-__run_hrtimer
gmond-6684  [004] 13285965.088309: ktime_get <-tick_sched_timer
gmond-6684  [004] 13285965.088310: tick_do_update_jiffies64 <-tick_sched_timer
gmond-6684  [004] 13285965.088310: update_process_times <-tick_sched_timer

2. Function graph tracer

Function graph tracer 和 function tracer 類似猿诸，但輸出為函數(shù)調(diào)用圖，更加容易閱讀：

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

四狡忙、體系結(jié)構(gòu)

Ftrace有兩大組成部分两芳，framework和一系列的tracer 。每個(gè)tracer完成不同的功能去枷，它們統(tǒng)一由framework管理怖辆。 ftrace 的trace信息保存在ring buffer中，由framework負(fù)責(zé)管理删顶。Framework 利用debugfs建立tracing目錄竖螃，并提供了一系列的控制文件。

Linux ftrace架構(gòu)示意圖

ftrace is a dynamic tracing system. 當(dāng)你開始“ftracing”一個(gè)內(nèi)核函數(shù)的時(shí)候逗余，該函數(shù)的代碼實(shí)際上就已經(jīng)發(fā)生變化了特咆。內(nèi)核將在程序集中插入一些額外的指令，使得函數(shù)調(diào)用時(shí)可以隨時(shí)通知追蹤程序录粱。

WARNNING:使用ftrace追蹤內(nèi)核將有可能對(duì)系統(tǒng)性能產(chǎn)生影響腻格，追蹤的函數(shù)越多，開銷越大啥繁。
使用者必須提前做好準(zhǔn)備工作菜职，生產(chǎn)環(huán)境必須謹(jǐn)慎使用。

#cat available_tracers //查看支持的tracers
blk kmemtrace function_graph wakeup_rt wakeup function sysprof sched_switch initcall nop

五旗闽、Useful Tools

1. trace-cmd

trace-cmd是一個(gè)非常有用的Ftrace命令行工具酬核。

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

使用方法：


sudo trace-cmd record --help #help
sudo trace-cmd record -p function -P 123456 #record for PID
sudo trace-cmd record -p function -l do_page_fault #record for function
  plugin 'function'
Hit Ctrl^C to stop recording

trace.dat

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

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

# cat available_events  //查看支持的事件類型
power:power_start
power:power_frequency
power:power_end

sched:sched_kthread_stop
sched:sched_kthread_stop_ret
sched:sched_wait_task
sched:sched_wakeup
sched:sched_wakeup_new
sched:sched_switch
sched:sched_migrate_task
sched:sched_process_free
sched:sched_process_exit
sched:sched_process_wait
sched:sched_process_fork
sched:sched_stat_wait
sched:sched_stat_sleep
sched:sched_stat_iowait
sched:sched_stat_runtime

sudo trace-cmd record -e sched:sched_switch
sudo trace-cmd report

輸出如下：

 16169.624862:   Chrome_ChildIOT:24817 [112] S ==> chrome:15144 [120]
 16169.624992:   chrome:15144 [120] S ==> swapper/3:0 [120]
 16169.625202:   swapper/3:0 [120] R ==> Chrome_ChildIOT:24817 [112]
 16169.625251:   Chrome_ChildIOT:24817 [112] R ==> chrome:1561 [112]
 16169.625437:   chrome:1561 [112] S ==> chrome:15144 [120]

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

2. perf-tools

perf-tools 是性能調(diào)試大神Brendan Gregg開發(fā)的一個(gè)工具包，提供了很多強(qiáng)大的功能捣辆，例如：
iosnoop: 磁盤I/O分析詳細(xì)包括延遲
iolatency: 磁盤I/O分析概要(柱狀圖)
execsnoop: 追蹤進(jìn)程exec()
opensnoop: 追蹤open()系統(tǒng)調(diào)用蔬螟，包含文件名
killsnoop: 追蹤kill()信號(hào)（進(jìn)程和信號(hào)詳細(xì)）

代碼下載：https://github.com/brendangregg/perf-tools

# ./execsnoop  //顯示新進(jìn)程和參數(shù)：
Tracing exec()s. Ctrl-C to end.
   PID   PPID ARGS
 22898  22004 man ls
 22905  22898 preconv -e UTF-8
 22908  22898 pager -s
 22907  22898 nroff -mandoc -rLL=164n -rLT=164n -Tutf8
 22906  22898 tbl
 22911  22910 locale charmap
 22912  22907 groff -mtty-char -Tutf8 -mandoc -rLL=164n -rLT=164n
 22913  22912 troff -mtty-char -mandoc -rLL=164n -rLT=164n -Tutf8
 22914  22912 grotty


# ./iolatency -Q  //測量設(shè)備I/O延遲
Tracing block I/O. Output every 1 seconds. Ctrl-C to end.
  >=(ms) .. <(ms)   : I/O      |Distribution                          |
       0 -> 1       : 1913     |######################################|
       1 -> 2       : 438      |#########                             |
       2 -> 4       : 100      |##                                    |
       4 -> 8       : 145      |###                                   |
       8 -> 16      : 43       |#                                     |
      16 -> 32      : 43       |#                                     |
      32 -> 64      : 1        |#                                     |
[...]

六、可視化工具:KernelShark

KernelShark是trace-cmd的前端工具汽畴，提供了對(duì)trace.dat的可視化分析（Graph View 旧巾、List View耸序、Simple and Advance filtering）。


Linux ftrace KernelShark
Linux ftrace KernelShark Filters

擴(kuò)展閱讀：Linux 操作系統(tǒng)

推薦：電子書《Linux Perf Master》

發(fā)表在GitBook平臺(tái)菠齿，歡迎訂閱、下載坐昙、批評(píng)指正:
https://www.gitbook.com/book/riboseyim/linux-perf-master/details

eBook
最后編輯于 ：
?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請(qǐng)聯(lián)系作者
  • 人面猴
    序言：七十年代末绳匀，一起剝皮案震驚了整個(gè)濱河市，隨后出現(xiàn)的幾起案子炸客，更是在濱河造成了極大的恐慌疾棵，老刑警劉巖，帶你破解...
    沈念sama閱讀 221,576評(píng)論 6贊 515
  • 死咒
    序言：濱河連續(xù)發(fā)生了三起死亡事件痹仙，死亡現(xiàn)場離奇詭異是尔，居然都是意外死亡，警方通過查閱死者的電腦和手機(jī)开仰，發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 94,515評(píng)論 3贊 399
  • 救了他兩次的神仙讓他今天三更去死
    文/潘曉璐 我一進(jìn)店門拟枚，熙熙樓的掌柜王于貴愁眉苦臉地迎上來，“玉大人众弓，你說我怎么就攤上這事恩溅。” “怎么了谓娃？”我有些...
    開封第一講書人閱讀 168,017評(píng)論 0贊 360
  • 道士緝兇錄：失蹤的賣姜人
    文/不壞的土叔 我叫張陵脚乡，是天一觀的道長。 經(jīng)常有香客問我滨达，道長奶稠，這世上最難降的妖魔是什么？ 我笑而不...
    開封第一講書人閱讀 59,626評(píng)論 1贊 296
  • ?港島之戀（遺憾婚禮）
    正文 為了忘掉前任捡遍，我火速辦了婚禮锌订，結(jié)果婚禮上，老公的妹妹穿的比我還像新娘画株。我一直安慰自己瀑志，他們只是感情好，可當(dāng)我...
    茶點(diǎn)故事閱讀 68,625評(píng)論 6贊 397
  • 惡毒庶女頂嫁案：這布局不是一般人想出來的
    文/花漫 我一把揭開白布污秆。 她就那樣靜靜地躺著劈猪，像睡著了一般。 火紅的嫁衣襯著肌膚如雪良拼。 梳的紋絲不亂的頭發(fā)上战得，一...
    開封第一講書人閱讀 52,255評(píng)論 1贊 308
  • 城市分裂傳說
    那天，我揣著相機(jī)與錄音庸推，去河邊找鬼常侦。 笑死浇冰，一個(gè)胖子當(dāng)著我的面吹牛，可吹牛的內(nèi)容都是我干的聋亡。 我是一名探鬼主播肘习，決...
    沈念sama閱讀 40,825評(píng)論 3贊 421
  • 雙鴛鴦連環(huán)套：你想象不到人心有多黑
    文/蒼蘭香墨 我猛地睜開眼，長吁一口氣：“原來是場噩夢啊……” “哼坡倔！你這毒婦竟也來了漂佩？” 一聲冷哼從身側(cè)響起，我...
    開封第一講書人閱讀 39,729評(píng)論 0贊 276
  • 萬榮殺人案實(shí)錄
    序言：老撾萬榮一對(duì)情侶失蹤罪塔，失蹤者是張志新（化名）和其女友劉穎投蝉，沒想到半個(gè)月后，有當(dāng)?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體征堪，經(jīng)...
    沈念sama閱讀 46,271評(píng)論 1贊 320
  • ?護(hù)林員之死
    正文 獨(dú)居荒郊野嶺守林人離奇死亡瘩缆，尸身上長有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點(diǎn)故事閱讀 38,363評(píng)論 3贊 340
  • ?白月光啟示錄
    正文 我和宋清朗相戀三年，在試婚紗的時(shí)候發(fā)現(xiàn)自己被綠了佃蚜。 大學(xué)時(shí)的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片庸娱。...
    茶點(diǎn)故事閱讀 40,498評(píng)論 1贊 352
  • 活死人
    序言：一個(gè)原本活蹦亂跳的男人離奇死亡，死狀恐怖谐算，靈堂內(nèi)的尸體忽然破棺而出涌韩，到底是詐尸還是另有隱情，我是刑警寧澤氯夷，帶...
    沈念sama閱讀 36,183評(píng)論 5贊 350
  • ?日本核電站爆炸內(nèi)幕
    正文 年R本政府宣布臣樱，位于F島的核電站，受9級(jí)特大地震影響腮考，放射性物質(zhì)發(fā)生泄漏雇毫。R本人自食惡果不足惜，卻給世界環(huán)境...
    茶點(diǎn)故事閱讀 41,867評(píng)論 3贊 333
  • 男人毒藥：我在死后第九天來索命
    文/蒙蒙 一踩蔚、第九天 我趴在偏房一處隱蔽的房頂上張望棚放。 院中可真熱鬧，春花似錦馅闽、人聲如沸飘蚯。這莊子的主人今日做“春日...
    開封第一講書人閱讀 32,338評(píng)論 0贊 24
  • 一樁弒父案福也，背后竟有這般陰謀
    文/蒼蘭香墨 我抬頭看了看天上的太陽局骤。三九已至，卻和暖如春暴凑，著一層夾襖步出監(jiān)牢的瞬間峦甩，已是汗流浹背。 一陣腳步聲響...
    開封第一講書人閱讀 33,458評(píng)論 1贊 272
  • 情欲美人皮
    我被黑心中介騙來泰國打工现喳， 沒想到剛下飛機(jī)就差點(diǎn)兒被人妖公主榨干…… 1. 我叫王不留凯傲，地道東北人犬辰。 一個(gè)月前我還...
    沈念sama閱讀 48,906評(píng)論 3贊 376
  • 代替公主和親
    正文 我出身青樓，卻偏偏與公主長得像冰单，于是被迫代替她去往敵國和親幌缝。 傳聞我的和親對(duì)象是個(gè)殘疾皇子，可洞房花燭夜當(dāng)晚...
    茶點(diǎn)故事閱讀 45,507評(píng)論 2贊 359

推薦閱讀更多精彩內(nèi)容