整理自《奔跑吧 Linux内核,张天飞著》
1. 动态ftrace
在配置内核时打开了CONFIG_DYNAMIC_FTRACE选项,就可以支持动态ftrace功能。set_ftrace_filter和set_ftrace_notrace这两个文件可以配对使用,其中,前者设置要跟踪的函数,后者指定不要跟踪的函数。
在实际的调试过程中,我们通常会被ftrace提供的大量信息淹没,因此动态过滤的方法非常有用。avaliable_filter_functions文件可以列出当前系统支持的所有函数,例如现在我只想关注hrtimer_nanosleep()和hrtimer_interrupt()这两个函数。
# cd /sys/kernel/debug/tracing
# echo hrtimer_nanosleep hrtimer_interrupt > set_ftrace_filter
# echo function > current_tracer
# echo 1 > tracing_on
# usleep 1
# echo 0 > tracing_on
# cat trace
抓取的数据如下:
# tracer: function
#
# entries-in-buffer/entries-written: 57/57 #P:4
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
rcu_preempt-10 [002] d.h2 11073.199551: hrtimer_interrupt <-arch_timer_handler_virt
rcu_preempt-10 [002] d.h2 11073.215430: hrtimer_interrupt <-arch_timer_handler_virt
rcu_preempt-10 [002] d.h3 11073.235407: hrtimer_interrupt <-arch_timer_handler_virt
rcu_preempt-10 [002] d.h2 11074.191632: hrtimer_interrupt <-arch_timer_handler_virt
rcu_preempt-10 [000] d.h2 11074.603390: hrtimer_interrupt <-arch_timer_handler_virt
rcu_preempt-10 [001] d.h1 11074.719377: hrtimer_interrupt <-arch_timer_handler_virt
rcu_preempt-10 [001] d.h1 11074.735375: hrtimer_interrupt <-arch_timer_handler_virt
rcu_preempt-10 [001] d.h1 11074.791404: hrtimer_interrupt <-arch_timer_handler_virt
rcu_preempt-10 [001] d.h3 11075.828143: hrtimer_interrupt <-arch_timer_handler_virt
......
此外,过滤器还支持如下通配符。
<match>*
:匹配所有match开头的函数*<match>
:匹配所有match结尾的函数*<match>*
:匹配所有包含match的函数
如果跟踪所有"hrtimer"开头的函数,可以"echo \`hrtimer\_*\` > set_ftrace_filter"。还有两个非常有用的操作符,">"表示会覆盖过滤器里的内容;">>"表示新加的函数会增加到过滤器中,但不会覆盖。
# echo do_nanosleep > set_ftrace_filter // 往过滤器里写入do_nanosleep
# cat set_ftrace_filter
do_nanosleep
# echo 'hrtimer_*' >> set_ftrace_filter // 追加写入
# cat set_ftrace_filter
hrtimer_init_sleeper
hrtimer_active
hrtimer_reprogram
hrtimer_force_reprogram
hrtimer_update_softirq_timer
hrtimer_run_softirq
hrtimer_forward
hrtimer_init
hrtimer_wakeup
hrtimer_start_range_ns
hrtimer_try_to_cancel
hrtimer_cancel
hrtimer_get_next_event
hrtimer_next_event_without
hrtimer_interrupt
hrtimer_run_queues
hrtimer_nanosleep
do_nanosleep
hrtimer_nanosleep_restart
# echo '*preempt*' '*lock*' > set_ftrace_notrace // 表示不跟踪包含preempt和lock的函数
# echo > set_ftrace_filter // 向过滤器中输入空字符表示清空过滤器
cat set_ftrace_filter
#### all functions enabled ####
2. 事件跟踪
ftrace里的跟踪机制主要有两种,分别是函数和tracepoint。前者属于"傻瓜式"操作,后者tracepoint可以理解为一个Linux内核中的的占位符函数,内核子系统的开发者通常喜欢利用它来调试。
tracepoint可以输出开发者想要的参数、局部变量等信息。tracepoint的位置比较固定,一般都是内核开发者添加上去的,可以把它理解为传统C语言中#if DEBUG
部分。如果在运行中没有开启DEBUG,那么是不占用任何系统开销的。
在阅读内核代码时经常会遇到以trace_
开头的函数,例如CFS调度器里的update_curr()函数。
*/
static void update_curr(struct cfs_rq *cfs_rq)
{
......
curr->vruntime += calc_delta_fair(delta_exec, curr);
update_min_vruntime(cfs_rq);
if (entity_is_task(curr)) {
struct task_struct *curtask = task_of(curr);
trace_sched_stat_runtime(curtask, delta_exec, curr->vruntime);
cgroup_account_cputime(curtask, delta_exec);
account_group_exec_runtime(curtask, delta_exec);
}
......
}
update_curr()函数使用了一个sched_stat_runtime的tracepoint,我们可以在avaliable_events文件中查到,把想要跟踪的事件添加到set_event文件中即可,该文件同样支持通配符。
# cd /sys/kernel/debug/tracing
# cat available_events | grep sched_stat_runtime
sched:sched_stat_runtime
# echo sched:sched_stat_runtime > set_event
# echo 1 > tracing_on
# cat trace
# echo sched:* > set_event // 支持通配符,跟踪所有sched开头的事件
# echo *:* > set_event // 跟踪系统所有事件
输出如下:
# tracer: nop
#
# entries-in-buffer/entries-written: 456/51078 #P:4
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
mali-cmar-backe-5672 [002] d..2 5880.987504: sched_stat_runtime: comm=mali-cmar-backe pid=5672 runtime=117420 [ns] vruntime=216701544114 [ns]
Colors-5658 [002] d..2 5880.987548: sched_stat_runtime: comm=Colors pid=5658 runtime=50800 [ns] vruntime=216706582321 [ns]
mali-cmar-backe-5672 [002] d..2 5880.987621: sched_stat_runtime: comm=mali-cmar-backe pid=5672 runtime=73240 [ns] vruntime=216701590175 [ns]
......
另外事件跟踪还支持另外一个强大的功能,可以设定跟踪条件,做到更精细化的设置。每个tracepoint都定义一个format格式,其中定义了该tracepoint支持的域。
# cd /sys/kernel/debug/tracing/events/sched/sched_stat_runtime
# cat format
输出如下:
name: sched_stat_runtime
ID: 246
format:
field:unsigned short common_type; offset:0; size:2; signed:0;
field:unsigned char common_flags; offset:2; size:1; signed:0;
field:unsigned char common_preempt_count; offset:3; size:1; signed:0;
field:int common_pid; offset:4; size:4; signed:1;
field:char comm[16]; offset:8; size:16; signed:0;
field:pid_t pid; offset:24; size:4; signed:1;
field:u64 runtime; offset:32; size:8; signed:0;
field:u64 vruntime; offset:40; size:8; signed:0;
print fmt: "comm=%s pid=%d runtime=%Lu [ns] vruntime=%Lu [ns]", REC->comm, REC->pid, (unsigned long long)REC->runtime, (unsigned long long)REC->vruntime
例如,sched_stat_runtime这个tracepoint支持8个域,前4个是通用域,后4个是该tracepoint支持的域,comm是一个字符串域,其他都是数字域。
支持类似C语言表达式对事件进行过滤,对于数字域支持==, !=, <, <=, >, >=, &
操作符,对于字符串域支持==, !=, ~
操作符。
例如只想跟踪进程名字开头为sh的所有进程的sched_stat_runtime事件。
# cd /sys/kernel/debug/tracing/events/sched/sched_stat_runtime
# echo 'comm ~ "sh*"' > filter // 跟踪所有进程名字开头为sh的
echo 'pid==5658' > filter // 跟踪进程PID为5658的
输出如下:
#
# entries-in-buffer/entries-written: 474/51988245 #P:4
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
Colors-5658 [003] d..2 18238.020119: sched_stat_runtime: comm=Colors pid=5658 runtime=1010360 [ns] vruntime=1531587993187 [ns]
Colors-5658 [003] dn.2 18238.023648: sched_stat_runtime: comm=Colors pid=5658 runtime=425020 [ns] vruntime=1531588418207 [ns]
Colors-5658 [003] dn.2 18238.023837: sched_stat_runtime: comm=Colors pid=5658 runtime=52780 [ns] vruntime=1531588470987 [ns]
Colors-5658 [003] dn.2 18238.024666: sched_stat_runtime: comm=Colors pid=5658 runtime=637600 [ns] vruntime=1531589108587 [ns]
3. 添加tracepoint
内核各个子系统目前已经有大量的tracepoint,如果觉得这些tracepoint还不满足需求,可以自己手动添加一个,这在实际工作中也是很常用的技巧。
还是以CFS
评论