ANR的日志分析与初步定位

拿到一台ANR的设备,第一步该做什么?我个人习惯是:先别急着翻代码,把日志先理顺了再说。

ANR日志说白了就三块:traces.txt、logcat 和 CPU/IO 状态。这三者要配合着看,缺一个都可能漏掉真凶。我记得有一次线上ANR,只看traces堆栈以为是主线程卡在Binder调用,后来把logcat拉出来才发现是后台线程写文件把磁盘IO打满了——嗯,表面和真相往往差着一层。

日志文件在哪?怎么拿?

常规路径两个:

  • 线上环境:通过 adb bugreport 或者系统 dropbox 目录下的 anr/ 文件夹。
  • 开发测试:直接 adb pull /data/anr/traces.txt 就能抓到。

但要注意,Android 高版本(比如 11 以上)对 traces.txt 的访问权限收紧了。我建议你在应用里加一个ANR日志自动上传模块,把关键时段的数据直接拉到服务端。后面我会专门讲这个埋点方案。

分析步骤:三步走

  1. 看主线程堆栈 — 是不是卡在某个方法里?
  2. 查锁竞争与死锁 — 是否有线程持有锁不放?
  3. 扫系统状态 — CPU 使用率、IO 等待、内存压力怎么样?

这三步走完,大部分ANR的根因就浮出水面了。下面详细拆。

第一步:主线程堆栈分析

打开 traces.txt,你会看到类似这样的结构:

----- pid 12345 at 2025-03-01 10:00:00 -----
Cmd line: com.example.myapp

"main" prio=5 tid=1 Blocked
  | 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 78910 200 ) utm=50 stm=20 core=0 HZ=100
  | stack=...
  at com.example.MyActivity.onClick(MyActivity.java:50)
  - waiting to lock <0x12345678> (a java.lang.Object)
  at android.view.View.performClick(View.java:...)
  ...

关键要看 state 字段:

state 含义 常见原因
Blocked 主线程在等待锁 其他线程持锁不释放,导致死锁或长时间阻塞
Sleeping 主线程主动休眠 调用了Thread.sleep()或Object.wait()
Runnable 主线程正在执行 通常是CPU密集型计算或大量GC引起

重点看 stack 顶部的方法。如果主线程停在 Looper.loop() 那其实是正常状态——这时候要关注它上面调用的回调方法。我曾经遇到过主线程卡在 View.draw() 里,后来发现是某个自定义 View 的 onDraw 里做了重图片解码。

第二步:锁竞争与死锁排查

traces.txt 会把每个线程的锁信息列出来。比如:

"pool-1-thread-5" prio=5 tid=23 Blocked
  at com.example.MyTask.run(MyTask.java:30)
  - waiting to lock <0x12345678> (a java.util.ArrayList)
  ...

同时,另一个线程可能持有这个锁:

"main" prio=5 tid=1 Blocked
  - locked <0x12345678> (a java.util.ArrayList)
  ...

这样做就能快速定位锁的拥有者和等待者。如果是死锁,你会在不同的线程间看到循环等待:线程A等线程B的锁,线程B等线程A的锁。我记得有一次项目里出现这个,排查后发现是两个同步方法互相调用导致的——代码写得绕,锁就成了死结。

避坑指南:我曾经写过一段代码,在onCreate里用synchronized块等一个网络回调,结果网络线程也在等主线程的锁——死锁了。后来统一改用Handler+Looper模型解决。记住:主线程里永远不要主动等别的线程的锁。

第三步:系统状态扫描

堆栈只能告诉你“哪里卡了”,但“为什么卡”要看系统上下文。这里我会拉出三个指标:

  • CPU 使用率(在 bugreport 的 CPU info 段):如果主线程的CPU时间片很低(utm很小),说明它没在计算,而是在等IO或等锁。
  • IO 等待(/proc/stat 里的 iowait):如果很高,大概率是磁盘读写拖累了主线程。比如 SharedPreferences 的大量写操作,或者数据库事务没及时提交。
  • 内存压力(dumpsys meminfo 里的 PSS 和 swap):如果频繁触发GC,主线程会被打断。你看到 GC_FOR_ALLOC 在 traces 里出现很多次,那就是内存吃紧了。

注意:有些ANR其实是系统层面的,比如系统服务卡顿导致输入事件分发延迟。这种你只看自己App的堆栈是找不到原因的。一定要结合logcat看有没有 Input dispatching timed out 或者 Broadcast of Intent { ... } timed out 这类日志。

常见ANR类型速查

类型 触发条件 堆栈特征
输入事件ANR 5秒内未响应触摸/按键 主线程堆栈停在 InputMethodManager 或 View.dispatchTouchEvent 相关方法
广播ANR 前台广播10秒 / 后台广播60秒未完成 onReceive 方法阻塞,可能是网络请求或数据库操作
服务ANR 前台服务20秒 / 后台服务200秒未完成 onStartCommand 或者 onBind 方法里做了长时间计算
ContentProvider ANR ContentProvider 的 query/insert 等方法耗时超过 一般是数据库大查询或者磁盘IO慢

学会快速对号入座,能省下很多翻日志的时间。我个人习惯是先把logcat里搜索"ANR"关键词,确定是哪种类型,再反推去看对应线程的堆栈。

一张图理清分析流程

ANR日志分析流程 捕获ANR日志 traces.txt logcat 系统状态 (/proc) 合并分析:主线程堆栈 + 锁 + CPU/IO 是否卡在业务方法? 是否有锁竞争/死锁? 系统资源是否充足? 定位根因:优化代码 / 减少锁 / 降IO 验证修改后ANR是否复现

实战案例:一个真实的 broadcast ANR

我去年接手过一个模块,用户反馈打开某个页面后频繁ANR。我拿到的traces里主线程停在 onReceive 方法,里面调了一个网络请求用的 HttpURLConnection。logcat里搜到 Broadcast of Intent { act=ACTION_DOWNLOAD } timed out。CPU使用率正常,但IO等待很高——原来是网络请求超时设置成30秒,而前台广播只给10秒窗口。典型的长操作跑在主线程上了。

说人话的解决方案:广播接收器里只用 IntentService 或者 JobScheduler,不要直接执行耗时操作。你想想看,广播的5秒(前台)或10秒(后台)窗口,连一次网络握手都有可能超时,更别提下载文件了。

小结:记住这四句话

  • 主线程堆栈 + 锁信息是破案的第一手线索。
  • logcat里的ANR类型标签帮你缩小范围。
  • CPU/IO/内存状态告诉你“为什么慢”。
  • 同样的ANR可能由不同原因引起,别只盯着堆栈。

嗯,这一章的内容差不多就到这。有了这个分析框架,下次再看到ANR日志,你应该能快速锁定真凶了。后续我会讲怎么把这些日志聚合起来,做成自动埋点——那才是真正意义上的线上防御。