📚 课程目录第4章 trace文件结构解析

trace 文件结构解析

拿到一份 ANR trace，很多人第一反应是「看最上面那个线程在干嘛」。其实啊，trace 文件就像一份「事故现场勘察报告」，里面藏着大量关键信息。我这些年排查 ANR，90% 的根因都藏在 trace 的结构细节里。今天咱们就来拆一拆这个文件，看看每个字段到底在说什么。

trace 文件长什么样？

一份典型的 traces.txt，开头会有一段系统信息，然后按线程分组。每个线程从 "----- pid xxx" 开始，到下一个线程或文件结束。我习惯先扫一眼 header，再聚焦到主线程。

----- pid 12345 at 2023-12-01 14:30:00.789 -----
Cmd line: com.example.myapp
Build fingerprint: 'google/...'
ABI: 'arm64'
...
"main" prio=5 tid=1 Sleeping
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x...
  | sysTid=12345 nice=0 cgrp=default sched=0/0 handle=0x...
  | state=S schedstat=( 123456 789012 100 ) utm=50 stm=30 core=4
  at java.lang.Thread.sleep(Native method)
  at java.lang.Thread.sleep(Thread.java:373)
  at android.os.SystemClock.sleep(SystemClock.java:120)
  - locked <0x0a3b4c5d> (a java.lang.Object)
  at com.example.myapp.MainActivity.onClick(SourceFile:42)
  ...

上面这个代码块就是 trace 的标准骨架。接下来我们逐块解析。

Header 区：第一手的线索

header 里最有用的是 Cmd line 和 Build fingerprint。Cmd line 告诉你哪个进程出事了，fingerprint 可以判断系统版本。我曾经遇到过一个案例，两个包名相似的进程互相抢锁，一看 header 里 pid 相同，才发现是同一个进程的两个线程——差点被误导。

另外，header 末尾有时会打印 DALVIK THREADS: 或 ART THREADS:，这个标记表明运行时环境，对解读锁信息有影响。

线程状态：一眼判断 ANR 性质

状态标记	含义	常见根因
Running	线程正在执行代码	CPU 被长时间占满（死循环、大量计算）
Sleeping	主动调用 sleep / wait / join	在主线程调用 Thread.sleep() / wait()
Blocked	等待获取锁（synchronized 或 ReentrantLock）	死锁、锁竞争、持有锁线程挂起
Waiting	等待条件满足（wait / park）	等待队列过长、通知丢失
Native	正在执行 JNI 调用	native 层卡住（Binder 超时、驱动阻塞）

很多新手只看线程名称，忽略了 state。我建议你第一眼就盯着 state 列——是 Sleeping 还是 Blocked，排查方向完全不同。

堆栈帧：谁在占用时间

堆栈帧从 at 开始，从最顶层（当前执行点）往下到入口。注意看最顶层的那个 at 如果是 native 方法，通常是在等待系统响应。我们在实际项目里排查过一条典型 trace：

  at com.android.internal.os.BinderInternal.joinThreadPool(Native method)
  at android.os.Binder.execTransactInternal(Binder.java:1234)
  at android.os.Binder.execTransact(Binder.java:1178)

这种堆栈表明线程在 Binder 线程池中空闲，不是 ANR 的根源。真正要警惕的是主线程堆栈里出现 onClick、onCreate 等应用层调用，后面跟着 sleep 或 wait。

  关键原则：看堆栈时关注「线程当前停在哪」，然后逆着调用链往上找「谁调了它」。主线程堆栈最深的那个应用层方法，极可能是 ANR 的触发点。

锁信息：死锁和锁竞争的证据

锁信息一般以 - locked、- waiting on、- waiting to lock 开头。举个例子：

  - locked <0x0a3b4c5d> (a java.lang.Object)
  - waiting to lock <0x0e1f2a3b> (a android.view.ViewRootImpl)

这说明当前线程持有了第一个锁，正在等待第二个锁。如果另一个线程也拿着第二个锁在等第一个锁——恭喜你，找到了死锁。

我曾经在一个多线程下载场景里，主线程和下载线程互相持有了对方需要的锁。关键就是 trace 里两个线程的 waiting to lock 指向了对方持有的对象地址。把这个对照表列出来，死锁一目了然。

小技巧：记下锁对象的地址（如 0x0a3b4c5d），然后全文搜索这个地址，就能找到是哪个线程持有了它。这是排查锁竞争最快捷的方法。

CPU 时间：判断是 CPU 繁忙还是 IO 阻塞

CPU 时间信息在 schedstat=( ) utm= stm= core= 这一行。参数含义：

字段	含义	典型值
schedstat	( CPU时间(纳秒) 等待时间(纳秒) 上下文切换次数 )	utm=50 stm=30 表示用户态 50ms，内核态 30ms
utm	用户态 CPU 时间 (ms)	越大越可能是应用层代码计算量过大
stm	内核态 CPU 时间 (ms)	大时可能涉及系统调用、IO、Binder 驱动
core	最后运行在哪个 CPU 核心	有助判断是否跨核调度

如果你看到 utm 很大（比如几百毫秒到几秒），而 stm 很小，那问题大概率是应用层计算消耗了 CPU。反之，如果 stm 很大，要怀疑系统调用或 Binder 通信。

注意：schedstat 中的 CPU 时间是累计值，不是瞬时值。你需要结合 ANR 触发点前后的变化来判断。只凭一个快照有时会误判，最好对比多个 trace 的 schedstat 差异。

综合案例分析

我记得有一次线上 ANR，主线程 trace 显示：

state = Blocked
堆栈顶是 Object.wait()
等待锁 0x12345678
schedstat 显示 utm=2, stm=98

从 stm 高达 98ms 和 Blocked 状态，我立刻判断是 Binder 通信卡住了。搜索锁地址发现被另一个 Binder 线程持有，那个线程正在等待网络 IO。最终解决是在 Binder 线程中加了超时机制。你看，只要结构化地解析每个字段，根因就藏在这些数字和地址里。

总结一下我个人的解析流程：先看 Header 确认进程，再看主线程 state，然后读堆栈帧，接着查锁关系，最后用 CPU 时间做佐证。这套方法帮我快速定位了不下 50 个 ANR。你也试试看。