今日头条 ANR 优化实践系列 - Barrier 致使主线程假死

简述：

前文，咱们经过线上案例对影响 ANR 问题的六大场景进行剖析，这几类场景基本覆盖了线上大部分问题，详见ANR 案例分析集锦。同时咱们选取了较多 NativePollOnce 场景的案例，便于你们更好理解，ANR 时看到的 NativePollOnce 场景的问题，并非致使 ANR 的根本问题。java

下面要介绍的这类问题，Trace 现场依然是 NativePollOnce 信息，但与前几类问题不一样的是，这类问题真的发生在 NativePollOnce 场景，接下来就看看究竟是什么缘由致使的。markdown

主线程 Trace 堆栈：

分析思路：

针对该类问题，当看到这个信息时，第一判断依然是主线程历史消息耗时严重，或者系统负载太重致使的问题，由于工做平常分析了太多这类场景的 ANR 问题，并且最后的结论也证实都与此场景无关。但分析这个问题时，进一步拆解大盘指标发现一段时间内 ANR 增长的量级，基本所有落在这个场景，这不太符合咱们的预期。可是鉴于 Trace 信息有限，只好把目光转移到系统侧，看看是否有线索。架构

分析系统&进程负载：

观察系统负载： 在 ANR Info 中查看 Load 关键字，发现系统在前 1 分钟，前 5 分钟，前 15 分钟各个时段负载并不高。并发

观察进程 CPU 分布： 进一步观察"CPU usage from 0 ms to 24301 later"，看到 ANR 以后这 24S 多的时间，应用主进程 CPU 占使用率只有 15%，可是 com.meizu.mstore 应用 CPU 使用率达到 92%，user 与 kenel 比例分别为 71%，20%。与此同时 kswapd,mmc-cmdqd 等内核线程 CPU 使用率并不高，说明系统负载整体正常。若是根据咱们前面案例分析得出的结论来看，这种场景难道是 com.meizu.mstore 进程严重抢占 CPU 致使的？带着这个疑惑，继续观察系统 CPU 分布。异步

观察系统 CPU 分布：async

进一步分析系统负载，发现总体 CPU 使用率稍微有些高。user 占比 37%，kernel 占比 24%，iowait 占比 6.9%，说明这段时间系统 IO 确实有些繁忙。工具

系统侧结论： 经过观察系统负载和各个进程的 CPU 使用状况，发现系统环境比较正常，可是 com.meizu.mstore 进程 CPU 占比偏高，并且 kernel 层 cpu 使用率(20%)较高，与系统 iowait (6.9%)占用较高可能存在必定关联，那么 IO 负载较高对当前应用有多大影响呢？咱们回到应用侧进一步分析。oop

应用侧分析：

根据上面的分析，咱们将方向再回到当前进程，经过对比各线程 cpu 耗时(utm+stm)，并无看到某个线程存在明显异常。主线程 CPU 执行时长 utm:187，stm:57，基本正常。post

在分析对比完线程 CPU 耗时以后，将目光再次聚焦到Raster 监控工具的调度时序图上面。性能

经过该时序图，观察如下三类信息特征：ANR 前的历史消息，正在执行的消息，被 Block 的消息：

历史消息： 主线程并不存在单次历史消息耗时严重的现象。

当正在执行的消息：正在执行的消息 Wall Duration 为 21744ms，CPU Duration 为 100ms。也就是说大量的时间发生在等待的场景，结合该场景，若是期间是由于执行 Idle Task 致使的耗时严重或长时间 Wait，那么 ANR 抓取的堆栈应该有 IdleTask 相关信息才对，所以首先排除了是 Idle Task 耗时严重致使的问题。

被 Block 消息：从上图能够看到， 第一个待调度的消息被 block 时长为 22343ms，其 block 时长基本等于当前正在执行消息的 Wall Duration 时长。也就说明了本场景大量消息 blcok 是受到了当前正在执行的消息影响。

分析到这里咱们就有些困惑了，ANR 发生时当前正处于 NativePollOnce 场景，可是前面咱们屡次在案例分析中提到，进入 NativePollOnce 场景的条件是：消息队列没有马上调度的消息时，会有条件的进入 wait 状态，等到超时或者新消息加入时会唤醒该线程并执行，可是从上图能够看到消息队列中存在大量待调度消息，并且不少消息都被 block 了 20 多 S，既然这么多消息能够被调度，那么系统为什么仍是一直在 NativePollOnce 环境中呢？难道真的是底层发生了问题，致使没法唤醒当前线程？

带着这个疑惑，咱们陆续分析了同段时间内其余用户上报的问题，发现存在一样的现象：NativePollOnce 场景的 WallDuration 广泛较长，有的甚至超过了 100S，可是 Cpu 时长很短。以下图：

为此咱们第一反应是系统出问题了？可是进一步对比来看，该类现象只在某个版本以后明显增长，而以前的版本并无这类现象，若是是厂商更新 rom 致使的问题，应该影响全版本，甚至会影响全部应用，但事实并不是如此，所以这与咱们的推测并不符合，没法自圆其说。

按照咱们的理解，若是直接进入 NativePollOnce 场景而且一直没有唤醒的话，那么 CPU Duration 应该会不多，并不该该是这样表现(CPU Duration 达到或超过 100ms)。

定向监控：

考虑到国内厂商对 Rom 定制化的习惯，为了确认上面监控的 Cpu 耗时是不是厂商在底层定制产生的耗时，咱们在 Native 层经过 Hook 代理对 nativePollOnce 接口进行了监测。

在线上小范围验证和复现，经过观察这类 ANR 问题时的线程调度时序图，最终找到一个 NativePollOnce 停留时长高达 100S 的案例，以下图：

经过上图(TYPE=5)能够发现，ANR 发生前，主线程在消息调度结束与下次消息调度开始前，发生屡次长时间停留的现象，并且期间都存在必定的 Cpu 耗时，可是远小于 Wall duration。与此同时查看本次进行 epoll_wait 期间，NativePollOnce 是不是一直没有返回，经过监控输出的日志，发现以下现象：

在对齐监控时序图与上图日志时间戳以后，看到 Java 层调用 looper.next()获取下一个消息过程当中，Native 层 NativePollOnce 接口调用了屡次，并且每次进入 epollwait 时传入的参数 timeout 为-1。分析到这里有些疑惑了，这并非咱们预期的一直 wait 场景啊，参数-1 表明什么意思呢？继续向下看。

MessageQueue 代码分析：

既然 ANR 这段时间，执行屡次 NativePollOnce，就说明其它线程已经屡次将主线程屡次从 epoll wait 状态唤醒，可是消息队列已经有大量待调度的消息，为什么主线程还依然停留在 looper.next()内部呢？分析到这里只好再次回到上层代码继续分析，这个参数-1 是哪里设置的。

从上图能够看到，每当消息执行结束后，获取下个消息以前会先主动调用一次 NativePollOnce，可是 nextPollTimeoutMillis 默认为 0，并非底层接口代理时看到的-1，那么这个-1 是哪里传入的呢？继续向下看。

经过上图能够看到，只有一个地点将 nextPollTimeoutMillis 设置为-1，可是经过注释能够清晰的看到提示"msg=mMessage"，没有消息？这与现实严重不符啊，ANR 发生时，消息队列明显有不少消息待执行，这里却提示"msg=mMessage"。

经过进一步观察上述逻辑发现，该提示发生在 else 分支，若是进入到该分支，那么则说明 msg 对象获取为空，可是在上面明明看到赋值过程"msg=mMessage"，并且当前这种场景 mMessage 确定不为 null，毕竟在 ANR 时获取的待调度消息也是经过 mMessage 遍历获得的。

既然 mMessage 不是 null，那么就说明"msg=mMessage"确定不是 null，可是到了下面却为 null，说明在此过程确定被某个逻辑给从新赋值了，继续分析。

经过上图能够看到只有这个场景可能将 msg 从新赋值，那么这部分逻辑是作什么的呢？

Barrier 机制介绍：

看到上面的注释瞬间明白了，原来是 Barrier 机制，是 Android 系统用来保障部分系统消息高优调度的一种机制，实现原理很简单：会在每次消息返回前，检测该消息是不是 barrier 消息，barrier 消息的典型特征就是 msg.target 对象为 null，以下图：

若是是 Barrier 消息，那么将对消息队列中的消息进行遍历，找到第一个异步消息，而后将其赋值给 msg。可是若是遍历了全部的消息都没有找到异步消息，那么最后一个消息 msg.next 确定为 null，此时 msg 会被置为 null，并退出循环。

上图为异步消息的设置和判断是不是异步消息的接口实现，咱们平常建立的 Message 是不会设置该属性的。只有系统在某些特殊场景，如 UI 刷新，为了保障交互体验，会在请求 vsync 信号前，先发送一个 barrier 消息，而后等到 barrier 消息执行时，遍历 vsync 消息并将其强制调整到头部，以保证该类消息的响应能力：barrier 消息设置和移除，实现逻辑以下：

经过上面实现能够看到，barrier 消息是不会主动移除的，须要设置 barrier 消息的业务消息获得响应后主动移除该消息，不然 barrier 消息会一直存在！

分析到这里就能够很好的解释为什么在 MessageQueue.next()接口内部屡次调用 NativePollOnce 了，必定是当前的 mMessage 是个 barrier 消息，可是与其关联的业务消息一直没有出现，或者执行以后没有同步移除该消息，致使该 barrier 消息一直处于消息队列头部，每次获取下一个消息时，都被 barrier 拦截和并遍历异步消息，若是有异步消息则响应，没有异步消息则经过 nativePollOnce 进行等待，从而阻塞了正常消息的调度和响应！

进一步梳理 MessageQueue.next 接口执行逻辑，经过下图就能够清晰的看到咱们在 Native 层 Hook 时看到 nextPollTimeMills 传参-1 的场景是怎么设置的。

那么结合本类 ANR 问题，消息队列第一个待调度的消息是否是 barrier 消息呢？咱们再次找到上面分析的案例，经过监控时序图观察第一个被 block 的消息。

经过上图能够清晰的看到，当前消息 target 对象为 null，正是 barrier 消息！破案了！

连锁反应：

按照上面的分析，若是 barrier 消息没有及时移除，那么每次经过 MessageQueue.next()查询时，只能过滤并返回带有异步属性的消息，如用户点击消息 input，vsync 消息等等。 即便用户交互和 UI 刷新消息能够正常执行，可是大量业务消息没法执行，这就致使了 UI 展现可能存在异常或功能异常，而且应用 service，receiver 等消息并无异步属性，所以也会被 block，最终形成响应超时发生 ANR！

结合当前问题，咱们发现该用户在第一次 ANR 不久以后再次发生 ANR，主线程 Trace：

第二次 ANR 时，对应的调度时序图以下：

经过当前用户连续 2 次 ANR 的消息调度监控时序图能够看到，本次 ANR 时，以前的历史消息记录没有发生任何变化，也就是说第一个 ANR 发生后确实没有再调度其余消息，但 2 次 ANR 的 WallTime 间隔超过 40S，也就是说这 40S 时间里，主线程确实一直 Block 在当前场景！

在消息调度时序图上进一步对比分析，发现两次 ANRCase，主线程当前正在执行消息的 Cpu Time 时长却发生了变化，即从 100ms 增长 450ms。那么这个数据是否置信吗？

结合这两次 ANR，分别分析一下 ANR Trace 主线程 utm+stm 的耗时(见上图 2 次 Trace 堆栈)：

发生第一次 ANR 时线程状态及 utm,stm 耗时：

state=S schedstat=( 2442286229 338070603 5221 ) utm=187 stm=57 core=5 HZ=100
复制代码

发生第二次 ANR 时线程状态及 utm,stm 耗时：

| state=S schedstat=( 2796231342 442294098 6270 ) utm=202 stm=77 core=5 HZ=100
复制代码

用第二次发生 ANR 时的 utm+stm 减去第一次 ANR 时的 utm+stm，即 202+77-(187+57)=35ms。这个值对应的是 cpu 时间片，utm,stm 单位换算成时间单位为 1 比 10ms，即 35*10=350ms。这个值刚好等于 Raset 监控工具统计到的两次 Cputime 差值：450ms-100ms=350ms。

说明在此期间消息队列增长了多个消息，由于每次增长一个消息，主线程都会从 epollwait 场景唤醒，而后回到 java 环境对消息队列进行遍历，判断是否有异步消息，若是没有找到，则再次进入 epollwait 状态，如此反复，从而致使了上述现象！

问题初定位：

经过上面的层层分析，咱们知道了是 barrier 同步机制出现了问题，致使消息调度发生异常，即：在 barrier 消息没有被移除以前，主线程只能处理 asyncronous 属性的消息，这类消息一般是用来刷新的 vsync 消息，以及响应用户交互的 input 消息，可是正常的业务消息及其余系统消息则没法正常调度，如 Serivce，Receiver 具体超时行为的消息，所以致使了 ANR。

定位及修复：

在定位到缘由以后，接下来就是找到问题并解决问题，具体什么样的改动会引发这里问题了，经过分析咱们知道既然是 Barrier 消息同步的问题，那么咱们能够在设置 barrier 和移除 barrier 的过程加入监控，判断哪里设置了 barrier 消息，可是没有同步移除。经过 Java hook 代理了 MessageQueue 的 postSyncBarrier 和 removeSyncBarrier 接口，进行 Barrier 消息同步监测，遗憾的是线下并无复现。

所以只能再次回到代码层面，对相关改动进行分析，最终在一笔需求提交中发现了线索。

逻辑调整前： 先移除将要强制调度的并设置了异步属性的消息，再强制调度该消息，以保证该消息不受 barrier 消息以前的消息 block，进而提升响应能力。

if (hasMsg) {
    ......
    handler.removeCallbacks(message.getCallback()); //先移除
    handler.dispatchMessage(cloneMsg); //再强制调度该消息
    ......
}
复制代码

逻辑调整后： 先强制调度该消息，而后再将该消息从队列中移除。

......
        handler.dispatchMessage(newMessage); //先强制调度
       handler.removeCallbacks(message.getCallback());  //从队列中移除消息
    ......
    }
复制代码

可是时序调整后存在必定隐患，即在强制调用 DoFrame 消息期间，业务可能会再次触发 UI 刷新逻辑，产生 barrier 消息并发出 vsync 请求，若是系统及时响应 vsync，并产生 DoFrame 消息，那么调用 removeCallbacks 接口会一次性清除消息队列中全部的 DoFrame 消息，即：移除了消息队列以前的 DoFrame 消息和下次待调度的 DoFrame 消息，可是与下次 DoFrame 消息同步的 barrier 消息并无被移除。

那么为何会移除多个消息呢？这就要从handler.removeCallbacks 的实现提及了。

进一步查看 messageQueue.removeMessages 接口实现，发现该接口会遍历消息队列中符合当前 runnable 以及 object 的消息，可是上面传递的 Object 对象是 null，所以就至关于移除了当前 Handler 对象下面全部相同 runnable 对象的消息！

由于强制刷新和时序调整的问题，致使了消息队列中同时存在 2 个 UI doFrame 消息，并在强制执行以后被同时移除，从而致使一个无人认领的 barrier 消息一直停留在消息队列！

其它场景：

此外，除了上面遇到的场景会致使这类问题以外，还有一种场景也可能会致使这类问题，即:UI 异步刷新，尽管 Android 系统禁止异步刷新，并利用 checkThread 机制对 UI 刷新进行线程检查，可是百密一疏，若是开启硬件加速，在 AndroidO 及以后的版本会间接调用 onDescendantInvalidated 触发 UI 刷新，该逻辑躲过了系统 checkThread 检查，将会形成线程并发隐患。以下图，若是并发执行则会致使前一个线程的 mTraversalBarrier 被覆盖，从而致使 vsync 消息与 barrier 出现同步问题。

查看 Android Q 源码，看到 onDescendantInvalidated 内部加上了 checkThread，但被注释掉了！解释以下：修复摄像头后从新启用或者经过 targetSdk 检查？好吧，或许是忘记这个 TODO 了。

总结：

至此，咱们完成了该类问题的分析和最终定位，综合来看该类问题因 Trace 场景(NativePollOnce)和问题自己的高度隐蔽性，给排查和定位带来了极大挑战，若是单纯依靠系统提供的日志，是很难发现 MessageQueue.next()内部发生了异常。这里咱们经过 Raster 监控工具，还原了问题现场，并提供了重要线索。如今总结来看，该类问题其实具备很明显的特征，表如今如下几个方面：

问题场景 ANR Trace 集中聚合在 NativePollOnce，此过程 Wall duration 持续很长，而且屏蔽了后续全部正常消息调度，看起来像主线被冻结同样。
经过 Raster 监控工具能够清晰的看到，消息队列中若是第一个待消息 target 为 null，即为 barrier 消息，能够经过后续消息 block 时长评估影响程度。
出现该类问题时，由于正常消息没法被调度，如 Service，Receiver 消息，将会致使应用连续发生 ANR，直到用户主动 Kill 该进程。

后续：

接下来的文章中，咱们将会介绍系统服务与客户端 binder 通讯过程当中，由于时序颠倒引发的 ANR 问题，由于是系统机制出现了 bug，理论上全部应用都会受到影响，问题表现一样很隐蔽，那么这类问题究竟是什么样的表现呢？敬请期待。

优化实践更多参考：

今日头条 ANR 优化实践系列(1)-设计原理及影响因素

今日头条 ANR 优化实践系列(2)-监控工具与分析思路

今日头条 ANR 优化实践系列(3)-实例剖析集锦

Android 平台架构团队

咱们是字节跳动 Android 平台架构团队，以服务今日头条为主，面向 GIP，同时服务公司其余产品，在产品性能稳定性等用户体验，研发流程，架构方向上持续优化和探索，知足产品快速迭代的同时，追求极致的用户体验。

若是你对技术充满热情，想要迎接更大的挑战和舞台，欢迎加入咱们，北京，深圳均有岗位，感兴趣发送邮箱：tech@bytedance.com ，邮件标题：姓名 - GIP - Android 平台架构。

欢迎关注「字节跳动技术团队」