邳州信息网

标题: 使用 trace-cmd 追踪内核 [打印本页]

作者: 3AAA    时间: 2021-10-6 10:20
标题: 使用 trace-cmd 追踪内核

trace-cmd 是一个易于使用,且特性众多、可用来追踪内核函数的命令。



在 之前的文章里,我介绍了如何利用ftrace来追踪内核函数。通过写入和读出文件来使用ftrace会变得很枯燥,所以我对它做了一个封装来运行带有选项的命令,以启用和禁用追踪、设置过滤器、查看输出、清除输出等等。

trace-cmd命令是一个可以帮助你做到这一点的工具。在这篇文章中,我使用trace-cmd来执行我在ftrace文章中所做的相同任务。由于会经常参考那篇文章,建议在阅读这篇文章之前先阅读它。

安装 trace-cmd


本文中所有的命令都运行在 root 用户下。

因为 ftrace机制被内置于内核中,因此你可以使用下面的命令进行验证它是否启用:
# mount | grep tracefsnone on /sys/kernel/tracing type tracefs (rw,relatime,seclabel)
不过,你需要手动尝试安装 trace-cmd命令:
# dnf install trace-cmd -y

列出可用的追踪器


当使用 ftrace时,你必须查看文件的内容以了解有哪些追踪器可用。但使用trace-cmd,你可以通过以下方式获得这些信息:
# trace-cmd list -thwlat blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop

启用函数追踪器


在我 之前的文章中,我使用了两个追踪器,在这里我也会这么做。用function启用你的第一个追踪器:
$ trace-cmd start -p function  plugin 'function'

查看追踪输出


一旦追踪器被启用,你可以通过使用 show参数来查看输出。这只显示了前 20 行以保持例子的简短(见我之前的文章对输出的解释):
# trace-cmd show | head -20## tracer: function## entries-in-buffer/entries-written: 410142/3380032   #P:8##                                _-----=> irqs-off#                               / _----=> need-resched#                              | / _---=> hardirq/softirq#                              || / _--=> preempt-depth#                              ||| /     delay#           TASK-PID     CPU#  ||||   TIMESTAMP  FUNCTION#              | |         |   ||||      |         |           gdbus-2606    [004] ..s. 10520.538759: __msecs_to_jiffies

停止追踪并清除缓冲区


追踪将会在后台继续运行,你可以继续用 show查看输出。

要停止追踪,请运行带有 stop参数的trace-cmd命令:
# trace-cmd stop
要清除缓冲区,用 clear参数运行它:
# trace-cmd clear

启用函数调用图追踪器


运行第二个追踪器,通过 function_graph参数来启用它。
# trace-cmd start -p function_graph  Plugin 'function_graph'
再次使用 show参数查看输出。正如预期的那样,输出与第一次追踪输出略有不同。这一次,它包括一个函数调用链:
# trace-cmd show | head -20## tracer: function_graph## CPU  DURATION                  FUNCTION CALLS# |     |   |                     |   |   |   | 4)   0.079 us    |        } /* rcu_all_qs */ 4)   0.327 us    |      } /* __cond_resched */ 4)   0.081 us    |      rcu_read_unlock_strict; 4)               |      __cond_resched { 4)   0.078 us    |        rcu_all_qs; 4)   0.243 us    |      } 4)   0.080 us    |      rcu_read_unlock_strict; 4)               |      __cond_resched { 4)   0.078 us    |        rcu_all_qs; 4)   0.241 us    |      } 4)   0.080 us    |      rcu_read_unlock_strict; 4)               |      __cond_resched { 4)   0.079 us    |        rcu_all_qs; 4)   0.235 us    |      } 4)   0.095 us    |      rcu_read_unlock_strict; 4)               |      __cond_resched {
使用 stop和clear命令来停止追踪和清除缓存区:
# trace-cmd stop# trace-cmd clear

调整追踪以增加深度


如果你想在函数调用中看到更多的深度,你可以对追踪器进行调整:
# trace-cmd start -p function_graph --max-graph-depth 5  plugin 'function_graph'
现在,当你将这个输出与你之前看到的进行比较时,你应该看到更多的嵌套函数调用:
# trace-cmd show | head -20## tracer: function_graph## CPU  DURATION                  FUNCTION CALLS# |     |   |                     |   |   |   | 6)               |        __fget_light { 6)   0.804 us    |          __fget_files; 6)   2.708 us    |        } 6)   3.650 us    |      } /* __fdget */ 6)   0.547 us    |      eventfd_poll; 6)   0.535 us    |      fput; 6)               |      __fdget { 6)               |        __fget_light { 6)   0.946 us    |          __fget_files; 6)   1.895 us    |        } 6)   2.849 us    |      } 6)               |      sock_poll { 6)   0.651 us    |        unix_poll; 6)   1.905 us    |      } 6)   0.475 us    |      fput; 6)               |      __fdget {

了解可被追踪的函数


如果你想只追踪某些函数而忽略其他的,你需要知道确切的函数名称。你可以用 list -f参数来得到它们。例如搜索常见的内核函数kmalloc,它被用来在内核中分配内存:
# trace-cmd list -f | grep kmallocbpf_map_kmalloc_nodemempool_kmalloc__traceiter_kmalloc__traceiter_kmalloc_nodekmalloc_slabkmalloc_orderkmalloc_order_tracekmalloc_large_node__kmalloc__kmalloc_track_caller__kmalloc_node__kmalloc_node_track_caller[...]
下面是我的测试系统中可被追踪的函数总数:
# trace-cmd list -f | wc -l63165

追踪内核模块相关的函数


你也可以追踪与特定内核模块相关的函数。假设你想追踪 kvm内核模块相关的功能,你可以通过以下方式来实现。请确保该模块已经加载:
# lsmod | grep kvm_intelkvm_intel 335872 0kvm 987136 1 kvm_intel
再次运行 trace-cmd,使用list参数,并从输出结果中,grep查找以]结尾的行。这将过滤掉内核模块。然后grep内核模块kvm_intel,你应该看到所有与该内核模块有关的函数。
# trace-cmd list -f | grep ]$  | grep kvm_intelvmx_can_emulate_instruction [kvm_intel]vmx_update_emulated_instruction [kvm_intel]vmx_setup_uret_msr [kvm_intel]vmx_set_identity_map_addr [kvm_intel]handle_machine_check [kvm_intel]handle_triple_fault [kvm_intel]vmx_patch_hypercall [kvm_intel][...]vmx_dump_dtsel [kvm_intel]vmx_dump_sel [kvm_intel]

追踪特定函数


现在你知道了如何找到感兴趣的函数,请用一个例子把这些内容用于时间。就像前面的文章一样,试着追踪与文件系统相关的函数。我的测试系统上的文件系统是 ext4。

这个过程略有不同;你在运行命令时,不使用 start参数,而是在record参数后面加上你想追踪的函数的“模式”。你还需要指定你想要的追踪器;在这种情况下,就是function_graph。该命令会继续记录追踪,直到你用Ctrl+C停止它。所以几秒钟后,按Ctrl+C停止追踪:
# trace-cmd list -f | grep ^ext4_# trace-cmd record -l ext4_* -p function_graph  plugin 'function_graph'Hit Ctrl^C to stop recording^CCPU0 data recorded at offset=0x856000    8192 bytes in size[...]

查看追踪记录


要查看你之前的追踪记录,运行带有 report参数的命令。从输出结果来看,很明显过滤器起作用了,你只看到ext4相关的函数追踪:
# trace-cmd report | head -20[...]cpus=8       trace-cmd-12697 [000] 11303.928103: funcgraph_entry:                   |  ext4_show_options {       trace-cmd-12697 [000] 11303.928104: funcgraph_entry:        0.187 us   |    ext4_get_dummy_policy;       trace-cmd-12697 [000] 11303.928105: funcgraph_exit:         1.583 us   |  }       trace-cmd-12697 [000] 11303.928122: funcgraph_entry:                   |  ext4_create {       trace-cmd-12697 [000] 11303.928122: funcgraph_entry:                   |    ext4_alloc_inode {       trace-cmd-12697 [000] 11303.928123: funcgraph_entry:        0.101 us   |      ext4_es_init_tree;       trace-cmd-12697 [000] 11303.928123: funcgraph_entry:        0.083 us   |      ext4_init_pending_tree;       trace-cmd-12697 [000] 11303.928123: funcgraph_entry:        0.141 us   |      ext4_fc_init_inode;       trace-cmd-12697 [000] 11303.928123: funcgraph_exit:         0.931 us   |    }       trace-cmd-12697 [000] 11303.928124: funcgraph_entry:        0.081 us   |    ext4_get_dummy_policy;       trace-cmd-12697 [000] 11303.928124: funcgraph_entry:        0.133 us   |    ext4_get_group_desc;       trace-cmd-12697 [000] 11303.928124: funcgraph_entry:        0.115 us   |    ext4_free_inodes_count;       trace-cmd-12697 [000] 11303.928124: funcgraph_entry:        0.114 us   |    ext4_get_group_desc;

追踪一个特定的 PID


假设你想追踪与一个进程(PID)有关的函数。打开另一个终端,注意运行中的 shell 的PID:
# echo $$10885
再次运行 record命令,用-P选项传递PID。这一次,让终端运行(也就是说,先不要按Ctrl+C):
# trace-cmd record -P 10885 -p function_graph  Plugin 'function_graph'Hit Ctrl^C to stop recording

在 shell 上运行一些命令


移动到另一个终端,在那里你有一个以特定 PID 运行的 shell,并运行任何命令,例如,ls命令用来列出文件:
# lsTemp-9b61f280-fdc1-4512-9211-5c60f764d702tracker-extract-3-files.1000v8-compile-cache-1000[...]
移动到你启用追踪的终端,按 Ctrl+C停止追踪:
# trace-cmd record -P 10885 -p function_graph  plugin 'function_graph'Hit Ctrl^C to stop recording^CCPU1 data recorded at offset=0x856000    618496 bytes in size[...]
在追踪的输出中,你可以看到左边是 PID 和 Bash shell,右边是与之相关的函数调用。这对于缩小你的追踪范围是非常方便的:
# trace-cmd report  | head -20cpus=8         

试一试


这些简短的例子显示了使用 trace-cmd命令而不是底层的ftrace机制,是如何实现既容易使用又拥有丰富的功能,许多内容本文并没有涉及。要想了解更多信息并更好地使用它,请查阅它的手册,并尝试使用其他有用的命令。

via: https://opensource.com/article/21/7/linux-kernel-trace-cmd

作者:Gaurav Kamathe选题:lujun9972译者:萌新阿岩校对:wxy

本文由 LCTT原创编译,Linux中国荣誉推出
作者: 一起发财    时间: 2021-10-6 10:21
淘汰了
作者: 夜渐凉    时间: 2021-10-6 10:22
转发了
作者: 东风快递来了    时间: 2021-10-6 10:24
转发了
作者: 起啥用户名    时间: 2021-10-6 10:25
转发了
作者: 一起发财    时间: 2021-10-6 10:25
转发了
作者: bcmytpazcw    时间: 2021-10-6 10:27
转发了
作者: 烟笼寒水    时间: 2021-10-6 10:28
转发了




欢迎光临 邳州信息网 (https://www.pzxxw.com/) Powered by Discuz! X3.4