记录一次Recovery问题的排查

于 2024-06-18 13:27:25 发布
阅读量996 收藏 9
点赞数 23
分类专栏： FrameWork 文章标签： android
版权声明：本文为博主原创文章，遵循 CC 4.0 BY-SA 版权协议，转载请附上原文出处链接和本声明。
本文链接：https://blog.csdn.net/WolfGGGGGG/article/details/139770583
版权

Recovery问题排查

Android Recovery问题排查

Android Recovery问题排查是一个关键的过程，它主要集中在找出触发Recovery模式的原因。Recovery模式是一个特殊的引导模式，通常是因为系统出现严重错误或者需要进行系统更新等操作时被触发。了解触发Recovery模式的原因有助于我们有效地进行问题排查和解决。

以下是一些可能触发Recovery模式的常见原因：

  1. 系统更新：当Android设备进行系统更新时，设备通常会自动进入Recovery模式。这是因为更新过程通常需要在系统级别进行，需要关闭用户界面。在Recovery模式下，系统能够在没有用户干预的情况下完成更新操作，完成更新后设备会自动重启。
  2. 系统恢复：如果系统出现严重错误，设备可能会自动进入Recovery模式进行系统恢复。这种情况下，Recovery模式允许系统在没有加载用户界面的情况下运行，这样就能够避免用户界面可能会引起的任何问题，从而更好地解决系统级别的错误。
  3. 手动操作：用户也可以手动触发Recovery模式，例如进行系统重置或者从USB或SD卡安装更新等。当用户需要对设备进行一些高级操作时（比如刷机，恢复出厂设置等），通常需要进入Recovery模式。在这种模式下，用户可以在不影响设备正常运行的情况下进行一些操作。

了解以上触发Recovery模式的原因，可以帮助我们更深入地理解Android系统的工作方式，从而更有效地进行问题的排查和解决。

问题背景：

部分S10设备会在运行一段时间后进入到Recovery状态，时间周期长，大概在25~30天中会复现，且无法明确复现场景，发生后通过日志大部分已经是系统异常前的日志，分析不到根因。

先抛出结论：

是由于内存不足导致关键service无法正常启动，导致在执行方法getService时抛出异常，zygote强制重新forkSystemServer进程后仍在短时间内重复触发导致设备进入Recovery。

结论依据和推断过程：

  1. 搞明白这50份tombstone日志

    我们在设备异常进入到recovery后，通过pull获取tombstones文件夹(/data/tombstones)，可以看到进入Recovery模式的设备中会有且只有50份文件，why？这是因为墓碑文件数量有上限的，达到上限时会删除最旧的墓碑文件，可以通过配置属性tombstoned.max_tombstone_count来修改默认的墓碑文件数量，也可以通过adb查看。

    *rk3566_r:/ # getprop | grep max_tombstone_count
[tombstoned.max_tombstone_count]: [50]
rk3566_r:/ #*

    但之前了解的进入Recovery不是只需要达到*LEVEL_FACTORY_RESET*(4)便会触发吗？为什么这里会多达50份文件？

    虽然文件有五十份，但分析后发现共性，通过filter，可以看到： 在这里插入图片描述

    注意：并不一定是三个一组，可以看这个：
    在这里插入图片描述

    (Linux kernel会发送相应的signal给异常进程，debuggerd捕获这些signal，做出相应处理的同时（一般来说是退出异常进程），在/data/tombstones目录下生成一个tombstone。)

    也就是说，虽然生成了tombstone，但其实只有在system_server在挂了之后，才会通过RescueParty进行increaseLevelCount（这一点后面通过代码和日志结合看也可以证实），所以，我们重点关注计数连续阶段（非连续触发会重置level）的system_serve最后和首次发生异常的时间，但首次已经无法关注，因为被覆盖了，所以我们就关注最后一次即可。

  2. 锁定案发时间点和日志现场

    OK，接着我们可以通过排序的方法得到tombstone的最晚时间，再结合该时间点，通过日志查看对应的Rescue-Tag相关日志，相互验证是否为触发Recovery的原因。

    # sort -t ' ' -k4,4: 使用空格作为分隔符（-t ' '），并按第四列（时间部分）排序。
❯ cat all | grep '2024-05-23' | sort -t ' ' -k4,4
    5: Timestamp: 2024-05-23 07:16:18+0800
    5: Timestamp: 2024-05-23 07:16:18+0800
    5: Timestamp: 2024-05-23 07:16:30+0800
    5: Timestamp: 2024-05-23 07:16:30+0800
    ...
    5: Timestamp: 2024-05-23 07:19:37+0800 
    //↑这个就是最晚的时间点，基本锁定案发时间点，那么我们再通过android log去到日志现场

    在目录/data/vendor/logs 下可以看到捕获到的日志文件目录有如下这些

    bash-3.2$ tree -d                                                                                                                                                                                                                                                        
.
├── logs
    ├── 17-08-04-17-00-10-0001
    ├── 17-08-04-17-00-24-0002
    ├── 24-04-01-12-04-14-0000
    ├── 24-04-28-10-41-27-0003  ←←←这里
    └── 24-05-23-10-09-19-0004

    这里的文件夹名称是文件创建时的时间，通过比对， 2024-05-23 07:19:37时间点就在文件夹**24-04-28-10-41-27-0003** 中。查找到日志：
    在这里插入图片描述

  3. 为什么我们在tombstone中看到的都是getService错误？

    由于我们的tombstones目录下批量出现两个服务和system_serveer错误，那么我们再往前看看，是否有/apex/com.android.os.statsd/bin/statsd 的相关日志（不一定有，可以看看），我们可以看到确实在2024-05-23 07:19:36 时，/apex/com.android.os.statsd/bin/statsd 已经发生异常并且写入到tomestone目录下了，这里指向的是pid:32128，这个服务会在系统启动后被系统拉起，在frameworks/base/apex/statsd/statsd.rc 下定义
    在这里插入图片描述

    这里我们不去关注这个服务是干嘛的先，关注这个进程id和tid,pid: 32128, tid: 32477,往上看。

    在这里插入图片描述

    这里的HwBinder.getService 看着很眼熟，就是对应到我们的tombstone中的错误
    在这里插入图片描述

    那这个为什么会getService报错呢，我们可以看到报错的错误类型是NoSuchElementException,结合源码推测是不是服务获取失败导致的.
    在这里插入图片描述

    再继续跟踪源码，可以在文件android_os_HwParcel.cpp 的signalExceptionForError() 中看到：

    在这里插入图片描述

    再结合android_os_HwBinder.cpp 的JHwBinder_native_getService 方法中确实是由于service不存在发出signalNAME_NOT_FOUND抛出了NoSunchElementException 错误

    在这里插入图片描述

  4. 服务为何启动失败？

    在getService 异常发生前，我们能够通过过滤正则条件low.*mem 看到以下这些日志内容：

    在这里插入图片描述

    report的file是system_server_lowmem@ ，我们可以取任意一个看下这些文件的内容（都类似）：

    在这里插入图片描述

    在这里插入图片描述

    由于内容较多，我这边只截取了本次分析用到部分

    上面的Low on memory — 800MB total中的800MB ，取决于当前系统中VSS>0的应用进程所占用的pss之和，是通过ProcessCpuTracker 进行获取，通过读取 /proc 文件系统中的进程信息来更新现有进程的统计数据或添加新进程的数据和移除不存在的进程。

    补充知识：TOTAL 是695016 KB， 所以这里显示的是800MB….What？怎么算都不会是800MB啊，原因就是在AMS中的reportMemUsage方法中，我们本次分析该文本也是通过该方法进行深度分析：

    在这里插入图片描述

    下面是我们重点关注的地方：

    • Lost Ram，定义如下：

       memInfoBuilder.append("  Lost RAM: ");
        memInfoBuilder.append(stringifyKBSize(memInfo.getTotalSizeKb()
                - (totalPss - totalSwapPss) - memInfo.getFreeSizeKb() - memInfo.getCachedSizeKb()
                - kernelUsed - memInfo.getZramTotalSizeKb()));
        memInfoBuilder.append("\n");

    • Free RAM，定义如下：

      memInfoBuilder.append(stringifyKBSize(cachedPss + memInfo.getCachedSizeKb()
                + memInfo.getFreeSizeKb()));

    具体的内存获取，大家可以去看看Debug.java#getMemInfo() 方法。

    • am_low_memory:2后会报一次LowMemory，并且dump进程状态，此时后续继续打印多一次am_low_memory:5后就会看到打印日志：

    在这里插入图片描述

    在这里插入图片描述

    从源码也可以看出，当system_server crashed后，则关闭zygote，以便由init重新启动，系统服务器将从那里重新启动。

    那system_server是什么时候crashed的呢？以pid为22945的system_server crash来看，往上继续跟踪，可以看到

    在这里插入图片描述

    再继续往上看，我们来看看这个statsd服务到底被拉起后发生了什么，再继续往上看可以看pid: 32128 的存活日志，发现就只有几行了，除了main.cpp中打印的ALOGI("Statsd starts to listen to socket."); 被打印外，在下面就是
    在这里插入图片描述

    这些错误日志来自 IPCThreadState，表示在尝试增加某个句柄的强引用计数时遇到了问题。attemptIncStrongHandle(N): Not supported 表示对于句柄 N 的操作不被支持。这通常与进程间通信（IPC）系统的内部问题有关，通常是由于资源不足导致无法分配或权限问题。

    statscompanion service died 表示 statscompanion 服务已崩溃。

    崩溃链路通过日志可以看到：statds获取失败→system_server getSignal → gpu_service getSignal → Zygote Exit and restart.

    到这我们getService异常的原因就找到了。

  5. 重启进入Recovery的证据

    先抛结论：system_server在{triggerWindow}内异常退出20次，导致sys.rescue_level达到等级*LEVEL_FACTORY_RESET*从而进入Recovery。

    接下来，我们会从源码的角度再结合日志来验证我们的推断。

    在这里插入图片描述
    在这里插入图片描述
    在这里插入图片描述
    在这里插入图片描述
    我们可以通过上方的日志可以看出等级是如何一步一步到达等级FACTORY_RESET的.并且也可以确认在触发后便执行了reboot，且显示出reason为recovery ！

  6. Recovery的真相

    由于涉及的流程较多，我会list出涉及到的角色，并且介绍其作用（注意，这里的作用重点介绍其在流程中的，不发散），通过画图的方式方便大家理解。

    1. RescueParty ：此类将通过几次救援操作缓慢升级，然后最终重新启动并提示用户是否要擦除数据作为最后的手段。

    2. RescueParty#Threshold（android11后，这个逻辑也移到了PackageWatchdog）：
      记录触发次数，设定触发窗口时间，设定触发阈值（这里需要注意，是升级的触发阈值，不是进入Recovery的阈值，目前android11系统下，rescue_level 是固定的，分为5个级别，如下）：

      在这里插入图片描述

      • BootThreshold：触发于SystemServer#startBootstrapServices，关注system_server的异常， triggerCount为5，triggerWindow为300s。
      • AppThreshold ：触发于AppErrors 对象中，关注persistent 级别的应用异常， triggerCount为5，triggerWindow为30s。

    3. ActivityManagerService ：持有AppErrors ，在异常时除了通知AppErrors 之外，还会通过方法addErrorToDropBox()将异常信息输出到/data/system/dropbox文件夹中

    4. AppErrors :对application异常时进行处理，包括dump消息（我们看到的/data/anr/trace.txt文件就是它给输出的），anr弹窗拉起，调度RescueParty等工作。在该流程中，起到了判断是否为persistent应用，直接调用或通过PackageWatchdog调用RescueParty 进行记录。

    5. PackageWatchdog :在android11版本后出现，顾名思义，就是对Package进行观测，可以在/data/system/pacakge-watchdog.xml 中找到对应的观测者.

      rk3566_r:/data/system # cat package-watchdog.xml
<?xml version='1.0' encoding='utf-8' standalone='yes' ?>
<package-watchdog version="1">
<observer name="rescue-party-observer" />
<observer name="rollback-observer" />
</package-watchdog>

    6. RecoverySystem ：可通过Context.*RECOVERY_SERVICE 获取，调用PMS执行重启*

    这里我们只需要知道程序异常时，AMS会调用handleApplicationCrash ，之前的链路暂不追溯（停不下来，就不在本次分析中继续深耕）。

    RescueParty工作流程图如下：

    在这里插入图片描述

尝试复现：

  1. 设备105：
  2. 设备119：

下一步和反思？

在分析过程中发现了LostRam的增长，目前并无法掌握该值的释放和增长规律，如何排查

  1. 为什么问题会分析那么久？
  2. 有没有什么措施可以避免以后这种情况的出现？
我可能在飞
关注
  • 23
    点赞
  • 踩
  • 9
    收藏
    觉得还不错? 一键收藏
  • 1
    评论
专栏目录
android系统异常日志文件,Android如何查看系统recovery日志，从而找到系统程序、刷机异常…...
weixin_34553907的博客
05-29 966
该楼层疑似违规已被系统折叠隐藏此楼查看此楼举例说明如何使用logcat来查找程序异常的原因(仅举一例，logcat的其他用法和使用范围请各学员自行探索学习)我打算去掉“设置->关于->法律信息”一项。于是我反编译Settings.apk后，修改Settings\res\xml\device_info_settings.xml，删除了以下部分：复制代码修改完成后替换系统中的原文件，开始...
【recovery】android使用串口打印recovery调试日志
三言两语
12-18 4227
1、应用背景：         调试android recovery时，由于recovery默认的日志是存储到/cache相关文件夹下的文件中的，所以每次只能在升级完成后重启系统后才能看到相关的调试日志信息，这对调试带来很大的不变，如有的时候recovery操作失败导致系统无法启动时，无法看到相关的日志，因此这时候可以使用本文中提供的方法将相关日志从调试串口输出，直接用串口在升级过程中查看日
android日志输出到串口,android使用串口打印recovery调试日志
weixin_28902749的博客
05-26 1001
1、应用背景：调试android recovery时，由于recovery默认的日志是存储到/cache相关文件夹下的文件中的，所以每次只能在升级完成后重启系统后才能看到相关的调试日志信息，这对调试带来很大的不变，如有的时候recovery操作失败导致系统无法启动时，无法看到相关的日志，因此这时候可以使用本文中提供的方法将相关日志从调试串口输出，直接用串口在升级过程中查看日志。2、实现思路实现思路...
Android 进阶——Binder IPC之Native家族成员驱动通信桥梁IPCThreadState 详解（七）
最美不过，心中有梦，身旁有你！
03-20 1201
无论是BpBinder还是BnBinder，都是通过IPCThreadState和Binder 驱动程序通信的，换言之，Server进程是通过Binder库（客户端与服务端）的IPCThreadState 来处理与Binder驱动的协议的，类似Socket通信一样，IPCThreadState的代码一部分给客户端使用，一部分给服务端使用。
【android系统】android系统升级流程分析（四）---recovery升级过程中log调试方法
看图的博客
06-05 2922
前面的文章我们介绍recovery模式升级流程，以及升级脚本的的基本语法。今天我们来看下升级过程中我们应该怎么添加调试信息，怎么更方便的获取调试信息。 基本环境 Android 版本：android 6.0 芯片硬件：全志H6 常见的log获取方式 我们在调试recovery升级的时候，我们经常需要查看recovery的log，google的原始逻辑中，recovery的l...
一次简单的Oracle恢复Case实战记录
12-16
在本案例中，我们面临的是一个Oracle数据库由于硬件故障（坏盘）和存储系统断电导致的严重问题，使得数据库无法正常打开。从错误日志分析，我们可以看到一系列的内部错误代码，这些错误通常与数据恢复、重做日志处理...
10大绝招轻松排除XP系统启动故障.docx
09-26
2. **使用最后一次正确配置**：如果问题源自注册表CurrentControlSet键的错误修改，可以选择“最后一次正确配置”来启动系统。在开机时按F8进入高级选项菜单，选择“最后一次正确配置”，然后按Enter键。 3. **系统...
Azure 备份代理中设置的备份计划不执行-vivianx1
08-08
3. **创建测试计划**：创建一个临时的、频繁执行的备份任务，如每5分钟一次，以确定是任务计划程序的问题还是备份代理本身的问题。如果测试计划也无法执行，那么问题可能出在任务计划程序。 4. **分析任务详情**：...
xp启动失败的恢复方法
07-13
如果启动问题是由最近的系统更改引起的，可以选择“最后一次正确的配置”选项。在启动过程中按F8进入高级选项菜单，选择“最后一次正确的配置”，这将恢复系统到上一次成功启动的状态。 3. 进行系统恢复 系统恢复...
光盘恢复软件.zip
03-02
7. **日志记录**：软件可能记录恢复过程，方便用户了解每个步骤的详细情况，以及在出现问题时进行排查。 8. **技术支持**：提供详细的使用指南和客户服务，以解决用户在使用过程中遇到的问题。 总的来说，"光盘...
如何获取recovery模式的log
ll_j_21的博客
05-03 3300
第一种：recovery下，遥控器选择view recovery logs，界面上查看。 第二种：recovery下，输入命令，cat /tmp/recovery.log 第三种：android下，输入命令，cat /cache/recovery/last_log
IPCThreadState 详解
06-11 5443
IPC是Android的精华，找了个时间，详细分析下IPCThreadState 的组织架构及其功能 初始化：用这个方法，我们可以在每个线程里取得IPCThreadState IPCThreadState* IPCThreadState::self() {     // 全局标志位，代表是否TSD已经建立     if (gHaveTLS) { restart:
FPGA时序分析与约束（8）——时序引擎
最新发布
apple_53311083的博客
10-29 3698
FPGA时序分析，时序引擎如何实现建立分析（setup），保持分析(hold)，恢复时间分析(recovery)和移除时间分析(removal)。
android persist apk 多次crash会进入recovery模式
qq_25815655的博客
02-21 1499
1.基本介绍 Google在Android 8.0加入该新功能，称之为rescue party救援程序。 主要监控系统核心程序出现循环崩溃的时候，会启动该程序，根据不同的救援级别做出一系列操作，看是否可恢复设备，最严重的时候则是通过进入recovery然后提供用户清空用户数据恢复出厂设置解决。 代码： frameworks\base\services\core\java\com\android\server\RescueParty.java 1.级别 private static final i
什么是recovery time和removal time？
aa666888io89的博客
08-23 8203
removal time /recovery time类似于DFF的setup time / hold time，不同之处在于前者是用来描述异步复位的。 一般设计中,异步复位信号需要进行同步化处理，即让本来异步输入的复位信号，用时钟来锁存，这样本来和时钟没有相位关系的复位信号就和时钟用相位关系了。 STA时，如果DFF的异步rst和该DFF的时钟有相位关系，则需要进行removal和recovery的检查。removal和recovery检查的目的是让DFF的异步rst信号在时钟沿附近满足建立/...
android如何分析进程被杀问题
热门推荐
xiaoyantan的博客
07-05 3万+
查看进程被杀的3个步骤 确定被杀进程的包名 有人给出直接用 百度搜索app对应的包名 确定进程被杀的精确时间点 有进程被杀时间点及原因包名，则直接用 log中搜索正则表达式（gedit支持正则）am_proc_died: [0,[0-9]*,xxxx,，xxxx代表包名 ，拿到这行log的时间点以及进程pid eg: 08-19 10:06:55.302 1000 1699 12137 I am_proc_died: [0,9307,com.quark.browser,905,11] 如上栗子：
Android 常驻应用崩溃导致进入recovery过程
weixin_38622593的博客
05-25 587
应用崩溃过程：常驻应用不断崩溃，救援等级增加，最终达到LEVEL_FACTORY_RESET等级。进入recovery（Android 9.0源码）： frameworks\base\services\core\java\com\android\server\am\AppErrors.java /** * Bring up the "unexpected error" dialog box for a crashing app. * Deal with edge cases (inter
安卓recovery的log如何直接输出到串口
技术交流
06-15 3467
我们在调试recovery升级的时候，我们经常需要查看recovery的log，google的原始逻辑中，recovery的log并非直接输出到串口，我们需要输入命令才能获取，我们有三种方式： 第一种：recovery下，遥控器选择view recovery logs，界面上查看。 第二种：recovery下，输入命令，cat /tmp/recovery.log 第三种：android下，输入...
Android Recovery模式详解与ROM制作指南
了解和掌握Recovery模式以及ROM制作对于Android开发人员和爱好者来说，是提升系统定制能力和故障排查能力的重要步骤。通过深入研究，可以更好地理解和控制Android系统的运行，为用户提供更加个性化的体验。

“相关推荐”对你有帮助么？

  • 非常没帮助
  • 没帮助
  • 一般
  • 有帮助
  • 非常有帮助
提交
评论 1
添加红包

请填写红包祝福语或标题

个

红包个数最小为10个

元

红包金额最低5元

当前余额3.43元 前往充值 >
需支付：10.00元
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付元
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明：

1.余额是钱包充值的虚拟货币，按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载，可以购买VIP、付费专栏及课程。

余额充值