一. 问题描述
1.1 问题JIRA
1.2 现象
手机无限重启,清数据后能开机,恢复数据的时候还是会无限重启.
1.3 结论
1.无限重启的原因:
由于每次开机AccessibilityManagerService都会去解析每个有辅助功能的app,system_server每次解析到千牛时就会crash,然后陷入无限循环.
2.恢复出厂设置后能开机,恢复数据时又无限重启:
恢复出厂设置后千牛会被卸载,开机时不会解析到它,所以能正常开机.恢复数据又会安装上千牛,安装上之后又会走到AccessibilityManagerService去解析千牛app,所以又会无限重启.
1.4导致问题的patch:
XXX
1.5修复链接:
XXX
二. 初步分析
2.1 查看system_server crash traces
03-25 15:38:07.968 1000 2311 2311 W ResourceType: Bad string block: string #6751 is not null-terminated
03-25 15:38:07.968 1000 2311 2311 W ResourceType: CREATING STRING CACHE OF 179048 bytes
03-25 15:38:07.968 1000 2311 2311 W ResourceType: Bad string block: string #6751 decoded length is not correct -1 vs 77
03-25 15:38:07.968 1000 2311 2311 D AndroidRuntime: Shutting down VM
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: *** FATAL EXCEPTION IN SYSTEM PROCESS: main
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: java.lang.RuntimeException: Error receiving broadcast Intent { act=android.intent.action.USER_SWITCHED flg=0x50000010 (has extras) } in com.android.server.accessibility.AccessibilityManagerService$2@5f00bfc
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at android.app.LoadedApk$ReceiverDispatcher$Args.lambda$-android_app_LoadedApk$ReceiverDispatcher$Args_51571(LoadedApk.java:1314)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at android.app.-$Lambda$FilBqgnXJrN9Mgyks1XHeAxzSTk.$m$0(Unknown Source:4)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at android.app.-$Lambda$FilBqgnXJrN9Mgyks1XHeAxzSTk.run(Unknown Source:0)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at android.os.Handler.handleCallback(Handler.java:789)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at android.os.Handler.dispatchMessage(Handler.java:98)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at android.os.Looper.loop(Looper.java:164)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at com.android.server.SystemServer.run(SystemServer.java:438)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at com.android.server.SystemServer.main(SystemServer.java:275)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at java.lang.reflect.Method.invoke(Native Method)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:240)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:780)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: Caused by: java.lang.IndexOutOfBoundsException
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at android.content.res.StringBlock.nativeGetString(Native Method)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at android.content.res.StringBlock.get(StringBlock.java:82)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at android.content.res.AssetManager.getPooledStringForCookie(AssetManager.java:336)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at android.content.res.TypedArray.loadStringValueAt(TypedArray.java:1274)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at android.content.res.TypedArray.getValueAt(TypedArray.java:1260)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at android.content.res.TypedArray.peekValue(TypedArray.java:1114)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at android.accessibilityservice.AccessibilityServiceInfo.<init>(AccessibilityServiceInfo.java:527)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at com.android.server.accessibility.AccessibilityManagerService.readInstalledAccessibilityServiceLocked(AccessibilityManagerService.java:1267)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at com.android.server.accessibility.AccessibilityManagerService.readConfigurationForUserStateLocked(AccessibilityManagerService.java:1848)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at com.android.server.accessibility.AccessibilityManagerService.switchUser(AccessibilityManagerService.java:1054)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at com.android.server.accessibility.AccessibilityManagerService.-wrap28(Unknown Source:0)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at com.android.server.accessibility.AccessibilityManagerService$2.onReceive(AccessibilityManagerService.java:420)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: at android.app.LoadedApk$ReceiverDispatcher$Args.lambda$-android_app_LoadedApk$ReceiverDispatcher$Args_51571(LoadedApk.java:1304)
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: ... 10 more
system_server 无限crash
对于分析java crash问题,我们首先看一下问题发生在哪一个servevice,然后再看一下具体crash的异常是什么,在这里我们能看到crash的service是AccessibilityManagerService,具体异常是IndexOutOfBoundsException.
2.2 手机断点调试
首先我们直接找到AccessibilityManagerService相关的最后的一个调用栈:
这里看上去是在解析资源文件,直接在代码里搜索了一下AccessibilityService_description是什么,找了半天没有找到这个资源.没办法自己找了个机器,然后断点调试看看这是什么东西:
首先这里会去查询packagemanager里所有关于"android.accessibilityservice.AccessibilityService"相关的service.
单步调试继续往下走:
继续点...
我们能看到每次peekedValue解析后都是一串字符串,看上去都和辅助功能有关系.点了很多次后发现一个规律,每一个有辅助功能的app都会被解析一遍.解析的内容看上去是app自己定义的,然后我找了一个com.miui.personalassistant应用看看它的AccessibilityService_description哪里来的,
首先去com.miui.personalassistant应用的AndroidManifest.xml中找到"android.accessibilityservice.AccessibilityService"
然我继续找到quickstart_accessibility
快要看到quickstart_accessibility_description的定义是什么了,如果和断点调试输出的内容"该服务为 [ 桌面信息助手 - 快捷功能卡片 ] 提供部分第三方应用页面的跳转支持,关闭该服务会导致页面跳转失效。"一样的话,那么这个AccessibilityService_description就能确定是app自定义的了.
点过去之后发现和自己的怀疑是一致的,这个资源是app自己定义的.到了这里得出了一个比较重要的信息,有可能是app自己定义了某些异常的字符串导致system_server解析失败,最终crash了.刚好有一个同事复现了这个问题,然后我拿到了现场之后继续debug,看看到底是哪一个app有问题呢?
经过多次断点调试发现每次都在解析千牛app的时候system_server crash了:
现在很怀疑就是千牛app导致的,我先把千牛这个apk从手机里pull出来(备份),然后用adb命令把这个apk卸载了,卸载完了之后立马就开机了.接着我再把千牛装上,system_server立刻又进入了无限crash的状态中.到这里已经得出了一个结论:千牛肯定和重启有关系.
2.3 找到出问题的patch
根据目前的结论"千牛肯定和重启有关系",然后调查了下是不是所有的机器都有这个问题,我随便找了几台手机装了我备份的千牛apk,装了好几台手机,全部无限重启....这问题真是相当的严重了,不知道是不是只有千牛一个app才会复现,要是还有其他app也复现,那就不得了了...
然后我们继续看数组越界这个地方是从哪里抛出来的异常:
Caused by: java.lang.IndexOutOfBoundsException
at android.content.res.StringBlock.nativeGetString(Native Method)
at android.content.res.StringBlock.get(StringBlock.java:82)
at android.content.res.AssetManager.getPooledStringForCookie(AssetManager.java:336)
at android.content.res.TypedArray.loadStringValueAt(TypedArray.java:1274)
at android.content.res.TypedArray.getValueAt(TypedArray.java:1260)
at android.content.res.TypedArray.peekValue(TypedArray.java:1114)
由于nativeGetString是个native方法,所以我们需要去对应的cpp文件中查找.一般这种方法都是放在"包名+方法+.cpp"文件中,所以我直接去找了"android_content_res_StringBlock.cpp"文件,找了一下没有找到这个文件.因为没有找到对应的文件,所以不清楚这个异常从哪里抛出来的.
因为这个问题是从某个版本才开始的,所以我逐个版本尝试装上千牛看看是不是会无限重启,最终确定了这个机器是在24号才开始复现的,接着直接去排查了那天的提交.
最终找到这个提交:
http://gerrit.pt.miui.com/#/c/262687/3/libs/androidfw/ResourceTypes.cpp
这个提交和我们的log刚好能匹配上:
03-25 15:38:07.968 1000 2311 2311 W ResourceType: Bad string block: string #6751 is not null-terminated
03-25 15:38:07.968 1000 2311 2311 W ResourceType: CREATING STRING CACHE OF 179048 bytes
03-25 15:38:07.968 1000 2311 2311 W ResourceType: Bad string block: string #6751 decoded length is not correct -1 vs 77
03-25 15:38:07.968 1000 2311 2311 D AndroidRuntime: Shutting down VM
03-25 15:38:07.969 1000 2311 2311 E AndroidRuntime: *** FATAL EXCEPTION IN SYSTEM PROCESS: main
随即revert掉这个change,然后带上有问题版本的manifest打了一个包进行了测试.结果是装上千牛也不会无限重启了.
三. 深入分析
因为没有找到抛异常的地方,所以还是不清楚这个问题的具体原因,为了继续调查原因我修改了这个patch,制造了一个native crash:
if (str[encLen] != 0x00) {
ALOGW("Bad string block: string #%d %s is not null-terminated pzc",
(int)idx, str);
FILE *fd = fopen("/sys/class/switch/h2w/state", "r");
fclose(fd);
return NULL;
}
(系统中没有/sys/class/switch/h2w/state节点)
这里会fclose一个null的fd,然后system_server 会native crash,接着我得到了一个正确的native调用栈:
03-28 22:34:00.924 4614 4614 F DEBUG : backtrace:
03-28 22:34:00.924 4614 4614 F DEBUG : #00 pc 00000000000733f8 /system/lib64/libc.so (fclose+16)
03-28 22:34:00.924 4614 4614 F DEBUG : #01 pc 000000000001f294 /system/lib64/libandroidfw.so (_ZNK7android13ResStringPool9string8AtEmPm+264)
03-28 22:34:00.924 4614 4614 F DEBUG : #02 pc 0000000000108be0 /system/lib64/libandroid_runtime.so http://guard.pt.miui.com/opengrok2/xref/v8-n-mido-dev/frameworks/base/core/jni/android_util_StringBlock.cpp#91
03-28 22:34:00.924 4614 4614 F DEBUG : #03 pc 0000000001d30f6c /system/framework/arm64/boot-framework.oat (offset 0x1985000) (android.content.res.StringBlock.nativeGetString+136)
03-28 22:34:00.924 4614 4614 F DEBUG : #04 pc 0000000001d314cc /system/framework/arm64/boot-framework.oat (offset 0x1985000) (android.content.res.StringBlock.get+488)
03-28 22:34:00.924 4614 4614 F DEBUG : #05 pc 0000000001d091f0 /system/framework/arm64/boot-framework.oat (offset 0x1985000) (android.content.res.AssetManager.getPooledStringForCookie+92)
03-28 22:34:00.924 4614 4614 F DEBUG : #06 pc 0000000001d25ec0 /system/framework/arm64/boot-framework.oat (offset 0x1985000) (android.content.res.TypedArray.loadStringValueAt+236)
03-28 22:34:00.924 4614 4614 F DEBUG : #07 pc 0000000001d25d44 /system/framework/arm64/boot-framework.oat (offset 0x1985000) (android.content.res.TypedArray.getValueAt+240)
03-28 22:34:00.924 4614 4614 F DEBUG : #08 pc 0000000001d2ac34 /system/framework/arm64/boot-framework.oat (offset 0x1985000) (android.content.res.TypedArray.peekValue+80)
03-28 22:34:00.924 4614 4614 F DEBUG : #09 pc 000000000198ed50 /system/framework/arm64/boot-framework.oat (offset 0x1985000) (android.accessibilityservice.AccessibilityServiceInfo.<init>+1324)
03-28 22:34:00.924 4614 4614 F DEBUG : #10 pc 00000000010fb3f0 /system/framework/oat/arm64/services.odex (offset 0xee7000)
(这个地方是多线程的,我得到过很多不一样的调用栈,尝试很多次,终于得到一个对应java crash的调用栈)
然后终于找到了抛异常的地方:
解析字符串主要是在android_util_StringBlock.cpp中的android_content_StringBlock_nativeGetString方法中,会进行两次解析,解析对应的方法分别是:string8At/stringAt.
由于string8At和stringAt方法都解析失败,最终抛出了IndexOutOfBoundsException,刚好也能对应上我们的Log:
03-25 15:38:07.968 1000 2311 2311 W ResourceType: Bad string block: string #6751 is not null-terminated
03-25 15:38:07.968 1000 2311 2311 W ResourceType: CREATING STRING CACHE OF 179048 bytes
我们继续看看这个patch的改动:
这里原来并不会校验字符串的末尾,修改之后开始检验字符串的末尾了,由于末尾不等有0,所以返回了NULL.
四.总结所有的疑问
1.无限重启的原因:
由于每次开机AccessibilityManagerService都会去解析每个有辅助功能的app,system_server每次解析到千牛时就会crash,然后陷入无限循环.
2.恢复出厂设置后能开机,恢复数据时又无限重启:
恢复出厂设置后千牛会被卸载,开机时不会解析到它,所以能正常开机.恢复数据又会安装上千牛,安装上之后又会走到AccessibilityManagerService去解析千牛app,所以又会无限重启.
五.千牛app的资源为什么不正常
apktool反编译了千牛的app:
AndroidManifest.xml中:
</service>
<service android:exported="false" android:label="@string/as_label" android:name="com.taobao.qianniu.common.notification.as.ASMN" android:permission="android.permission.BIND_ACCESSIBILITY_SERVICE" android:process=":mc">
<intent-filter>
<action android:name="android.accessibilityservice.AccessibilityService"/>
</intent-filter>
<meta-data android:name="android.accessibilityservice" android:resource="@xml/asc"/>
</service>
asc.xml中:
<?xml version="1.0" encoding="utf-8"?>
<accessibility-service android:description="@string/as" android:accessibilityEventTypes="typeAllMask" android:accessibilityFeedbackType="feedbackAllMask" android:notificationTimeout="100" android:accessibilityFlags="flagDefault" android:canRetrieveWindowContent="true"
xmlns:android="http://schemas.android.com/apk/res/android" />
string.xml中:
<string name="as" />
我发现as并没有值(是打包的时候出错了?),发邮件给千牛的app开发做了检查,目前还没有回复.