通过log学习RescueParty机制

现象：
手机开机后，拔掉usb线会关机重启进入recovery 恢复出厂模式模式

kmsglog：
20:59:28.633 <14>[   81.034763] init: Received sys.powerctl='reboot,recovery' from pid: 987 (system_server)
20:59:28.633 <14>[   81.035089] init: Clear action queue and start shutdown trigger
20:59:28.633 <14>[   81.035554] init: processing action (shutdown_done) from (<Builtin Action>:0)
20:59:28.633 <14>[   81.035608] init: Reboot start, reason: reboot,recovery, rebootTarget: recovery

从kmsglog可知，在20:59:28.633时刻，sys.powerctl被设置为’reboot,recovery’，init守护进程开始重启进入recovery流程（具体流程之后分析）

接下来再看为什么sys.powerctl会被system_server （pid: 987）设置为’reboot,recovery’？

在logcat中的20:59:28.633时刻附近可以搜索到如下log，system_server的线程ShutdownThread（tid = 3226）发起重启进入recovey的流程，同时还有一个子系统关闭超时的报错。

logcat:
20:59:28.618   987  3226 W ShutdownThread: Subsystem modemdid not shut down within timeout
20:59:28.618   987  3226 I ShutdownThread: Rebooting, reason: recovery

继续跟踪ShutdownThread，可以从下面的log看到RescueParty线程的打印，在过去的5秒记录到了关于UID 10118的5次事件，接着就尝试进恢复出厂模式了

20:59:16.748   987  2785 W RescueParty: Noticed 5 events for UID 10118 in last 5 sec
20:59:16.749   987  2785 W PackageManager: Incremented rescue level to FACTORY_RESET triggered by UID 10118
20:59:16.756   987  2785 W RescueParty: Attempting rescue level FACTORY_RESET
20:59:17.782  3224  3224 I /system/bin/uncrypt:   received command: [--prompt_and_wipe_data
20:59:17.782  3224  3224 I /system/bin/uncrypt: --reason=RescueParty
20:59:17.782  3224  3224 I /system/bin/uncrypt: --locale=zh_CN_#Hans
20:59:17.782  3224  3224 I /system/bin/uncrypt: ] (65)
20:59:17.794   987  2785 I RecoverySystemService: uncrypt setup bcb successfully finished.
20:59:17.795  3224  3224 I /system/bin/uncrypt:   received 0, exiting now
20:59:17.796   987  1464 D ShutdownThread: Notifying thread to start shutdown longPressBehavior=1

终于到RescueParty了，接下来看下RescueParty是怎么被应用一步步逼进recovery的。

RescueParty的原理大致为：同一个uid的persistent应用发生多次异常，RescueParty会根据该uid记录发生的次数，当次数达到默认次数后会调整拯救的策略。拯救策略等级分为：
1.NONE
2.RESET_SETTINGS_UNTRUSTED_DEFAULTS
3.RESET_SETTINGS_UNTRUSTED_CHANGES
4.RESET_SETTINGS_TRUSTED_DEFAULTS
5.FACTORY_RESET
最终的拯救策略是进recovery模式。
下面的log完美的描述了这一机制，UID为10118的persistent应用每crash 5次后就提升一次等级直至FACTORY_RESET

20:58:51.473   987  2122 W RescueParty: Noticed 2 events for UID 10118 in last 2 sec
20:58:53.296   987  1874 W RescueParty: Noticed 3 events for UID 10118 in last 3 sec
20:58:54.724   987  2304 W RescueParty: Noticed 4 events for UID 10118 in last 5 sec
20:58:56.136   987  2134 W RescueParty: Noticed 5 events for UID 10118 in last 6 sec
20:58:56.143   987  2134 W RescueParty: Attempting rescue level RESET_SETTINGS_UNTRUSTED_DEFAULTS
20:58:58.948   987  2854 W RescueParty: Noticed 2 events for UID 10118 in last 1 sec
20:59:00.342   987  2901 W RescueParty: Noticed 3 events for UID 10118 in last 2 sec
20:59:01.668   987  1091 W RescueParty: Noticed 4 events for UID 10118 in last 4 sec
20:59:03.032   987  2483 W RescueParty: Noticed 5 events for UID 10118 in last 5 sec
20:59:03.042   987  2483 W RescueParty: Attempting rescue level RESET_SETTINGS_UNTRUSTED_CHANGES
20:59:05.810   987  2901 W RescueParty: Noticed 2 events for UID 10118 in last 1 sec
20:59:07.149   987  2901 W RescueParty: Noticed 3 events for UID 10118 in last 2 sec
20:59:08.518   987  3025 W RescueParty: Noticed 4 events for UID 10118 in last 4 sec
20:59:09.884   987  3025 W RescueParty: Noticed 5 events for UID 10118 in last 5 sec
20:59:09.887   987  3025 W RescueParty: Attempting rescue level RESET_SETTINGS_TRUSTED_DEFAULTS
20:59:12.660   987  3125 W RescueParty: Noticed 2 events for UID 10118 in last 1 sec
20:59:14.008   987  3149 W RescueParty: Noticed 3 events for UID 10118 in last 2 sec
20:59:15.364   987  2951 W RescueParty: Noticed 4 events for UID 10118 in last 4 sec
20:59:16.748   987  2785 W RescueParty: Noticed 5 events for UID 10118 in last 5 sec
20:59:16.756   987  2785 W RescueParty: Attempting rescue level FACTORY_RESET

本文仅结合log初步学习了下RescueParty机制，具体代码分析和原理可以参考这篇android-O RescueParty 介绍.