关于客户端:Android-卡顿与-ANR-的分析实践

本文首发于微信公众号“Shopee 技术团队”

摘要

针对客户端开发的“终生之敌”——卡顿和 ANR 问题，本文将深刻分析零碎音讯队列机制和常见的卡顿与 ANR 成因，并介绍监控工具 LooperMonitor 如何借助多维分析平台 MDAP 的智能聚合和可视化看板，为业务方提供更精准、易用的剖析能力。

这是 MDAP 系列的第三篇文章，前文回顾：

• 《MDAP：可观测性数据分析平台设计与实际》
• 《机器学习在基于 URL 的客户端监控剖析中的优化和实际》

前言

卡顿和 ANR，这是一个所有客户端开发同学都非常关注的话题，也是一个无奈绕过的话题。

卡顿的体现是 App 呈现丢帧、滑动不晦涩、用户的触摸事件响应慢；当产生十分重大的卡登时，App 甚至可能会弹出 Application not responding 的弹窗，提醒用户以后 App 无响应。

卡顿和 ANR 除了会影响用户的应用体验外，对于电商平台来说，在订单高峰期更是会间接影响成交量，导致理论的支出损失。能够说卡顿与 ANR 是客户端开发同学的终生之敌。

然而卡顿和 ANR 问题的剖析与解决又具备肯定的难度，尤其是 ANR。次要起因是 ANR 是主线程忙碌导致要害的零碎音讯不能及时执行而触发的，导致主线程忙碌的起因很多，同时系统对 ANR 的认定阈值又比拟久，最低也是 5s 起步，在这段时间内，有可能呈现了设施 CPU 资源缓和或主线程执行了一些耗时音讯的场景，这些场景都有可能是“导致雪崩产生的那几片雪花”。

目前业内支流的监控 SDK，其基本思路都是监听 ANR 信号，并在 ANR 产生现场抓取线程堆栈和零碎 ANR 日志，此时的堆栈抓取是一种预先策略，除了一些非常明显的比方线程死锁或者以后正好存在异样耗时的业务逻辑外，对更费解和简单的起因就无能为力了，这种“预先策略”往往导致上报的 ANR 数据里充斥着大量的“有效堆栈”。比方经典的 MessageQueue.nativePollOnce：

大量堆栈都聚合到 MessageQueue.nativePollOnce 这里了，难道是因为主线程调用 nativePollOnce 在 jni 层始终阻塞没有被唤醒吗？如果只借助这么一份堆栈数据的话，咱们无奈找到剖析思路，这些 ANR 问题是很难被解决的。

为了解决这些痛点，ShopeeFood 团队和 Shopee Engineering Infrastructure 团队通过深入研究零碎音讯队列机制和常见的卡顿与 ANR 成因，实现了一套新的监控工具 LooperMonitor，作为 APM-SDK 根底能力的一部分，与卡顿和 ANR 上报联合，借助多维分析平台 MDAP（Multi-dimension-analysis-platform）的智能聚合和可视化看板，旨在为业务方提供更精准和易用的剖析能力。

1. 卡顿与 ANR 的产生原理

在正式介绍 LooperMonitor 计划之前，咱们有必要搞清楚为什么传统计划抓取的 ANR 现场堆栈会不准？要解答这个问题，须要先弄清楚卡顿和 ANR 是如何产生的。

咱们晓得，Android 的应用层是基于 Looper+MessageQueue 的事件循环模型运作起来的。

Looper 是一个音讯轮询器，它不停地在 MessageQueue 中取出音讯并执行。

这里的音讯，包含 UI 绘制音讯、零碎四大组件的调度音讯、业务本人通过 Handler 构建的音讯等。

外面负责 UI 绘制的是 doFrame 的音讯。它是由 Choreographer 通过申请和监听硬件层的 vsync 垂直同步信号后，将 UI 绘制工作包装成一个 doFrame 的音讯，在适合的帧绘制工夫点将音讯抛到主线程音讯队列去执行的。

一个 doFrame 音讯外部有五个 callback 队列，比拟重要的是 input_queue、animation_queue 和 traversal_queue。它们别离解决触摸事件、动画事件、UI 绘制事件。

当一个 doFrame 音讯被执行时，上述三个队列的事件会被执行，咱们认为 App 响应了一次用户的触摸，同时 UI 更新了一帧，实现了一次交互。

当一个 doFrame 音讯执行实现后，会告诉 Choreographer 申请下一次的 vsync 信号。此时 UI 绘制工作便被串起来了，如下图：

如果在每一个 vsync 距离都能执行完一个新的 doFrame 音讯的话，此时设施是满帧运行的。

然而有种状况会导致下一个 doFrame 音讯不能在一个 vsync 距离内被执行，比方以后的 doFrame 音讯正好超出了 vsync 距离，导致下一个 vsync 不能及时申请；或者 doFrame 音讯前，主线程 Looper 被其余耗时工作占据了。

一旦 doFrame 不能及时被执行，体现在体验上，就是设施绘制丢了一帧。当这个距离越大，丢帧体现就越显著，App 就越卡顿。

对于 ANR 来说，其原理是相似的。咱们拿零碎创立 Service 举例，在指标 Service 创立过程中会调用到 realStartServiceLocked()，在 realStartServiceLocked() 外部最终会调用到 ActiveServices 的 scheduleServiceTimeoutLocked 办法，零碎会在此时埋下“炸弹”，同时根据服务是前台还是后盾的不同，炸弹会依照不同的工夫引爆，这里前台服务是 20s。

ActiveServices.java

void scheduleServiceTimeoutLocked(ProcessRecord proc) {
    ……
    Message msg = mAm.mHandler.obtainMessage(ActivityManagerService.SERVICE_TIMEOUT_MSG);
    msg.obj = proc;
    mAm.mHandler.sendMessageDelayed(msg,
            proc.execServicesFg ? SERVICE_TIMEOUT : SERVICE_BACKGROUND_TIMEOUT);
}

用图示意如下：

通过一系列的零碎调用，最终 ActivityThread 的外部类 ActivityThread$H 中会接管到一条 CREATE_SERVICE 音讯。当 CREATE_SERVICE 被执行时，service 实例会被创立，并且会回调其 onCreate() 办法，在 onCreate() 被调用前，会告诉 ActiveServices 勾销掉这条超时引爆的信息。

ActiveServices.java

private void serviceDoneExecutingLocked(ServiceRecord r, boolean inDestroying,
        boolean finishing) {
        ……
        mAm.mHandler.removeMessages(ActivityManagerService.SERVICE_TIMEOUT_MSG, r.app);

如果因为种种原因导致本次 CREATE_SERVICE 不能在 20s 内失去执行，SERVICE_TIMEOUT_MSG 音讯便会被执行，此时便会产生 ANR。

系统对不同的事件，其“容忍度”和 ANR 信息引爆后的体现也有所不同，具体定义见表：

总结一下：

卡顿产生的起因是 doFrame 的音讯无奈在 vsync 的工夫距离内实现执行，而 ANR 是因为要害的零碎音讯，或者 Input 事件无奈在零碎定义的超时阈值内实现执行。

从实质上来说，它们是同一个问题的两种体现，只是重大水平不同而已。当设施产生了 ANR 时，往往也产生了十分重大的卡顿。

2. 为什么堆栈不准？

从前文剖析可知，卡顿和 ANR 的产生起因都是特定类型音讯在指定阈值内没有失去及时执行。这个阈值的工夫有长有短。

对于卡顿监控，咱们的阈值距离不会很长，按业务场景和产品复杂度可能会有所不同，但个别可能在几百毫秒左右。ANR 的监控阈值更长，产生用户可感知的 ANR，最短也有 5s，最长 10s。

当监控到卡顿和 ANR 时，其实意味着过来的几百毫秒，5s，10s 的主线程音讯队列有异样的耗时工作呈现，如果此时抓取堆栈，只意味着咱们抓取到了卡顿和 ANR 现场的堆栈数据。

对于卡顿来说，几百毫秒的距离不算很长，本次抓取的堆栈有较高概率可能能够命中异样耗时工作的堆栈，但也只是“可能”。

对于 ANR 就没有那么容易命中了，毕竟过来了 5s，10s，主线程执行过的工作太多了，在这 5s 和 10s 内，每一个耗时工作，都有可能导致关键性零碎音讯无奈及时被执行。如果在 ANR 信号产生时去抓取堆栈，大概率会将这些场景 miss 掉。

ANR 的信号是异步产生的，在接管到 ANR 信号时采集堆栈，除了有可能采集到以后音讯内执行的业务堆栈外，也有可能采集到主线程 MesageQueue 正在取音讯的“过程”，这个取下一条音讯的办法 MessageQueue.next() 调用得十分频繁，所以命中概率很高，这也是为什么很多 ANR 上报里最终都命中了这个堆栈。

晓得了堆栈不准的起因后，解决它也便有了一个很清晰的思路。

3. MDAP-LooperMonitor

其实通过上述剖析能够看到，导致 ANR 和卡顿产生的起因是主线程 Looper 中有异样音讯。

同时，有提醒的可感知 ANR 最长耗时是 10s，如果能够通过一种机制，记录主线程过来 10s 内所有音讯的调度历史，保留业务方须要的要害数据，并解决好性能和内存占用，在问题产生时，上报监控阈值内的调度数据：

• 比方在卡登时，上报过来 500ms（可在配置平台灵便调整）的调度数据；
• 在 ANR 产生时，上报过来 10s 和尚未调度的 Pending 音讯。

这样对于开发者来说，就等同于领有了“看穿过来和将来”的能力，应该就能够解决大部分卡顿和 ANR 问题了。

MDAP 的 LooperMonitor 便是基于此思路的一种监控计划，咱们在外部也做了大量技术优化来确保计划落地，比方寻找性能更优的监控入口，应用对象复用技术缩小 GC 压力，应用多实例单线程模型缩小同步开销，应用小音讯聚合和滚动淘汰策略缩小内存占用等，详见下文。

3.1 监控入口

找到主线程 Looper 的调度的入口是本次监控计划的外围，如果能够在调度的起止点插入咱们想要的代码，便能够获取到以后 msg 的执行耗时。

Looper 的源码只摘取要害信息如下：

for (;;) {Message msg = queue.next(); // might block
            ...
            // This must be in a local variable, in case a UI event sets the logger
            final Printer logging = me.mLogging;
            if (logging != null) {
                logging.println(">>>>> Dispatching to" + msg.target + " " +
                        msg.callback + ":" + msg.what);
            }
            try {msg.target.dispatchMessage(msg);
                if (observer != null) {observer.messageDispatched(token, msg);
                }
                dispatchEnd = needEndTime ? SystemClock.uptimeMillis() : 0;} catch (Exception exception) {throw exception;} finally { }
            
            if (logging != null) {logging.println("<<<<< Finished to" + msg.target + " " + msg.callback);
            } 
            ...
        }

目前绝大部分 APM SDK 都是通过设置一个 Printer 对象，在 println 办法的回调中去判断字符串是否以 >>>>> Dispatching to 和 <<<<< Finished to 来判断音讯起止点的，在起止点插入统计代码，即可取得音讯执行耗时。

如果有异样耗时的音讯，为了定位到异样点，通常还须要取得一些额定数据：

1. 以后音讯的 target：起源自哪个 Handler，如果业务侧是通过继承 Handler 并且在 handleMessage 中解决音讯的，咱们须要晓得这个 Handler 的地位。
2. 以后音讯的 callback：如果是间接 post 一个 runnable，此时须要通过 callback 能力定位到业务代码的地位。
3. 零碎音讯的类型：如果音讯是由 ActivityThread$H 解决的，咱们须要晓得以后调度的是哪一类零碎音讯，从而筛选出会导致 ANR 的四大组件调度信息。

设置 Printer 的计划能够满足 1 和 2 的要求，然而无奈拿到零碎音讯类型，也就是无奈做到 3 的要求。

对于 3，能够再通过 hook 零碎的 ActivityThread$H 的 what 字段拿到调度的音讯类型。

除了设置 Printer 之外，还有更好的计划吗？

翻看源码时发现，在 Android api ≥ 28 时，Looper 中新增了一个 Observer 的接口，在音讯被调度前后会回调其对应办法，并将音讯对象作为参数传入了，能够尝试将其替换成咱们本人的实现，这看起来是一个更高效的办法，不必产生大量长期 String 对象。

源码见下：

for (;;) {Message msg = queue.next(); // might block
            ...
            // Make sure the observer won't change while processing a transaction.
            final Observer observer = sObserver;
            ...
            if (observer != null) {token = observer.messageDispatchStarting();
            }
            try {msg.target.dispatchMessage(msg);
                if (observer != null) {observer.messageDispatched(token, msg);
                }
            } catch (Exception exception) {if (observer != null) {observer.dispatchingThrewException(token, msg, exception);
                }
                throw exception;
            } finally { }
            ...
        }

然而该类是一个 Hidden 的 API，无奈间接拿到其类定义，从而无奈在 App 侧实现该接口，同时又在反射黑名单中，无奈通过反射将实现设置到 Looper 中。

对于反射限度，能够采取元反射的办法破解掉该限度，概括来说就是应用零碎身份去反射，在 Api ≥31 时零碎限度了元反射调用，咱们对此也做了兼容解决，使得计划在 Api≥31 的设施上依然可用。

对于无奈拿到类定义，能够通过实现一个本人定义的 Stub 接口，并在编译时批改 Stub 接口对应的类型信息，保障能够通过编译的同时，也能够通过运行时类校验。

比照上述两种实现不难发现，对于业内常见的设置 Printer 的计划，随着 Looper 的 for 循环不断执行，会导致字符串频繁拼接，产生大量长期对象，有可能减轻 App 的 GC 频率，导致内存抖动。

MDAP 通过绕过高版本反射限度以及编译时插桩，实现了性能更优良的 LooperObserver 计划，同时为了兼容性和低版本的可用性，保留了设置 Printer 的能力，在 LooperObserver 计划失败时，会降级到 Printer 计划。

3.2 反对多 Looper

对于 Looper 的监控，咱们心愿做成通用能力，能够监控任意线程的 Looper。因为 Looper 模型不仅仅在 Android 主线程应用了，在 ReactNative 中也大量应用了，比方 NativeModulesMessageQueueThread 和 JSMessageQueueThread，对于以 RN 为次要技术栈的 App 来说，这两个线程的 Looper 执行异样，同样会导致 App 卡顿。

如果对多 Looper 进行监控，监控模块势必被多个线程调用，为了缩小频繁加锁带来的上下文切换开销，咱们采纳了多实例 + 单线程的模型。通过为每一个 Looper 创立对应的 LooperRecorder 对象来解决数据采集，每个 LooperRecorder 依照 Looper 的线程 ID 进行映射，以此做到 Recorder 实例的外部无锁。

3.3 信息采集

有了监控入口，如何采集不同音讯的对应数据？

3.3.1 音讯分类

其实对于不同耗时阈值的音讯，业务方的关注重点也是不太一样的。

比方在大部分场景下，音讯都是不耗时的小音讯，执行耗时在 30ms 以下，这类音讯对于 ANR 的产生影响不大，为了节约内存，记录一个总耗时和完结工夫戳，以及最初一条音讯的相干数据，用来将音讯队列串联起来即可。

一般滚动音讯，记录其 target、callback、what 字段，基于线上的符号还原，根本也能够定位到业务逻辑在哪。

对于耗时的音讯，比方超过 200ms 的，只晓得其 target 和 callback，能够定位到 Handler 的具体位置，但其外部的具体执行逻辑依然是未知的，业务方更心愿会有堆栈。

对于零碎音讯，除了上述根底数据外，还须要晓得以后调度的是哪一类零碎音讯，从而筛选出会导致 ANR 的四大组件调度信息。

此外，当 ANR 产生时，还须要获取尚未调度的 Pending 音讯。对于 Pending 音讯，除了须要记录 target、what、callback 字段外，还须要记录他们超时了多久，这样当 ANR 产生时，能够检索 Pending 音讯队列，找到触发本次 ANR 产生的“炸弹”。

3.3.2 堆栈采集

对于耗时音讯的堆栈采集，常见的次要是两种计划，

计划 1：编译时插桩，在函数的起止地位，插入统计代码。

这种计划的益处是，能够清晰晓得办法的具体耗时；此外，如果在编译时为每个函数生成惟一 ID，还能够借助 ID 与函数名映射表，应用十分小的容量保留堆栈数据。

但这种计划对包体积和运行时性能都有一些影响；同时，它依赖接入方接入了插桩插件。

计划 2：应用子线程进行超时检测抓取。

这种计划的长处是实现简略，并且不依赖接入方是否接入插件。

毛病是抓取的堆栈比插桩计划大，并且如果频率管制不好的话，有可能对 App 性能产生较大影响。

对于计划 1，MDAP 曾经实现了一套较高性能的线上函数 Tracing 计划。

计划 2 是 LooperMonitor 目前采纳的计划。咱们通过协程的非阻塞式挂起能力实现了高效的异步检测和采集，同时对 Looper 的 IDLE 状态做了过滤，若以后并无音讯执行时，不会采集指标线程堆栈，避免采集到大量的 NativePollOnce 调用。

对耗时音讯，检测阈值会线性减少，尽可能管制好采样频率，缩小对线上 App 的性能影响。
对采集到的堆栈数据，会提早到卡顿和 ANR 上报时才序列化。

后续咱们会思考将两个计划联合起来，若接入方接入了插件并且开启了 trace 性能，优先从 trace 组件获取精简的堆栈数据，进一步缩小 trace 对 App 的内存和性能占用。

3.4 内存占用

App 内存是十分贵重的资源，LooperMonitor 必须尽量保障对 App 的内存占用可控，并且尽可能减少占用，才有真正在线上运行的价值。

咱们采纳了一系列伎俩来达到这个目标。

3.4.1 对象池复用

对象池技术对于须要频繁创立和销毁的场景十分实用，能够大大减少对象创立带来的内存压力，对于缩小内存抖动有非常明显的帮忙。在 Android 零碎外部有大量应用对象池技术的场景，比方 Message 对象、TouchEvent 对象的创立等。
在 Message 外部有一个 sPool，当应用 Message.obtain() 时，便会尝试从 sPool 中返回一个已有对象。因为整个 Android 下层是基于 Looper 和 Message 的音讯循环机制实现的，所以 Message 对象的创立和销毁会十分频繁，非常适合应用对象池技术。

LooperMonitor 的音讯执行记录对象 MessageInfo 同样也是实用于该场景的。

通过测试，MessageInfo 队列绝大部分只会用到 100 个左右的记录，通过为 MessageInfo 设置了一个较小的 50 个 size 的 Pool，在大部分场景下，能够缩小约 50% 左右的新对象 allocating。

3.4.2 聚合小音讯 + 滚动淘汰旧值

对于不耗时的小音讯，其对 ANR 的影响无限，为了不占用贵重的内存资源，咱们会将间断的小音讯聚合成一条，记录最初一条小音讯的 callback 和 traget，总耗时和音讯的 occurTime，用来串起整个音讯 Record 队列。

音讯 Record 队列的最大值目前设置为 500 条，并通过 Size + occurTime 滚动淘汰旧值。概括来说就是“超出队列下限的”以及“音讯产生工夫超出设定阈值比方 10s 的旧数据”会被滚动删除。

通过测算，即便在实践上的极限值（每一个音讯都没有命中聚合，导致队列被小音讯塞满），500 的队列长度依然能够记录 8s 的数据。

500 个塞满是实践上的极限场景，通过对线上 App 进行理论测算个别都在 100 – 200 个 Records 之间。

不同音讯因为记录的数据略有差异，内存占用状况并非完全一致。

整体的内存概览如下：

当前期开启线上 Trace 性能，fat 音讯的内存占用会进一步放大。

对主线程不同忙碌水平，这里也做了一个大略的 场景 + 内存占用 统计：

能够看到，计划根本做到了内存占用的可控。

3.5 数据看板

Looper 监控数据会追随 ANR 和卡顿监控 一起上报到 MDAP 的剖析平台去，作为卡顿和 ANR 上报的补充数据。

3.5.1 MDAP Looper 看板

Looper 的 H5 剖析看板如下：

顶部色条为历史调度音讯时间轴，色块长短根据音讯耗时时长不同而不同，从左到右为最旧到最新的音讯数据，最左边一条记录代表 JANK 产生时，也即 ANR/ 卡顿现场的数据，不同类型音讯依照不同色彩进行辨别，时间轴可横向缩放，点击每条音讯均可查看具体数据。

为了不便研发同学线下开发调试，咱们也提供了 Debug 的 Looper 监控看板，能够监控实时调度信息，点击能够去到详情页，查看每条调度历史详情。

3.5.2 实时 Looper 监控浮窗

Looper 实时监控浮窗应用不同色彩的柱状图代表每一条音讯的耗时情况，浮窗实时更新，不同音讯类型，其色彩不同。

• 横坐标代表耗时工夫，单位毫秒。
• 纵坐标代表音讯索引，从上到下代表最新到最旧的音讯。
• 点击右上角箭头，能够采集以后快照后进入详情看板页面查看。

3.5.3 Debug 详情看板

详情看板数据和 MDAP 平台看板数据统一，只是款式有些不同，次要分为两个局部。

1）上半部分为“Pending 音讯数据”

横坐标代表 Pending 音讯在 MessageQueue 的索引，从左到右代表从队头到队尾。

纵坐标代表 Pending 音讯“指标执行工夫点”与“卡顿 /ANR 产生时”的工夫点差值。

• 如果为负数，其可能是一条通过 sendMessageAtTime() 放入音讯队列的音讯，还未到指标执行工夫点，数值代表与指标执行工夫点的差值。
• 如果为正数，示意音讯曾经超时，其值示意超时时长，比方一个 CREATE_SERVICE 音讯超时触发的 ANR，会在 Pending 音讯列表中看到一个蓝色的零碎音讯，其 Pending 时长 <-10000ms。

2）下半部分为“历史调度数据”

• 横坐标代表音讯耗时，单位为毫秒。
• 纵坐标代表音讯索引，从上到下代表最新到最旧的音讯，与 Looper 实时监控浮窗统一。
• 对于不同音讯应用不同色彩色条进行辨别，点击能够查看具体数据。

到这里，Looper 监控工具的根本介绍就完结了。上面会举一些具体案例与大家分享。

4. 案例分享

案例 1

这是一份线上的 System.log 日志：

2021-11-12 11:26:19.996 1657-11869/? E/ActivityManager: ANR in com.***.***.***
    PID: 11093
    Reason: Input dispatching timed out (*****.**CheckInActivity_ (server) is not responding. Waited 8014ms for MotionEvent(action=DOWN))
    Load: 3.89 / 2.63 / 2.44
    CPU usage from 0ms to 6012ms later (2021-11-12 11:26:13.938 to 2021-11-12 11:26:19.949):
      53% 1657/system_server: 32% user + 21% kernel / faults: 14664 minor 589 major
      52% 11093/com.***.***.***: 37% user + 14% kernel / faults: 17832 minor 34 major
      19% 25179/cnss_diag: 11% user + 7.6% kernel / faults: 7 minor
      12% 853/surfaceflinger: 4.1% user + 8.4% kernel / faults: 503 minor 7 major
      10% 499/logd: 4.3% user + 6.4% kernel / faults: 22 minor
      0% 1227/media.swcodec: 0% user + 0% kernel / faults: 19869 minor 68 major
      10% 10580/com.miui.securitycenter: 5.8% user + 4.4% kernel / faults: 4022 minor 3 major
      9.2% 9835/adbd: 3.4% user + 5.8% kernel / faults: 14 minor
      7.9% 3307/com.android.systemui: 5.4% user + 2.4% kernel / faults: 1546 minor 2 major
      7.6% 23896/com.google.android.gms.persistent: 4.4% user + 3.1% kernel / faults: 3190 minor 29 major
      0% 1135/media.codec: 0% user + 0% kernel / faults: 8815 minor 66 major
      3.6% 27550/com.miui.powerkeeper: 2.4% user + 1.1% kernel / faults: 3265 minor 104 major
      3.1% 149/kswapd0: 0% user + 3.1% kernel
      2.8% 773/android.hardware.wifi@1.0-service: 2.1% user + 0.6% kernel / faults: 262 minor
      2.8% 3685/com.android.phone: 1.4% user + 1.3% kernel / faults: 2965 minor 202 major
      2.6% 10542/kworker/u16:8: 0% user + 2.6% kernel
      ...
      0.4% 90/system: 0% user + 0.4% kernel

这里简略提一下 System.log 日志怎么看：

1）看 ANR 类型，确认剖析范畴

先找 ANR 起因，次要是看 Reason 这一行，对于不同的 ANR 类型，Reason 的内容会有所区别。比方 Input dispatching timed out 示意 ANR 是 Input 派发超时导致，executing service com.xx.xxx 示意是 Service 创立超时导致，通过 Reason 这一行能够定位到 ANR 类型，进而断定超时阈值是多少，比方本次 ANR 是 Input 导致，Input 超时工夫是 5s，这个能够进一步帮咱们放大问题剖析的工夫范畴。

2）看 CPU LOAD Average 数据

Load: 3.89 / 2.63 / 2.44 示意过来 1、5、15 分钟内的，正在应用或者期待应用 CPU（处于 Run queue 或 Ready queue）的过程数的平均值。具体定义可参考维基百科)。

在个别 Linux 规范下，单核 CPU 通常以 70 分位数为分水岭，也即 <0.7 为现实负载，多核 CPU 则需乘以对应外围数，但古代 Android 设施个别对多过程都有智能调度策略，例如主动解冻后盾过程，或者对后盾过程只定时调配大量 CPU 工夫等，此时高 Load 也未必代表设施遇到性能瓶颈，某些设施其 Load average 常常维持在 40+，但仍然响应晦涩，CPU 使用率也不高，基于此，咱们无奈单纯为 Load average 定义一个相对的判断公式。

在剖析 ANR 问题时，更多是看该值有无显著劣化的趋势，比方本次 System.log 设施应用的是一颗 8 外围 CPU，4 大核 4 小核，整体看 CPU load 并无显著异样，有轻微减轻趋势，但不算重大。

3）看过程 CPU 占用率

CPU usage from 0ms to 6012ms later，这里的 later 示意采集的 CPU 占用率数据为 ANR 产生后的数据，除了 later 还可能有 before 的字样，代表数据在 ANR 产生前采集。

留神：零碎并不能保障采集 CPU 使用率的具体工夫，咱们查看此类日志也要区别来看，比方如果 CPU 数据为 ANR 后采集，那么 system_server 的 CPU 使用率高是失常的，因为 system_server 此时须要做 dump 操作。

日志中会依照 CPU 使用率从高到低将过程信息打印进去，包含 CPU 使用率、过程号、过程名、user 和 kernel CPU 占比、页谬误数。

kernel 若 CPU 占比拟高，阐明利用侧应该产生了大量的零碎调用。一般来说，产生零碎调用的少数场景都是文件 IO 操作。

从日志看，本次 ANR 产生时，利用过程 CPU 占比 52%，较其余过程高出不少，ANR 产生瓶颈应该与零碎其余过程无关，但 user 与 kernal 占比无显著异样，主过程应该没有 IO 异样。

4）看 App 过程页谬误数量

过程的 minor 和 major 代表主要页谬误和次要页谬误，别离示意内存与缓存的命中状况。页谬误过高阐明内存频繁换页，会导致分配内存与 GC 速度显著变慢。

5）看 kswapd0 过程

kswapd0 是治理虚拟内存的过程。当设施 RAM 空间被耗尽时，kswapd0 会负责将 App 过程的局部虚拟内存写入 swap 替换区，当该过程占用率很高时，往往反映设施处于低内存状态。

整体而言，通过上述 SystemLog，能够大略看出设施 ANR 产生前后的一段时间的根本情况：CPU 负载无减轻趋势，kswapd0 过程只有 3.1%，无低内存场景，利用过程 52%，相比设施其余过程而言，CPU 占用率较高，但无显著 IO 异样。

此时，须要进一步借助 Looper 监控看板工具查看本次 ANR 上报的 Looper 数据。

当 ANR 产生时，以后正在调度的音讯耗时超过了 8s；持续看其 Wall 和 CPU Duration，能够看到 WallDuration 是 8369ms，然而 CPU 工夫是 0，阐明主线程在此时没有拿到工夫片，可能处于阻塞状态。有可能是主线程 IO 了，或者在期待锁。

进一步通过堆栈定位到对应的业务逻辑，发现的确有死锁产生。

通过 Looper 看板工具，能够发现本次 ANR 的本源音讯就是以后正在调度的信息重大耗时，解决掉该 bug 也就解决了这个 ANR。

另外一种场景会更隐秘一些:

案例 2

ANR in **.***.*******
    PID: 5111
    Reason: executing service **.***.*******/com.***.*****.******Service
    Load: 32.79 / 32.69 / 33.14
    CPU usage from 0ms to 12126ms later (2021-12-12 20:22:05.251 to 2021-12-12 20:22:17.377):
      67% 5111/**.***.********: 52% user + 14% kernel / faults: 2186 minor 1 major
      55% 1309/system_server: 36% user + 19% kernel / faults: 2084 minor 3 major
      14% 24540/com.google.android.gms.persistent: 12% user + 2.4% kernel / faults: 29 minor 1 major
      13% 706/adbd: 2.5% user + 10% kernel
      12% 634/surfaceflinger: 8.2% user + 4.5% kernel / faults: 93 minor
      7.3% 2433/glgps4774: 4.4% user + 2.8% kernel / faults: 5 minor
      2.2% 636/powerlogd: 1.7% user + 0.4% kernel
      2.2% 1874/com.oppo.launcher: 1.4% user + 0.7% kernel / faults: 7267 minor
      0.3% 150/kswapd0: 0% user + 0.3% kernel
      0% 32322/com.google.android.gms.ui: 0% user + 0% kernel / faults: 1021 minor 22 major

先看 System.log：
executing service **.***.*******/com.***.*****.******Service 阐明本次 ANR 是 Service 超时导致。

CPU 负载失常，App 主过程无显著 CPU 应用异样，kswapd0 0.3%，设施无低内存场景，本次 ANR 产生大概率不是因为设施负载和 RAM 不够，咱们将剖析重点放在 App 过程的 Looper 上报中。

通过 ANR 看板工具能够看到，主线程以后正在调度的音讯执行耗时超过了 1767ms，是一个十分重大的耗时音讯，抓取的堆栈停留在了 registerSensorManager，这个堆栈也是其余 ANR 监控 SDK 上报时抓取的 ANR 线程堆栈，如果只看到这个数据，业务方可能认为解决了这个耗时场景，就能够解决掉 ANR 问题了，但理论状况是吗？

查看顶部的 Pending 音讯看板能够发现，Pending 队列曾经被塞满，大量音讯没有失去及时执行。

点击右边蓝色的零碎音讯查看详情：

一个 CREATE_SERVICE 的音讯 pending 了 10s 无余，它才是引爆本次 ANR 的“炸弹”。

但以后正在执行的音讯只消耗了 1.7s，它必定不是全副起因。持续查看历史调度数据。

再往前递推 10s，发现历史还有两条重大耗时音讯，总执行耗时超过 6s。这两条音讯才是本次 ANR 产生的最大起因。业务方只有同时看到并解决了这两个问题，这次的 ANR 问题才能够被彻底解决。

案例 3

本次的数据比拟有代表性，能够看到主线程 Looper 调度历史中，有大量飘红的音讯。

每个耗时音讯的 CPU 与 Wall 差距都很大，有些理论 CPU 工夫只有 1ms 的，然而 WallDuration 却有 220ms，阐明在此期间主线程简直很难抢占到 CPU 工夫片，大量的工夫节约在 CPU 进行工作切换上，猜想可能是以后设施 CPU 负载过重，或者主线程被其余线程抢占了太多 CPU 资源。

持续剖析 system.log 日志：

12-03 19:01:47.821 1309-1328/? E/ActivityManager: ANR in com.***.******
    PID: 5323
    Reason: executing service *******/com.***.*****.service.**AppTrackingService
    Load: 46.81 / 40.09 / 41.53
    CPU usage from 0ms to 12496ms later (2021-12-03 19:01:35.306 to 2021-12-03 19:01:47.801):
      116% 5323/com.***.****** 64% user + 52% kernel / faults: 11566 minor 11 major
      45% 1309/system_server: 26% user + 18% kernel / faults: 1830 minor 4 major
      18% 634/surfaceflinger: 12% user + 5.8% kernel / faults: 49 minor
      10% 590/android.hardware.graphics.composer@2.2-service: 5% user + 5.6% kernel
      6.7% 2433/glgps4774: 4.3% user + 2.4% kernel / faults: 55 minor
      6.4% 630/audioserver: 5.7% user + 0.6% kernel / faults: 54 minor 1 major
      3% 1756/com.huawei.lbs: 2.1% user + 0.8% kernel / faults: 1 minor
      2.7% 4811/kworker/0:0: 0% user + 2.7% kernel
      2.6% 598/vendor.huawei.hardware.audio@4.0-service: 0.7% user + 1.9% kernel / faults: 4 minor
      1.9% 150/kswapd0: 0% user + 1.9% kernel
      1.2% 4542/kworker/u17:0: 0% user + 1.2% kernel
      1.1% 1849/com.android.phone: 0.6% user + 0.4% kernel / faults: 1 minor
      1.1% 30529/kworker/u16:0: 0% user + 1.1% kernel

能够看到设施整体负载有减轻趋势，但不算重大（8 核 CPU）。可是，以后线程 CPU 使用率却高达 116%，kernal 占比 52%，根本占据了一半的 CPU 使用率，示意以后主过程有大量 syscall。

进一步查看 log 文件：

       46% 5323/com.***.******: 61% user + 23% kernel / faults: 247 minor
        44% 5698/realm_thread-io-4: 4% user + 40% kernel
        11% 5776/OkHttp TaskRunn: 5.8% user + 5.8% kernel
        8.7% 6055/Thread-764: 5.8% user + 2.9% kernel
        5.8% 5345/Jit thread pool: 0% user + 5.8% kernel
        3.8% 5699/realm_thread-io-5: 5.8% user + 0% kernel
        2.9% 5645/realm_thread-io-1: 2.9% user + 0% kernel
        2.9% 5704/DefaultExecutor: 0% user + 2.9% kernel
        2.9% 5724/pool-35-thread-: 2.9% user + 0% kernel

发现 realm_thread-io-4 线程占用 44% 的 CPU，同时 OkHttp TaskRunn 占用了 11%，这两个子线程加起来占用了 55% 的 CPU 使用率，同时 realm_thread-io-4 的 kernal 占比高达 40%。

这里根本能够破案了，通过进一步剖析业务逻辑也印证了这个问题：一个异样的 realm_thread-io-4 在进行大量 IO，同时因为种种原因导致其 nice 值较高，抢占了大量主线程的 CPU 工夫，触发了这次的 ANR。

5. 结语

以上几种案例比拟典型，置信大家也留神到了这些本应该比较复杂和艰涩的 ANR 问题，借助于 LooperMonitor 弱小的数据收集和可视化能力，居然都变得十分直观起来，这也是咱们心愿 LooperMonitor 能给业务侧同学带来的理论价值。

当然，工具只是辅助，最终解决和定位问题的还是要靠人的教训和剖析，线上的 ANR 问题千奇百怪，只靠 LooperMonitor 的数据必定是无奈解决所有场景的。MDAP 目前仍在紧锣密鼓地开发更多能力来丰盛卡顿 ANR 监控上报，为剖析和定位问题提供更为详实和齐备的数据，目前已有的包含 Java、Native 侧堆栈 dump、线程死锁监控，后续还行将上线线程监控，在 ANR 产生时提供更为清晰的存活线程数据。

本文作者

Xiaqiu，Android 开发工程师，来自 ShopeeFood 团队。