【Android11】Autocyclefunction挂测进入recovery模式问题分析笔记

一、last_log中确认recovery模式的原因

参考日志如下：
[    0.264872] stage is []
[    0.264891] reason is [
RescueParty]
[    0.268536]        installing_text: en_US (304 x 38 @ 1446)
[    0.277906] Command
: "/system/bin/recovery" "--prompt_and_wipe_data" "
--reason=RescueParty" "
--locale=en_US"
[    0.277925]
如上日志，可以基本判断是由于系统异常出发了救援程序，救援程序与Android8.0后引入默认开启；
 

二、RescueParty 简单介绍：

在 Android 8.0 中，救援程序默认处于启用状态，其实现位于 
/services/core/java/com/android/server/RescueParty.java 
中。在出现以下情况时，救援程序会收到有关启动和崩溃事件的信息，然后即会启动：

• 
  system_server 在 5 分钟内重启 5 次以上。
  
• 
  永久性系统应用在 30 秒内崩溃 5 次以上。
  

当检测到上述某种情况时，救援程序会将其上报给下一救援级别、处理与该级别相关联的任务，并让设备继续运行，看看能否恢复。清除或重置内容的程度随级别而增加。最高级别会提示用户将设备恢复出厂设置。
无需特别的硬件支持即可为救援程序提供支持。实现后，设备的恢复系统必须响应 
--prompt_and_wipe_data 
命令，且设备必须先提供一种方法，让用户确认用户数据是否有任何损坏，然后再继续运行。此外，恢复系统还应为用户提供有关尝试再次启动设备的选项。
由于每个救援级别都会使设备再次变为可运行状态的时间延后（可能长达 5 分钟），因此设备制造商不应添加自定义救援级别。设备处于不可运行的状态的时间越长，用户发出支持请求或保修咨询，而不是自行恢复其设备的可能性就越大。
验证：
当设备具有有效的 USB 数据连接时，系统会停止所有救援事件，因为这是一个较强的信号，表示有人正在调试设备。
如需停止此类抑制行为，请运行以下命令：
adb shell setprop persist.sys.enable_rescue 1
在此处，您可以触发系统或界面崩溃循环。
如需触发低级 
system_server 
崩溃循环，请运行以下命令：
adb shell setprop debug.crash_system 1
如需触发中级 SystemUI 崩溃循环，请运行以下命令：
adb shell setprop debug.crash_sysui 1
这两个崩溃循环都会启动救援逻辑。所有的救援操作也都会记录到存储在 
/data/system/uiderrors.txt 
中的永久性 PackageManager 日志中，以供日后进行检查和调试。此外，“软件包警告消息”部分下的每个错误报告中也会包含这些永久性的日志。

三、android 常规日志确认救援程序触发重启进入recovery模式

 
由于是自动化测试，测试工程师无法准确记录问题发生的时间点，这个找log的过程比较通过，那么改善方式则是在recoverysystem重启进入recovery时写misc分区添加一个--date的参数，传递一个年月日时分秒的值，方便定位时间点。接着说，logcat的main buffer log中确认uncrypt接收到了相关指令，如下：
04-13 08:32:44.075 18774 18774 I /system/bin/uncrypt:   received command: [--prompt_and_wipe_data
04-13 08:32:44.075 18774 18774 I /system/bin/uncrypt: --reason=RescueParty
04-13 08:32:44.075 18774 18774 I /system/bin/uncrypt: --locale=en_US
04-13 08:32:44.075 18774 18774 I /system/bin/uncrypt: ] (59)
04-13 08:32:44.075 18774 18774 I /system/bin/uncrypt: [libfs_mgr]dt_fstab: Skip disabled entry for partition vendor
 
结合system buffer的日志分析，参考日志：
    行 342: 04-13 08:32:40.717  1539  3552 I ActivityTaskManager: START u0 {act=android.intent.action.SEND_MULTIPLE typ=application/zip flg=0x10000001 clip={text/plain U:
content://com.android.systemui.fileprovider/leak/hprof-1618273957401.zip} (has extras)} from uid 10033
    行 356: 04-13 08:32:40.835  1539  1615 D ConnectivityService: ConnectivityService NetworkRequestInfo binderDied(NetworkRequest [ TRACK_DEFAULT id=15, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 10033] ], android.os.BinderProxy@f13cf33)
    行 360: 04-13 08:32:40.836  1539  2111 D ConnectivityService: releasing NetworkRequest [ TRACK_DEFAULT id=15, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 10033] ] (release request)
    行 493: 04-13 08:32:41.051  1539  2569 W RescueParty: Noticed 2 events for UID 10033 in last 0 sec
    行 508: 04-13 08:32:41.180  1539  4649 W RescueParty: Noticed 3 events for UID 10033 in last 0 sec
    行 519: 04-13 08:32:41.311  1539  5186 W RescueParty: Noticed 4 events for UID 10033 in last 0 sec
    行 529: 04-13 08:32:41.463  1539  5186 W RescueParty: Noticed 5 events for UID 10033 in last 0 sec
    行 532: 04-13 08:32:41.473  1539  5186 W RescueParty: Attempting rescue level RESET_SETTINGS_UNTRUSTED_DEFAULTS
    行 552: 04-13 08:32:41.745  1539  4482 W RescueParty: Noticed 2 events for UID 10033 in last 0 sec
    行 564: 04-13 08:32:41.851  1539  4482 W RescueParty: Noticed 3 events for UID 10033 in last 0 sec
    行 573: 04-13 08:32:41.950  1539  5186 W RescueParty: Noticed 4 events for UID 10033 in last 0 sec
    行 582: 04-13 08:32:42.050  1539  4649 W RescueParty: Noticed 5 events for UID 10033 in last 0 sec
    行 584: 04-13 08:32:42.052  1539  4649 W RescueParty: Attempting rescue level RESET_SETTINGS_UNTRUSTED_CHANGES
    行 607: 04-13 08:32:42.259  1539  5186 W RescueParty: Noticed 2 events for UID 10033 in last 0 sec
    行 616: 04-13 08:32:42.355  1539 17630 W RescueParty: Noticed 3 events for UID 10033 in last 0 sec
    行 625: 04-13 08:32:42.454  1539  1615 W RescueParty: Noticed 4 events for UID 10033 in last 0 sec
    行 634: 04-13 08:32:42.551  1539  2083 W RescueParty: Noticed 5 events for UID 10033 in last 0 sec
    行 636: 04-13 08:32:42.553  1539  2083 W RescueParty: Attempting rescue level RESET_SETTINGS_TRUSTED_DEFAULTS
    行 659: 04-13 08:32:42.764  1539  5550 W RescueParty: Noticed 2 events for UID 10033 in last 0 sec
    行 668: 04-13 08:32:42.867  1539  2798 W RescueParty: Noticed 3 events for UID 10033 in last 0 sec
    行 677: 04-13 08:32:42.967  1539  4848 W RescueParty: Noticed 4 events for UID 10033 in last 0 sec
    行 686: 04-13 08:32:43.065  1539  4848 W RescueParty: Noticed 5 events for UID 10033 in last 0 sec
    行 688: 04-13 08:32:43.066  1539  4848 W RescueParty: Attempting rescue level FACTORY_RESET
触发了救援程序的最高级别的任务，即
提示用户将设备恢复出厂设置。
行 691: 04-13 08:32:44.087  1539  4848 I RecoverySystemService: uncrypt setup bcb successfully finished.
紧接着，rss触发重启。

 

四、系统异常原因分析

 
如上log确认为systemui crash导致异常的发生，那么从crash log中再次确认异常原因：
04-13 08:32:41.459 18431 18431 E AndroidRuntime: FATAL EXCEPTION: main
04-13 08:32:41.459 18431 18431 E AndroidRuntime: Process: com.android.systemui, PID: 18431
04-13 08:32:41.459 18431 18431 E AndroidRuntime: java.lang.RuntimeException: Unable to get provider com.android.systemui.keyguard.KeyguardSliceProvider: java.lang.NullPointerException: Attempt to invoke virtual method 'int android.telephony.UiccSlotInfo.getLogicalSlotIdx()' on a null object reference
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at android.app.ActivityThread.installProvider(ActivityThread.java:7207)
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at android.app.ActivityThread.installContentProviders(ActivityThread.java:6747)
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at android.app.ActivityThread.handleBindApplication(ActivityThread.java:6658)
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at android.app.ActivityThread.access$1400(ActivityThread.java:233)
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1995)
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at android.os.Handler.dispatchMessage(Handler.java:107)
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at android.os.Looper.loop(Looper.java:241)
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at android.app.ActivityThread.main(ActivityThread.java:7582)
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at java.lang.reflect.Method.invoke(Native Method)
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:492)
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:941)
04-13 08:32:41.459 18431 18431 E AndroidRuntime: Caused by: java.lang.NullPointerException: Attempt to invoke virtual method 'int android.telephony.UiccSlotInfo.getLogicalSlotIdx()' on a null object reference
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at com.android.keyguard.KeyguardUpdateMonitor.isEsim(KeyguardUpdateMonitor.java:3053)
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at com.android.keyguard.KeyguardUpdateMonitor.(KeyguardUpdateMonitor.java:2129)
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at com.android.keyguard.KeyguardUpdateMonitor.getInstance(KeyguardUpdateMonitor.java:1915)
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at com.android.systemui.keyguard.KeyguardSliceProvider.getKeyguardUpdateMonitor(KeyguardSliceProvider.java:461)
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at com.android.systemui.keyguard.KeyguardSliceProvider.registerClockUpdate(KeyguardSliceProvider.java:406)
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at com.android.systemui.keyguard.KeyguardSliceProvider.onCreateSliceProvider(KeyguardSliceProvider.java:327)
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at androidx.slice.SliceProvider.onCreate(SliceProvider.java:208)
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at android.content.ContentProvider.attachInfo(ContentProvider.java:2092)
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at android.content.ContentProvider.attachInfo(ContentProvider.java:2066)
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at
androidx.slice.compat.SliceProviderWrapperContainer$SliceProviderWrapper.attachInfo(SliceProviderWrapperContainer.java:77)
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     at android.app.ActivityThread.installProvider(ActivityThread.java:7202)
04-13 08:32:41.459 18431 18431 E AndroidRuntime:     ... 10 more
最终解决掉systemui空指针问题即可。