前言
前段时间在 bugly 上发现公司某款十万级 DAU 的应用出现了某个类型的 ANR 异常,发生数量几百次,异常信息如下:
ANR Input dispatching timed out (Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 2. Wait queue head age: 6326.2ms.)
com.tencent.smtt.sdk.o.com.tencent.smtt.sdk.o a(boolean)(Unknown Source)
其中 com.tencent.smtt.sdk
是腾讯浏览器 X5 内核 SDK,结合出错堆栈也大都指向 X5 内核,初步怀疑是 X5 内核所引起。
查找原因
bugly 按异常类型和出错堆栈进行分门别类,所以同一类型异常的信息和出错堆栈千篇一律,几乎完全没用。
主要着手方向为两个点:
- 跟踪日志
- trace.txt 文件
对于跟踪日志并没有看出太多诸如 io GC 之类的信息,不过通过埋点信息还是大致定位了 ANR 发生的场景处于应用刚启动不久。
对于 trace 文件,也有两个方面入手:
一方面是挨个寻找 bugly 该类型异常下面的附件看是否有 trace 文件;另一方面尽量在本地重现提取 trace 文件。
本地重现的艰难就不说了,直接说结果吧:不可行。只能寄希望于 bugly 上的附件了。
Android 系统发生 ANR 后会把当前的 ANR 信息以及堆栈信息全部保存起来置于 /data/anr
目录下,bugly 通过 FileObserver
去监听 /data/anr
目录下是否有文件更新,从而获取 trace 文件。
由于 /data/anr
目录权限等问题 bugly 大多数时候都无法搜集到 trace 文件,这个时候就只能碰运气了。
在查看了上百个异常 id 后,终于在另外一位同事的帮助下逮到了一个 trace 文件。一番查看之后发现锁等待超时 ANR,非常开心,几乎与死锁造成的 ANR 一样简单、清晰明了。
分析 trace
在 trace 文件搜索关键字 com.tencent.smtt.sdk.o.a
,发现出现该关键字的两处地方:
···
"main" prio=5 tid=1 Blocked
| group="main" sCount=1 dsCount=0 obj=0x7550f000 self=0xab62a9e0
| sysTid=2426 nice=-1 cgrp=top_visible sched=0/0 handle=0xf7694b38
| state=S schedstat=( 3501533945 1232846831 7661 ) utm=298 stm=52 core=0 HZ=100
| stack=0xff2e5000-0xff2e7000 stackSize=8MB
| held mutexes=
at com.tencent.smtt.sdk.o.a(unavailable:-1)
- waiting to lock <0x0e1b02ea> (a com.tencent.smtt.sdk.o) held by thread 50
at com.tencent.smtt.sdk.bt.a(unavailable:-1)
- locked <0x02830f51> (a com.tencent.smtt.sdk.bt)
at com.tencent.smtt.sdk.WebView.c(unavailable:-1)
at com.tencent.smtt.sdk.WebView.<init>(unavailable:-1)
at com.tencent.smtt.sdk.WebView.<init>(unavailable:-1)
at com.tencent.smtt.sdk.WebView.<init>(unavailable:-1)
at com.tencent.smtt.sdk.WebView.<init>(unavailable:-1)
at com.wlqq.websupport.widget.WLWebView.<init>(TbsSdkJava:31)
at java.lang.reflect.Constructor.newInstance!(Native method)
at android.view.LayoutInflater.createView(LayoutInflater.java:641)
···
"tbs_preinit" prio=10 tid=50 Native
| group="main" sCount=1 dsCount=0 obj=0x133df400 self=0xac93fa18
| sysTid=2564 nice=-8 cgrp=top_visible sched=0/0 handle=0xd96cf930
| state=S schedstat=( 43762445 28224114 130 ) utm=3 stm=1 core=4 HZ=100
| stack=0xd95cd000-0xd95cf000 stackSize=1038KB
| held mutexes=
kernel: __switch_to+0x70/0x7c
kernel: do_wait+0x1e0/0x264
kernel: SyS_wait4+0xb8/0xf8
kernel: compat_SyS_wait4+0x2c/0xf4
kernel: el0_svc_naked+0x20/0x28
at dalvik.system.DexFile.openDexFileNative(Native method)
at dalvik.system.DexFile.openDexFile(DexFile.java:303)
at dalvik.system.DexFile.<init>(DexFile.java:115)
at dalvik.system.DexFile.loadDex(DexFile.java:155)
at dalvik.system.DexPathList.loadDexFile(DexPathList.java:287)
at dalvik.system.DexPathList.makePathElements(DexPathList.java:253)
at dalvik.system.DexPathList.<init>(DexPathList.java:120)
at dalvik.system.BaseDexClassLoader.<init>(BaseDexClassLoader.java:48)
at dalvik.system.DexClassLoader.<init>(DexClassLoader.java:57)
at com.tencent.smtt.export.external.DexLoader.createDexClassLoader(unavailable:-1)
at com.tencent.smtt.export.external.DexLoader.<init>(unavailable:-1)
at com.tencent.smtt.sdk.bh.<init>(unavailable:-1)
at com.tencent.smtt.sdk.o.a(unavailable:-1)
- locked <0x0e1b02ea> (a com.tencent.smtt.sdk.o)
at com.tencent.smtt.sdk.k.run(unavailable:-1)
···
可以很明显地看到 main 线程在等待去锁一个 com.tencent.smtt.sdk.o 类的对象 0x0e1b02ea,而该对象目前正被一个叫 tbs_preinit 的子线程(即tid 50,tid:thread id)所持有,该子线程锁住 0x0e1b02ea 后在做一个耗时操作,从而导致主线程响应事件等待超时 ANR。
tbs_preinit 线程的耗时操作主要包含两部分:
- tbs sdk jar 包本身并没有包含 X5 内核,应用在集成后首次启动时,该 sdk 会外界先获取 X5 内核相关东西,获取的方式是先通过当前手机上其他企鹅系的应用共享(比如微信、QQ、QQ 浏览器), 共享获取失败的情况下才会去网络下载。
- X5 内核获取成功后执行一系列的 dex2oat 操作
所以该 ANR 问题几乎只会在首次安装或者清除应用缓存的时候才发生,这一猜测也通过发生次数对比用户数(1.0x ≈ 1)得到了证实。同时这也是之前本地难以重现的一个重要因素。
解决思路
上面分析出是主线程等待锁 0x0e1b02ea 超时,那么对应的解决方法要么是让 tbs_preinit 线程尽早让出 0x0e1b02ea,要么干脆让主线程不去锁 0x0e1b02ea。
tbs_preinit 线程属于 tbs sdk 内部逻辑,大概是无法更改。而主线程的逻辑,经过顺藤摸瓜得知是应用打开后首页布局里有用到 tbs sdk 的 WebView,从而 tbs WebView 在主线程执行初始化时会去锁 0x0e1b02ea,看起来只需要在安装或者缓存清除后首次打开时不使用 tbs WebView 即可(貌似也没其他更好办法)。在翻了 tbs sdk jar 包混淆的代码后,得知可以通过 QbSdk.forceSysWebView()
让 tbs sdk 使用系统默认的 WebView。
最终的解决方案是本地缓存一个 SharePreference 的 flag,用来标记 X5 内核初始化是否成功,首页加载 tbs WebView 时判断该 flag 决定是否使用系统默认 WebView。
tbs jar 相关源码分析
version:v4.3.0
首次加载 X5 内核:
- 方法 com.tencent.smtt.sdk.k.run 子线程运行(tbs_preinit),第 28 行调用 com.tencent.smtt.sdk.o.a 初始化 x5 SDKEngine 并锁住(48 行)。
- 方法 com.tencent.smtt.sdk.o.a,第 129 行调用 com.tencent.smtt.sdk.bh 初始化。
- 类 com.tencent.smtt.sdk.bh,第 46 行调用com.tencent.smtt.export.external.DexLoader 初始化。
- 类 com.tencent.smtt.export.external.DexLoader,第 73行调用当前类方法 com.tencent.smtt.export.external.DexLoader.createDexClassLoader(108 行)。 方法 createDexClassLoader 最终调用系统 DexClassLoader 去加载 dex class。
main 线程加载 tbs WebView 并初始化:
- 当前页面 LayoutInflater 创建 tbs WebView。
- tbs WebView 初始化调用类方法 com.tencent.smtt.sdk.WebView.c(431 行),第 437 行调用 com.tencent.smtt.sdk.bt.a(50 行)。
- 方法 com.tencent.smtt.sdk.bt.a,第 53 行调用 com.tencent.smtt.sdk.o.a,发现 com.tencent.smtt.sdk.o.a 被子线程 tbs_preinit 锁住,于是主线程进行等待。
- 外部有诸如屏幕点击事件需要响应,主线程等待中,响应事件处理超时,ANR
解决方案的关键在于让主线程的 WebView 初始化不进入抢锁 com.tencent.smtt.sdk.o.a 的逻辑,也就是不执行 com.tencent.smtt.sdk.WebView.c,也就是 com.tencent.smtt.sdk.WebView 第 179 行的 this.c 逻辑不被执行。顺藤摸瓜一路反推上去发现执行处于第 159 行的 else 条件,只需要让与之对应的第 132 行 if 条件满足即可走另外的分支。132 行的 if 条件第一个方法 QbSdk.getIsSysWebViewForcedByOuter() 即是设置的 QbSdk 类的 b 属性,该属性可以通过第 904 行的 forceSysWebView 方法设置,一旦设置为 true,那么 WebView 类的 132 行 if 条件即可满足(第二个 boolean 位即判断是否是第三方 app,自动满足)。
后记
-
问题修复后持续关注了一段时间,效果不错,ANR 大幅下降,但是与预期中有差距。理论上这个解决思路应该能够完美修复,但实际上后续的版本还是陆续收到小部分 ANR 异常(大概占之前的 8%)。
鉴于成果已见效、混淆源码实在晦涩难懂以及时间关系,没有再继续深究了。 -
X5 内核通过共享或者下载的方式集成,这个思路本身不错,可以大幅减少 sdk 包的体积,同时更新也很方便。但是任何一个库都应该竭力避免在未完成初始化的情况下供用户使用,X5 内核预初始化和 tbs WebView 使用初始化冲突 ANR 示范了一个典型案例。
-
最后,吐两个槽:
- X5 内核的文档略等于无,一切都需要自己去扒混淆的 jar 包代码。
- X5 内核的反馈途径不够人性化,解决问题后本想给官方反映改进下,一点开我要反馈页面顿时失去了欲望。