Linux hung_task故障分析：用ftrace与trace-cmd构建Flight Recorder

第7章：hung_task Flight Recorder——用ftrace与trace-cmd自动保留异常现场

0. 源码基线、工具边界与安全说明

本文以内核 Linux v6.1 为基线，对应上游标签提交830b3c68c1fb1e9176028d02ef86f3cf76aa2476。主要参考：

• Documentation/trace/ftrace.rst：tracefs、buffer、snapshot、clock和instance；
• Documentation/trace/events.rst：event与过滤；
• Documentation/trace/tracepoints.rst：内核tracepoint模型；
• kernel/trace/trace.c：tracing_on与tracing_off()等实现；
• kernel/trace/trace_events_trigger.c：event trigger；
• include/trace/events/：v6.1 trace事件定义。

trace-cmd属于用户态工具，有独立版本演进。本文给出的是命令骨架；实际使用前必须检查目标机的trace-cmd --help、trace-cmd list -e以及tracefs文件。Tracing会改变时序和内存占用，所有配置先在可恢复测试环境验证。

7.1 为什么需要Flight Recorder

hung_task检测关注长期无进展，告警可能在初始故障发生几十秒甚至几分钟后出现。真正关键的命令提交、DMA启动、中断丢失或错误状态迁移早已过去。

Flight Recorder平时只在固定内存中循环保存最近历史，异常发生时冻结或复制缓冲区，弥合“故障发生”和“检测到故障”之间的Observability Gap。

7.2 为什么事后开始trace太晚

T0         command submit
T0+20ms    expected IRQ missing
T0+100ms   task sleeps in D
T0+120s    khungtaskd warning

在最后一步才启动trace，只能看见告警之后。正确策略是故障前已开始记录，并尽可能在driver timeout或首个异常状态处冻结，而不是等hung_task阈值到期。

7.3 ftrace Ring Buffer是什么

ftrace把事件写入内核ring buffer。buffer容量固定，新记录持续推进写位置；在overwrite模式下，空间不足会覆盖最老数据。因此它保存的是“最近一段历史”，而不是无限日志。

trace输出是buffer内容的视图，读取、清空、关闭写入是不同操作，不能混为一谈。

7.4 Ring Buffer为什么适合异常诊断

相比长期把所有事件写入文件，内存ring buffer具有固定容量、无需持续存储I/O、可在异常点冻结的特点。代价是历史长度有限，异常冻结过晚会覆盖根因事件。

Flight Recorder设计目标不是“保存一切”，而是用有限开销保存足以回答当前依赖链问题的历史。

7.5 per-CPU Ring Buffer

ftrace通常为各CPU维护buffer，降低多CPU写入同一全局结构造成的竞争。事件天然携带CPU上下文，离线时再按时间戳合并。

这也意味着高事件率CPU可能比其他CPU更快覆盖历史，不能只用系统总buffer除以总事件率粗略判断每个CPU窗口。

7.6 overwrite模式

tracefs的options/overwrite控制buffer满后的策略：

overwrite启用：覆盖最老记录，持续保留最近历史
overwrite关闭：buffer满后不再接受新记录，可能丢失后续事件

Flight Recorder通常选择overwrite，因为未知故障发生时间，需要始终保留最近窗口。但冻结后必须尽快导出，避免误操作重新开启写入。

7.7 buffer_size_kb

buffer_size_kb用于设置每CPU trace buffer请求大小，实际值可能因页大小和实现取整。示例：

cd /sys/kernel/tracing
cat buffer_size_kb
echo 4096 > buffer_size_kb

4个在线CPU、每CPU约4 MiB时，总分配量大约16 MiB，还需考虑元数据、snapshot备用buffer和instance。

7.8 buffer_total_size_kb

buffer_total_size_kb用于观察当前tracing instance的buffer总量。它比简单的CPU数 × buffer_size_kb更适合核对实际分配，但仍要结合在线CPU和snapshot/instance额外占用理解整机成本。

7.9 怎样估算History Window

粗略关系：

单CPU History Window ≈ 该CPU buffer字节数 / 该CPU事件字节率

估算只用于初始配置。最终要在真实业务负载下读取trace或per-CPU stats，比较最老与最新事件时间戳。目标窗口必须覆盖“预计异常前兆到冻结动作”的最大间隔。

7.10 tracing_on是什么

每个tracing instance有tracing_on控制是否允许继续记录：

echo 1 > tracing_on   # 允许写入
echo 0 > tracing_on   # 停止写入

它不是event选择器。事件可以仍处于enable状态，而instance暂时不向buffer写入。

7.11 tracing_on=0发生什么

写0会冻结现有buffer内容，通常不会清空历史；因此之后仍可读取trace或使用工具导出。

“停止记录”不等于绝对零开销：已启用的tracepoint静态分支、触发器和工具状态仍可能有不同程度成本。若长期停用，应按目标设计决定是否同时disable events。

7.12 tracing_off()是什么

内核代码可以调用：

tracing_off();

它从内核侧关闭top-level tracing，适合在检测到确定异常时快速冻结buffer。直接把它加入通用错误路径是代码行为变化，应审查并仅用于调试或明确的产品诊断设计。

7.13 traceoff Trigger是什么

ftrace event trigger可以在某个已存在event发生时执行traceoff。典型接口位于：

events/<system>/<event>/trigger

概念命令：

echo 'traceoff' > events/<system>/<event>/trigger

可结合过滤条件缩小触发范围。具体trigger语法和能力必须读取目标机该文件及v6.1文档；普通hung_task printk本身不会自动成为event trigger。

7.14 snapshot是什么

snapshot为当前instance维护一份快照buffer。触发snapshot时保存当前历史，主buffer随后可继续接收新事件，从而同时保留“触发前历史”和“触发后过程”。

snapshot需要相应内核配置、内存和接口支持；应先确认/sys/kernel/tracing/snapshot存在。它不是把数据自动写到磁盘。

7.15 snapshot和traceoff区别

traceoff：停止当前buffer继续变化，保留单一冻结现场
snapshot：保留触发时历史，同时允许主buffer继续记录

traceoff更简单、内存更少且不怕触发后覆盖；snapshot适合还需观察恢复、reset或后续阶段，但必须单独导出snapshot和当前buffer。

7.16 hung_task应该选traceoff还是snapshot

只关注首次异常、系统可立即采集时，优先traceoff。既要保留异常前历史，又要观察自动恢复过程时选择snapshot。

真正关键是触发时机：driver在5秒命令超时处冻结，通常比120秒后的hung_task告警更能保留根因窗口。

7.17 Flight Recorder需要抓哪些事件

事件集合由Dependency Chain决定：

所有场景基础：sched
Completion由硬件产生：irq
Completion由worker产生：workqueue
存储等待：block + writeback/vmscan（按需）
网络文件系统：rpc/nfs/network（按需）
自有设备：driver custom tracepoints

先写调查问题，再添加能够回答它的事件。

7.18 sched_switch

它能显示任务何时切出和切入、切出时的prev_state以及所在CPU。对Waiter重点寻找：最后一次运行、何时以睡眠状态切出、之后是否重新切入。

prev_state要按目标内核事件格式解释，不能只凭单个字母推断全部内部状态。

7.19 sched_waking与sched_wakeup

它们提供唤醒路径的重要时间点，可帮助区分：

从未发生wake
wake发生但任务迟迟没有运行
wake后运行但condition仍不满足又睡眠

事件字段和语义需结合v6.1 trace format；仅看到wakeup不证明业务条件已经成立。

7.20 irq_handler_entry与irq_handler_exit

这两个事件回答预期硬中断是否进入、退出以及大致处理时长。它们不能自动证明ISR执行到哪个分支，也不能证明设备完成状态正确。

因此硬件Completion问题通常还要增加驱动状态或自定义tracepoint。

7.21 softirq

网络接收、tasklet或其他延后处理依赖softirq时，可按需启用softirq_raise、softirq_entry和softirq_exit。这样可以区分硬中断已到但后续softirq未运行，还是整个中断链未发生。

7.22 block_rq_issue与block_rq_complete

块事件可验证request是否发出以及是否完成，并计算可观察的I/O延迟。事件名称和字段会受内核配置与版本影响，先查看：

trace-cmd list -e 'block:*'

issue没有complete是重要证据，但还要考虑采集窗口、request重排、merge和ID关联。

7.23 Workqueue

常用事件包括workqueue_queue_work、workqueue_execute_start和workqueue_execute_end。它们区分：work未入队、已入队未执行、正在执行未结束。

要确认work地址、函数和目标queue，避免把不同实例的相同work函数混在一起。

7.24 Timer

超时、重试和恢复由timer驱动时，可按需启用timer事件，验证timer是否启动、到期和执行。timer到期不等于回调内恢复动作成功，因此关键分支仍建议加入自定义事件。

7.25 NFS与RPC

只有分类已指向网络文件系统时才加入nfs/rpc事件，并先查看目标机available_events。需要关联RPC task、xid、server和重传，单纯增加所有网络事件会迅速耗尽buffer。

7.26 Driver Custom Tracepoint

自有驱动应围绕协议状态机提供结构化事件：

CMD_SUBMIT、DMA_START、FW_SEND、FW_ACK
IRQ_STATUS、CMD_COMPLETE、TIMEOUT、RESET

tracepoint比大量printk更易过滤和跨CPU排序，但它也有维护成本；字段应稳定、精简，避免把敏感数据或巨大buffer写入事件。

7.27 Trace Event设计原则

一个好事件应回答一次明确状态转换：谁、对哪个对象、从什么状态到什么状态、结果是什么。建议包含：

device/queue ID
request/command ID
PID/TID（若有业务意义）
state/result/error
关键长度、channel或descriptor ID

不要依赖指针作为跨重启永久ID；指针可用于同一次trace内部关联，但对象复用需要结合时间和generation。

7.28 怎么关联Command ID或Request ID

所有跨层事件共享同一ID：

SUBMIT id=42 -> DMA id=42 -> IRQ id=42 -> COMPLETE id=42

如果硬件只返回tag或queue slot，就在提交时记录software request ID到hardware tag映射，在完成时同时输出两者。

7.29 怎么关联PID或TID

ftrace事件本身带有当前上下文信息，但IRQ发生时current未必是原始提交者。Driver事件应在请求对象中保存并输出submitter PID/TID或业务ID，不能用ISR执行时的current代替提交任务。

7.30 怎么关联CPU

CPU字段用于连接sched、IRQ和driver事件，并发现迁移。由于buffer是per-CPU，跨CPU合并依赖trace clock；相同时间戳附近应结合因果ID，而不是只靠显示顺序判断先后。

7.31 怎么关联IRQ

记录Linux IRQ number、设备/queue/vector以及ISR内读取的状态位。共享IRQ场景下，“handler entry”只证明该IRQ线被处理，不证明目标设备声称中断，必须结合状态位或driver trace。

7.32 怎么从hung_task触发traceoff

可选层次：

最优：靠近First Non-progress Point的driver timeout/error触发
其次：现有trace event + 过滤器 + traceoff trigger
再次：内核hung_task路径加入专用hook
最晚：userspace观察日志后写tracing_on=0

v6.1默认hung_task告警不会替你冻结任意自建instance。触发方案必须显式设计和测试。

7.33 内核触发方式

在driver或内核明确异常点调用tracing_off()响应快，但它可能影响全局top instance，而且与自建instance关系需按实现核实。产品化方案更适合使用专用trace event，再由instance event trigger执行动作。

修改kernel/hung_task.c直接冻结trace属于定制内核行为，也可能在120秒后才触发，未必保存最早事件。

7.34 Userspace触发方式

守护进程可监控kmsg、uevent或设备健康接口，检测异常后写目标instance的tracing_on=0，再导出。优点是无需内核改动；缺点是调度、日志传递和脚本处理存在延迟，旧事件可能继续被覆盖。

脚本还需处理多次触发、权限、存储空间和服务重启。

7.35 Event Trigger方式

已有错误/超时trace event时，可向其trigger文件配置traceoff或snapshot，并用event filter限定设备、request或错误码。优势是触发发生在内核事件点附近。

应先用测试event验证trigger是否作用于预期instance、能否一次触发、如何清除配置以及快照是否可读。

7.36 trace-cmd start

trace-cmd start配置并启动内核tracing，但不持续把事件流写成最终trace.dat，适合Flight Recorder。概念命令：

trace-cmd start \
  -e sched:sched_switch \
  -e sched:sched_waking \
  -e sched:sched_wakeup \
  -e irq:irq_handler_entry \
  -e irq:irq_handler_exit

buffer大小、clock、过滤和instance参数应根据所装trace-cmd版本显式配置并核对。

7.37 trace-cmd stop

trace-cmd stop停止tracing但不以清空buffer为目的，因此可以在后续执行extract。它与内核trigger冻结的区别在于控制路径和延迟：命令发出前事件仍可能继续写入。

不要在extract前执行trace-cmd reset或向trace文件写空操作，否则可能破坏现场。

7.38 trace-cmd extract

trace-cmd extract从现有内核buffer生成trace.dat，通常用于start -> 异常 -> stop/traceoff -> extract流程。导出后可用：

trace-cmd report trace.dat

或KernelShark查看。snapshot和自定义instance的导出选项取决于trace-cmd版本，应提前演练，不能等线上故障后才研究命令。

7.39 record和start/extract区别

trace-cmd record负责启动、收集并在结束时写出文件，适合有明确开始/结束的实验；Flight Recorder更希望事件常驻内核固定buffer，只在异常后落盘，因此通常使用start和extract组合。

二者并非谁绝对更好，选择依据是采集窗口、持续时间、存储写入和触发方式。

7.40 怎么检查Ring Buffer overrun

查看目标instance的：

cat per_cpu/cpu0/stats

关注entries、overrun、dropped events、bytes、oldest event ts等目标内核实际提供字段。overwrite模式中overrun增长表示旧记录被覆盖，是设计行为；真正指标是最老事件是否仍早于所需故障前兆。

7.41 怎么控制Tracing开销

按优先级优化：

1. 只启用能验证Dependency Chain的tracepoint；
2. 使用event filter缩小设备、PID或状态；
3. 减少事件字段和高频事件；
4. 调整每CPU buffer，不盲目扩大；
5. 在真实负载下测量CPU、延迟、内存与窗口；
6. 记录丢失和覆盖统计。

必须同时比较Tracing关闭与开启的业务基线。

7.42 为什么不要全开function tracer

全系统function/function_graph事件率极高，会增加执行开销并让短buffer只剩极短历史。hung_task通常需要几十秒甚至更长窗口，因此应坚持event-first。

必须使用function tracer时，用set_ftrace_filter等机制限制到少量关键函数，并实测开销和覆盖窗口。

7.43 Trace Clock怎么选

trace_clock列出可用时钟，方括号表示当前选择。local时钟开销低，但跨CPU排序特性可能不如global类时钟直观；global通常更适合跨CPU因果分析，但可能有额外开销。

选择前先查看目标机说明，切换后在多CPU测试中验证单调性和成本。一次证据集必须记录使用的clock。

7.44 Trace Instance是什么

tracefs的instances/允许创建独立tracing instance，每个instance拥有自己的buffer、events、filters和tracing_on。实例隔离能防止其他调试会话修改主Flight Recorder配置。

并非所有tracer和功能都可在所有instance完全独立使用，需按v6.1文档和目标配置验证。

7.45 为hung_task单独建Instance

概念流程：

cd /sys/kernel/tracing
mkdir instances/hung
cd instances/hung
echo 4096 > buffer_size_kb
echo 1 > options/overwrite
# 按需启用events与filters
echo 1 > tracing_on

删除instance是破坏现场的操作，只能在导出完成并确认不再需要后执行。工具接管instance时避免同时手写相同控制文件。

7.46 如何离线重建Dependency Timeline

先选锚点：driver timeout、traceoff触发event或hung告警。然后向前按request ID寻找submit，向后寻找wake/reset；不要从几十万条事件第一行顺序阅读。

输出应是时间轴与依赖图的结合，每个“缺失事件”都要先排除buffer窗口不足、event未启用、filter不匹配和trace丢失。

7.47 Scheduler Timeline

对Waiter记录：

最后一次switch in
提交请求
以何种prev_state switch out
是否出现sched_waking/wakeup
是否再次switch in
是否醒来后再次睡眠

这能区分Missing Wakeup、Runnable但调度延迟和condition不成立的重复等待。

7.48 IRQ Timeline

从submit或DMA start开始，寻找预期IRQ的entry/exit，再用driver event确认ISR状态分支：

SUBMIT -> HW_START -> IRQ_ENTRY -> IRQ_STATUS -> COMPLETE

只有IRQ entry而没有目标状态，可能是共享中断或错误状态；完全无IRQ则继续检查设备是否完成、mask和routing。

7.49 IO Timeline

以request标识关联：

bio/request created -> block_rq_issue -> driver dispatch
-> device completion -> block_rq_complete -> upper-layer wake

issue存在而complete缺失只是“完成未被观测”，还要验证trace窗口、ID关联、queue状态和设备超时日志。

7.50 Driver Timeline

理想事件：

T0 CMD_SUBMIT id=42
T1 DMA_START id=42
T2 IRQ_STATUS id=42 done=1
T3 CMD_COMPLETE id=42
T4 sched_waking waiter

异常中最后一个已确认事件与第一个预期但缺失的事件，限定了First Non-progress区间。

7.51 将多个Timeline合并

使用统一clock和request ID，把sched、driver、IRQ、block、firmware日志对齐：

T0 CPU1 Task提交cmd=42
T1 CPU1 Task以D状态切出
T2 CPU2 DMA启动
T3 预期IRQ缺失
T4 Driver timeout触发traceoff

若firmware时钟不同，需要同步点或显式说明只能确定局部顺序，不能伪造绝对时间对齐。

7.52 本章推荐配置

一个起点而非万能配置：

独立hung instance
overwrite enabled
按实测配置per-CPU buffer
合适的跨CPU trace clock

基础事件：
sched_switch / sched_waking / sched_wakeup
irq_handler_entry / irq_handler_exit

按分类增加：
workqueue、block、vmscan/writeback、rpc/nfs
driver submit/complete/timeout/reset自定义事件

触发：优先driver timeout或过滤后的错误event

上线前必须验证history window、性能开销、触发可靠性和导出脚本。

7.53 本章实验

7.53.1 基础Flight Recorder

在测试机只启用sched与IRQ事件，运行负载后手工写tracing_on=0，确认旧数据保留并能导出。

7.53.2 测量History Window

分别在空闲和真实压力下运行30、60、120秒，读取per-CPU stats和最老/最新时间戳，记录各CPU实际窗口。

7.53.3 对比事件集合

依次测试sched、sched+irq、sched+irq+block，测量事件率、overrun、CPU/延迟开销，选择满足目标窗口的最小集合。

7.53.4 验证snapshot

确认接口和配置存在后，在触发点执行snapshot，验证snapshot历史固定而主buffer继续变化，并提前练习两个buffer的导出方法。

7.53.5 Completion Hang

在具备安全清理的测试模块中故意不complete()，用driver事件记录submit和timeout，捕获最后一次sched switch及缺失wake。不要在生产系统制造永久D状态。

7.53.6 自动触发

为测试timeout event配置过滤与traceoff trigger，验证只冻结目标设备/请求，重复触发不会破坏第一份现场。

7.53.7 离线还原

用trace-cmd report或KernelShark建立Scheduler、IRQ和Driver三个时间轴，标出最后已确认事件、首个缺失预期事件及证据限制。

7.54 工程意义

Flight Recorder把偶发、不可即时复现的hung_task从“只有最终栈”提升为“具有故障前历史”。Dependency Graph说明谁依赖谁，Timeline说明依赖从何时停止推进，两者结合才能建立强因果证据。

它也要求产品化设计：内存预算、低开销事件、稳定ID、一次性触发、持久化、隐私和自动清理都必须纳入方案。

7.55 常见误区

误区1：hung_task出现后再开始trace

关键前史通常已丢失。

误区2：tracing_on=0会清空buffer

它用于停止继续写入，已有记录通常保留。

误区3：停止tracing等于绝对零开销

已配置event、trigger和工具状态仍可能有成本，需实测。

误区4：buffer越大越好

还要考虑每CPU内存、snapshot、instance和目标窗口。

误区5：event越多越好

高事件率会增加开销并更快覆盖真正需要的历史。

误区6：function_graph适合长期全开

通常数据量过大；Flight Recorder应优先语义tracepoint。

误区7：snapshot和traceoff相同

前者保存触发历史并继续记录，后者冻结当前buffer。

误区8：trace-cmd stop后不能extract

stop的Flight Recorder用途正是停止写入后再extract；不要先reset。

误区9：overrun代表采集失败

overwrite模式允许覆盖；判断标准是所需History Window是否仍在。

误区10：IRQ entry证明目标设备完成

共享IRQ和错误状态都可能产生entry，需检查driver状态位和Completion事件。

误区11：缺失事件必然表示事件没有发生

还要排除event未启用、filter错误、窗口覆盖和记录丢失。

7.56 博客总结

hung_task的检测延迟决定了事后启动trace通常过晚。有效方案是在故障前使用低开销tracepoint持续写入per-CPU ring buffer，并在接近First Non-progress Point的driver timeout或错误event处执行traceoff或snapshot。traceoff冻结唯一现场；snapshot保留触发前历史并允许继续观察恢复过程。

事件集合应围绕Dependency Chain选择：sched重建Waiter睡眠与唤醒，IRQ确认硬件中断，workqueue确认Producer是否执行，block确认请求issue/complete，自定义driver tracepoint以request ID连接submit、DMA、IRQ、complete、timeout和reset。buffer大小最终要用真实负载下的History Window验证，而不是凭容量猜测。

离线分析通过统一clock和对象ID合并Scheduler、IRQ、I/O与Driver Timeline。Dependency Graph回答“谁依赖谁”，Temporal Timeline回答“从什么时候开始不推进”，二者共同把单条Call Trace升级为可验证的Root Cause证据。

7.57 学完检查题

1. hung_task为何天然存在Observability Gap？
2. Flight Recorder与持续写文件有什么区别？
3. per-CPU buffer解决什么问题，又带来什么分析要求？
4. overwrite和非overwrite模式分别如何处理buffer满？
5. buffer_size_kb为什么不能简单理解为整机总大小？
6. snapshot会增加哪些内存成本？
7. 怎样在真实负载下测量History Window？
8. 为什么各CPU窗口可能不同？
9. tracing_on与event enable有什么区别？
10. 写0后为什么还能导出旧记录？
11. tracing_off()适合放在哪类异常点？
12. 为什么默认hung_task告警不会自动冻结自建instance？
13. event trigger依赖什么前提？
14. snapshot与traceoff如何选择？
15. 为什么driver 5秒timeout优于120秒hung告警触发？
16. sched_switch能说明哪些事实？
17. wakeup发生但任务未运行可能意味着什么？
18. wakeup后再次睡眠又意味着什么？
19. IRQ entry为什么不等于目标设备完成？
20. softirq事件适合哪类完成路径？
21. block issue/complete缺一条时应先排除什么采集问题？
22. workqueue三个关键事件如何区分不同停滞阶段？
23. Driver tracepoint应包含哪些关联字段？
24. 为什么ISR中的current不能代替原提交者PID？
25. 指针为什么不适合作为跨重启永久ID？
26. 多CPU事件为什么需要合适trace clock？
27. Userspace触发冻结的主要风险是什么？
28. 内核直接tracing_off()为何可能影响全局调试？
29. trace-cmd start与record适用场景有何不同？
30. extract之前为什么不能reset？
31. per-CPU stats中的overrun应如何解释？
32. 如何控制trace开销并验证结果？
33. 为什么Flight Recorder坚持event-first？
34. Trace instance解决什么隔离问题？
35. instance是否保证所有tracer能力完全独立？
36. 离线分析为何先找锚点而不是从第一条事件看起？
37. Scheduler Timeline如何区分Missing Wakeup和调度延迟？
38. IRQ Timeline还需要什么driver证据？
39. IO Timeline如何关联同一request？
40. First Non-progress区间怎样从Driver Timeline获得？
41. firmware时钟无法对齐时应怎样表达证据？
42. 最小基础事件集合包含什么？
43. 哪些场景需要增加block事件？
44. 哪些场景需要增加vmscan/writeback事件？
45. 自动trigger为什么要测试重复触发？
46. 缺失trace event为何不自动等于事件没有发生？
47. Dependency Graph与Timeline分别提供什么证据？
48. 如何设计request ID贯穿host、firmware与hardware tag？
49. 如何验证Flight Recorder没有显著改变故障时序？
50. 你能否为一个“Task等待DMA Completion”的场景设计事件、buffer、trigger、导出和离线分析完整方案？

下一章将使用一份完整Case Study，把hung日志、源码、Wait Object、Dependency Chain和Flight Recorder Timeline组合起来，从原始症状一直推导到Root Cause、修复与回归验证。