使用 ftrace 调试 Linux 内核

使用ftrace调试Linux内核，第1部分

/article/2458804.html

简介：ftrace是Linux内核中提供的一种调试工具。使用ftrace可以对内核中发生的事情进行跟踪，这在调试bug或者分析内核时非常有用。本系列文章对ftrace进行了介绍，分为三部分。本文是第一部分，介绍了内核相关的编译选项、用户态访问ftrace的接口、ftrace的数据文件，并对ftrace提供的跟踪器的用途进行了介绍，以使读者更好的了解和使用该工具。

ftrace是内建于Linux内核的跟踪工具，从2.6.27开始加入主流内核。使用ftrace可以调试或者分析内核中发生的事情。ftrace提供了不同的跟踪器，以用于不同的场合，比如跟踪内核函数调用、对上下文切换进行跟踪、查看中断被关闭的时长、跟踪内核态中的延迟以及性能问题等。系统开发人员可以使用ftrace对内核进行跟踪调试，以找到内核中出现的问题的根源，方便对其进行修复。另外，对内核感兴趣的读者还可以通过ftrace来观察内核中发生的活动，了解内核的工作机制。

让内核支持ftrace

使用ftrace，首先要将其编译进内核。内核源码目录下的kernel/trace/Makefile文件给出了ftrace相关的编译选项。

清单1.ftrace相关的配置选项列表

CONFIG_FUNCTION_TRACER CONFIG_FUNCTION_GRAPH_TRACER CONFIG_CONTEXT_SWITCH_TRACER CONFIG_NOP_TRACER CONFIG_SCHED_TRACER ...

ftrace相关的配置选项比较多，针对不同的跟踪器有各自对应的配置选项。不同的选项有不同的依赖关系，内核源码目录下的kernel/trace/Kconfig文件描述了这些依赖关系。读者可以参考Makefile文件和Konfig文件，然后选中自己所需要的跟踪器。

通常在配置内核时，使用makemenuconfig会更直观一些。以2.6.33.1版本的内核为例，要将ftrace编译进内核，可以选中Kernelhacking（图1）下的Tracers菜单项（图2）。

图1.Kernelhacking



图2.Tracers



进入Tracers菜单下，可以看到内核支持的跟踪器列表。如图3所示，这里选中了所有的跟踪器，读者可以根据自己的需要选中特定的跟踪器。

图3.内核支持的跟踪器列表



这里要注意，如果是在32位x86机器上，编译时不要选中Generalsetup菜单项（图4）下的Optimizeforsize选项（图5），否则就无法看到图3中的KernelFunctionGraphTracer选项。这是因为在Konfig文件中，针对32位x86机器，表项FUNCTION_GRAPH_TRACER有一个特殊的依赖条件：

dependson!X86_32||!CC_OPTIMIZE_FOR_SIZE

图4.Generalsetup



图5.Optimizeforsize



ftrace通过debugfs向用户态提供了访问接口，所以还需要将debugfs编译进内核。激活对debugfs的支持，可以直接编辑内核配置文件.config，设置CONFIG_DEBUG_FS=y；或者在makemenuconfig时到Kernelhacking菜单下选中对debugfs文件系统的支持，如图6所示。

图6.debugfs编译选项



配置完成后，编译安装新内核，然后启动到新内核。注意，激活ftrace支持后，编译内核时会使用编译器的-pg选项，这是在kernel/trace/Makefile文件中定义的，如清单2所示。

清单2.激活编译选项-pg

ifdefCONFIG_FUNCTION_TRACER ORIG_CFLAGS:=$(KBUILD_CFLAGS) KBUILD_CFLAGS=$(subst-pg,,$(ORIG_CFLAGS)) ... endif ...

使用-pg选项会在编译得到的内核映像中加入大量的调试信息。一般情况下，只是在开发测试阶段激活ftrace支持，以调试内核，修复bug。最终用于发行版的内核则会关闭-pg选项，也就无法使用ftrace。

通过debugfs访问ftrace

ftrace通过debugfs向用户态提供访问接口。配置内核时激活debugfs后会创建目录/sys/kernel/debug，debugfs文件系统就是挂载到该目录。要挂载该目录，需要将如下内容添加到/etc/fstab文件：

debugfs/sys/kernel/debugdebugfsdefaults00

或者可以在运行时挂载：

mount-tdebugfsnodev/sys/kernel/debug

激活内核对ftrace的支持后会在debugfs下创建一个tracing目录/sys/kernel/debug/tracing。该目录下包含了ftrace的控制和输出文件，如图7所示。根据编译内核时针对ftrace的设定不同，该目录下实际显示的文件和目录与这里也会不同。

图7.tracing目录下的文件



回页首
ftrace的数据文件

/sys/kernel/debug/trace目录下文件和目录比较多，有些是各种跟踪器共享使用的，有些是特定于某个跟踪器使用的。在操作这些数据文件时，通常使用echo命令来修改其值，也可以在程序中通过文件读写相关的函数来操作这些文件的值。下面只对部分文件进行描述，读者可以参考内核源码包中Documentation/trace目录下的文档以及kernel/trace下的源文件以了解其余文件的用途。

README文件提供了一个简短的使用说明，展示了ftrace的操作命令序列。可以通过cat命令查看该文件以了解概要的操作流程。
current_tracer用于设置或显示当前使用的跟踪器；使用echo将跟踪器名字写入该文件可以切换到不同的跟踪器。系统启动后，其缺省值为nop，即不做任何跟踪操作。在执行完一段跟踪任务后，可以通过向该文件写入nop来重置跟踪器。
available_tracers记录了当前编译进内核的跟踪器的列表，可以通过cat查看其内容；其包含的跟踪器与图3中所激活的选项是对应的。写current_tracer文件时用到的跟踪器名字必须在该文件列出的跟踪器名字列表中。
trace文件提供了查看获取到的跟踪信息的接口。可以通过cat等命令查看该文件以查看跟踪到的内核活动记录，也可以将其内容保存为记录文件以备后续查看。
tracing_enabled用于控制current_tracer中的跟踪器是否可以跟踪内核函数的调用情况。写入0会关闭跟踪活动，写入1则激活跟踪功能；其缺省值为1。
set_graph_function设置要清晰显示调用关系的函数，显示的信息结构类似于C语言代码，这样在分析内核运作流程时会更加直观一些。在使用function_graph跟踪器时使用；缺省为对所有函数都生成调用关系序列，可以通过写该文件来指定需要特别关注的函数。
buffer_size_kb用于设置单个CPU所使用的跟踪缓存的大小。跟踪器会将跟踪到的信息写入缓存，每个CPU的跟踪缓存是一样大的。跟踪缓存实现为环形缓冲区的形式，如果跟踪到的信息太多，则旧的信息会被新的跟踪信息覆盖掉。注意，要更改该文件的值需要先将current_tracer设置为nop才可以。
tracing_on用于控制跟踪的暂停。有时候在观察到某些事件时想暂时关闭跟踪，可以将0写入该文件以停止跟踪，这样跟踪缓冲区中比较新的部分是与所关注的事件相关的；写入1可以继续跟踪。
available_filter_functions记录了当前可以跟踪的内核函数。对于不在该文件中列出的函数，无法跟踪其活动。
set_ftrace_filter和set_ftrace_notrace在编译内核时配置了动态ftrace（选中CONFIG_DYNAMIC_FTRACE选项）后使用。前者用于显示指定要跟踪的函数，后者则作用相反，用于指定不跟踪的函数。如果一个函数名同时出现在这两个文件中，则这个函数的执行状况不会被跟踪。这些文件还支持简单形式的含有通配符的表达式，这样可以用一个表达式一次指定多个目标函数；具体使用在后续文章中会有描述。注意，要写入这两个文件的函数名必须可以在文件
available_filter_functions中看到。缺省为可以跟踪所有内核函数，文件set_ftrace_notrace的值则为空。

ftrace跟踪器

ftrace当前包含多个跟踪器，用于跟踪不同类型的信息，比如进程调度、中断关闭等。可以查看文件available_tracers获取内核当前支持的跟踪器列表。在编译内核时，也可以看到内核支持的跟踪器对应的选项，如之前图3所示。

nop跟踪器不会跟踪任何内核活动，将nop写入current_tracer文件可以删除之前所使用的跟踪器，并清空之前收集到的跟踪信息，即刷新trace文件。
function跟踪器可以跟踪内核函数的执行情况；可以通过文件set_ftrace_filter显示指定要跟踪的函数。
function_graph跟踪器可以显示类似C源码的函数调用关系图，这样查看起来比较直观一些；可以通过文件set_grapch_function显示指定要生成调用流程图的函数。
sched_switch跟踪器可以对内核中的进程调度活动进行跟踪。
irqsoff跟踪器和preemptoff跟踪器分别跟踪关闭中断的代码和禁止进程抢占的代码，并记录关闭的最大时长，preemptirqsoff跟踪器则可以看做它们的组合。

ftrace还支持其它一些跟踪器，比如initcall、ksym_tracer、mmiotrace、sysprof等。ftrace框架支持扩展添加新的跟踪器。读者可以参考内核源码包中Documentation/trace目录下的文档以及kernel/trace下的源文件，以了解其它跟踪器的用途和如何添加新的跟踪器。

小结

本系列文章对ftrace的配置和使用进行了介绍。本文是其中的第一部分，介绍了ftrace的编译配置、用户态访问ftrace的接口和ftrace的数据文件，并对ftrace所提供的部分跟踪器的用途进行了描述。由于篇幅的限制，本文没有对ftrace的具体使用和如何在代码中与ftrace进行交互进行描述，这些内容将分别在本系列文章的后续篇章中给出。

使用ftrace调试Linux内核，第2部分

/article/2458805.html

简介：ftrace是Linux内核中提供的一种调试工具。使用ftrace可以对内核中发生的事情进行跟踪，这在调试bug或者分析内核时非常有用。本系列文章对ftrace进行了介绍，分为三部分。本文是第二部分，通过示例介绍了如何使用ftrace中的跟踪器，并对不同格式的跟踪信息进行了描述，同时还对如何使用ftrace调试指定内核模块进行了介绍。通过对本文的学习，读者可以了解如何在实践中使用ftrace。

ftrace操作概述

使用ftrace提供的跟踪器来调试或者分析内核时需要如下操作：

切换到目录/sys/kernel/debug/tracing/下
查看available_tracers文件，获取当前内核支持的跟踪器列表
关闭ftrace跟踪，即将0写入文件tracing_enabled
激活ftrace_enabled，否则function跟踪器的行为类似于nop；另外，激活该选项还可以让一些跟踪器比如irqsoff获取更丰富的信息。建议使用ftrace时将其激活。要激活ftrace_enabled，可以通过proc文件系统接口来设置：

echo1>/proc/sys/kernel/ftrace_enabled

将所选择的跟踪器的名字写入文件current_tracer
将要跟踪的函数写入文件set_ftrace_filter，将不希望跟踪的函数写入文件set_ftrace_notrace。通常直接操作文件set_ftrace_filter就可以了
激活ftrace跟踪，即将1写入文件tracing_enabled。还要确保文件tracing_on的值也为1，该文件可以控制跟踪的暂停
如果是对应用程序进行分析的话，启动应用程序的执行，ftrace会跟踪应用程序运行期间内核的运作情况
通过将0写入文件tracing_on来暂停跟踪信息的记录，此时跟踪器还在跟踪内核的运行，只是不再向文件trace中写入跟踪信息；或者将0写入文件tracing_enabled来关闭跟踪
查看文件trace获取跟踪信息，对内核的运行进行分析调试

接下来将对跟踪器的使用以及跟踪信息的格式通过实例加以讲解。

fucntion跟踪器

function跟踪器可以跟踪内核函数的调用情况，可用于调试或者分析bug，还可用于了解和观察Linux内核的执行过程。清单1给出了使用function跟踪器的示例。

[b]清单1.function跟踪器使用示例

[cpp]
viewplaincopyprint?

<PREclass=cppname="code">[root@linuxtracing]#pwd /sys/kernel/debug/tracing [root@linuxtracing]#echo0>tracing_enabled [root@linuxtracing]#echo1>/proc/sys/kernel/ftrace_enabled [root@linuxtracing]#echofunction>current_tracer [root@linuxtracing]#echo1>tracing_on [root@linuxtracing]#echo1>tracing_enabled #让内核运行一段时间，这样ftrace可以收集一些跟踪信息，之后再停止跟踪 [root@linuxtracing]#echo0>tracing_enabled [root@linuxtracing]#cattrace|head-10 #tracer:function # #TASK-PIDCPU#TIMESTAMPFUNCTION #||||| <idle>-0[000]20654.426521:_raw_spin_lock<-scheduler_tick <idle>-0[000]20654.426522:task_tick_idle<-scheduler_tick <idle>-0[000]20654.426522:cpumask_weight<-scheduler_tick <idle>-0[000]20654.426523:cpumask_weight<-scheduler_tick <idle>-0[000]20654.426523:run_posix_cpu_timers<-update_process_times <idle>-0[000]20654.426524:hrtimer_forward<-tick_sched_timer</PRE><BR>
<BR>
<PRE></PRE>
<P>trace文件给出的信息格式很清晰。首先，字段“tracer:”给出了当前所使用的跟踪器的名字，这里为function跟踪器。然后是跟踪信息记录的格式，TASK字段对应任务的名字，PID字段则给出了任务的进程ID，字段CPU#表示运行被跟踪函数的CPU号，这里可以看到idle进程运行在0号CPU上，其进程ID是0；字段TIMESTAMP是时间戳，其格式为“<secs>.<usecs><CODE>”</CODE>，表示执行该函数时对应的时间戳；FUNCTION
一列则给出了被跟踪的函数，函数的调用者通过符号“<-”标明，这样可以观察到函数的调用关系。</P>
<DIVclass=ibm-alternate-rule>
<HR>
</DIV>
<Pclass="ibm-ind-linkibm-back-to-top"></P>
<P><Aname=major3><SPANclass=atitle>function_graph跟踪器</SPAN></A></P>
<P>在function跟踪器给出的信息中，可以通过FUNCTION列中的符号“<-”来查看函数调用关系，但是由于中间会混合不同函数的调用，导致看起来非常混乱，十分不方便。function_graph跟踪器则可以提供类似C代码的函数调用关系信息。通过写文件set_graph_function可以显示指定要生成调用关系的函数，缺省会对所有可跟踪的内核函数生成函数调用关系图。清单2给出了使用function_grapch跟踪器的示例，示例中将内核函数__do_fault作为观察对象，该函数在内核运作过程中会被频繁调用。</P>
<Aname=listing2><STRONG>清单2.function_graph跟踪器使用示例</STRONG></A><SPANstyle="FONT-SIZE:16px"></SPAN>
<P>在文件trace的输出信息中，首先给出的也是当前跟踪器的名字，这里是function_graph。接下来是详细的跟踪信息，可以看到，函数的调用关系以类似C代码的形式组织。</P>
<P>CPU字段给出了执行函数的CPU号，本例中都为1号CPU。DURATION字段给出了函数执行的时间长度，以us为单位。FUNCTIONCALLS则给出了调用的函数，并显示了调用流程。注意，对于不调用其它函数的函数，其对应行以“;”结尾，而且对应的DURATION字段给出其运行时长；对于调用其它函数的函数，则在其“}”对应行给出了运行时长，该时间是一个累加值，包括了其内部调用的函数的执行时长。DURATION字段给出的时长并不是精确的，它还包含了执行ftrace自身的代码所耗费的时间，所以示例中将内部函数时长累加得到的结果会与对应的外围调用函数的执行时长并不一致；不过通过该字段还是可以大致了解函数在时间上的运行开销的。清单
2中最后通过echo命令重置了文件set_graph_function。</P>
<DIVclass=ibm-alternate-rule>
<HR>
</DIV>
<Pclass="ibm-ind-linkibm-back-to-top"></P>
<P><Aname=major4><SPANclass=atitle>sched_switch跟踪器</SPAN></A></P>
<P>sched_switch跟踪器可以对进程的调度切换以及之间的唤醒操作进行跟踪，如清单3所示。</P>
<Aname=listing3><STRONG>清单3.sched_switch跟踪器使用示例</STRONG></A><SPANstyle="FONT-SIZE:16px"></SPAN><PREclass=cppname="code">
[root@linuxtracing]#pwd
/sys/kernel/debug/tracing
[root@linuxtracing]#echo0>tracing_enabled
[root@linuxtracing]#echo1>/proc/sys/kernel/ftrace_enabled
[root@linuxtracing]#echosched_switch>current_tracer
[root@linuxtracing]#echo1>tracing_on
[root@linuxtracing]#echo1>tracing_enabled

#让内核运行一段时间，这样ftrace可以收集一些跟踪信息，之后再停止跟踪

[root@linuxtracing]#echo0>tracing_enabled
[root@linuxtracing]#cattrace|head-10
#tracer:sched_switch
#
#TASK-PIDCPU#TIMESTAMPFUNCTION
#|||||
bash-1408[000]26208.816058:1408:120:S+[000]1408:120:Sbash
bash-1408[000]26208.816070:1408:120:S+[000]1408:120:Sbash
bash-1408[000]26208.816921:1408:120:R+[000]9:120:Revents/0
bash-1408[000]26208.816939:1408:120:R==>[000]9:120:Revents/0
events/0-9[000]26208.817081:9:120:R+[000]1377:120:Rgnome-terminal
events/0-9[000]26208.817088:9:120:S==>[000]1377:120:Rgnome-terminal
</PRE><BR>
<BR>
<P>在sched_swich跟踪器获取的跟踪信息中记录了进程间的唤醒操作和调度切换信息，可以通过符号‘+’和‘==>’区分；唤醒操作记录给出了当前进程唤醒运行的进程，进程调度切换记录中显示了接替当前进程运行的后续进程。</P>
<P>描述进程状态的格式为“Task-PID:Priority:Task-State”。以示例跟踪信息中的第一条跟踪记录为例，可以看到进程bash的PID为1408，其对应的内核态优先级为120，当前状态为S（可中断睡眠状态），当前bash并没有唤醒其它进程；从第3条记录可以看到，进程bash将进程events/0唤醒，而在第4条记录中发生了进程调度，进程bash切换到进程events/0执行。</P>
<P>在Linux内核中，进程的状态在内核头文件include/linux/sched.h中定义，包括可运行状态TASK_RUNNING（对应跟踪信息中的符号‘R’）、可中断阻塞状态TASK_INTERRUPTIBLE（对应跟踪信息中的符号‘S’）等。同时该头文件也定义了用户态进程所使用的优先级的范围，最小值为MAX_USER_RT_PRIO（值为100），最大值为MAX_PRIO-1（对应值为139），缺省为DEFAULT_PRIO（值为120）；在本例中，进程优先级都是缺省值
120。</P>
<DIVclass=ibm-alternate-rule>
<HR>
</DIV>
<Pclass="ibm-ind-linkibm-back-to-top"><BR>
</P>
<P><Aname=major5><SPANclass=atitle>irqsoff跟踪器</SPAN></A></P>
<P>当关闭中断时，CPU会延迟对设备的状态变化做出反应，有时候这样做会对系统性能造成比较大的影响。irqsoff跟踪器可以对中断被关闭的状况进行跟踪，有助于发现导致较大延迟的代码；当出现最大延迟时，跟踪器会记录导致延迟的跟踪信息，文件tracing_max_latency则记录中断被关闭的最大延时。</P>
<BR>
<Aname=listing4><STRONG>清单4.irqsoff跟踪器使用示例</STRONG></A><BR>
<SPANstyle="FONT-FAMILY:monospace"><SPANstyle="WHITE-SPACE:pre"></SPAN></SPAN><PREclass=cppname="code">
[root@linuxtracing]#pwd
/sys/kernel/debug/tracing
[root@linuxtracing]#echo0>tracing_enabled
[root@linuxtracing]#echo1>/proc/sys/kernel/ftrace_enabled
[root@linuxtracing]#echoirqsoff>current_tracer
[root@linuxtracing]#echo1>tracing_on
[root@linuxtracing]#echo1>tracing_enabled

#让内核运行一段时间，这样ftrace可以收集一些跟踪信息，之后再停止跟踪

[root@linuxtracing]#echo0>tracing_enabled
[root@linuxtracing]#cattrace|head-35
#tracer:irqsoff
#
#irqsofflatencytracev1.1.5on2.6.33.1
#--------------------------------------------------------------------
#latency:34380us,#6/6,CPU#1|(M:desktopVP:0,KP:0,SP:0HP:0#P:2)
#-----------------

#|task:-0(uid:0nice:0policy:0rt_prio:0)
#-----------------

#=>startedat:reschedule_interrupt
#=>endedat:restore_all_notrace
#
#
#_------=>CPU#
#/_-----=>irqs-off
#|/_----=>need-resched
#||/_---=>hardirq/softirq
#|||/_--=>preempt-depth
#||||/_--=>lock-depth
#|||||/delay
#cmdpid||||||time|caller
#\/||||||\|/
<idle>-01dN...4285us!:trace_hardirqs_off_thunk<-reschedule_interrupt
<idle>-01dN...34373us+:smp_reschedule_interrupt<-reschedule_interrupt
<idle>-01dN...34375us+:native_apic_mem_write<-smp_reschedule_interrupt
<idle>-01dN...34380us+:trace_hardirqs_on_thunk<-restore_all_notrace
<idle>-01dN...34384us:trace_hardirqs_on_caller<-restore_all_notrace
<idle>-01dN...34384us:<stacktrace>
=>trace_hardirqs_on_thunk
[root@linuxtracing]#cattracing_max_latency
34380</PRE><BR>
<BR>
<P>从清单4中的输出信息中，可以看到当前irqsoff延迟跟踪器的版本信息。接下来是最大延迟时间，以us为单位，本例中为34380us，查看文件tracing_max_latency也可以获取该值。从“task:”字段可以知道延迟发生时正在运行的进程为idle（其pid为0）。中断的关闭操作是在函数reschedule_interrupt中进行的，由“=>startedat:”标识，函数restore_all_ontrace重新激活了中断，由“=>endedat:”标识；中断关闭的最大延迟发生在函数
trace_hardirqs_on_thunk中，这个可以从最大延迟时间所在的记录项看到，也可以从延迟记录信息中最后的“=>”标识所对应的记录行知道这一点。</P>
<P>在输出信息中，irqs-off、need_resched等字段对应于进程结构structtask_struct的字段或者状态标志，可以从头文件arch/<platform>/include/asm/thread_info.h中查看进程支持的状态标志，include/linux/sched.h则给出了结构structtask_struct的定义。其中，irqs-off字段显示是否中断被禁止，为‘d’表示中断被禁止；need_resched字段显示为‘N’表示设置了进程状态标志
TIF_NEED_RESCHED。hardirq/softirq字段表示当前是否发生硬件中断/软中断；preempt-depth表示是否禁止进程抢占，例如在持有自旋锁的情况下进程是不能被抢占的，本例中进程idle是可以被其它进程抢占的。结构structtask_struct中的lock_depth字段是与大内核锁相关的，而最近的内核开发工作中有一部分是与移除大内核锁相关的，这里对该字段不再加以描述。</P>
<P>另外，还有用于跟踪禁止进程抢占的跟踪器preemptoff和跟踪中断/抢占禁止的跟踪器preemptirqsoff，它们的使用方式与输出信息格式与irqsoff跟踪器类似，这里不再赘述。</P>
<DIVclass=ibm-alternate-rule>
<HR>
</DIV>
<Pclass="ibm-ind-linkibm-back-to-top"><BR>
</P>
<P><Aname=major6><SPANclass=atitle>跟踪指定模块中的函数</SPAN></A></P>
<P>前面提过，通过文件set_ftrace_filter可以指定要跟踪的函数，缺省目标为所有可跟踪的内核函数；可以将感兴趣的函数通过echo写入该文件。为了方便使用，set_ftrace_filter文件还支持简单格式的通配符。</P>
<UL>
<LI><STRONG>begin*</STRONG>选择所有名字以begin字串开头的函数<LI><STRONG>*middle*</STRONG>选择所有名字中包含middle字串的函数<LI><STRONG>*end</STRONG>选择所有名字以end字串结尾的函数</LI></UL>
<P>需要注意的是，这三种形式不能组合使用，比如“begin*middle*end”实际的效果与“begin”相同。另外，使用通配符表达式时，需要用单引号将其括起来，如果使用双引号，shell可能会对字符‘*’进行扩展，这样最终跟踪的对象可能与目标函数不一样。</P>
<P>通过该文件还可以指定属于特定模块的函数，这要用到mod指令。指定模块的格式为：</P>
<TABLEborder=0cellSpacing=0cellPadding=0width="100%"sizcache="0"sizset="6"><TBODYsizcache="0"sizset="6"><TRsizcache="0"sizset="6"><TDclass=code-outlinesizcache="0"sizset="6"><PREclass=displaycodename="code">echo':mod:[module_name]'>set_ftrace_filter
</PRE></TD></TR></TBODY></TABLE>
<BR>
<P>下面给出了一个指定跟踪模块ipv6中的函数的例子。可以看到，指定跟踪模块ipv6中的函数会将文件set_ftrace_filter的内容设置为只包含该模块中的函数。</P>
<BR>
<Aname=listing5><STRONG>清单5.指定跟踪ipv6模块中的函数</STRONG></A><BR>
<SPANstyle="FONT-SIZE:16px"></SPAN><PREclass=cppname="code">
[root@linuxtracing]#pwd
/sys/kernel/debug/tracing
[root@linuxtracing]#echo':mod:ipv6'>set_ftrace_filter
[root@linuxtracing]#catset_ftrace_filter|head-5
ipv6_opt_accepted
inet6_net_exit
ipv6_gro_complete
inet6_create
ipv6_addr_copy
</PRE><BR>
<BR>
<DIVclass=ibm-alternate-rule>
<HR>
</DIV>
<Pclass="ibm-ind-linkibm-back-to-top"><BR>
</P>
<P><Aname=major7><SPANclass=atitle>小结</SPAN></A></P>
<P>本系列文章对ftrace的配置和使用进行了介绍。本文是其中的第二部分，介绍了ftrace所提供的跟踪器的使用，重点对不同格式的跟踪信息进行了描述，并对如何跟踪指定模块中的函数进行了介绍。当前Linux内核中ftrace支持多个跟踪器，由于篇幅限制，这里不能对其全部加以描述。读者可参照参考资料中给出的信息对ftrace跟踪器进行更深入的了解。下一篇文章将对如何在代码中通过ftrace提供的工具函数与ftrace交互进行描述。</P>
<BR>
<BR>
<PRE></PRE>

[cpp]viewplaincopyprint?
[root@linuxtracing]#pwd
/sys/kernel/debug/tracing
[root@linuxtracing]#echo0>tracing_enabled
[root@linuxtracing]#echo1>/proc/sys/kernel/ftrace_enabled
[root@linuxtracing]#echofunction>current_tracer
[root@linuxtracing]#echo1>tracing_on
[root@linuxtracing]#echo1>tracing_enabled

#让内核运行一段时间，这样ftrace可以收集一些跟踪信息，之后再停止跟踪

[root@linuxtracing]#echo0>tracing_enabled
[root@linuxtracing]#cattrace|head-10
#tracer:function
#
#TASK-PIDCPU#TIMESTAMPFUNCTION
#|||||
<idle>-0[000]20654.426521:_raw_spin_lock<-scheduler_tick
<idle>-0[000]20654.426522:task_tick_idle<-scheduler_tick
<idle>-0[000]20654.426522:cpumask_weight<-scheduler_tick
<idle>-0[000]20654.426523:cpumask_weight<-scheduler_tick
<idle>-0[000]20654.426523:run_posix_cpu_timers<-update_process_times
<idle>-0[000]20654.426524:hrtimer_forward<-tick_sched_timer

[root@linuxtracing]#pwd
/sys/kernel/debug/tracing
[root@linuxtracing]#echo0>tracing_enabled
[root@linuxtracing]#echo1>/proc/sys/kernel/ftrace_enabled
[root@linuxtracing]#echofunction>current_tracer
[root@linuxtracing]#echo1>tracing_on
[root@linuxtracing]#echo1>tracing_enabled

#让内核运行一段时间，这样ftrace可以收集一些跟踪信息，之后再停止跟踪

[root@linuxtracing]#echo0>tracing_enabled
[root@linuxtracing]#cattrace|head-10
#tracer:function
#
#TASK-PIDCPU#TIMESTAMPFUNCTION
#|||||
<idle>-0[000]20654.426521:_raw_spin_lock<-scheduler_tick
<idle>-0[000]20654.426522:task_tick_idle<-scheduler_tick
<idle>-0[000]20654.426522:cpumask_weight<-scheduler_tick
<idle>-0[000]20654.426523:cpumask_weight<-scheduler_tick
<idle>-0[000]20654.426523:run_posix_cpu_timers<-update_process_times
<idle>-0[000]20654.426524:hrtimer_forward<-tick_sched_timer

trace文件给出的信息格式很清晰。首先，字段“tracer:”给出了当前所使用的跟踪器的名字，这里为function跟踪器。然后是跟踪信息记录的格式，TASK字段对应任务的名字，PID字段则给出了任务的进程ID，字段CPU#表示运行被跟踪函数的CPU号，这里可以看到idle进程运行在0号CPU上，其进程ID是0；字段TIMESTAMP是时间戳，其格式为“<secs>.<usecs>[code]”

，表示执行该函数时对应的时间戳；FUNCTION一列则给出了被跟踪的函数，函数的调用者通过符号“<-”标明，这样可以观察到函数的调用关系。[/code]

function_graph跟踪器

在function跟踪器给出的信息中，可以通过FUNCTION列中的符号“<-”来查看函数调用关系，但是由于中间会混合不同函数的调用，导致看起来非常混乱，十分不方便。function_graph跟踪器则可以提供类似C代码的函数调用关系信息。通过写文件set_graph_function可以显示指定要生成调用关系的函数，缺省会对所有可跟踪的内核函数生成函数调用关系图。清单2给出了使用function_grapch跟踪器的示例，示例中将内核函数__do_fault作为观察对象，该函数在内核运作过程中会被频繁调用。

清单2.function_graph跟踪器使用示例

在文件trace的输出信息中，首先给出的也是当前跟踪器的名字，这里是function_graph。接下来是详细的跟踪信息，可以看到，函数的调用关系以类似C代码的形式组织。

CPU字段给出了执行函数的CPU号，本例中都为1号CPU。DURATION字段给出了函数执行的时间长度，以us为单位。FUNCTIONCALLS则给出了调用的函数，并显示了调用流程。注意，对于不调用其它函数的函数，其对应行以“;”结尾，而且对应的DURATION字段给出其运行时长；对于调用其它函数的函数，则在其“}”对应行给出了运行时长，该时间是一个累加值，包括了其内部调用的函数的执行时长。DURATION字段给出的时长并不是精确的，它还包含了执行ftrace自身的代码所耗费的时间，所以示例中将内部函数时长累加得到的结果会与对应的外围调用函数的执行时长并不一致；不过通过该字段还是可以大致了解函数在时间上的运行开销的。清单2中最后通过echo命令重置了文件set_graph_function。

sched_switch跟踪器

sched_switch跟踪器可以对进程的调度切换以及之间的唤醒操作进行跟踪，如清单3所示。

清单3.sched_switch跟踪器使用示例

[cpp]viewplaincopyprint?
[root@linuxtracing]#pwd
/sys/kernel/debug/tracing
[root@linuxtracing]#echo0>tracing_enabled
[root@linuxtracing]#echo1>/proc/sys/kernel/ftrace_enabled
[root@linuxtracing]#echosched_switch>current_tracer
[root@linuxtracing]#echo1>tracing_on
[root@linuxtracing]#echo1>tracing_enabled

#让内核运行一段时间，这样ftrace可以收集一些跟踪信息，之后再停止跟踪

[root@linuxtracing]#echo0>tracing_enabled
[root@linuxtracing]#cattrace|head-10
#tracer:sched_switch
#
#TASK-PIDCPU#TIMESTAMPFUNCTION
#|||||
bash-1408[000]26208.816058:1408:120:S+[000]1408:120:Sbash
bash-1408[000]26208.816070:1408:120:S+[000]1408:120:Sbash
bash-1408[000]26208.816921:1408:120:R+[000]9:120:Revents/0
bash-1408[000]26208.816939:1408:120:R==>[000]9:120:Revents/0
events/0-9[000]26208.817081:9:120:R+[000]1377:120:Rgnome-terminal
events/0-9[000]26208.817088:9:120:S==>[000]1377:120:Rgnome-terminal

[root@linuxtracing]#pwd
/sys/kernel/debug/tracing
[root@linuxtracing]#echo0>tracing_enabled
[root@linuxtracing]#echo1>/proc/sys/kernel/ftrace_enabled
[root@linuxtracing]#echosched_switch>current_tracer
[root@linuxtracing]#echo1>tracing_on
[root@linuxtracing]#echo1>tracing_enabled

#让内核运行一段时间，这样ftrace可以收集一些跟踪信息，之后再停止跟踪

[root@linuxtracing]#echo0>tracing_enabled
[root@linuxtracing]#cattrace|head-10
#tracer:sched_switch
#
#TASK-PIDCPU#TIMESTAMPFUNCTION
#|||||
bash-1408[000]26208.816058:1408:120:S+[000]1408:120:Sbash
bash-1408[000]26208.816070:1408:120:S+[000]1408:120:Sbash
bash-1408[000]26208.816921:1408:120:R+[000]9:120:Revents/0
bash-1408[000]26208.816939:1408:120:R==>[000]9:120:Revents/0
events/0-9[000]26208.817081:9:120:R+[000]1377:120:Rgnome-terminal
events/0-9[000]26208.817088:9:120:S==>[000]1377:120:Rgnome-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。

irqsoff跟踪器

当关闭中断时，CPU会延迟对设备的状态变化做出反应，有时候这样做会对系统性能造成比较大的影响。irqsoff跟踪器可以对中断被关闭的状况进行跟踪，有助于发现导致较大延迟的代码；当出现最大延迟时，跟踪器会记录导致延迟的跟踪信息，文件tracing_max_latency则记录中断被关闭的最大延时。

清单4.irqsoff跟踪器使用示例

[cpp]viewplaincopyprint?
[root@linuxtracing]#pwd
/sys/kernel/debug/tracing
[root@linuxtracing]#echo0>tracing_enabled
[root@linuxtracing]#echo1>/proc/sys/kernel/ftrace_enabled
[root@linuxtracing]#echoirqsoff>current_tracer
[root@linuxtracing]#echo1>tracing_on
[root@linuxtracing]#echo1>tracing_enabled

#让内核运行一段时间，这样ftrace可以收集一些跟踪信息，之后再停止跟踪

[root@linuxtracing]#echo0>tracing_enabled
[root@linuxtracing]#cattrace|head-35
#tracer:irqsoff
#
#irqsofflatencytracev1.1.5on2.6.33.1
#--------------------------------------------------------------------
#latency:34380us,#6/6,CPU#1|(M:desktopVP:0,KP:0,SP:0HP:0#P:2)
#-----------------
#|task:-0(uid:0nice:0policy:0rt_prio:0)
#-----------------
#=>startedat:reschedule_interrupt
#=>endedat:restore_all_notrace
#
#
#_------=>CPU#
#/_-----=>irqs-off
#|/_----=>need-resched
#||/_---=>hardirq/softirq
#|||/_--=>preempt-depth
#||||/_--=>lock-depth
#|||||/delay
#cmdpid||||||time|caller
#\/||||||\|/
<idle>-01dN...4285us!:trace_hardirqs_off_thunk<-reschedule_interrupt
<idle>-01dN...34373us+:smp_reschedule_interrupt<-reschedule_interrupt
<idle>-01dN...34375us+:native_apic_mem_write<-smp_reschedule_interrupt
<idle>-01dN...34380us+:trace_hardirqs_on_thunk<-restore_all_notrace
<idle>-01dN...34384us:trace_hardirqs_on_caller<-restore_all_notrace
<idle>-01dN...34384us:<stacktrace>
=>trace_hardirqs_on_thunk
[root@linuxtracing]#cattracing_max_latency
34380

[root@linuxtracing]#pwd
/sys/kernel/debug/tracing
[root@linuxtracing]#echo0>tracing_enabled
[root@linuxtracing]#echo1>/proc/sys/kernel/ftrace_enabled
[root@linuxtracing]#echoirqsoff>current_tracer
[root@linuxtracing]#echo1>tracing_on
[root@linuxtracing]#echo1>tracing_enabled

#让内核运行一段时间，这样ftrace可以收集一些跟踪信息，之后再停止跟踪

[root@linuxtracing]#echo0>tracing_enabled
[root@linuxtracing]#cattrace|head-35
#tracer:irqsoff
#
#irqsofflatencytracev1.1.5on2.6.33.1
#--------------------------------------------------------------------
#latency:34380us,#6/6,CPU#1|(M:desktopVP:0,KP:0,SP:0HP:0#P:2)
#-----------------
#|task:-0(uid:0nice:0policy:0rt_prio:0)
#-----------------
#=>startedat:reschedule_interrupt
#=>endedat:restore_all_notrace
#
#
#_------=>CPU#
#/_-----=>irqs-off
#|/_----=>need-resched
#||/_---=>hardirq/softirq
#|||/_--=>preempt-depth
#||||/_--=>lock-depth
#|||||/delay
#cmdpid||||||time|caller
#\/||||||\|/
<idle>-01dN...4285us!:trace_hardirqs_off_thunk<-reschedule_interrupt
<idle>-01dN...34373us+:smp_reschedule_interrupt<-reschedule_interrupt
<idle>-01dN...34375us+:native_apic_mem_write<-smp_reschedule_interrupt
<idle>-01dN...34380us+:trace_hardirqs_on_thunk<-restore_all_notrace
<idle>-01dN...34384us:trace_hardirqs_on_caller<-restore_all_notrace
<idle>-01dN...34384us:<stacktrace>
=>trace_hardirqs_on_thunk
[root@linuxtracing]#cattracing_max_latency
34380

从清单4中的输出信息中，可以看到当前irqsoff延迟跟踪器的版本信息。接下来是最大延迟时间，以us为单位，本例中为34380us，查看文件tracing_max_latency也可以获取该值。从“task:”字段可以知道延迟发生时正在运行的进程为idle（其pid为0）。中断的关闭操作是在函数reschedule_interrupt中进行的，由“=>startedat:”标识，函数restore_all_ontrace重新激活了中断，由“=>endedat:”标识；中断关闭的最大延迟发生在函数trace_hardirqs_on_thunk中，这个可以从最大延迟时间所在的记录项看到，也可以从延迟记录信息中最后的“=>”标识所对应的记录行知道这一点。

在输出信息中，irqs-off、need_resched等字段对应于进程结构structtask_struct的字段或者状态标志，可以从头文件arch/<platform>/include/asm/thread_info.h中查看进程支持的状态标志，include/linux/sched.h则给出了结构structtask_struct的定义。其中，irqs-off字段显示是否中断被禁止，为‘d’表示中断被禁止；need_resched字段显示为‘N’表示设置了进程状态标志TIF_NEED_RESCHED。hardirq/softirq字段表示当前是否发生硬件中断/软中断；preempt-depth表示是否禁止进程抢占，例如在持有自旋锁的情况下进程是不能被抢占的，本例中进程idle是可以被其它进程抢占的。结构structtask_struct中的lock_depth字段是与大内核锁相关的，而最近的内核开发工作中有一部分是与移除大内核锁相关的，这里对该字段不再加以描述。

另外，还有用于跟踪禁止进程抢占的跟踪器preemptoff和跟踪中断/抢占禁止的跟踪器preemptirqsoff，它们的使用方式与输出信息格式与irqsoff跟踪器类似，这里不再赘述。

跟踪指定模块中的函数

前面提过，通过文件set_ftrace_filter可以指定要跟踪的函数，缺省目标为所有可跟踪的内核函数；可以将感兴趣的函数通过echo写入该文件。为了方便使用，set_ftrace_filter文件还支持简单格式的通配符。

begin*选择所有名字以begin字串开头的函数
*middle*选择所有名字中包含middle字串的函数
*end选择所有名字以end字串结尾的函数

需要注意的是，这三种形式不能组合使用，比如“begin*middle*end”实际的效果与“begin”相同。另外，使用通配符表达式时，需要用单引号将其括起来，如果使用双引号，shell可能会对字符‘*’进行扩展，这样最终跟踪的对象可能与目标函数不一样。

通过该文件还可以指定属于特定模块的函数，这要用到mod指令。指定模块的格式为：

echo':mod:[module_name]'>set_ftrace_filter

下面给出了一个指定跟踪模块ipv6中的函数的例子。可以看到，指定跟踪模块ipv6中的函数会将文件set_ftrace_filter的内容设置为只包含该模块中的函数。

清单5.指定跟踪ipv6模块中的函数

[cpp]
viewplaincopyprint?

[root@linuxtracing]#pwd
/sys/kernel/debug/tracing
[root@linuxtracing]#echo':mod:ipv6'>set_ftrace_filter
[root@linuxtracing]#catset_ftrace_filter|head-5
ipv6_opt_accepted
inet6_net_exit
ipv6_gro_complete
inet6_create
ipv6_addr_copy

[root@linuxtracing]#pwd
/sys/kernel/debug/tracing
[root@linuxtracing]#echo':mod:ipv6'>set_ftrace_filter
[root@linuxtracing]#catset_ftrace_filter|head-5
ipv6_opt_accepted
inet6_net_exit
ipv6_gro_complete
inet6_create
ipv6_addr_copy

小结

本系列文章对ftrace的配置和使用进行了介绍。本文是其中的第二部分，介绍了ftrace所提供的跟踪器的使用，重点对不同格式的跟踪信息进行了描述，并对如何跟踪指定模块中的函数进行了介绍。当前Linux内核中ftrace支持多个跟踪器，由于篇幅限制，这里不能对其全部加以描述。读者可参照参考资料中给出的信息对ftrace跟踪器进行更深入的了解。下一篇文章将对如何在代码中通过ftrace提供的工具函数与ftrace交互进行描述。

使用ftrace调试Linux内核，第3部分

/article/2458806.html

简介：ftrace是Linux内核中提供的一种调试工具。使用ftrace可以对内核中发生的事情进行跟踪，这在调试bug或者分析内核时非常有用。本系列文章对ftrace进行了介绍，分为三部分。本文是第三部分，通过示例代码介绍如何在代码中使用ftrace提供的工具函数，以与ftrace交互。通过本文的讲解，读者可以在实际代码中使用ftrace，方便了调试和分析。

内核头文件include/linux/kernel.h中描述了ftrace提供的工具函数的原型，这些函数包括trace_printk、tracing_on/tracing_off等。本文通过示例模块程序向读者展示如何在代码中使用这些工具函数。

使用trace_printk打印跟踪信息

ftrace提供了一个用于向ftrace跟踪缓冲区输出跟踪信息的工具函数，叫做trace_printk()，它的使用方式与printk()类似。可以通过trace文件读取该函数的输出。从头文件include/linux/kernel.h中可以看到，在激活配置CONFIG_TRACING后，trace_printk()定义为宏：

#definetrace_printk(fmt,args...) \ ...

下面通过一个示例模块ftrace_demo来演示如何使用trace_printk()向跟踪缓冲区输出信息，以及如何查看这些信息。这里的示例模块程序中仅提供了初始化和退出函数，这样读者不会因为需要为模块创建必要的访问接口比如设备文件而分散注意力。注意，编译模块时要加入-pg选项。

清单1.示例模块ftrace_demo

[cpp]
viewplaincopyprint?

/*
*ftrace_demo.c
*/
#include<linux/init.h>

#include<linux/module.h>
#include<linux/kernel.h>

MODULE_LICENSE("GPL");

staticintftrace_demo_init(void)
{
trace_printk("Cannotseethisintraceunlessloadedforthesecondtime\n");
return0;
}

staticvoidftrace_demo_exit(void)
{
trace_printk("Moduleunloading\n");
}

module_init(ftrace_demo_init);
module_exit(ftrace_demo_exit);

/*
*ftrace_demo.c
*/
#include<linux/init.h>
#include<linux/module.h>
#include<linux/kernel.h>

MODULE_LICENSE("GPL");

staticintftrace_demo_init(void)
{
trace_printk("Cannotseethisintraceunlessloadedforthesecondtime\n");
return0;
}

staticvoidftrace_demo_exit(void)
{
trace_printk("Moduleunloading\n");
}

module_init(ftrace_demo_init);
module_exit(ftrace_demo_exit);

示例模块非常简单，仅仅是在模块初始化函数和退出函数中输出信息。接下来要对模块的运行进行跟踪，如清单2所示。

清单2.对模块ftrace_demo进行跟踪

[cpp]viewplaincopyprint? [root@linuxtracing]#pwd /sys/kernel/debug/tracing [root@linuxtracing]#echo0>tracing_enabled [root@linuxtracing]#echo1>/proc/sys/kernel/ftrace_enabled [root@linuxtracing]#echofunction_graph>current_tracer #事先加载模块ftrace_demo [root@linuxtracing]#echo':mod:ftrace_demo'>set_ftrace_filter [root@linuxtracing]#catset_ftrace_filter ftrace_demo_init ftrace_demo_exit #将模块ftrace_demo卸载 [root@linuxtracing]#echo1>tracing_enabled #重新进行模块ftrace_demo的加载与卸载操作 [root@linuxtracing]#cattrace #tracer:function_graph # #CPUDURATIONFUNCTIONCALLS #||||||| 1)|/*Cannotseethisintraceunlessloadedforthesecondtime*/ 0)|/*Moduleunloading*/ [root@linuxtracing]#pwd /sys/kernel/debug/tracing [root@linuxtracing]#echo0>tracing_enabled [root@linuxtracing]#echo1>/proc/sys/kernel/ftrace_enabled [root@linuxtracing]#echofunction_graph>current_tracer #事先加载模块ftrace_demo [root@linuxtracing]#echo':mod:ftrace_demo'>set_ftrace_filter [root@linuxtracing]#catset_ftrace_filter ftrace_demo_init ftrace_demo_exit #将模块ftrace_demo卸载 [root@linuxtracing]#echo1>tracing_enabled #重新进行模块ftrace_demo的加载与卸载操作 [root@linuxtracing]#cattrace #tracer:function_graph # #CPUDURATIONFUNCTIONCALLS #||||||| 1)|/*Cannotseethisintraceunlessloadedforthesecondtime*/ 0)|/*Moduleunloading*/

在这个例子中，使用mod指令显式指定跟踪模块ftrace_demo中的函数，这需要提前加载该模块，否则在写文件set_ftrace_filter时会因为找不到该模块报错。这样在第一次加载模块时，其初始化函数ftrace_demo_init中调用trace_printk打印的语句就跟踪不到了。因此这里会将其卸载，然后激活跟踪，再重新进行模块ftrace_demo的加载与卸载操作。最终可以从文件trace中看到模块在初始化和退出时调用trace_printk()输出的信息。

这里仅仅是为了以简单的模块进行演示，故只定义了模块的init/exit函数，重复加载模块也只是为了获取初始化函数输出的跟踪信息。实践中，可以在模块的功能函数中加入对trace_printk的调用，这样可以记录模块的运作情况，然后对其特定功能进行调试优化。还可以将对trace_printk()的调用通过宏来控制编译，这样可以在调试时将其开启，在最终发布时将其关闭。

回页首
使用tracing_on/tracing_off控制跟踪信息的记录

在跟踪过程中，有时候在检测到某些事件发生时，想要停止跟踪信息的记录，这样，跟踪缓冲区中较新的数据是与该事件有关的。在用户态，可以通过向文件tracing_on写入0来停止记录跟踪信息，写入1会继续记录跟踪信息。而在内核代码中，可以通过函数tracing_on()和tracing_off()来做到这一点，它们的行为类似于对/sys/kernel/debug/tracing下的文件tracing_on分别执行写1和写0的操作。使用这两个函数，会对跟踪信息的记录控制地更准确一些，这是因为在用户态写文件
tracing_on到实际暂停跟踪，中间由于上下文切换、系统调度控制等可能已经经过较长的时间，这样会积累大量的跟踪信息，而感兴趣的那部分可能会被覆盖掉了。

现在对清单1中的代码进行修改，使用tracing_off()来控制跟踪信息记录的暂停。

清单3.使用tracing_off的模块ftrace_demo

[cpp]viewplaincopyprint?/* *ftrace_demo.c *modifiedtodemostratetheusageoftracing_off */ #include<linux/init.h> #include<linux/module.h> #include<linux/kernel.h> MODULE_LICENSE("GPL"); staticintftrace_demo_init(void) { trace_printk("ftrace_demo_initcalled\n"); tracing_off(); return0; } staticvoidftrace_demo_exit(void) { trace_printk("ftrace_demo_exitcalled\n"); tracing_off(); } module_init(ftrace_demo_init); module_exit(ftrace_demo_exit); /* *ftrace_demo.c *modifiedtodemostratetheusageoftracing_off */ #include<linux/init.h> #include<linux/module.h> #include<linux/kernel.h> MODULE_LICENSE("GPL"); staticintftrace_demo_init(void) { trace_printk("ftrace_demo_initcalled\n"); tracing_off(); return0; } staticvoidftrace_demo_exit(void) { trace_printk("ftrace_demo_exitcalled\n"); tracing_off(); } module_init(ftrace_demo_init); module_exit(ftrace_demo_exit);

下面对其进行跟踪，如清单4所示。

清单4.跟踪

[cpp]viewplaincopyprint?[root@linuxtracing]#pwd /sys/kernel/debug/tracing [root@linuxtracing]#echo0>tracing_enabled [root@linuxtracing]#echo1>/proc/sys/kernel/ftrace_enabled [root@linuxtracing]#echo1>tracing_on [root@linuxtracing]#echofunction>current_tracer [root@linuxtracing]#echo1>tracing_enabled #加载模块ftrace_demo，模块初始化函数ftrace_demo_init被调用 [root@linuxtracing]#cattracing_on 0 [root@linuxtracing]#cattrace|wc-l 120210 [root@linuxtracing]#cattrace|grep-nftrace_demo_init 120187:insmod-2897[000]2610.504611:ftrace_demo_init<-do_one_initcall 120193:insmod-2897[000]2610.504667:ftrace_demo_init:ftrace_demo_initcalled [root@linuxtracing]#echo1>tracing_on#继续跟踪信息的记录 #卸载模块ftrace_demo，模块函数ftrace_demo_exit被调用 [root@linuxtracing]#cattracing_on 0 [root@linuxtracing]#wc-ltrace 120106trace [root@linuxtracing]#grep-nftrace_demo_exittrace 120106:rmmod-2992[001]3016.884449::ftrace_demo_exitcalled [root@linuxtracing]#pwd /sys/kernel/debug/tracing [root@linuxtracing]#echo0>tracing_enabled [root@linuxtracing]#echo1>/proc/sys/kernel/ftrace_enabled [root@linuxtracing]#echo1>tracing_on [root@linuxtracing]#echofunction>current_tracer [root@linuxtracing]#echo1>tracing_enabled #加载模块ftrace_demo，模块初始化函数ftrace_demo_init被调用 [root@linuxtracing]#cattracing_on 0 [root@linuxtracing]#cattrace|wc-l 120210 [root@linuxtracing]#cattrace|grep-nftrace_demo_init 120187:insmod-2897[000]2610.504611:ftrace_demo_init<-do_one_initcall 120193:insmod-2897[000]2610.504667:ftrace_demo_init:ftrace_demo_initcalled [root@linuxtracing]#echo1>tracing_on#继续跟踪信息的记录 #卸载模块ftrace_demo，模块函数ftrace_demo_exit被调用 [root@linuxtracing]#cattracing_on 0 [root@linuxtracing]#wc-ltrace 120106trace [root@linuxtracing]#grep-nftrace_demo_exittrace 120106:rmmod-2992[001]3016.884449::ftrace_demo_exitcalled

在这个例子中，跟踪开始之前需要确保tracing_on的值为1。跟踪开始后，加载模块ftrace_demo，其初始化方法ftrace_demo_init被调用，该方法会调用tracing_off()函数来暂停跟踪信息的记录，这时文件tracing_on的值被代码设置为0。查看文件trace，可以看到ftrace_demo_init相关的记录位于跟踪信息的末端，这是因为从调用trace_off()到其生效需要一段时间，这段时间中的内核活动会被记录下来；相比从用户态读写tracing_on
文件，这段时间开销要小了许多。卸载模块时的情况与此类似。从这里可以看到，在代码中使用tracing_off()可以控制将感兴趣的信息保存在跟踪缓冲区的末端位置，不会很快被新的信息所覆盖，便于及时查看。

实际代码中，可以通过特定条件（比如检测到某种异常状况，等等）来控制跟踪信息的记录，函数的使用方式类似如下的形式：

if(condition) tracing_on()ortracing_off()

跟踪模块运行状况时，使用ftrace命令操作序列在用户态进行必要的设置，而在代码中则可以通过traceing_on()控制在进入特定代码区域时开启跟踪信息，并在遇到某些条件时通过tracing_off()暂停；读者可以在查看完感兴趣的信息后，将1写入tracing_on文件以继续记录跟踪信息。实践中，可以通过宏来控制是否将对这些函数的调用编译进内核模块，这样可以在调试时将其开启，在最终发布时将其关闭。

用户态的应用程序可以通过直接读写文件tracing_on来控制记录跟踪信息的暂停状态，以便了解应用程序运行期间内核中发生的活动。

回页首
小结

本系列文章对ftrace的配置和使用进行了介绍。本文是其中的第三部分，通过示例代码介绍了ftrace所提供的部分工具函数的使用，包括trace_printk、tracing_on/tracing_off。至此，本系列文章的所有内容都已经介绍完毕。通过本系列文章，读者可以了解如何使用ftrace来对内核进行调试和分析。ftrace使用起来非常灵活，并且支持多种跟踪器，而且它的框架结构使得在添加新的跟踪器的时候会比较方便。读者可以在以后的工作和学习中探索ftrace的各种用法。