📚 课程目录第4章 Trace文件的结构

Trace文件结构：读懂ANR的“诊断报告”

说实话，我入行头两年查ANR，看到trace.txt就头疼。密密麻麻的堆栈，一堆看不懂的线程状态和锁标记，根本不知道从哪下手。后来跟着老法师学了一招——把trace.txt当成「案发现场」的嫌疑人关系网络来看，每个线程就是一个人，锁信息和状态就是他当时的动作。今天我就带你把这个思维搭起来。

整体骨架：trace.txt里到底有什么？

一个标准的trace.txt文件，你打开后会发现它大致分成三大块：

文件头——时间、进程名、系统负载等元信息
进程块——每个进程锚点，里面包着一堆线程
线程块——每个线程的详细状态、持有的锁、等待的锁、堆栈

往下拆，线程块又细分为：线程描述行、线程状态、锁信息、堆栈。别急，我一个一个带你看。

我个人经验：好多同学只扫堆栈，线程状态和锁信息一眼带过，结果方向全错。我曾经排查过一个「卡死ANR」，堆栈显示在Binder线程里等消息，折腾半天发现是被另一个线程持锁不释放，主线程在那等锁——这种只能靠锁信息来破案。

先看一个真实的trace片段

品一品这个例子：

----- pid 12345 at 2025-04-01 10:15:30 -----
Cmd line: com.example.myapp
Build fingerprint: 'google/marlin/marlin:10/QP1A.190711.020/5972270:user/release-keys'
ABI: 'arm64'

"main" prio=5 tid=1 Blocked
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x71c0e5f8 self=0x7f91f44c00
  | sysTid=12345 nice=-10 cgrp=default sched=0/0 handle=0x7f928e4000
  | state=R schedstat=( 123456789 1234567 123 ) utm=10 stm=5 core=1 HZ=100
  | stack=0x7f925eb000-0x7f925ed000 stackSize=8MB
  held by thread "pool-1-thread-1" (tid=27)
  waiting for <0x0a6c2c80> (a java.lang.Object) held by thread "binder:12345_3" (tid=12)
  at com.example.MyService.doSomething(MyService.java:50)
  - waiting to lock <0x0a6c2c80> (a java.lang.Object) held by thread "binder:12345_3" (tid=12)
  at com.example.MyService.handleRequest(MyService.java:30)
  at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2045)
  ...
  at android.os.Looper.loop(Looper.java:193)
  at android.app.ActivityThread.main(ActivityThread.java:7382)
  at java.lang.reflect.Method.invoke(Native method)
  at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:492)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:980)

这个块里已经包含了我们能挖的全部线索。下面我拆开讲。

1. 文件头——案发时间与环境

文件开头几行就是案发时的「快照」：

pid 和 Cmd line：出事进程是谁
Build fingerprint：机型、系统版本
ABI：32位还是64位——这个会影响某些native栈的符号解析

这些元信息用来确认环境。我遇到过抓错trace的情况——两个进程同名的测试包崩溃，结果手忙脚乱看了半小时才发现root了自己的app。所以先确认pid是否对得上。

2. 线程状态——线程此刻在干嘛

每个线程第一行就有状态：Blocked、RUNNABLE、WAITING 等。ART虚拟机定义的线程状态其实很多，但trace里常见的就这几个：

trace中显示	实际含义	常见场景
RUNNABLE	正在运行或可运行	确实在干活，或者单核抢占中
BLOCKED	阻塞在锁上	main线程阻塞，是最常见的ANR缘由
WAITING	调用了Object.wait()	等待条件满足，正常并发设计
TIMED_WAITING	调用了sleep/join(wait)	延迟等待，时间到就醒
NATIVE	跑在JNI方法里	底层卡住，比如文件读写、pipe等待
SUSPENDED	被GC或其他暂停	一般不是ANR根源

你看上面那个例子——main线程状态是Blocked，非常直观地告诉我们：它在等锁。

一个小细节：state=R 是内核态调度状态，R表示可运行，和我们trace第一行的语义不同。有些内核日志里也能看到这个字段，别搞混。

3. 锁信息——谁抢了谁的资源

这可能是整个trace文件里最有价值的部分。锁信息一般出现在堆栈前面，有两种写法：

等待锁：waiting to lock <0x0a6c2c80> (a java.lang.Object) held by thread "binder:12345_3" (tid=12) —— 没跑偏，一读就懂：这个线程想拿某把锁，但锁在另一个线程手里。
持有锁：held by thread "pool-1-thread-1" (tid=27) 表示当前线程正抓着锁不放。

这俩一配对，谁持锁、谁等待就全连上了。上面的例子里，main线程(主线程)等锁&<0x0a6c2c80>&，而binder线程12正抱着那锁不放。再看binder线程12的堆栈，就知道它卡在哪儿了。

我建议你画一个「锁依赖图」——从每个线程的等待锁和持有锁信息里提取，就能看到死锁或长时间持锁的链路。我用这个方法搞掉过不少hard case。

注意：trace里堆栈只是采样时刻的快照，时间很短。有时候锁竞争几毫秒就被采样到，不一定都是卡死。需要结合schedstat里的CPU时间判断：如果线程长时间没跑，那才是真梗阻。

4. 堆栈——最终操作痕迹

堆栈从at行开始，从顶到底，从应用代码一直到虚拟机入口。重点关注waiting to lock上面那一两条——那是线程正在执行的同步代码。

上面例子里：

at com.example.MyService.doSomething(MyService.java:50) 就是要调的入口
下一行 - waiting to lock <0x0a6c2c80> 说明正是在那行代码等锁。

经验：很多ANR是「多个线程共用一个锁来读写共享变量」，读也要锁、写也要锁，并发一上来就该ANR了。遇到这种情况，要么用ReadWriteLock，要么减小锁粒度。

5. 整个结构一目了然

我画了张图，把trace.txt的结构分层展示出来，方便你快速定位：

6. 怎么连起来用？一个实战思路

当你拿到一个ANR trace，我建议你按这个顺序扫：

看主线程的第一行——状态是不是 Blocked？如果是，恭喜，锁问题。
找 waiting to lock 后面的锁对象地址，记下来。
全局搜索这把锁，找到所有提到它的行。通常你能看到另一个线程写着 held by 或 waiting to lock 但不同地址。
看那个持锁线程的状态——如果是 RUNNABLE，说明它在运算；如果是 NATIVE，可能是I/O卡了；如果是 BLOCKED，那你可能遇到锁链/死锁。
最后看堆栈确认业务代码。

我回忆起一个案例：App启动ANR，trace显示主线程Blocked等锁，锁被一个叫pool-1-thread-1的线程拿着。但那线程是RUNNABLE，堆栈指向一个JSON解析方法。原来是启动时用线程池去解析大文件，占用共享锁不释放，主线程等那个锁去初始化数据库——无解。最后改成分步加载才搞定。

说白了，trace.txt就是个「钥匙环」，锁信息是钥匙，线程状态是锁孔。你能把这俩对上号，90%的ANR立破。