barrier repair barrier( 三 )


barrier repair barrier

文章插图
通过上面实现可以看到,barrier 消息是不会主动移除的,需要设置 barrier 消息的业务消息得到响应后主动移除该消息,否则 barrier 消息会一直存在!
分析到这里就可以很好的解释为何在 MessageQueue.next()接口内部多次调用 NativePollOnce 了,一定是当前的 mMessage 是个 barrier 消息,但是与其关联的业务消息一直没有出现,或者执行之后没有同步移除该消息,导致该 barrier 消息一直处于消息队列头部,每次获取下一个消息时,都被 barrier 拦截和并遍历异步消息,如果有异步消息则响应,没有异步消息则通过 nativePollOnce 进行等待,从而阻塞了正常消息的调度和响应!
进一步梳理 MessageQueue.next 接口执行逻辑,通过下图就可以清晰的看到我们在 Native 层 Hook 时看到 nextPollTimeMills 传参-1 的场景是怎么设置的 。
barrier repair barrier

文章插图
那么结合本类 ANR 问题,消息队列第一个待调度的消息是不是 barrier 消息呢?我们再次找到上面分析的案例,通过监控时序图观察第一个被 block 的消息 。
barrier repair barrier

文章插图
通过上图可以清晰的看到,当前消息 target 对象为 null,正是 barrier 消息!破案了!
连锁反应:按照上面的分析,如果 barrier 消息没有及时移除,那么每次通过 MessageQueue.next()查询时,只能过滤并返回带有异步属性的消息,如用户点击消息 input,vsync 消息等等 。即使用户交互和 UI 刷新消息可以正常执行,但是大量业务消息无法执行,这就导致了 UI 展示可能存在异常或功能异常,并且应用 service,receiver 等消息并没有异步属性,因此也会被 block,最终造成响应超时发生 ANR!
结合当前问题,我们发现该用户在第一次 ANR 不久之后再次发生 ANR,主线程 Trace:
barrier repair barrier

文章插图
第二次 ANR 时,对应的调度时序图如下:
barrier repair barrier

文章插图
通过当前用户连续 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=Sschedstat=(24422862293380706035221)utm=187stm=57core=5HZ=100发生第二次 ANR 时线程状态及 utm,stm 耗时:
|state=Sschedstat=(27962313424422940986270)utm=202stm=77core=5HZ=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 消息同步监测,遗憾的是线下并没有复现 。
因此只能再次回到代码层面,对相关改动进行分析,最终在一笔需求提交中发现了线索 。