Chipmunk & Panda

-- 鼠熊部落格

All work and no play makes Jack a dull boy.

litetrace —— 一个简易版的 trace-cmd 工具实现

  作业      

实现一个简易版的 trace-cmd 工具: litetrace

  1. 支持打开 function 跟踪和 function 过滤，动态开启和关闭跟踪
  2. 支持查看当前配置状态：
    • 跟踪类型 current_tracer
    • 开关状态 tracing_on
    • function 过滤器状态 set_ftrace_filter
  3. 支持导出跟踪结果
    • 打印 trace 中的跟踪内容

完整代码见文末。

ftrace

From WikiPedia.
ftrace (Function Tracer) is a tracing framework for the Linux kernel. Although its original name, Function Tracer, came from ftrace’s ability to record information related to various function calls performed while the kernel is running, ftrace’s tracing capabilities cover a much broader range of kernel’s internal operations.

ftrace 是 Linux 内核自带的一个调试跟踪工具，便于对用户态和内核态程序进行深入分析（轨迹、性能、系统调用等）。

ftrace 通过文件进行交互，即通过修改一些特定的文件并写入特定内容来使其执行不同的功能。本文仅涉及最最最最基础的跟踪内核态函数调用以及特定函数跟踪功能。

跟踪内核态函数调用

最好应当是在 root 用户下干这些事（不然可能没权限），如果 /sys/kernel/debug 目录是空的，需要执行一下 sudo mount -t debugfs debugfs /sys/kernel/debug。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
# 进入 ftrace 工作目录
cd /sys/kernel/debug/tracing
# 设置 trace 类型为 current_tracer
echo function > current_tracer
# 清空历史 trace 信息
echo > trace
# 打开 trace
echo 1 > tracing_on
# 关闭 trace
echo 0 > tracing_on
# 显示 trace 的前 50 行信息
head n 50 trace
# 以下是输出（这句话显然不是）
# tracer: function
#
# entries-in-buffer/entries-written: 187009/210400   #P:8
#
#                                _-----=> irqs-off
#                               / _----=> need-resched
#                              | / _---=> hardirq/softirq
#                              || / _--=> preempt-depth
#                              ||| /     delay
#           TASK-PID     CPU#  ||||   TIMESTAMP  FUNCTION
#              | |         |   ||||      |         |
            bash-221     [002] ....   508.325121: file_ra_state_init <-do_dentry_open
            bash-221     [002] ....   508.325123: do_truncate <-path_openat
            bash-221     [002] ....   508.325123: dentry_needs_remove_privs <-do_truncate
            bash-221     [002] ....   508.325123: dentry_needs_remove_privs.part.0 <-do_truncate
            bash-221     [002] ....   508.325124: should_remove_suid <-dentry_needs_remove_privs.part.0
            bash-221     [002] ....   508.325124: security_inode_need_killpriv <-dentry_needs_remove_privs.part.0
            bash-221     [002] ....   508.325125: cap_inode_need_killpriv <-security_inode_need_killpriv
            bash-221     [002] ....   508.325125: __vfs_getxattr <-cap_inode_need_killpriv
            bash-221     [002] ....   508.325125: xattr_resolve_name <-__vfs_getxattr
            bash-221     [002] ....   508.325126: is_bad_inode <-xattr_resolve_name
            bash-221     [002] ....   508.325126: down_write <-do_truncate
            bash-221     [002] ....   508.325126: notify_change <-do_truncate
            bash-221     [002] ....   508.325127: current_time <-notify_change
            bash-221     [002] ....   508.325127: ktime_get_coarse_real_ts64 <-current_time
            bash-221     [002] ....   508.325127: timestamp_truncate <-current_time
            bash-221     [002] ....   508.325128: security_inode_setattr <-notify_change
            bash-221     [002] ....   508.325128: simple_setattr <-notify_change
            bash-221     [002] ....   508.325128: setattr_prepare <-simple_setattr
            bash-221     [002] ....   508.325129: inode_newsize_ok <-setattr_prepare
            bash-221     [002] ....   508.325129: truncate_setsize <-simple_setattr
            bash-221     [002] ....   508.325129: truncate_pagecache <-simple_setattr
            bash-221     [002] ....   508.325130: unmap_mapping_range <-truncate_pagecache
            bash-221     [002] ....   508.325130: unmap_mapping_pages <-truncate_pagecache
            bash-221     [002] ....   508.325130: down_write <-unmap_mapping_pages
            bash-221     [002] ....   508.325130: up_write <-unmap_mapping_pages
            bash-221     [002] ....   508.325131: truncate_inode_pages_range <-truncate_pagecache
            bash-221     [002] ....   508.325131: unmap_mapping_range <-simple_setattr
            bash-221     [002] ....   508.325131: unmap_mapping_pages <-simple_setattr
            bash-221     [002] ....   508.325131: down_write <-unmap_mapping_pages
            bash-221     [002] ....   508.325131: up_write <-unmap_mapping_pages
            bash-221     [002] ....   508.325132: setattr_copy <-simple_setattr
            bash-221     [002] ....   508.325132: __mark_inode_dirty <-simple_setattr
            bash-221     [002] ....   508.325132: _raw_spin_lock <-__mark_inode_dirty
            bash-221     [002] ....   508.325133: __inode_attach_wb <-__mark_inode_dirty
            bash-221     [002] ....   508.325133: __fsnotify_parent <-notify_change
            bash-221     [002] ....   508.325134: up_write <-do_truncate
            bash-221     [002] ....   508.325134: mnt_drop_write <-path_openat
            bash-221     [002] ....   508.325136: terminate_walk <-path_openat
            bash-221     [002] ....   508.325136: dput <-terminate_walk

特定函数跟踪

在开始跟踪前设置一下要跟踪的函数，即可仅跟踪特定函数。

1
2
# 设置 set_ftrace_filter 为 vfs_write，即只跟踪 vfs_write 函数。
echo vfs_write > set_ftrace_filter

trace-cmd

直接使用 ftrace 未免有些繁琐，因此 ftrace 团队把上面那些操作封装了一下，整出来一个 trace-cmd。简而言之就是输入一条指令，trace-cmd 就自动把该指令对应的一连串操作给执行掉，而无需用户自己一个个敲了。

简易 litetrace 实现

重申一遍作业内容，虽然在文章开头就有。

实现一个简易版的 trace-cmd 工具: litetrace

  1. 支持打开 function 跟踪和 function 过滤，动态开启和关闭跟踪
  2. 支持查看当前配置状态：
    • 跟踪类型 current_tracer
    • 开关状态 tracing_on
    • function 过滤器状态 set_ftrace_filter
  3. 支持导出跟踪结果
    • 打印 trace 中的跟踪内容

实际就是根据用户输入执行相应的指令，相当适合用 Python 来应付。

思路：使用 input() 函数获取用户输入，根据输入调用不同的函数，每个函数对应不同的功能，实际就是对应了一条或者多条 bash 命令。

使用 subprocess 来执行系统命令，或者用其他的方法比如 os.system() 均可，全凭喜好。

功能设计

这里直接用一个 help() 函数，打印出所支持的所有功能和对应的指令。

1
2
3
4
5
6
7
8
9
10
11
12
13
def help():
    print('====================')
    print('help: 查看帮助')
    print('start: 打开跟踪')
    print('stop: 停止跟踪')
    print('start-func: 打开 function 跟踪')
    print('start-func-filter func_name: 打开 function 过滤并设置跟踪函数名为 func_name')
    print('show-ct: 查看跟踪类型 current_tracer')
    print('show-to: 查看状态 tracing_on')
    print('show-sff: 查看过滤器状态 set_ftrace_filter')
    print('show n: 打印 trace 中前 n 行的跟踪内容')
    print('exit: 退出')
    print('====================')

简易命令行

模拟一个简单的命令行，看起来会比较像那么回事。

设计一个死循环，不断获取用户输入，将每次输入根据空格划分成多个单词，用一个字典将指令与函数对应起来，就差不多得了。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
command = '' # 有的函数可能会需要传参，因此将用户输入存在全局变量 command 里以便获取。

command_dict = {
    # '指令': 函数
    'help': help,
    'start': start,
    'stop': stop,
    'start-func': setFunctionTracing,
    'start-func-filter': startFunctionFilter,
    'show-ct': showCurrentTracer,
    'show-to': showTraceingOn,
    'show-sff': showSetFtraceFilter,
    'show': show,
    'exit': exit
}

if __name__ == '__main__':
    help()  # 开局给个帮助信息
    while True:
        command = input('>>> ').split()
        if command:
            command_dict.get(command.pop(0))()  # 将输入的第一个单词视为指令并执行指令对应的函数

注意，上面 command_dict.get(command.pop(0)) 未考虑没有对应指令的情况，解决方法是给个默认返回就可以了，不赘述。

打开和关闭跟踪

  • 指定 cwd 参数，这样就不用 cd /sys/kernel/debug/tracing 了。
  • echo content > file 的指令需要设置直接在 shell 中执行 shell=True，不然会被理解成 echo "content > file" 来执行。
1
2
3
4
5
6
7
8
9
10
def start():  # 打开跟踪
    subprocess.run(['echo > trace'],
                   cwd='/sys/kernel/debug/tracing', shell=True)
    subprocess.run(['echo 1 > tracing_on'],
                   cwd='/sys/kernel/debug/tracing', shell=True)


def stop():  # 关闭跟踪
    subprocess.run(['echo 0 > tracing_on'],
                   cwd='/sys/kernel/debug/tracing', shell=True)

打开 function 跟踪

套娃函数调用，便于复用。

1
2
3
4
5
6
7
8
9
def setFunctionTracing():  # 设置 trace 类型为 function
    stop()
    subprocess.run(['echo function > current_tracer'],
                   cwd='/sys/kernel/debug/tracing', shell=True)


def startFunctionTracing():  # 打开 function 跟踪
    setFunctionTracing()
    start()

打开 function 过滤

停跟踪，设置 function 跟踪，设置 function 过滤。

1
2
3
4
5
6
7
8
9
10
11
def startFunctionFilter():
    if not command:  # 需要传参要跟踪的函数名
        print('!!--------------------!!')
        print('Error: no function name!')
        print('!!--------------------!!')
        return
    func = command.pop(0)
    stop()
    setFunctionTracing()
    subprocess.run(['echo {} > set_ftrace_filter'.format(func)],
                   cwd='/sys/kernel/debug/tracing', shell=True)

查看当前配置状态

其实就是查看对应文件的内容。

1
2
3
4
5
6
7
8
9
10
11
def showCurrentTracer():
    subprocess.run(['cat', 'current_tracer'], cwd='/sys/kernel/debug/tracing')


def showTraceingOn():
    subprocess.run(['cat', 'tracing_on'], cwd='/sys/kernel/debug/tracing')


def showSetFtraceFilter():
    subprocess.run(['cat', 'set_ftrace_filter'],
                   cwd='/sys/kernel/debug/tracing')

导出跟踪结果

除了接受指令，还额外接受一个参数 n，以表示要打印前 n 行的跟踪内容。

要注意判断没传 n 以及传的不是个非负整数的情况。

其实可以将 n 设为可选，即当没传 n 的时候则打印全部内容，那样的话把 head 改为 cat 就差不多了，但是一般 trace 内容都超超超多，自认为 cat 可不兴随便用，所以就没搞了，差不多那意思就成。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
def show():  # 打印 trace 中的跟踪内容
    if command:
        n = command.pop(0)
        if n.isdigit() and int(n) >= 0:
            subprocess.run(['head', '-n', n, 'trace'],
                           cwd='/sys/kernel/debug/tracing')
        else:
            print('!!--------------------!!')
            print('Error: invalid num!')
            print('!!--------------------!!')
            return
    else:
        print('!!--------------------!!')
        print('Error: no num!')
        print('!!--------------------!!')
        return

完整代码

实际没什么技术含量……主要目的其实是熟悉一下 ftrace 的使用罢了。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
import subprocess

command = ''  # 有的函数可能会需要传参，因此将用户输入存在全局变量 command 里以便获取。


def start():  # 打开跟踪
    subprocess.run(['echo > trace'],
                   cwd='/sys/kernel/debug/tracing', shell=True)
    subprocess.run(['echo 1 > tracing_on'],
                   cwd='/sys/kernel/debug/tracing', shell=True)


def stop():  # 关闭跟踪
    subprocess.run(['echo 0 > tracing_on'],
                   cwd='/sys/kernel/debug/tracing', shell=True)


def setFunctionTracing():  # 设置 trace 类型为 function
    stop()
    subprocess.run(['echo function > current_tracer'],
                   cwd='/sys/kernel/debug/tracing', shell=True)


def startFunctionTracing():  # 打开 function 跟踪
    setFunctionTracing()
    start()


def startFunctionFilter():
    if not command:  # 需要传参要跟踪的函数名
        print('!!--------------------!!')
        print('Error: no function name!')
        print('!!--------------------!!')
        return
    func = command.pop(0)
    stop()
    setFunctionTracing()
    subprocess.run(['echo {} > set_ftrace_filter'.format(func)],
                   cwd='/sys/kernel/debug/tracing', shell=True)


def showCurrentTracer():
    subprocess.run(['cat', 'current_tracer'], cwd='/sys/kernel/debug/tracing')


def showTraceingOn():
    subprocess.run(['cat', 'tracing_on'], cwd='/sys/kernel/debug/tracing')


def showSetFtraceFilter():
    subprocess.run(['cat', 'set_ftrace_filter'],
                   cwd='/sys/kernel/debug/tracing')


def show():  # 打印 trace 中的跟踪内容
    if command:
        n = command.pop(0)
        if n.isdigit() and int(n) >= 0:
            subprocess.run(['head', '-n', n, 'trace'],
                           cwd='/sys/kernel/debug/tracing')
        else:
            print('!!--------------------!!')
            print('Error: invalid num!')
            print('!!--------------------!!')
            return
    else:
        print('!!--------------------!!')
        print('Error: no num!')
        print('!!--------------------!!')
        return


def help():
    print('====================')
    print('help: 查看帮助')
    print('start: 打开跟踪')
    print('stop: 停止跟踪')
    print('start-func: 打开 function 跟踪')
    print('start-func-filter func_name: 打开 function 过滤并设置跟踪函数名为 func_name')
    print('show-ct: 查看跟踪类型 current_tracer')
    print('show-to: 查看状态 tracing_on')
    print('show-sff: 查看过滤器状态 set_ftrace_filter')
    print('show n: 打印 trace 中前 n 行的跟踪内容')
    print('exit: 退出')
    print('====================')


command_dict = {
    # '指令': 函数
    'help': help,
    'start': start,
    'stop': stop,
    'start-func': setFunctionTracing,
    'start-func-filter': startFunctionFilter,
    'show-ct': showCurrentTracer,
    'show-to': showTraceingOn,
    'show-sff': showSetFtraceFilter,
    'show': show,
    'exit': exit
}

if __name__ == '__main__':
    help()  # 开局给个帮助信息
    while True:
        command = input('>>> ').split()
        if command:
            command_dict.get(command.pop(0))()  # 将输入的第一个单词视为指令并执行指令对应的函数