恢复出厂设置卡住10分钟问题

And乔

已于 2022-04-08 23:50:55 修改

阅读量2.5k

点赞数

分类专栏： # Exception处理 Android 文章标签： android linux

于 2020-07-27 21:08:00 首次发布

本文链接：https://blog.youkuaiyun.com/xiaoqiaoq0/article/details/107621405

版权

恢复出厂设置卡住10分钟问题

文章目录

恢复出厂设置卡住10分钟问题

1. 信息初步收集

1.1 现象描述

恢复出厂设置操作；
重启进入recovery 清除data/cache分区；
概率性出现卡住10分钟后再次启动的情况；

1.2 问题概率以及实验情况确认

反复进行恢复出厂设置动作，约半天出现一次；
仅有一台机器出现此case；
recovery log没有抓取到；
正常进行recovery基本在1分钟左右；

2. 分析过程

从反馈现象分析存在两种可能性：

recovery 逻辑中存在case，卡在某个逻辑中无法退出；
上述recovery逻辑主要为清除data分区内容，则可能在写emmc操作时出现问题卡住；
则需要log信息来进一步证实上述猜测情况；

2.1 确认recovery log信息情况

当前机器中未保存recovery log，而分析问题需要该部分log信息，但是无法确认为个例问题还是普遍问题，则该机器软件环境需要尽可能小的改动；

recovery log部分会在执行时生成，但是该部分log会在recovery完成后清除掉；
默认recovery为单独分区，但是AB版本recovery是打包在boot.img中的，修改后需要升级boot.img
recovery部分code：bootable/recovery/recovery.cpp，目前直接将log修改为在串口输出；

2.2 log分析

2.2.1 recovery 重启

从log中找到最后3次重启，找到对应的recovery触发重启的操作：

触发recovery 重启；

[ 169.275465] <0>.(0)[1:init]reboot: Restarting system with command ‘recovery’
[ 169.276568] <0>-(0)[1:init]ARCH_RESET happen!!!
[ 169.277142] <0>-(0)[1:init]arch_reset: cmd = recovery
重启到kernel进入recovery 模块内进行清除分区操作；
清除结束后重启进入系统：

[ 659.341311] Data wipe complete.
…
[ 659.383821] Rebooting…
[ 661.897156] <1>.(1)[1:init]init: Received sys.powerctl=‘reboot,’ from pid: 256 (/sbin/recovery)
[ 661.898310] <1>.(1)[1:init]init: PropSet [sys.powerctl]=[reboot,] Done
[ 661.899163] <1>.(1)[1:init]init: Clear action queue and start shutdown trigger
[ 661.900146] <1>.(1)[1:init]init: processing action (shutdown_done) from (:0)
[ 661.901214] <1>.(1)[1:init]init: Reboot start, reason: reboot, rebootTarget:
[ 661.902274] <1>.(1)[1:init]init: PropSet [persist.sys.boot.reason]=[reboot,] Done
[ 661.903366] <1>.(1)[1:init]init: Shutdown timeout: 1000 ms

从时间戳可以看得出来，recovery清除操作这次启动时间约11min，则确认问题确实出现在此次recovery 清除逻辑；

2.2.2 recovery 清除操作

则分析这次数据清除逻辑，发现如下信息：

kernel进入后30s左右提示emmc 写异常，device端没有回复信息，超时；
中间经过10分钟的系统调度；
最终emmc reset 恢复后recovery快速进行完重启

2.2.2.1 block 进入逻辑：

[ 37.859926] <1>.(0)[210:kworker/0:2][msdc][msdc_check_data_timeout]: XXX DMA Data Busy Timeout: 30000 ms, CMD<25>
[ 37.859919] <1>.(0)[210:kworker/0:2][msdc]Accumulated dma cnt: 23
[ 37.880459] <1>.(0)[210:kworker/0:2][msdc]msdc0 -> check card state<6> <- msdc_check_data_timeout() : L<4764> PID<kworker/0:2><0xd2>
[ 37.880465] <1>.(0)[210:kworker/0:2][msdc]msdc0 -> state<6> need cmd12 to stop <- msdc_check_data_timeout() : L<4766> PID<kworker/0:2><0xd2>
[ 60.250439] <0>.(0)[210:kworker/0:2][msdc][msdc_command_resp_polling]: msdc0 CMD<12> MSDC_INT_CMDTMO Arg<0x00000000>
[ 60.251914] <0>.(0)[210:kworker/0:2][msdc][msdc_command_resp_polling]: msdc0 CMD<12> Arg<0x00000000> tmo: 21474ms (max 21474ms)
[ 60.253356] <0>.(0)[210:kworker/0:2][msdc]msdc0 -> card stuck in 6 state <- msdc_check_data_timeout() : L<4777> PID<kworker/0:2><0xd2>