作者

pengdonglin137@163.com

概述

下面是之前写的使用funcgraph-retval的文章：

上面的文章里，都是直接通过命令行配置ftrace来使用的，过程稍微有些繁琐，linux提供了perf工具，通过perf工具可以简化上面的一些操作。

正文

这里用到的是perf的ftrace子命令，帮助信息如下：

# perf ftrace -h

 Usage: perf ftrace [<options>] [<command>]
    or: perf ftrace [<options>] -- [<command>] [<options>]
    or: perf ftrace {trace|latency} [<options>] [<command>]
    or: perf ftrace {trace|latency} [<options>] -- [<command>] [<options>]

    -D, --delay <n>       Number of milliseconds to wait before starting tracing after program start
    -F, --funcs <[FILTER]>
                          Show available functions to filter
    -G, --graph-funcs <func>
                          Trace given functions using function_graph tracer
    -g, --nograph-funcs <func>
                          Set nograph filter on given functions
    -m, --buffer-size <size>
                          Size of per cpu buffer, needs to use a B, K, M or G suffix.
    -N, --notrace-funcs <func>
                          Do not trace given functions
    -T, --trace-funcs <func>
                          Trace given functions using function tracer
    -t, --tracer <tracer>
                          Tracer to use: function_graph(default) or function
        --func-opts <options>
                          Function tracer options, available options: call-graph,irq-info
        --graph-opts <options>
                          Graph tracer options, available options: nosleep-time,noirqs,verbose,thresh=<n>,depth=<n>
        --inherit         Trace children processes

ftrace子命令默认使用的是function_graph这个跟踪器，并且提供了下面一些辅助选项：


-G	指定要跟踪的函数，只能设置一个
-g	设置不跟踪的函数，只能设置一个
--graph-opts	控制输出哪些信息，比如verbose参数可以输出最详细的信息

下面以cat /proc/stat为例：

# echo 1 > /sys/kernel/tracing/options/funcgraph-retval
# perf ftrace -G ksys_read cat /proc/stat

可以得到下面的日志：

...
 43)               |    vfs_read() {
 43)               |      rw_verify_area() {
 43)               |        security_file_permission() {
 43)               |          selinux_file_permission() {
 43)               |            inode_security() {
 43)   0.159 us    |              __cond_resched(); /* = 0x0 */
 43)   0.475 us    |            } /* inode_security = 0xffff88811534def8 */
 43)   0.160 us    |            avc_policy_seqno(); /* = 0x1 */
 43)   1.103 us    |          } /* selinux_file_permission = 0x0 */
 43)   0.161 us    |          bpf_lsm_file_permission(); /* = 0x0 */
 43)   1.865 us    |        } /* security_file_permission = 0x0 */
 43)   2.151 us    |      } /* rw_verify_area = 0x0 */
 43)   0.174 us    |      __get_task_ioprio(); /* = 0x4004 */
 43)               |      proc_reg_read_iter() {
 43)               |        seq_read_iter() {
 43)               |          mutex_lock() {
 43)   0.172 us    |            __cond_resched(); /* = 0x0 */
 43)   0.482 us    |          } /* mutex_lock = 0x0 */
 43)   0.160 us    |          single_start(); /* = 0x0 */
 43)   0.162 us    |          single_stop(); /* = 0xffffffff81490e70 */
 43)   0.251 us    |          mutex_unlock(); /* = 0xffff888836c3d180 */
 43)   2.244 us    |        } /* seq_read_iter = 0x0 */
 43)   2.689 us    |      } /* proc_reg_read_iter = 0x0 */
 43)   5.745 us    |    } /* vfs_read = 0x0 */
...