分类: LINUX
2010-08-03 15:25:23
简介:ftrace 是 Linux 内核中提供的一种调试工具。使用 ftrace 可以对内核中发生的事情进行跟踪,这在调试 bug 或者分析内核时非常有用。本系列文章对 ftrace 进行了介绍,分为三部分。本文是第一部分,介绍了内核相关的编译选项、用户态访问 ftrace 的接口、ftrace 的数据文件,并对 ftrace 提供的跟踪器的用途进行了介绍,以使读者更好的了解和使用该工具。
ftrace 是内建于 Linux 内核的跟踪工具,从 2.6.27 开始加入主流内核。使用 ftrace 可以调试或者分析内核中发生的事情。ftrace 提供了不同的跟踪器,以用于不同的场合,比如跟踪内核函数调用、对上下文切换进行跟踪、查看中断被关闭的时长、跟踪内核态中的延迟以及性能问题等。系统开 发人员可以使用 ftrace 对内核进行跟踪调试,以找到内核中出现的问题的根源,方便对其进行修复。另外,对内核感兴趣的读者还可以通过 ftrace 来观察内核中发生的活动,了解内核的工作机制。
使用 ftrace ,首先要将其编译进内核。内核源码目录下的 kernel/trace/Makefile 文件给出了 ftrace 相关的编译选项。
1.
CONFIG_FUNCTION_TRACER
2.
CONFIG_FUNCTION_GRAPH_TRACER
3.
CONFIG_CONTEXT_SWITCH_TRACER
4.
CONFIG_NOP_TRACER
5.
CONFIG_SCHED_TRACER
6.
...
ftrace 相关的配置选项比较多,针对不同的跟踪器有各自对应的配置选项。不同的选项有不同的依赖关系,内核源码目录下的 kernel/trace/Kconfig 文件描述了这些依赖关系。读者可以参考 Makefile 文件和 Konfig 文件,然后选中自己所需要的跟踪器。
通常在配置内核时,使用 make menuconfig 会更直观一些。以 2.6.33.1 版本的内核为例,要将 ftrace 编译进内核,可以选中 Kernel hacking (图 1 )下的 Tracers 菜单项(图 2 )。
进入 Tracers 菜单下,可以看到内核支持的跟踪器列表。如图 3 所示,这里选中了所有的跟踪器,读者可以根据自己的需要选中特定的跟踪器。
这里要注意,如果是在 32 位 x86 机器上,编译时不要选中 General setup 菜单项(图 4 )下的 Optimize for size 选项(图 5 ),否则就无法看到图 3 中的 Kernel Function Graph Tracer 选项。这是因为在 Konfig 文件中,针对 32 位 x86 机器,表项 FUNCTION_GRAPH_TRACER 有一个特殊的依赖条件:
ftrace 通过 debugfs 向用户态提供了访问接口,所以还需要将 debugfs 编译进内核。激活对 debugfs 的支持,可以直接编辑内核配置文件 .config ,设置 CONFIG_DEBUG_FS=y ;或者在 make menuconfig 时到 Kernel hacking 菜单下选中对 debugfs 文件系统的支持,如图 6 所示。
配置完成后,编译安装新内核,然后启动到新内核。 注意,激活 ftrace 支持后,编译内核时会使用编译器的 -pg 选项,这是在 kernel/trace/Makefile 文件中定义的,如清单 2 所示。
1.
ifdef CONFIG_FUNCTION_TRACER
2.
ORIG_CFLAGS := $(KBUILD_CFLAGS)
3.
KBUILD_CFLAGS = $(subst -pg,,$(ORIG_CFLAGS))
4.
...
5.
endif
6.
...
使用 -pg 选项会在编译得到的内核映像中加入大量的调试信息。一般情况下,只是在开发测试阶段激活 ftrace 支持,以调试内核,修复 bug 。最终用于发行版的内核则会关闭 -pg 选项,也就无法使用 ftrace。
ftrace 通过 debugfs 向用户态提供访问接口。配置内核时激活 debugfs 后会创建目录 /sys/kernel/debug ,debugfs 文件系统就是挂载到该目录。要挂载该目录,需要将如下内容添加到 /etc/fstab 文件:
1.
debugfs /sys/kernel/debug debugfs defaults 0 0
或者可以在运行时挂载:
1.
mount
-t debugfs nodev /sys/kernel/debug
激活内核对 ftrace 的支持后会在 debugfs 下创建一个 tracing 目录 /sys/kernel/debug/tracing 。该目录下包含了 ftrace 的控制和输出文件,如图 7 所示。根据编译内核时针对 ftrace 的设定不同,该目录下实际显示的文件和目录与这里也会不同。
/sys/kernel/debug/tracing 目录下文件和目录比较多,有些是各种跟踪器共享使用的,有些是特定于某个跟踪器使用的。在操作这些数据文件时,通常使用 echo 命令来修改其值,也可以在程序中通过文件读写相关的函数来操作这些文件的值。下面只对部分文件进行描述,读者可以参考内核源码包中 Documentation/trace 目录下的文档以及 kernel/trace 下的源文件以了解其余文件的用途。
ftrace 当前包含多个跟踪器,用于跟踪不同类型的信息,比如进程调度、中断关闭等。可以查看文件 available_tracers 获取内核当前支持的跟踪器列表。在编译内核时,也可以看到内核支持的跟踪器对应的选项,如之前图 3 所示。
ftrace 还支持其它一些跟踪器,比如 initcall、ksym_tracer、mmiotrace、sysprof 等。ftrace 框架支持扩展添加新的跟踪器。读者可以参考内核源码包中 Documentation/trace 目录下的文档以及 kernel/trace 下的源文件,以了解其它跟踪器的用途和如何添加新的跟踪器。
使用 ftrace 提供的跟踪器来调试或者分析内核时需要如下操作:
1.
echo
1 > /proc/sys/kernel/ftrace_enabled
接下来将对跟踪器的使用以及跟踪信息的格式通过实例加以讲解。
function 跟踪器可以跟踪内核函数的调用情况,可用于调试或者分析 bug ,还可用于了解和观察 Linux 内核的执行过程。清单 1 给出了使用 function 跟踪器的示例。
01.
[root@linux tracing]
# pwd
02.
/sys/kernel/debug/tracing
03.
[root@linux tracing]
# echo 0 > tracing_enabled
04.
[root@linux tracing]
# echo 1 > /proc/sys/kernel/ftrace_enabled
05.
[root@linux tracing]
# echo function > current_tracer
06.
[root@linux tracing]
# echo 1 > tracing_on
07.
[root@linux tracing]
# echo 1 > tracing_enabled
08.
09.
# 让内核运行一段时间,这样 ftrace 可以收集一些跟踪信息,之后再停止跟踪
10.
11.
[root@linux tracing]
# echo 0 > tracing_enabled
12.
[root@linux tracing]
# cat trace | head -10
13.
# tracer: function
14.
#
15.
# TASK-PID CPU# TIMESTAMP FUNCTION
16.
# | | | | |
17.
-0 [000] 20654.426521: _raw_spin_lock <-scheduler_tick
18.
-0 [000] 20654.426522: task_tick_idle <-scheduler_tick
19.
-0 [000] 20654.426522: cpumask_weight <-scheduler_tick
20.
-0 [000] 20654.426523: cpumask_weight <-scheduler_tick
21.
-0 [000] 20654.426523: run_posix_cpu_timers <-update_process_times
22.
-0 [000] 20654.426524: hrtimer_forward <-tick_sched_timer
trace 文件给出的信息格式很清晰。首先,字段“tracer:”给出了当前所使用的跟踪器的名字,这里为 function
跟踪器。然后是跟踪信息记录的格式,TASK 字段对应任务的名字,PID 字段则给出了任务的进程 ID,字段 CPU# 表示运行被跟踪函数的
CPU 号,这里可以看到 idle 进程运行在 0 号 CPU 上,其进程 ID 是 0 ;字段 TIMESTAMP
是时间戳,其格式为“
在 function 跟踪器给出的信息中,可以通过 FUNCTION 列中的符号 “<-” 来查看函数调用关系,但是由于中间会混合不同函数的调用,导致看起来非常混乱,十分不方便。function_graph 跟踪器则可以提供类似 C 代码的函数调用关系信息。通过写文件 set_graph_function 可以显示指定要生成调用关系的函数,缺省会对所有可跟踪的内核函数生成函数调用关系图。清单 2 给出了使用 function_grapch 跟踪器的示例,示例中将内核函数 __do_fault 作为观察对象,该函数在内核运作过程中会被频繁调用。
01.
[root@linux tracing]
# pwd
02.
/sys/kernel/debug/tracing
03.
[root@linux tracing]
# echo 0 > tracing_enabled
04.
[root@linux tracing]
# echo 1 > /proc/sys/kernel/ftrace_enabled
05.
[root@linux tracing]
# echo function_graph > current_tracer
06.
[root@linux tracing]
# echo __do_fault > set_graph_function
07.
[root@linux tracing]
# echo 1 > tracing_on
08.
[root@linux tracing]
# echo 1 > tracing_enabled
09.
10.
# 让内核运行一段时间,这样 ftrace 可以收集一些跟踪信息,之后再停止跟踪
11.
12.
[root@linux tracing]
# echo 0 > tracing_enabled
13.
[root@linux tracing]
# cat trace | head -20
14.
# tracer: function_graph
15.
#
16.
# CPU DURATION FUNCTION CALLS
17.
# | | | | | | |
18.
1) 9.936 us | }
19.
1) 0.714 us | put_prev_task_fair();
20.
1) | pick_next_task_fair() {
21.
1) | set_next_entity() {
22.
1) 0.647 us | update_stats_wait_end();
23.
1) 0.699 us | __dequeue_entity();
24.
1) 3.322 us | }
25.
1) 0.865 us | hrtick_start_fair();
26.
1) 6.313 us | }
27.
1) | __switch_to_xtra() {
28.
1) 1.601 us | memcpy();
29.
1) 3.938 us | }
30.
[root@linux tracing]
# echo > set_graph_function
在文件 trace 的输出信息中,首先给出的也是当前跟踪器的名字,这里是 function_graph 。接下来是详细的跟踪信息,可以看到,函数的调用关系以类似 C 代码的形式组织。
CPU 字段给出了执行函数的 CPU 号,本例中都为 1 号 CPU。DURATION 字段给出了函数执行的时间长度,以 us 为单位。FUNCTION CALLS 则给出了调用的函数,并显示了调用流程。注意,对于不调用其它函数的函数,其对应行以“;”结尾,而且对应的 DURATION 字段给出其运行时长;对于调用其它函数的函数,则在其“}”对应行给出了运行时长,该时间是一个累加值,包括了其内部调用的函数的执行时长。 DURATION 字段给出的时长并不是精确的,它还包含了执行 ftrace 自身的代码所耗费的时间,所以示例中将内部函数时长累加得到的结果会与对应的外围调用函数的执行时长并不一致;不过通过该字段还是可以大致了解函数在时间 上的运行开销的。清单 2 中最后通过 echo 命令重置了文件 set_graph_function 。
sched_switch 跟踪器可以对进程的调度切换以及之间的唤醒操作进行跟踪,如清单 3 所示。
01.
[root@linux tracing]
# pwd
02.
/sys/kernel/debug/tracing
03.
[root@linux tracing]
# echo 0 > tracing_enabled
04.
[root@linux tracing]
# echo 1 > /proc/sys/kernel/ftrace_enabled
05.
[root@linux tracing]
# echo sched_switch > current_tracer
06.
[root@linux tracing]
# echo 1 > tracing_on
07.
[root@linux tracing]
# echo 1 > tracing_enabled
08.
09.
# 让内核运行一段时间,这样 ftrace 可以收集一些跟踪信息,之后再停止跟踪
10.
11.
[root@linux tracing]
# echo 0 > tracing_enabled
12.
[root@linux tracing]
# cat trace | head -10
13.
# tracer: sched_switch
14.
#
15.
# TASK-PID CPU# TIMESTAMP FUNCTION
16.
# | | | | |
17.
bash
-1408 [000] 26208.816058: 1408:120:S + [000] 1408:120:S
bash
18.
bash
-1408 [000] 26208.816070: 1408:120:S + [000] 1408:120:S
bash
19.
bash
-1408 [000] 26208.816921: 1408:120:R + [000] 9:120:R events/0
20.
bash
-1408 [000] 26208.816939: 1408:120:R ==> [000] 9:120:R events/0
21.
events/0-9 [000] 26208.817081: 9:120:R + [000] 1377:120:R gnome-terminal
22.
events/0-9 [000] 26208.817088: 9:120:S ==> [000] 1377:120:R gnome-terminal
在 sched_swich 跟踪器获取的跟踪信息中记录了进程间的唤醒操作和调度切换信息,可以通过符号‘ + ’和‘ ==> ’区分;唤醒操作记录给出了当前进程唤醒运行的进程,进程调度切换记录中显示了接替当前进程运行的后续进程。
描述进程状态的格式为“Task-PID:Priority:Task-State”。以示例跟踪信息中的第一条跟踪记录为例,可以看到进程 bash 的 PID 为 1408 ,其对应的内核态优先级为 120 ,当前状态为 S(可中断睡眠状态),当前 bash 并没有唤醒其它进程;从第 3 条记录可以看到,进程 bash 将进程 events/0 唤醒,而在第 4 条记录中发生了进程调度,进程 bash 切换到进程 events/0 执行。
在 Linux 内核中,进程的状态在内核头文件 include/linux/sched.h 中定义,包括可运行状态 TASK_RUNNING(对应跟踪信息中的符号‘ R ’)、可中断阻塞状态 TASK_INTERRUPTIBLE(对应跟踪信息中的符号‘ S ’)等。同时该头文件也定义了用户态进程所使用的优先级的范围,最小值为 MAX_USER_RT_PRIO(值为 100 ),最大值为 MAX_PRIO - 1(对应值为 139 ),缺省为 DEFAULT_PRIO(值为 120 );在本例中,进程优先级都是缺省值 120 。
当关闭中断时,CPU 会延迟对设备的状态变化做出反应,有时候这样做会对系统性能造成比较大的影响。irqsoff 跟踪器可以对中断被关闭的状况进行跟踪,有助于发现导致较大延迟的代码;当出现最大延迟时,跟踪器会记录导致延迟的跟踪信息,文件 tracing_max_latency 则记录中断被关闭的最大延时。
01.
[root@linux tracing]
# pwd
02.
/sys/kernel/debug/tracing
03.
[root@linux tracing]
# echo 0 > tracing_enabled
04.
[root@linux tracing]
# echo 1 > /proc/sys/kernel/ftrace_enabled
05.
[root@linux tracing]
# echo irqsoff > current_tracer
06.
[root@linux tracing]
# echo 1 > tracing_on
07.
[root@linux tracing]
# echo 1 > tracing_enabled
08.
09.
# 让内核运行一段时间,这样 ftrace 可以收集一些跟踪信息,之后再停止跟踪
10.
11.
[root@linux tracing]
# echo 0 > tracing_enabled
12.
[root@linux tracing]
# cat trace | head -35
13.
# tracer: irqsoff
14.
#
15.
# irqsoff latency trace v1.1.5 on 2.6.33.1
16.
# --------------------------------------------------------------------
17.
# latency: 34380 us, #6/6, CPU#1 | (M:desktop VP:0, KP:0, SP:0 HP:0 #P:2)
18.
# -----------------
19.
# | task: -0 (uid:0 nice:0 policy:0 rt_prio:0)
20.
# -----------------
21.
# => started at: reschedule_interrupt
22.
# => ended at: restore_all_notrace
23.
#
24.
#
25.
# _------=> CPU#
26.
# / _-----=> irqs-off
27.
# | / _----=> need-resched
28.
# || / _---=> hardirq/softirq
29.
# ||| / _--=> preempt-depth
30.
# |||| /_--=> lock-depth
31.
# |||||/ delay
32.
# cmd pid |||||| time | caller
33.
# \ / |||||| \ | /
34.
-0 1dN... 4285us!: trace_hardirqs_off_thunk <-reschedule_interrupt
35.
-0 1dN... 34373us+: smp_reschedule_interrupt <-reschedule_interrupt
36.
-0 1dN... 34375us+: native_apic_mem_write <-smp_reschedule_interrupt
37.
-0 1dN... 34380us+: trace_hardirqs_on_thunk <-restore_all_notrace
38.
-0 1dN... 34384us : trace_hardirqs_on_caller <-restore_all_notrace
39.
-0 1dN... 34384us :
40.
=> trace_hardirqs_on_thunk
41.
[root@linux tracing]
# cat tracing_max_latency
42.
34380
从清单 4 中的输出信息中,可以看到当前 irqsoff 延迟跟踪器的版本信息。接下来是最大延迟时间,以 us 为单位,本例中为 34380 us ,查看文件 tracing_max_latency 也可以获取该值。从“task:”字段可以知道延迟发生时正在运行的进程为 idle(其 pid 为 0 )。中断的关闭操作是在函数 reschedule_interrupt 中进行的,由“=> started at:”标识,函数 restore_all_ontrace 重新激活了中断,由“=> ended at:”标识;中断关闭的最大延迟发生在函数 trace_hardirqs_on_thunk 中,这个可以从最大延迟时间所在的记录项看到,也可以从延迟记录信息中最后的“=>”标识所对应的记录行知道这一点。
在输出信息中,irqs-off、need_resched 等字段对应于进程结构 struct task_struct
的字段或者状态标志,可以从头文件 arch/
另外,还有用于跟踪禁止进程抢占的跟踪器 preemptoff 和跟踪中断 / 抢占禁止的跟踪器 preemptirqsoff,它们的使用方式与输出信息格式与 irqsoff 跟踪器类似,这里不再赘述。
前面提过,通过文件 set_ftrace_filter 可以指定要跟踪的函数,缺省目标为所有可跟踪的内核函数;可以将感兴趣的函数通过 echo 写入该文件。为了方便使用,set_ftrace_filter 文件还支持简单格式的通配符。
需要注意的是,这三种形式不能组合使用,比如“begin*middle*end”实际的效果与“begin”相同。另外,使用通配符表达式 时,需要用单引号将其括起来,如果使用双引号,shell 可能会对字符‘ * ’进行扩展,这样最终跟踪的对象可能与目标函数不一样。
通过该文件还可以指定属于特定模块的函数,这要用到 mod 指令。指定模块的格式为:
1.
echo
':mod:[module_name]' > set_ftrace_filter
下面给出了一个指定跟踪模块 ipv6 中的函数的例子。可以看到,指定跟踪模块 ipv6 中的函数会将文件 set_ftrace_filter 的内容设置为只包含该模块中的函数。
01.
[root@linux tracing]
# pwd
02.
/sys/kernel/debug/tracing
03.
[root@linux tracing]
# echo ':mod:ipv6' > set_ftrace_filter
04.
[root@linux tracing]
# cat set_ftrace_filter | head -5
05.
ipv6_opt_accepted
06.
inet6_net_exit
07.
ipv6_gro_complete
08.
inet6_create
09.
ipv6_addr_copy
内核头文件 include/linux/kernel.h 中描述了 ftrace 提供的工具函数的原型,这些函数包括 trace_printk、tracing_on/tracing_off 等。本文通过示例模块程序向读者展示如何在代码中使用这些工具函数。
ftrace 提供了一个用于向 ftrace 跟踪缓冲区输出跟踪信息的工具函数,叫做 trace_printk(),它的使用方式与 printk() 类似。可以通过 trace 文件读取该函数的输出。从头文件 include/linux/kernel.h 中可以看到,在激活配置 CONFIG_TRACING 后,trace_printk() 定义为宏:
1.
#define trace_printk(fmt, args...) \
2.
...
下面通过一个示例模块 ftrace_demo 来演示如何使用 trace_printk() 向跟踪缓冲区输出信息,以及如何查看这些信息。这里的示例模块程序中仅提供了初始化和退出函数,这样读者不会因为需要为模块创建必要的访问接口比如设备文 件而分散注意力。注意,编译模块时要加入 -pg 选项。
01.
/*
02.
* ftrace_demo.c
03.
*/
04.
#include
05.
#include
06.
#include
07.
08.
MODULE_LICENSE(
"GPL"
);
09.
10.
static int ftrace_demo_init(void)
11.
{
12.
trace_printk(
"Can not see this in trace unless loaded for the second time\n"
);
13.
return
0;
14.
}
15.
16.
static void ftrace_demo_exit(void)
17.
{
18.
trace_printk(
"Module unloading\n"
);
19.
}
20.
21.
module_init(ftrace_demo_init);
22.
module_exit(ftrace_demo_exit);
示例模块非常简单,仅仅是在模块初始化函数和退出函数中输出信息。接下来要对模块的运行进行跟踪,如清单 2 所示。
01.
[root@linux tracing]
# pwd
02.
/sys/kernel/debug/tracing
03.
[root@linux tracing]
# echo 0 > tracing_enabled
04.
[root@linux tracing]
# echo 1 > /proc/sys/kernel/ftrace_enabled
05.
[root@linux tracing]
# echo function_graph > current_tracer
06.
07.
# 事先加载模块 ftrace_demo
08.
09.
[root@linux tracing]
# echo ':mod:ftrace_demo' > set_ftrace_filter
10.
[root@linux tracing]
# cat set_ftrace_filter
11.
ftrace_demo_init
12.
ftrace_demo_exit
13.
14.
# 将模块 ftrace_demo 卸载
15.
16.
[root@linux tracing]
# echo 1 > tracing_enabled
17.
18.
# 重新进行模块 ftrace_demo 的加载与卸载操作
19.
20.
[root@linux tracing]
# cat trace
21.
# tracer: function_graph
22.
#
23.
# CPU DURATION FUNCTION CALLS
24.
# | | | | | | |
25.
1) | /* Can not see this
in
trace unless loaded
for
the second
time
*/
26.
0) | /* Module unloading */
在这个例子中,使用 mod 指令显式指定跟踪模块 ftrace_demo 中的函数,这需要提前加载该模块,否则在写文件 set_ftrace_filter 时会因为找不到该模块报错。这样在第一次加载模块时,其初始化函数 ftrace_demo_init 中调用 trace_printk 打印的语句就跟踪不到了。因此这里会将其卸载,然后激活跟踪,再重新进行模块 ftrace_demo 的加载与卸载操作。最终可以从文件 trace 中看到模块在初始化和退出时调用 trace_printk() 输出的信息。
这里仅仅是为了以简单的模块进行演示,故只定义了模块的 init/exit 函数,重复加载模块也只是为了获取初始化函数输出的跟踪信息。实践中,可以在模块的功能函数中加入对 trace_printk 的调用,这样可以记录模块的运作情况,然后对其特定功能进行调试优化。还可以将对 trace_printk() 的调用通过宏来控制编译,这样可以在调试时将其开启,在最终发布时将其关闭。
在跟踪过程中,有时候在检测到某些事件发生时,想要停止跟踪信息的记录,这样,跟踪缓冲区中较新的数据是与该事件有关的。在用户态,可以通过向 文件 tracing_on 写入 0 来停止记录跟踪信息,写入 1 会继续记录跟踪信息。而在内核代码中,可以通过函数 tracing_on() 和 tracing_off() 来做到这一点,它们的行为类似于对 /sys/kernel/debug/tracing 下的文件 tracing_on 分别执行写 1 和 写 0 的操作。使用这两个函数,会对跟踪信息的记录控制地更准确一些,这是因为在用户态写文件 tracing_on 到实际暂停跟踪,中间由于上下文切换、系统调度控制等可能已经经过较长的时间,这样会积累大量的跟踪信息,而感兴趣的那部分可能会被覆盖掉了。
现在对清单 1 中的代码进行修改,使用 tracing_off() 来控制跟踪信息记录的暂停。
01.
/*
02.
* ftrace_demo.c
03.
* modified to demostrate the usage of tracing_off
04.
*/
05.
#include
06.
#include
07.
#include
08.
09.
MODULE_LICENSE(
"GPL"
);
10.
11.
static int ftrace_demo_init(void)
12.
{
13.
trace_printk(
"ftrace_demo_init called\n"
);
14.
tracing_off();
15.
return
0;
16.
}
17.
18.
static void ftrace_demo_exit(void)
19.
{
20.
trace_printk(
"ftrace_demo_exit called\n"
);
21.
tracing_off();
22.
}
23.
24.
module_init(ftrace_demo_init);
25.
module_exit(ftrace_demo_exit);
下面对其进行跟踪,如清单 4 所示。
01.
[root@linux tracing]
# pwd
02.
/sys/kernel/debug/tracing
03.
[root@linux tracing]
# echo 0 > tracing_enabled
04.
[root@linux tracing]
# echo 1 > /proc/sys/kernel/ftrace_enabled
05.
[root@linux tracing]
# echo 1 > tracing_on
06.
[root@linux tracing]
# echo function > current_tracer
07.
[root@linux tracing]
# echo 1 > tracing_enabled
08.
09.
# 加载模块 ftrace_demo,模块初始化函数 ftrace_demo_init 被调用
10.
11.
[root@linux tracing]
# cat tracing_on
12.
0
13.
[root@linux tracing]
# cat trace | wc -l
14.
120210
15.
[root@linux tracing]
# cat trace | grep -n ftrace_demo_init
16.
120187: insmod-2897 [000] 2610.504611: ftrace_demo_init <-do_one_initcall
17.
120193: insmod-2897 [000] 2610.504667: ftrace_demo_init: ftrace_demo_init called
18.
19.
[root@linux tracing]
# echo 1 > tracing_on # 继续跟踪信息的记录
20.
21.
# 卸载模块 ftrace_demo,模块函数 ftrace_demo_exit 被调用
22.
23.
[root@linux tracing]
# cat tracing_on
24.
0
25.
[root@linux tracing]
# wc -l trace
26.
120106 trace
27.
[root@linux tracing]
# grep -n ftrace_demo_exit trace
28.
120106: rmmod-2992 [001] 3016.884449: : ftrace_demo_exit called
在这个例子中,跟踪开始之前需要确保 tracing_on 的值为 1。跟踪开始后,加载模块 ftrace_demo,其初始化方法 ftrace_demo_init 被调用,该方法会调用 tracing_off() 函数来暂停跟踪信息的记录,这时文件 tracing_on 的值被代码设置为 0。查看文件 trace,可以看到 ftrace_demo_init 相关的记录位于跟踪信息的末端,这是因为从调用 trace_off() 到其生效需要一段时间,这段时间中的内核活动会被记录下来;相比从用户态读写 tracing_on 文件,这段时间开销要小了许多。卸载模块时的情况与此类似。从这里可以看到,在代码中使用 tracing_off() 可以控制将感兴趣的信息保存在跟踪缓冲区的末端位置,不会很快被新的信息所覆盖,便于及时查看。
实际代码中,可以通过特定条件(比如检测到某种异常状况,等等)来控制跟踪信息的记录,函数的使用方式类似如下的形式:
1.
if
(condition)
2.
tracing_on() or tracing_off()
跟踪模块运行状况时,使用 ftrace 命令操作序列在用户态进行必要的设置,而在代码中则可以通过 traceing_on() 控制在进入特定代码区域时开启跟踪信息,并在遇到某些条件时通过 tracing_off() 暂停;读者可以在查看完感兴趣的信息后,将 1 写入 tracing_on 文件以继续记录跟踪信息。实践中,可以通过宏来控制是否将对这些函数的调用编译进内核模块,这样可以在调试时将其开启,在最终发布时将其关闭。
用户态的应用程序可以通过直接读写文件 tracing_on 来控制记录跟踪信息的暂停状态,以便了解应用程序运行期间内核中发生的活动。