电子技术论坛_中国专业的电子工程师学习交流社区-中电网技术论坛

标题: ftrace 简介（3） [打印本页]

作者: look_w 时间: 2018-6-13 14:55 标题: ftrace 简介（3）

Non-Tracer Tracer 的使用从 2.6.30 开始，ftrace 还支持几种 Non-tracer tracer，所谓 Non-tracer tracer 主要包括以下几种：

Max Stack Tracer
Profiling (branches / unlikely / likely / Functions)
Event tracing

和传统的 tracer 不同，Non-Tracer Tracer 并不对每个内核函数进行跟踪，而是一种类似逻辑分析仪的模式，即对系统进行采样，但似乎也不完全如此。无论怎样，这些 tracer 的使用方法和前面所介绍的 tracer 的使用稍有不同。下面我将试图描述这些 tracer 的使用方法。
Max Stack Tracer 的使用
这个 tracer 记录内核函数的堆栈使用情况，用户可以使用如下命令打开该 tracer：

1	# echo 1 > /proc/sys/kernel/stack_tracer_enabled

从此，ftrace 便留心记录内核函数的堆栈使用。 Max Stack Tracer 的输出在 stack_trace 文件中：

1
2
3
4
5
6
7
8
9
10

# cat /debug/tracing/stack_trace
Depth Size Location (44 entries)
----- ---- --------
0) 3088 64 update_curr+0x64/0x136
1) 3024 64 enqueue_task_fair+0x59/0x2a1
2) 2960 32 enqueue_task+0x60/0x6b
3) 2928 32 activate_task+0x27/0x30
4) 2896 80 try_to_wake_up+0x186/0x27f
…
42) 80 80 sysenter_do_call+0x12/0x32

从上例中可以看到内核堆栈最满的情况如下，有 43 层函数调用，堆栈使用大小为 3088 字节。此外还可以在 Location 这列中看到整个的 calling stack 情况。这在某些情况下，可以提供额外的 debug 信息，帮助开发人员定位问题。
Branch tracer
Branch tracer 比较特殊，她有两种模式，即是传统 tracer，又实现了 profiling tracer 模式。
作为传统 tracer 。其输出文件为 trace，格式如下：

1
2
3
4
5
6

# tracer: branch
#
#  TASK-PID CPU# TIMESTAMP       FUNCTION
# | |       |       |             |
  Xorg-2491 [000] 688.561593: [ ok ] fput_light:file.h:29
  Xorg-2491 [000] 688.561594: [ ok ] fput_light:file_table.c:330

在 FUNCTION 列中，显示了 4 类信息：
函数名，文件和行号，用中括号引起来的部分，显示了分支的信息，假如该字符串为 ok，表明 likely/unlikely 返回为真，否则字符串为 MISS 。举例来说，在文件 file.h 的第 29 行，函数 fput_light 中，有一个 likely 分支在运行时解析为真。我们看看 file.h 的第 29 行：

1
2
3
4

static inline void fput_light(struct file *file, int fput_needed)
{LINE29： if (unlikely(fput_needed))
fput(file);
}

Trace 结果告诉我们，在 688 秒的时候，第 29 行代码被执行，且预测结果为 ok，即 unlikely 成功。
Branch tracer 作为 profiling tracer 时，其输出文件为 profile_annotated_branch，其中记录了 likely/unlikely 语句完整的统计结果。

1
2
3
4

#cat trace_stat/branch_ annotated
correct incorrect %    function          file       line
------- ----------  ---- ------------------ -------------- -----
0    46          100 pre_schedule_rt sched_rt.c    1449

下面是文件 sched_rt.c 的第 1449 行的代码：

1 2	if (unlikely(rt_task(prev)) && rq->rt.highest_prio.curr > prev->prio) pull_rt_task(rq);

记录表明，unlikely 在这里有 46 次为假，命中率为 100% 。假如为真的次数更多，则说明这里应该改成 likely 。
Workqueue profiling
假如您在内核编译时选中该 tracer，ftrace 便会统计 workqueue 使用情况。您只需使用下面的命令查看结果即可：

1	#cat /debug/tracing/trace_stat/workqueue

典型输出如下：

1
2
3
4
5
6
7

# CPU INSERTED  EXECUTED  NAME
#  |    |       |          |
0 38044 38044 events/0
0    426    426 khelper
0 9853    9853 kblockd/0
0    0       0 kacpid
…

可以看到 workqueue events 在 CPU 0 上有 38044 个 worker 被插入并执行。
Event tracer
Event tracer 不间断地记录内核中的重要事件。用户可以用下面的命令查看 ftrace 支持的事件。

1	#cat /debug/tracing/available_event

下面以跟踪进程切换为例讲述 event tracer 的使用。首先打开 event tracer，并记录进程切换：

1
2
3

# echo sched:sched_switch >> /debug/tracing/set_event
# echo sched_switch >> /debug/tracing/set_event
# echo 1 > /debug/tracing/events/sched/sched_switch/enable

上面三个命令的作用是一样的，您可以任选一种。
此时可以查看 ftrace 的输出文件 trace:

1
2
3
4
5
6
7

>head trace
# tracer: nop
#
# TASK-PID CPU#  TIMESTAMP FUNCTION
# | |    |    |          |
<idle>-0 [000] 12093.091053: sched_switch: task swapper:0 [140] ==>
  /user/bin/sealer:2612 [120]

我想您会发现该文件很容易解读。如上例，表示一个进程切换 event，从 idle 进程切换到 sealer 进程。

欢迎光临电子技术论坛_中国专业的电子工程师学习交流社区-中电网技术论坛 (http://bbs.eccn.com/)