【 Android 性能优化】ANR 问题如何监控?

5,563 阅读10分钟

前言

ANR 即 Applicatipon No Response,程序无响应。Android 系统设计了 ANR 机制,其目的是监控与其交互的组件(Activity 等)和用户交互(InputEvent)的超时情况。这样能够判断应用进程(主线程)是否存在卡死或响应过慢的问题

相比 Crash,ANR 问题存在原因复杂,不易定位的特点,本文主要包括以下内容

  1. ANR 工作流程
  2. 如何监控 ANR?
  3. 如何定位 ANR 原因?

ANR 工作流程

ANR 可能触发的时机有多种,通常可以分为以下几方面:

图片来源:今日头条 ANR 优化实践系列 - 设计原理及影响因素

其基本原理其实 WatchDog 的思想,如果发出的事件,在一定时间内没有消费,则触发 ANR。具体源码就不在这里跟了,想详细了解的同学可查看:微信Android客户端的ANR监控方案

这里说一下总体流程,如下图所示:

  1. 发生 ANR 后,系统会采集许多进程数据,进行堆栈转储,以生成 ANR Trace文件。其中,第一个被采集的进程必定是发生 ANR 的进程。
  2. 系统会向这些应用进程发送 SIGQUIT 信号,这些应用进程收到信号后开始进行堆栈转储
  3. 应用进程 Dump 堆栈成功后通过 Socket 与系统进程通信写 Trace 文件
  4. 在 Trace 文件写入完成后,如果发生 ANR 的进程是前台进程则弹出 Dialog,否则则直接杀死进程

如何监控 ANR?

在了解了 ANR 的工作流程之后,我们该如何监控 ANR 的发生呢?

ANR WatchDog 检测思路

既然 ANR 的原因是输入在定时间内没有响应,那么我们很自然地想到,向主线程发送一个任务,如果一段时间内没有被执行的话,就认为发生了 ANR

这个思路主要有以下几个问题

  1. 不准确,超时条件不一定会导致 ANR,例如,5 秒超时只是在 TouchEvent 未被消耗时发生 ANR 的条件之一,而其他条件则不一定是 5 秒。
  2. 漏检测:如果超时时间定为 5 秒,去检测 TouchEvent 的 ANR 存在一定的漏检测的概率(周期不同步)。

ANR 信号监听思路

在上面介绍 ANR 总体流程时,我们注意到当 ANR 发生时会发送 SIGQUIT 信号,那么我们通过监听这一信号不就可以实现 ANR 监控了吗?事实上 XCrashMatrix 都是通过这种方式实现 ANR 监控的

在这里需要注意,默认情况下进程通过SignalCatcher监听SIGQUIT信号,进行堆栈转储生成 ANR Trace 文件。因此当我们监听SIGQUIT信号后,需要重新向SignalCatcher发送SIGQUIT

如果缺少重新向 SignalCatcher 发送 SIGQUIT 信号的步骤,Android System 管理服务(AMS)将一直等待 ANR 进程写入堆栈信息。直到超过20秒的超时时间,AMS 才会被迫中断,并继续后续流程。这将导致 ANR 弹窗的显示非常缓慢(因为超时时间为20秒),同时在 /data/anr 目录下也无法生成完整的 ANR Trace 文件。

误报情况处理

当监听到 SIGQUIT 信号时,不一定是发生了 ANR。

Matrix 的文档中提到了两种误报的情况:

  1. 比如可能是其它进程 ANR 了,发生 ANR 的进程不是唯一需要进行堆栈转储的进程。系统会收集许多其他进程进行堆栈转储,用于生成 ANR Trace 文件
  2. 厂商或者是开发者自己发送的SIGQUIT信号,发送SIGQUIT信号其实是很容易的一件事情

因此我们需要在监听到信号时再进行一次检查:在 ANR 弹窗前,会给发生 ANR 的进程标记一个 NOT_RESPONDING 的 flag,而这个 flag 我们可以通过 ActivityManager 来获取

private static boolean checkErrorState() {
    try {
        Application application = sApplication == null ? Matrix.with().getApplication() : sApplication;
        ActivityManager am = (ActivityManager) application.getSystemService(Context.ACTIVITY_SERVICE);
        List<ActivityManager.ProcessErrorStateInfo> procs = am.getProcessesInErrorState();
        if (procs == null) return false;
        for (ActivityManager.ProcessErrorStateInfo proc : procs) {
            if (proc.pid != android.os.Process.myPid()) continue;
            if (proc.condition != ActivityManager.ProcessErrorStateInfo.NOT_RESPONDING) continue;
            return true;
        }
        return false;
    } catch (Throwable t){
        MatrixLog.e(TAG,"[checkErrorState] error : %s", t.getMessage());
    }
    return false;
}

如上所示,我们可以在监听到信号时判断当前进程是否被标记为 NOT_RESPONDING 来判断当前进程是否发生了 ANR

漏报情况处理

当进程被标记为 NOT_RESPONDING 时一定发生了 ANR,但是当进程发生了 ANR 时,不一定会被标记为 NOT_RESPONDING

Matrix 的文档中提到了两种漏报情况

  1. 后台ANR(SilentAnr): 后台 ANR 会直接杀死进程,不会走到标记状态的代码
  2. 厂商定制逻辑: 相当一部分机型(比如 OPPO、VIVO 两家的高版本 Android )修改了 ANR 的逻辑,即使是前台 ANR 也会直接杀死进程

Matrix 通过判断主线程在收到 SIGQUIT 信号时是否处于卡顿状态来判断当前是否发生 ANR,如下所示

private static boolean isMainThreadStuck(){
    try {
        MessageQueue mainQueue = Looper.getMainLooper().getQueue();
        Field field = mainQueue.getClass().getDeclaredField("mMessages");
        field.setAccessible(true);
        final Message mMessage = (Message) field.get(mainQueue);
        if (mMessage != null) {
            long when = mMessage.getWhen();
            if(when == 0) {
                return false;
            }
            long time = when - SystemClock.uptimeMillis();
            long timeThreshold = BACKGROUND_MSG_THRESHOLD;
            if (foreground) {
                timeThreshold = FOREGROUND_MSG_THRESHOLD;
            }
            return time < timeThreshold;
        }
    } catch (Exception e){
        return false;
    }
    return false;
}
  1. 通过反射获取主线程LoopermMessage对象,该消息的when变量,就表示该消息的入队时间
  2. 将入队时间与当前时间进行比较,就可以获取该消息的等待时间
  3. 当等待时间超过一定阈值的话,我们就认为主线程处于阻塞状态,结合 SIGQUIT 信号,判断为发生了 ANR

如何定位 ANR 原因?

ANR 的影响因素有很多,我们可以把他们分为以下几类:

  1. 系统资源不足,其它进程或线程存在严重资源抢占,如 IO,Mem,CPU
  2. 线程间存在资源抢占,比如死锁等
  3. 主线程繁忙,用户输入得不到及时响应

在将 ANR 原因分为了以上几类之后,我们需要获取详细的日志信息,才能在发生 ANR 时及时定位原因

获取系统负载信息

想要获取系统负载信息,我们在线下可以通过获取 /data/anr 目录下的 trace 文件来查看,但是在高版本手机上,我们通常没有权限获取这个目录下的文件,那么在线上我们该如何获取系统负载信息呢?

应用层可通过 AcivityManager 获取 ProcessErrorStateInfo,如下所示:

    val am = application.getSystemService(Context.ACTIVITY_SERVICE) as ActivityManager
    val processesInErrorStates = am.processesInErrorState

通过ProcessErrorStateInfo我们可以获取shortMessagelongMessage,如下所示:

# shortMessage
ANR Input dispatching timed out (8445a92 com.android.test/com.android.test.anr.ANRActivity (server) is not responding. Waited 5000ms for MotionEvent(action=DOWN))

shortMessage就是产生 ANR 的原因,比较简单

# longMessage
ANR in com.android.test (com.android.test/.anr.ANRActivity)
PID: 23283
Reason: Input dispatching timed out (8445a92 com.android.test/com.android.test.anr.ANRActivity (server) is not responding. Waited 5000ms for MotionEvent(action=DOWN))
Parent: com.android.test/.anr.ANRActivity
ErrorId: 91ceb0ce-0af6-496e-8c4f-781075c056db
Frozen: false
Load: 0.0 / 0.29 / 0.33  # 表示 1, 5 和 15 分钟内的 CPU 平均负载
----- Output from /proc/pressure/memory -----
# avg10、avg60、avg300 分别代表 10s、60s、300s 的时间周期内因内存资源阻塞的时间百分比
# some 表示任一任务,full 表示所有非 idle 任务
some avg10=0.00 avg60=0.00 avg300=0.00 total=150136881
full avg10=0.00 avg60=0.00 avg300=0.00 total=51283028
----- End output from /proc/pressure/memory -----
CPU usage from 153ms to 605ms later (2023-05-04 22:38:19.034 to 2023-05-04 22:38:19.486):
  79% 1990/system_server: 35% user + 43% kernel / faults: 1598 minor
    43% 23375/AnrConsumer: 8.1% user + 35% kernel
    21% 2008/HeapTaskDaemon: 19% user + 2.7% kernel
    2.7% 2919/InputDispatcher: 2.7% user + 0% kernel
  32% 23283/com.android.test: 16% user + 16% kernel / faults: 7 minor
    28% 23315/RenderThread: 16% user + 12% kernel
    4% 23306/binder:23283_3: 0% user + 4% kernel
    4% 23354/binder:23283_5: 4% user + 0% kernel
  17% 1195/surfaceflinger: 17% user + 0% kernel
    10% 1195/surfaceflinger: 10% user + 0% kernel
    2.5% 1347/binder:1195_1: 2.5% user + 0% kernel
    2.5% 1414/TimerDispatch: 2.5% user + 0% kernel
  5% 1071/vendor.qti.hardware.display.composer-service: 2.5% user + 2.5% kernel
    2.5% 1071/composer-servic: 0% user + 2.5% kernel
  //...
21% TOTAL: 10% user + 10% kernel + 0.8% irq + 0.2% softirq

longMessage则是系统在发生 ANR 之后的一段时间内的负载信息,包括 CPU,IO,内存等

同时也可以结合线上 logcat 的输出,例如如果ANR时间点前后,日志里有打印 onTrimMemory,也可以作为内存紧张的一个参考判断,则此 ANR 可能由内存不足引起

获取进程内所有线程状态

发生 ANR 也可能是因为进程内的线程发生了资源抢占或者死锁,那么该如何获取进程内所有线程的状态,我们可以再看一下上面的这张图

Signal Catcher 的 Dump 发生在应用进程,并且通过 Socket Writer 来写 Trace的。如果我们能够在这个 write 方法上进行 Hook,就可以获取到系统记录下来的 ANR Trace 内容。这个内容非常全面,包括了所有线程的各种状态、锁和堆栈信息(包括 native 堆栈),对于排查问题非常有帮助,特别是一些与 native 问题、死锁等有关的问题。

Matrix 就是通过这种方式来获取 ANR Trace 的,具体实现可见:微信Android客户端的ANR监控方案

定位主线程问题

由主线程繁忙引起的 ANR 定位困难的原因在于:耗时可能由历史消息引起,发生 ANR 时正在执行的消息并不耗时。如下图所示:

图片来源:今日头条 ANR 优化实践系列 - 设计原理及影响因素

如果在系统服务执行某个历史消息时,已经耗费了大量时间,但在这个消息执行完毕后,系统服务并没有达到触发 ANR 超时的临界点,之后的主线程继续调度其他消息时,如果此时系统判定响应超时,那么正在执行的业务场景将不幸被命中。此时,当前正在执行的业务逻辑并不复杂,但由于之前的某个消息过度耗时,导致系统未能及时响应后续事件。

针对这类问题,一个解决方案是:记录主线程过去一段时间(比如 10s)内所有消息的调度历史,保存业务方需要的关键数据(比如消息耗时或者方法耗时),在发生 ANR 时,上报监控阈值内的历史数据

通过这种方式,在 ANR 发生时,可以回放过去一段时间的耗时方法,定位耗时原因

头条和虾皮都基于这种思路开发了一些 ANR 监控工具,详情可见:今日头条 ANR 优化实践系列 - 监控工具与分析思路Android 卡顿与 ANR 的分析实践

这些工具目前都没有开源,也有开发者基于头条的思路开源了一套实现,感兴趣的同学可以看看:app卡顿系列四 :今日头条卡顿监控方案落地

总结

本文主要是对 Matrix,今日头条等 ANR 监控方案的学习,介绍了系统 ANR 机制的工作流程,以及如何监控 ANR 问题,ANR 问题发生时如何定位具体原因等内容

ANR 问题定位困难的原因常常在于信息不足,通过上面介绍的获取系统负载信息,获取进程内所有线程状态,定位主线程问题等方案,应该可以比较有效地还原现场,帮助定位 ANR 问题,希望对你有所帮助~

参考资料

微信Android客户端的ANR监控方案
今日头条 ANR 优化实践系列 - 监控工具与分析思路