📚 课程目录第3章 ANR日志体系总览

ANR日志体系总览

说到ANR分析，我第一个想到的就是三件套：traces.txt、logcat 和 dumpsys。这三样东西就像案发现场的三种记录——哪个都不能少。

可能你会问：“系统都帮我们打印了，直接看不行吗？” 嗯，如果只盯着某一项看，很容易漏掉关键线索。我自己的习惯是：先把三份材料都拉到面前，再交叉比对。今天我们就挨个拆开，看看它们各自藏了什么秘密。

核心认知：ANR 日志是分散的——traces.txt 管线程堆栈，logcat 管事件日志，dumpsys 管系统状态。组合起来才能还原现场。

1. /data/anr/traces.txt — 线程堆栈的“验尸报告”

这个文件我把它叫做“第一现场”。每次 ANR 发生后，系统会 dump 出所有线程的堆栈信息。说白了，就是告诉你是谁在哪个函数里卡住了。

打开 traces.txt，你会看到这样的结构：

----- pid 12345 at 2025-01-10 14:30:00 -----
Cmd line: com.example.app

"main" prio=5 tid=1 Blocked
  at java.lang.Object.wait(Native Method)
  - waiting on <0x12345678> (a java.lang.Object)
  at com.example.MainActivity.onTouchEvent(MainActivity.java:56)
  - locked <0x87654321> (a java.util.ArrayList)
  ...

"Binder:12345_2" prio=5 tid=8 Native
  ...

这里有几个关键信息：

pid 和包名：确认是哪个进程的 ANR。
线程状态：Blocked、Waiting、Runnable、Native。我最关注 Blocked，它背后往往有死锁。
锁对象地址：locked <0x...> 和 waiting on <0x...>。我曾经碰到过一个案例，两个线程互相持有对方需要的锁，都在 Blocked，一看地址就明了了。
堆栈调用链：从最顶层往下看，找到入口点。通常是主线程触发了耗时操作。

个人小技巧：不要只看主线程。有时候是子线程长时间占用锁，导致主线程拿不到。我遇到过好几次，都是因为后台线程持有锁做大量 I/O，结果主线程 wait 超时。

2. logcat 中的 ANR 信息 — 事件的“时间线”

traces.txt 只告诉你“谁卡住了”，但 logcat 告诉你“什么时候卡住的”以及“系统当时的反应”。

搜这几个 tag：

ANR in：直接打出 ANR 的进程名。
am_anr：系统上报 ANR 事件的日志。
CPU usage：ANR 前后的 CPU 负载，用来判断系统是否超载。
Dispatching timeout：输入事件的超时。
Executing service timeout：前台服务执行超时。

举个实际日志片段：

01-10 14:30:00.123  4567  8910 I am_anr : [0,12345,com.example.app,917291452,DISPATCH,Input dispatching timed out]
01-10 14:30:00.124  4567  8910 I cpu     : Total CPU load: 95% (user 70%, kernel 25%)
01-10 14:30:00.125  4567  8910 I cpu     : CPU usage from 0ms to 5000ms later:
01-10 14:30:00.126  4567  8910 I cpu     :   com.example.app: 80% = 50% user + 30% kernel
01-10 14:30:00.127  4567  8910 I cpu     :   system_server: 5% = 3% user + 2% kernel
01-10 14:30:00.128  4567  8910 I cpu     :   ...

看到了吗？CPU 被应用自己吃掉了 80%，这就有意思了。到底是哪个线程吃掉了 CPU？这时候回头去看 traces.txt 里那个 Runnable 状态的线程，它的堆栈很可能在做循环运算或死循环。

注意：logcat 是环形缓冲区，ANR 发生前的一段日志可能已经被冲掉了。我曾经踩过这个坑——线上设备 logcat 默认 buffer 只有 64KB，一旦崩溃后捕获日志往往不全。我会在开发阶段把 logcat buffer 调到 8MB，或者直接抓取 logcat -b main -b system -b events 的持久化日志。

3. dumpsys 输出 — 系统的“体检报告”

这个命令能拿到系统级的快照。我个人分析 ANR 时必看的几个子命令：

dumpsys 子命令	看什么
`dumpsys cpuinfo`	各进程 CPU 占用，包括内核态、用户态
`dumpsys meminfo`	PSS、RSS、Heap 使用，检查是否内存泄漏
`dumpsys diskstats`	磁盘 I/O 负载，经常被忽略的 ANR 原因
`dumpsys window`	当前窗口状态，用来确认前台界面是否响应
`dumpsys activity processes`	进程 LRU 列表、oom_score_adj，判断是否被系统限杀了

这里我重点聊聊 dumpsys cpuinfo。它给出的信息比 logcat 更细粒度，能看到每个线程的 CPU 消耗。举个例子：

Load: 5.2 / 4.2 / 3.1
CPU usage from 0ms to 2000ms later:
  12% 12345/com.example.app: 8% user + 4% kernel / faults: 120 minor
    20% 12345/Binder:12345_2: 18% user + 2% kernel
    10% 12345/AsyncTask #1: 9% user + 1% kernel
  3% 4567/system_server: 2% user + 1% kernel

看到没有？Binder 线程占 20% 的 CPU，并且是用户态高，可能在做密集计算或序列化。结合 traces.txt 里这个线程的堆栈，就能定位到具体函数。

  我的经验法则：如果 dumpsys cpuinfo 显示某个进程 CPU 使用率超过 60% 并且持续时间长，十有八九那个进程里有一个或多个线程处于 Runnable 状态，而不是 Blocked。这种 ANR 不是因为锁，而是因为线程太忙，来不及处理主线程的消息。

4. 如何组合使用三份日志？

说了这么多，实际操作中我会按这个顺序排查：

看 logcat：找到 ANR 发生的确切时间、进程、CPU 负载概览。
对比 traces.txt：看主线程状态——如果 Blocked，找锁；如果 Runnable，看它在执行什么代码。
用 dumpsys 验证：如果是 CPU 高占用，用 cpuinfo 确认是哪个线程在烧 CPU；如果是内存问题，用 meminfo 检查是否存在泄漏。

还有个小细节：别忘了看 traces.txt 文件末尾的“----- end xxx -----”后面的汇总信息，里面会列出每个线程的 CPU 时间，直接告诉你哪个线程最耗 CPU。

举个例子：我处理过一个 ANR，logcat 显示 CPU 占用 90% 以上，但 traces.txt 里主线程却是 Blocked。是不是很奇怪？后来查 dumpsys 才发现，系统当时在做 GC，全局暂停了所有线程。这种情况其实不是应用的问题，而是系统内存压力太大。所以，不要只看单一来源。

嗯，三份日志就像是侦探的三件工具：traces.txt 是指纹、logcat 是时间线、dumpsys 是环境分析。单独看哪一个都有可能误判。把三者串起来，才能还原 ANR 的全貌。