如何利用ftrace精确跟踪特定进程调度信息

网上 已经有很多阐述 ftrace原理和使用方法的文章，本文不会面面俱到的介绍所有涉及的原理和方法，只会聚焦在阐述ftrace的event tracing机制，以及如何利用该机制（包括其他一些方法配合）去跟踪某个进程的调度信息。本文的分析基于处理器为ARM64的多核 手机平台， linux 版本为 msm-4.19 ，为 了行文方便，我们还是先回顾 下 ftrace的基本概念。

一、 ftrace基本原理

图 1-1 ftrace框架

一句话 总结：各类 tracer往ftrace主框架注册，不同的trace则在不同的probe点把信息通过probe函数 给送到 ring buffer中，再由暴露在用户态debufs实现相关控制。

对不同tracer来说

1）需要 实现 probe点（需要跟踪的代码侦测点） ，有的 probe点需要静态代码实现，有的probe点借助编译器在运行时动态替换 ， event tracing属于前者；

2）还要实现具体 的 probe函数，把需要 记录的信息送到 ring buffer中；

3） 增加 debugfs 相关的文件，实现信息的解析和控制。

而 ring buffer 和debugfs的通用部分的管理由框架负责。

二、ftrace event tracing原理介绍

图 2-1 ftrace event tracing原理

其它一些 trace 工具也具有相似的工作流程，需要一个 probe 点，一个 probe 函数，一种保存 log 信息的机制，还有用于户进行交互的接口（分别对应图中 A、B、C、D 点）。它们发现可以利用 function trace 的后两部分，也就是环形缓存的管理和用户交互接口部分的代码，只需要实现自己的 probe 点和 probe 函数就可以了。于是在 function trace 进入内核 mainline 后，kprobe 也借用了该机制。

1.   tracepoint 的实现原理

tracepoint 是早就存在于内核当中的一种 trace 工具，具体原理不再详细展开，示例代码大家可参照 内核源码 sample/tracepoints/相关内容。需要使用小于3.9版本的内核来看。 原因是 linux不期望开发人员直接使用 tracepoint，而应该使用更高层的 event tracing，但是有两个宏（DECLARE_TRACE 和 DEFINE_TRACE ）会被 trace event使用，需要看下。

（1） DECLARE_TRACE

该宏 在 <linux/tracepoint.h>被定义。

trace_##name最终调用__DO_TRACE宏将 信息送到 ring buffer中。

reg/unregister_trace_subsys_event 负责注册或注销 probe 函数，probe 函数的原型由 TP_PROTO 宏给出。例如：wakeup相关tracer则是调用了register_trace_sched_wakeup。

使用 tracepoint 需要自己实现 probe 函数， event tracing通过一套通用的机制省去了内核模块/驱动自己实现probe函数的麻烦 。

• __DO_TRACE

该 (it_func_ptr)->func 和 (tp)->funcs在enable event的时候会被赋值，下文会有展开描述。

（2）  DEFINE_TRACE

定义 了 __tpstrtab_##name字符串变量 和 struct tracepoint __tracepoint_##name。当然二者都放在了链接脚本专门的section里（ 详见 include/asm-generic/vmlinux.lds.h）。编译后可查看system.map去查看具体的变量位置。

2.  event tracing的 实现原理

event tracing 可以理解为 tracepoint 加 function trace 的接口组合而成，提供了接口给内核开发者，让其快速的定义信息保存的格式以及如何打印出来。具体原理 可参照 samples/trace_events/下的例子。

（1）TRACE_EVENT

该宏可以实现probe点、probe函数 、 event 的格式，以及 event打印出来的格式。

第 1次通过 包含 include/linux/tracepoint.h，将其 展开成 DECLARE_TRACE。

第 2次 通过 include/trace/trace_events.h，将其展开成DECLARE_EVENT_CLASS，而在该 头文件中 DECLARE_EVENT_CLASS会被多次展开。

第 3次 通过包含 include/trace/define_trace.h，将其 展开成 DEFINE_TRACE

其中 ， include/linux/和include/trace/define_trace.h必须显示被使用者显式包含。

总结下：

• trace_##name，是放置probe点的函数实现，如果该event enable则调用 注册进来的 trace_event_raw_event_##call

• trace_raw_output_##call，是输出信息的函数实现 （ cat trace时输出）

• trace_event_raw_event_##call， 是 probe函数

（2）trace_##name

细节参见上文宏展开结果。

（3）trace_raw_output_##call

该函数 在 cat trace文件节点的时候会被调用。

（4） trace_event_raw_event_##call

综上，通过上述宏展开，得到：

3.  关键流程梳理

（1） 定义 event

使用 TRACE_EVENT宏 定义 event的原型、信息打印格式等。参见上文描述。

（2） 记录 event

代码中静态埋点，调用trace_##name， 放置 probe点。参见上文描述。

（3） 使能 event

假设 tracefs已经提前挂载好（ 可以通过 cat /proc/mounts | grep tracefs命令查看）

tracefs /sys/kernel/debug/tracing tracefs rw,seclabel,relatime 0 0

对应命令：

echo 1 > /sys/kernel/debug/tracing/events/<one_trace_event>/enable

对应关键代码流程：

将上文描述的展开后的宏里面的trace_event_raw_event_##call 注册到 struct tracepoint_func中进去

（4） 输出 event

对应命令：

对应关键代码流程：

print_trace_fmt函数代码截图：

funcs->trace，参见上文被赋值成trace_raw_output_##call了 。

三、 使用 ftrace event tracing跟踪特定 进程调度原理

本章我们主要介绍手机平台实现精准跟踪特定进程调度使用的一些技巧。因为我们最终还是要 借助 systrace这个ftrace前端，所以简单介绍ftrace相关tag，包括Java 层和 Native层如何使用ftrace接口。同时 我们要简单研究下调度相关的 trace event以及filter功能，这是解决实际问题的关键。

1. Android systrace tag list

使用atrace –list即可 查看所有支持的 tag list。

2.   用户态如何使用 ftrace

有时候我们还要把用户态信息和 内核信息同步起来，可以通过 trace_marker 实现。

（1） 使用 trace_marker

Systrace利用ftrace提供了如下两个接口供用户程序调用：

• Java层：Trace.traceBegin(tag, name)/Trace.traceEnd(tag)

• Native层 ：ATRACE_BEGIN(name)/ATRACE_END()

当然，也可以根据特定 需求，直接利用 systrace现成 的 tag（即还可以使用systrace 设置tag和手动设置sched调度 的 event filfter搭配起来用）。如果想关闭用户态的信息打印也是可以的。

（2） 开关 trace_marker

查看：

cat options/markers

打开：

echo 1 > options/markers

关闭：

echo 0 > options/markers

3. Android Linux 状态

（1）Android 状态转移

图 3-1 Android 进程状态转移

1）Runnable -> Running：就绪态的进程获得了CPU的时间片，进入运行态；

2）Running -> Runnable: 运行态的进程在时间片用完后，必须出让CPU，进入就绪态；

3）Running -> Blocked：当进程请求资源的使用权(如外设)或等待事件发生(如I/O完成)时，由运行态转换为阻塞态；

4）Blocked -> Runnable：当进程已经获取所需资源的使用权或者等待事件已完成时，中断处理程序必须把相应进程的状态由阻塞态转为就绪态。

（2）Linux 原生状态信息

4.  调度相关 events 分析

可以 通过 cat available_events | grep sched:命令 或者 ls events/sched/去查看内核已经实现调度相关 的 events。结合上文的进程状态分析，我们从中挑选events如下：

这些trace events足够我们分析线程级别的调度信息。

5.   event的filter功能

为实现问题进程的跟踪，我们需要使用event的filter功能。

（1）event filter语法简单介绍

field-name relation-operatior value     

• 对于数字域，可以使用操作符==, !=, <, <=, >, >=, &

• 对于字符串域，可以使用==, !=, ~。目前字符串只支持完全匹配，且最多 可以组合 16个条件 。”~”支持 通配符 (*,?)。

例子：

（2）event filter format

可以先通过该event 目录下的 format查看event消息格式。

我们依次分析根据上文所有需要 跟踪的 events，可以根据comm（ 包括 pre_comm，next_comm） 和 PID等设置过滤条件。

剩下 就是把相关 events enable就可以了，细节本文就不展开了。

四、 实际例子

1.  实际问题

我们在实际的项目中曾经遇到过低概率问题，那个问题是相机切换模式时预览卡顿并出现闪退。我们第一反应 肯定是直接打开 systrace去抓取trace回来，但面临个问题：

1）问题低概率出现，复现一次不容易，需要一次复现就抓到问题现场；

2） 抓取 log量还是 过大（即使只用 “sched” 和 “camera”），问题场景对负载敏感；

3）问题复现后，需要手动停止，这块手动操作要到10几秒到1分钟不等，需要抓取log量尽可能短，以便抓到出问题时 的现场，不然 ring buffer被覆盖会导致前功尽弃。

2.  问题分析

问题 关键是要让 ftrace记录时间尽可能长，很自然能想到的措施：

1） 增大 ftrace buffer；

2） 减少 ftrace记录的内容，同时要保证足够问题分析。

虽然该问题概率低，但好消息是只要压测时间足够久，还是能复现出来。通过分析规律，我们发现每次相机切换时，都有 AlgoInterface::init 出现，重点怀疑该对应的进程调度异常，经确认该方法会对应“ APSRoutine ”的进程异常。

所以解决问题的关键就变成：

1） 利用 ftrace event tracing的过滤功能，跟踪“APSRoutine”进程， 具体的 events的filter设置参见上一章内容；

2）要知道对应的用户态操作，所以必须要打开trace_marker开关（但trace_marker不支持过滤功能，这点比较遗憾，不然可以让记录的内容更少）；

3） 在 Java 层 crash的地方加hook，crash时抓取ftrace。

所以做了这样满足上述条件的小工具。后续我们还可以将其完善，做成支持抓取任意Java/Native层特定进程 调度相关 log的功能。

这样 我们就把 ftrace event tracing的原理及一个基于ftrace的小工具解决实际问题的实践介绍完了，由于时间和个人水平有限，难免有出错的地方，如有还请大家帮忙指出。

参考材料

[1]  进程状态的切换，袁辉辉

[2] ftrace 中 eventtracing 的实现原理 ，普侯

[3]  史上最长的宏定义， Kernel Exploring

[4] https://www.kernel.org/doc/html/latest/trace/events.html

长按关注

内核工匠微信

Linux 内核黑科技 | 技术文章 | 精选教程