今日头条ANR优化实践系列 - Barrier导致主线程假死( 二 ) _ANR优化

文章插图

为此我们第一反应是系统出问题了？但是进一步对比来看，该类现象只在某个版本之后明显增加，而之前的版本并没有这类现象，如果是厂商更新 rom 导致的问题，应该影响全版本，甚至会影响所有应用，但事实并非如此，因此这与我们的推测并不符合，无法自圆其说。
按照我们的理解，如果直接进入 NativePollOnce 场景并且一直没有唤醒的话，那么 CPU Duration 应该会很少，并不应该是这样表现(CPU Duration 达到或超过 100ms) 。
定向监控：【今日头条ANR优化实践系列 - Barrier导致主线程假死】考虑到国内厂商对 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，如下图：