Android ANR 排查实战：从线上告警到主线程卡点定位

[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"都会变成有迹可循的工程问题。