ANR日志核心:traces.txt

说起ANR调试,有个文件你必须得会看——traces.txt。它就像是事故现场的黑匣子,记录了ANR发生那一瞬间所有线程的堆栈快照。我当年刚入行时,有次线上ANR天天报却死活查不出原因,后来才发现自己压根没读懂traces.txt里的锁信息。嗯,这堂课咱们就把这个黑匣子彻底拆开。

核心认知:traces.txt 不是实时日志,它是系统在检测到ANR时主动dump下来的“定格帧”。你看到的每一行堆栈,都是ANR触发那一刹那线程的执行状态。

traces.txt 在哪?怎么看?

不同Android版本路径稍有差异,但大体都在下面这些位置:

场景路径
普通APP ANR/data/anr/traces.txt
多用户/多进程/data/anr/traces_进程名.txt
低版本(4.4之前)/data/anr/traces_包名.txt

取文件很简单:

adb root
adb remount
adb pull /data/anr/traces.txt .

我个人习惯用Notepad++或者VS Code直接打开,按关键词搜索自己的包名。你想想看,如果一个APP里开了多个进程,traces.txt里可能会夹杂很多系统进程的堆栈,别慌,先定位到你的进程块。

👍 小技巧:用 grep -A 200 "你的包名" traces.txt 快速过滤出相关线程。我在项目里经常这么干。

traces.txt 的结构长什么样?

打开文件,你首先会看到类似这样的头部信息:

----- pid 12345 at 2025-03-20 14:30:15 -----
Cmd line: com.example.myapp
Build fingerprint: 'xxx'
ABI: 'arm64'

紧接着就是各个线程的堆栈。我把核心元素拆成一张图,这样你一眼就能看明白:

traces.txt 关键结构解析 头部信息(PID/时间/进程名) 主线程("main") 堆栈 + 锁状态 + 等待原因 Binder线程池 BLOCKED / WAITING 等 子线程(HandlerThread等) RUNNABLE / SLEEPING at java.lang.Object.wait(Native Method) at android.os.Handler.dispatchMessage - 等待锁 <0x1234> (a MyLock) 锁等待链:线程A→线程B→主线程 关键字段 • "BLOCKED" — 正在等锁 • "WAITING" — 调用了wait()/join() • "TIMED_WAITING" — 带超时等待 • "RUNNABLE" — 实际在CPU上跑或就绪

⚠️ 注意:主线程状态如果显示 "RUNNABLE",不代表它没阻塞。我曾经踩过一个坑——主线程里调用了阻塞式Binder,线程状态就是RUNNABLE,但实际是在内核态等待,这种情况同样会引发ANR。

如何读出ANR的根因?

光看一个线程不够,你得串起来读。我总结了一个三步法:

  1. 找到主线程堆栈。 搜索 "main" 或者 "tid=1",一般在进程块最前面。复制它的调用链。
  2. 检查锁信息。 主线程如果卡在某个锁上,它会打印 "waiting to lock <0x...>",然后下面会告诉你 "held by thread id=xx"。记下那个线程ID。
  3. 追查持锁线程。 跳到那个线程的堆栈,看它在干什么。通常会发现它在做耗时操作(网络请求、大文件读写、死循环)。

举个真实例子。有一次我查到主线程在等锁:

"main" prio=5 tid=1 Blocked
  at com.example.MyClass.doSomething(MyClass.java:50)
  - waiting to lock <0x0b5a> (a java.lang.Object)
  ...
  at android.os.Handler.dispatchMessage(Handler.java:102)
  
  "Binder:12345_2" prio=5 tid=15 Blocked
  at com.example.MyClass.doSomethingElse(MyClass.java:80)
  - waiting to lock <0x0b5a> (a java.lang.Object)
  - held by thread 1

看到了吗?主线程和Binder线程互相等锁!这就是典型的死锁。当时我们团队排查了一下午没头绪,我顺着锁字段一比对,五分钟就定位到了。那之后我养成了习惯——遇到Blocked状态,先查锁持有者。

关键判断准则:

  • 主线程状态是 BLOCKED → 大概率死锁或锁竞争
  • 主线程状态是 WAITING → 很可能在等某个条件变量(回调、广播等)超时
  • 主线程状态是 RUNNABLE → 未必是好的,可能是CPU密集型任务占用了太久

容易被忽略的细节

traces.txt里还有几个“暗坑”,我一个个说:

  • 锁对象地址重复。 同一个0x地址出现在多个线程里,一定是共享锁。如果其中一个线程持有锁后做了大耗时操作,别的线程只能干等。
  • 堆栈不完整。 有时候堆栈只打印到系统框架层(比如Looper.loop),这时你需要结合logcat里的 "DALVIK THREADS" 或者 "art::Thread::Dump" 来补全。我记得有一次ANR堆栈只显示了Handler的dispatchMessage,后来发现是底层So库的JNI调用占了200ms。
  • Binder线程数量。 tracess.txt里如果看到大量Binder线程都卡在同一个地方,那肯定是有个Binder服务端响应慢了。我曾经在项目里遇到过ContentProvider的query耗时超过25秒,所有Binder线程集体排队等待。

💡 高阶用法:把traces.txt喂给一些在线分析工具(比如开源的anr-trace-visualizer),可以自动画线程时间线。我个人更习惯手动撸,因为能注意到工具忽略的细节。

总结一下

traces.txt就像手术刀,切开了ANR那一刻的现场。你只需要盯着主线程的堆栈和锁等待链,基本都能揪出真凶。下次再遇到ANR,别急着重启,先pull一份traces.txt,说不定五分钟就搞定了。