代码改变世界

ftrace：跟踪你的内核函数！ | Linux 中国

2018-11-03 09:38  tlnshuju  阅读(659)  评论(0)  编辑  收藏  举报
版权声明：本文为博主原创文章。未经博主同意不得转载。 https://blog.csdn.net/F8qG7f9YD02Pe/article/details/79161135
640?wx_fmt=jpeg&wxfrom=5&wx_lazy=1ftrace 是一个 Linux 内核特性，它能够让你去跟踪 Linux 内核的函数调用。

为什么要这么做呢？好吧，如果你调试一个奇怪的问题，而你已经得到了你的内核版本号中这个问题在源码中的開始的位置。而你想知道这里究竟发生了什么？-- Julia Evans
本文导航◈ 什么是 ftrace？05%◈ 使用 ftrace 的第一步11%◈ 開始使用 trace-cmd：让我们仅跟踪一个函数19%◈ 下一个 ftrace 技巧：我们来跟踪一个进程！35%◈ “function graph” 跟踪47%◈ 怎样知道哪些函数能够被跟踪62%◈ 最后一件事：事件！63%◈ ftrace 是怎样工作的？73%◈ 更easy地使用 ftrace：brendan gregg 的工具及 kernelshark79%◈ 一个新的超能力85%◈ ftrace 系列文章的一个索引87%编译自　|　https://jvns.ca/blog/2017/03/19/getting-started-with-ftrace/ 
　作者　|　Julia Evans
　译者　|　qhwdw

大家好！今天我们将去讨论一个调试工具：ftrace。之前我的博客上还没有讨论过它。

还有什么能比一个新的调试工具更让人激动呢？

这个非常棒的 ftrace 并非个新的工具！它大约在 Linux 的 2.6 内核版本号中就有了，时间大约是在 2008 年。这一篇是我用谷歌能找到的最早的文档[1]。因此，如果你是一个调试系统的“老手”。可能早就已经使用它了！

我知道，ftrace 已经存在了大约 2.5 年了（LCTT 译注：距本文初次写作时）。可是还没有真正的去学习它。如果我明天要召开一个专题研究会，那么，关于 ftrace 应该讨论些什么？因此，今天是时间去讨论一下它了。

什么是 ftrace？

ftrace 是一个 Linux 内核特性，它能够让你去跟踪 Linux 内核的函数调用。为什么要这么做呢？好吧。如果你调试一个奇怪的问题，而你已经得到了你的内核版本号中这个问题在源码中的開始的位置，而你想知道这里究竟发生了什么？

每次在调试的时候。我并不会常常去读内核源码，可是，极个别的情况下会去读它。比如，本周在工作中，我有一个程序在内核中卡死了。查看究竟是调用了什么函数。能够帮我更好的理解在内核中发生了什么。哪些系统涉及当中！（在我的那个案例中，它是虚拟内存系统）。

我觉得 ftrace 是一个十分好用的工具（它肯定没有 strace 那样使用广泛，也比它难以使用），可是它还是值得你去学习。因此。让我们開始吧。

使用 ftrace 的第一步

不像 strace 和 perf。ftrace 并非真正的 程序 – 你不能仅仅执行 ftrace my_cool_function。那样太easy了！

如果你去读 使用 ftrace 调试内核[2]，它会告诉你从 cd /sys/kernel/debug/tracing 開始，然后做非常多文件系统的操作。

对于我来说，这种办法太麻烦——一个使用 ftrace 的简单样例像是这样：

  1. cd /sys/kernel/debug/tracing
  2. echo function > current_tracer
  3. echo do_page_fault > set_ftrace_filter
  4. cat trace
这个文件系统是跟踪系统的接口（“给这些奇妙的文件赋值，然后该发生的事情就会发生”）理论上看起来似乎可用，可是它不是我的首选方式。
幸运的是。ftrace 团队也考虑到这个并不友好的用户界面，因此，它有了一个更易于使用的界面。它就是 trace-cmd！！
！trace-cmd 是一个带命令行參数的普通程序。我们后面将使用它！
我在 LWN 上找到了一个 trace-cmd 的使用介绍：trace-cmd: Ftrace 的一个前端[3]。
開始使用 trace-cmd：让我们仅跟踪一个函数
首先，我须要去使用 sudo apt-get install trace-cmd 安装 trace-cmd。这一步非常easy。
对于第一个 ftrace 的演示，我决定去了解我的内核怎样去处理一个页面故障。当 Linux 分配内存时。它常常偷懒，（“你并非真的计划去使用内存，对吗？”）。
这意味着。当一个应用程序尝试去对分配给它的内存进行写入时。就会发生一个页面故障，而这个时候。内核才会真正的为应用程序去分配物理内存。
我们開始使用 trace-cmd 并让它跟踪 do_page_fault 函数。
  1. $ sudo trace-cmd record -p function -l do_page_fault
  2.   plugin 'function'
  3. Hit Ctrl^C to stop recording
我将它执行了几秒钟，然后按下了 Ctrl+C。 让我大吃一惊的是，它居然产生了一个 2.5MB 大小的名为 trace.dat 的跟踪文件。我们来看一下这个文件的内容！
  1. $ sudo trace-cmd report
  2.           chrome-15144 [000] 11446.466121: function:             do_page_fault
  3.           chrome-15144 [000] 11446.467910: function:             do_page_fault
  4.           chrome-15144 [000] 11446.469174: function:             do_page_fault
  5.           chrome-15144 [000] 11446.474225: function:             do_page_fault
  6.           chrome-15144 [000] 11446.474386: function:             do_page_fault
  7.           chrome-15144 [000] 11446.478768: function:             do_page_fault
  8.  CompositorTileW-15154 [001] 11446.480172: function:             do_page_fault
  9.           chrome-1830  [003] 11446.486696: function:             do_page_fault
  10.  CompositorTileW-15154 [001] 11446.488983: function:             do_page_fault
  11.  CompositorTileW-15154 [001] 11446.489034: function:             do_page_fault
  12.  CompositorTileW-15154 [001] 11446.489045: function:             do_page_fault
看起来非常整洁 – 它展示了进程名（chrome）、进程 ID（15144）、CPU ID（000）。以及它跟踪的函数。
通过察看整个文件。（sudo trace-cmd report | grep chrome）能够看到。我们跟踪了大约 1.5 秒。在这 1.5 秒的时间段内。Chrome 发生了大约 500 个页面故障。真是太酷了！这就是我们做的第一个 ftrace！
下一个 ftrace 技巧：我们来跟踪一个进程！
好吧，仅仅看一个函数是有点无聊！
假如我想知道一个程序中都发生了什么事情。我使用一个名为 Hugo 的静态网站生成器。
看看内核为 Hugo 都做了些什么事情？
在我的电脑上 Hugo 的 PID 如今是 25314，因此，我使用例如以下的命令去记录全部的内核函数：
  1. sudo trace-cmd record --help # I read the help!
  2. sudo trace-cmd record -p function -P 25314 # record for PID 25314
sudo trace-cmd report 输出了 18,000 行。如果你对这些感兴趣。你能够看 这里是全部的 18,000 行的输出[4]。
18,000 行太多了，因此。在这里仅摘录当中几行。
当系统调用 clock_gettime 执行的时候。都发生了什么：
  1.  compat_SyS_clock_gettime
  2.     SyS_clock_gettime
  3.        clockid_to_kclock
  4.        posix_clock_realtime_get
  5.           getnstimeofday64
  6.              __getnstimeofday64
  7.                 arch_counter_read
  8.     __compat_put_timespec
这是与进程调试相关的一些东西：
  1.  cpufreq_sched_irq_work
  2.     wake_up_process
  3.        try_to_wake_up
  4.           _raw_spin_lock_irqsave
  5.              do_raw_spin_lock
  6.           _raw_spin_lock
  7.              do_raw_spin_lock
  8.           walt_ktime_clock
  9.              ktime_get
  10.                 arch_counter_read
  11.           walt_update_task_ravg
  12.              exiting_task
尽管你可能还不理解它们是做什么的，可是，能够看到全部的这些函数调用也是件非常酷的事情。
“function graph” 跟踪
这里有另外一个模式，称为 function_graph。
除了它既能够进入也能够退出一个函数外，其他的功能和函数跟踪器是一样的。
这里是那个跟踪器的输出[5]
  1. sudo trace-cmd record -p function_graph -P 25314
相同，这里仅仅是一个片断（这次来自 futex 代码）：
  1.              |      futex_wake() {
  2.              |        get_futex_key() {
  3.              |          get_user_pages_fast() {
  4.   1.458 us   |            __get_user_pages_fast();
  5.   4.375 us   |          }
  6.              |          __might_sleep() {
  7.   0.292 us   |            ___might_sleep();
  8.   2.333 us   |          }
  9.   0.584 us   |          get_futex_key_refs();
  10.              |          unlock_page() {
  11.   0.291 us   |            page_waitqueue();
  12.   0.583 us   |            __wake_up_bit();
  13.   5.250 us   |          }
  14.   0.583 us   |          put_page();
  15. + 24.208 us  |        }
我们看到在这个演示样例中。在 futex_wake 后面调用了 get_futex_key。这是在源码中真实发生的事情吗？我们能够检查一下！！这里是在 Linux 4.4 中 futex_wake 的定义[6] (我的内核版本号是 4.4）。
为节省时间我直接贴出来，它的内容例如以下：
  1. static int
  2. futex_wake(u32 __user *uaddr, unsigned int flags, int nr_wake, u32 bitset)
  3. {
  4.     struct futex_hash_bucket *hb;
  5.     struct futex_q *this, *next;
  6.     union futex_key key = FUTEX_KEY_INIT;
  7.     int ret;
  8.     WAKE_Q(wake_q);
  10.     if (!bitset)
  11.         return -EINVAL;
  13.     ret = get_futex_key(uaddr, flags & FLAGS_SHARED, &key, VERIFY_READ);
如你所见，在 futex_wake 中的第一个函数调用真的是 get_futex_key！
 太棒了！
相比阅读内核代码，阅读函数跟踪肯定是更easy的找到结果的办法。而且让人高兴的是。还能看到全部的函数用了多长时间。
怎样知道哪些函数能够被跟踪
如果你去执行 sudo trace-cmd list -f，你将得到一个你能够跟踪的函数的列表。
它非常简单可是也非常重要。
最后一件事：事件。
如今，我们已经知道了怎么去跟踪内核中的函数。真是太酷了！
另一类我们能够跟踪的东西！有些事件与我们的函数调用并不相符。
比如，你可能想知道当一个程序被调度进入或者离开 CPU 时。都发生了什么事件！你可能想通过“盯着”函数调用计算出来，可是，我告诉你，不可行。
由于函数也为你提供了几种事件。因此，你能够看到当重要的事件发生时。都发生了什么事情。你能够使用 sudo cat /sys/kernel/debug/tracing/available_events 来查看这些事件的一个列表。
 
我查看了全部的 schedswitch 事件。我并不全然知道 schedswitch 是什么，可是，我推測它与调度有关。
  1. sudo cat /sys/kernel/debug/tracing/available_events
  2. sudo trace-cmd record -e sched:sched_switch
  3. sudo trace-cmd report
输出例如以下：
  1.  16169.624862:   Chrome_ChildIOT:24817 [112] S ==> chrome:15144 [120]
  2.  16169.624992:   chrome:15144 [120] S ==> swapper/3:0 [120]
  3.  16169.625202:   swapper/3:0 [120] R ==> Chrome_ChildIOT:24817 [112]
  4.  16169.625251:   Chrome_ChildIOT:24817 [112] R ==> chrome:1561 [112]
  5.  16169.625437:   chrome:1561 [112] S ==> chrome:15144 [120]
如今，能够非常清楚地看到这些切换。从 PID 24817 -> 15144 -> kernel -> 24817 -> 1561 -> 15114。(全部的这些事件都发生在同一个 CPU 上）。
ftrace 是怎样工作的？
ftrace 是一个动态跟踪系统。当我们開始 ftrace 内核函数时，函数的代码会被改变。
让我们如果去跟踪 do_page_fault 函数。
内核将在那个函数的汇编代码中插入一些额外的指令。以便每次该函数被调用时去提示跟踪系统。内核之所以能够加入额外的指令的原因是，Linux 将额外的几个 NOP 指令编译进每一个函数中。因此，当须要的时候，这里有加入跟踪代码的地方。
这是一个十分复杂的问题，由于，当不须要使用 ftrace 去跟踪我的内核时，它根本就不影响性能。
而当我须要跟踪时，跟踪的函数越多。产生的开销就越大。
（也许有些是不正确的，可是。我觉得的 ftrace 就是这样工作的）
更easy地使用 ftrace：brendan gregg 的工具及 kernelshark
正如我们在文件里所讨论的。你须要去考虑非常多的关于单个的内核函数/事件直接使用 ftrace 都做了些什么。能够做到这一点非常酷！
可是也须要做大量的工作！
Brendan Gregg （我们的 Linux 调试工具“大神”）有个工具仓库。它使用 ftrace 去提供关于像 I/O 延迟这种各种事情的信息。这是它在 GitHub 上全部的 perf-tools[7] 仓库。
这里有一个权衡，那就是这些工具易于使用，可是你被限制仅能用于 Brendan Gregg 认可并做到工具里面的方面。
它包含了非常多方面！:)
另一个工具是将 ftrace 的输出可视化，做的比較好的是 kernelshark[8]。我还没实用过它，可是看起来似乎非常实用。
你能够使用 sudo apt-get install kernelshark 来安装它。
一个新的超能力
我非常高兴能够花一些时间去学习 ftrace！对于不论什么内核工具。不同的内核版本号有不同的功效，我希望有一天你能发现它非常实用！
ftrace 系列文章的一个索引
最后，这里是我找到的一些 ftrace 方面的文章。
它们大部分在 LWN （Linux 新闻周刊）上，它是 Linux 的一个极好的资源（你能够购买一个 订阅[9]！
）
◈ 使用 Ftrace 调试内核 - part 1[2] (Dec 2009, Steven Rostedt)◈ 使用 Ftrace 调试内核 - part 2[10] (Dec 2009, Steven Rostedt)◈ Linux 函数跟踪器的秘密[11] (Jan 2010, Steven Rostedt)◈ trace-cmd：Ftrace 的一个前端[3] (Oct 2010, Steven Rostedt)◈ 使用 KernelShark 去分析实时调试器[8] (2011, Steven Rostedt)◈ Ftrace: 神奇的开关[12] (2014, Brendan Gregg)◈ 内核文档：（它十分实用） Documentation/ftrace.txt[13]◈ 你能跟踪的事件的文档 Documentation/events.txt[14]◈ linux 内核开发上的一些 ftrace 设计文档 （不是实用，而是有趣。) Documentation/ftrace-design.txt[15]
via: https://jvns.ca/blog/2017/03/19/getting-started-with-ftrace/
作者：Julia Evans[17] 译者：qhwdw 校对：wxy
本文由 LCTT 原创编译，Linux中国 荣誉推出
LCTT 译者640?wx_fmt=jpegqhwdw ? ? ? ?共计翻译：53 篇贡献时间：86 天
推荐文章
< 左右滑动查看相关文章 >
640?wx_fmt=png640?wx_fmt=png640?wx_fmt=png640?</p><p>wx_fmt=gif640?wx_fmt=gif
点击图片、输入文章 ID 或识别二维码直达

原文链接请訪问“原文链接”获得可点击的文内链接、全尺寸原图和相关文章。