突然弹出王者荣耀停止运行,GC超时导致的后台应用崩溃问题分析


写在前面
这个问题之所以会拿出来仔细分析,一方面是因为这个问题不是简单的应用崩溃而是框架层的报错,另一方面是因为希望通过这个问题梳理下后台GC的超时检测机制怎样的,这样我们后面在应用层如果重写finalize
方法回收时会考虑的更加全面点。
问题背景
复现概率: 偶现
问题版本: Android R
问题现象: 处于微信界面,突然弹出王者荣耀停止运行
初步分析
拿到问题日志后,先看下报错的堆栈

单单从这段堆栈看的话,BulkCursorToCursorAdaptor
执行finalize
超过了10s,导致FinalizerWatchdogDaemon
报错,FinalizerWatchdogDaemon
字面上看像是监测回收超时的守护线程。
看下FinalizerWatchdogDaemon
代码中的作用解释

简单解释下就是:如果对象的finalize
出现阻塞超时了会导致进程退出
这个问题中对应的是数据库的关闭,当然也可以发生在其它场景下,只要重写了成员函数finalize
的对象都有可能会遇到这个问题,所以如果再遇到GC超时的报错,报错堆栈AndroidRuntime:at java.lang.Daemons$
上面的内容可能会不一样。
那么对于重写了成员函数finalize
的对象,当它们被GC决定要被回收时,会立刻回收吗?
其实不会马上被回收,而是被放入到一个队列中,等待FinalizerDaemon
守护线程去调用它们的成员函数finalize
后再被回收。

超时阈值

注释中对于该值的说明是它很快将被移除,实际这个值在代码中并没有起到真正的作用了,更新它的值是为了方便在外边读取到。
真正的超时阈值是通过VMRuntime.getFinalizerTimeoutMs
获取,默认值是10s.

超时检测
通过watchdog机制检测finalizer
在超时时间内有没有成功析构回收对象

Step1 GC前的检查

开启回收之前,needToWork
会被置为true,此时sleepUntilNeeded
返回的是true,所以线程不会wait

如果此时线程处于wait
,被中断了或者有OOME
发生时,这个时候回到开头判断下isRunning()
,也就是看下回收对象这个线程是否为空,如果该线程为空的话,这个循环体就没有必要再继续执行下去了。

Step2 等待GC完成
这一步是等待回收结束的过程,这个睡眠过程中如果被中断,说明在这个周期内完成了析构,直接返回null

sleepForNanos
对应的函数很简单,如果在超时时间内完成GC,就会计算传进来的超时阈值减去当前已经睡眠的时间,如果这个差值小于0,说明睡眠的时间超过了阈值。

Step3 GC处理超时
如果第二步中的超时时间内析构没有完成,则返回析构的对象,触发finalizerTimedOut
。
到了这一步是最不希望看到的结局,此时系统会弹出应用停止运行的报错框。
注意这个时候并没有立刻杀死进程,杀死进程的选择权交给了用户,即通过弹窗展示给用户,但对于用户来说会一头雾水

分析结论
这种问题其实还是比较常见的,特别是低内存的机器上。RootCasue
就是对象回收超时了,一般是由于队列中等待FinalizerDaemon
线程回收的对象太多导致,或者此时系统资源异常紧张比如CPU负载过高或者低内存环境下。
场景实测
模拟还原现场
通过模拟GC
时耗时操作,应用退到后台后10s会弹出报错框,堆栈如下

验证了超时时间的确是10s,同时也验证了GC时耗时的操作确实会可能触发这个现象
对比机情况
在手头的小米note9 pro
上进行场景模拟测试,模拟GC耗时100s的情况

在小米的机器上,到了默认的10s后并不会有弹窗,说明小米肯定修改了超时时间,第一次是等待了全部的100s后竟然正常回收,说明超时时间设置的比较大。紧接着下一次在达到了近80s时,进程收到signal 9
直接被kill了,此时再点击应用是冷启动。
小米修改了超时阈值(超过100s),通过直接sig 9杀掉了进程,没有报错弹窗,所以用户无感知
测试机情况
同样的在我们的机器上模拟GC耗时100s的情况
退出应用到后台,此时系统触发GC回收,达到十秒钟时,界面上直接弹出停止运行的报错框,此时只有点击了关闭应用,才会去kill进程
修改策略
在GC规定的超时时间内如果没有完成析构,直接sig 9
给对应进程