[Android 从零到一] Android ANR 排查实战：从线上告警到主线程卡点定位
线上 ANR 率突然从 0.03% 涨到 0.4%,监控平台一堆 "Input dispatching timed out",但堆栈五花八门,主线程有时停在 nativePollOnce,有时停在一个看似无害的 getSharedPreferences。这类问题的难点在于:ANR 的堆栈往往是"受害者现场",不是"凶手现场"。本文以一次真实的线上 ANR 治理为主线,梳理从告警、trace 分析、卡点归因到修复验证的完整排查路径。
ANR 的触发机制:先弄清系统在等什么
ANR 不是崩溃,而是系统对"主线程长时间不响应"的兜底。常见触发场景和阈值:
- Input dispatching timed out:输入事件 5 秒内未被消费
- Service 超时:前台 Service 20 秒 / 后台 Service 200 秒内未执行完 onCreate/onStartCommand
- BroadcastReceiver 超时:前台广播 10 秒 / 后台广播 60 秒
- ContentProvider 超时:publish 阶段超时
关键认知:系统判定的是"从事件进入队列到被处理完"的总时长。也就是说,即使 ANR 堆栈里主线程正在执行 A 方法,真正的元凶可能是之前排在消息队列里的 B 消息把时间耗光了。
消息队列: [耗时消息B: 4.8s] -> [输入事件: 等待中...]
^ 5s 超时,ANR 触发
此时抓到的堆栈可能是 B 刚执行完、正在处理的任意消息
这就是为什么很多 ANR 堆栈看起来"人畜无害"。
拿到现场:trace 文件与线上监控数据
本地复现时
adb shell cat /data/anr/traces.txt
# Android 11+ 目录变化,用 bugreport
adb bugreport anr_report.zip
trace 文件里最先看三块:
- main 线程状态与堆栈:是 Blocked、Waiting 还是 Runnable
- 持锁信息:
waiting to lock <0x0abc> held by thread 21 - CPU 负载摘要:iowait 高说明 IO 竞争,total 接近 100% 说明 CPU 饥饿
线上监控
线上拿不到完整 trace 时,依赖两类数据:
- ANR 时的主线程堆栈(监控 SDK 抓取)
- 主线程消息调度监控:基于 Looper.setMessageLogging 或 Choreographer 统计每个消息耗时
Looper.getMainLooper().setMessageLogging { log ->
if (log.startsWith(">>>>> Dispatching")) {
dispatchStart = SystemClock.uptimeMillis()
} else if (log.startsWith("<<<<< Finished")) {
val cost = SystemClock.uptimeMillis() - dispatchStart
if (cost > 300) reportSlowMessage(currentMessageInfo, cost)
}
}
有了慢消息记录,就能把"ANR 时刻之前 5 秒内主线程都在干什么"拼出来,解决"受害者堆栈"的归因难题。
复盘现场:一次真实的归因过程
回到开头的案例。监控显示 ANR 集中在冷启动后 10 秒内,堆栈分散。拉取慢消息记录后发现共性:ANR 前主线程总有一条 800ms+ 的消息,栈底指向同一个 SDK 的初始化广播。
进一步用 trace 确认:
"main" prio=5 tid=1 Blocked
at com.xxx.sdk.ConfigManager.loadConfig(ConfigManager.java:88)
- waiting to lock <0x0d2f> (a java.lang.Object) held by thread=21
"pool-3-thread-1" tid=21 Runnable
at java.io.FileInputStream.read(Native method)
at com.xxx.sdk.ConfigManager.syncFromDisk(ConfigManager.java:132)
真相:SDK 在子线程做磁盘同步时持有锁,主线程的广播回调里恰好要拿同一把锁读配置。低端机磁盘 IO 慢,锁持有时间被放大,主线程被卡死。
归因链条总结:
- 堆栈分散 → 用慢消息监控找共性
- 慢消息栈底 → 定位到具体消息来源
- trace 持锁信息 → 找到真正持锁的线程和原因
高频 ANR 模式清单
排查了几十例后,可以归纳出几类高频模式:
主线程 IO
SharedPreferences 的 commit、apply 后紧跟的 getValue、文件读写、数据库大事务。特别注意 apply 的陷阱:apply 是异步写,但 Activity onPause/onStop 时系统会等待所有 pending 写入完成,等待发生在主线程。
// 高危: 大量 apply 积压后,onPause 时主线程集中等待
prefs.edit().putString("k1", bigJson).apply()
治理方向:迁移 DataStore,或把大 value 拆到文件/数据库。
锁竞争
主线程和子线程共用一把锁,子线程持锁期间做了耗时操作。典型如上面的 SDK 案例。治理方向:缩小临界区,持锁期间禁止 IO;必要时改为无锁的快照读。
跨进程调用(Binder)
主线程同步调用另一个进程的 Provider/Service,对端卡了自己也卡。trace 里的特征是主线程停在 BinderProxy.transactNative。治理方向:跨进程调用移到子线程,加超时兜底。
消息队列积压
单条消息都不超时,但几十条 100-200ms 的消息排队,输入事件被挤到 5 秒外。这类 ANR 堆栈完全随机,只有消息级监控能定位。治理方向:合并/延迟非关键任务,冷启动阶段用 IdleHandler 延后执行。
GC 与 CPU 饥饿
trace 中 CPU 摘要显示 kswapd0 或其他进程占用极高,主线程 Runnable 却迟迟得不到调度。这类 ANR 属于环境问题,治理方向是降内存、降峰值 CPU,而非改单点代码。
修复与验证:让数据说话
针对案例的修复:
- 推动 SDK 升级,配置读取改为内存快照,消除主线程锁等待
- 冷启动广播回调延迟到首帧后处理
- 对残留的主线程 IO 用 StrictMode 在灰度包中报警
if (BuildConfig.DEBUG || isGrayChannel) {
StrictMode.setThreadPolicy(
StrictMode.ThreadPolicy.Builder()
.detectDiskReads().detectDiskWrites()
.detectCustomSlowCalls()
.penaltyLog()
.build()
)
}
验证不是"发上去看看",而是提前定好指标:
- ANR 率:0.4% 回落到 0.05% 以下
- 慢消息(>300ms)条数:冷启动阶段人均从 6.2 条降到 1.8 条
- 分机型看:低端机 ANR 率降幅是否与整体一致(确认 IO 归因正确)
灰度三天后指标达标,全量发布,ANR 率稳定在 0.03% 左右。
建立长期防线
单次治理只是止血,防线要建在日常:
- 消息级监控常驻:慢消息、消息积压量、主线程 Looper 卡顿率进大盘
- CI 卡口:关键路径新增主线程 IO 直接拦截(StrictMode + lint 自定义规则)
- SDK 准入:第三方 SDK 初始化必须声明线程模型,主线程初始化超过 50ms 需评审
- ANR 值班机制:新增 ANR 聚类自动归因,按慢消息共性分组而不是按堆栈分组
小结
ANR 排查的核心是三句话:堆栈是现场不是元凶,归因要看消息队列的时间线;trace 的持锁信息和 CPU 摘要能区分锁竞争、IO、Binder 和调度饥饿;修复必须用 ANR 率和慢消息指标闭环验证。把消息级监控建起来之后,大多数"玄学 ANR"都会变成有迹可循的工程问题。
