关于Android9.0 断电后升级问题排查分析

最近遇到一个项目Android 9.0的,很多机器出现了开机dm-verify error的错误,排查了很久,做了大量的测试,在此坐下记录分析流程

1.问题复现

2.问题排查

3.问题解决

起初的信息并不全,升级的log也是全部跑完了,正好过年期间看了下updaer断电后升级的机制,年后重新看这个问题,发现升级的log其实都是retry的,也就是升级中间关机过

测试了下发现差分包升级过程中强制关机,问题必现

实际测试发现整包升级没有该问题,那就看下差分包于整包实际的区别,两方面排查

1.之前遇到过开机起不来 大部分是preloader或者lk升级问题,把整包的驱动部分全部替换到差分包里,测试失败

2.再次操作升级包,把升级驱动部分提前,放在升级system和vendor前面,测试失败

如果驱动部分一样了还是不行,那不用说了,就是system升坏了

其实发现system有问题也是老老实实自己按步骤测试出来的

1.按照复现路径测试

2.升级失败后单刷问题,一直到刷system才真正起来,说明system升挂了

3.回读出system与正常target做对比,发现transfer.list里面从恢复处开始,后面执行new的文件不一致了,为了排除是偶然因素,开始尝试从不同处中断

4.是从百分之40 差不多system 的transfer.list走了1000行 后面执行new的部分 数据跟target包里的都不一样

5.后面从60% 80% 一层层中断，结果就是 留下最后那个需要new的文件不一样

6.最后一次是85%左右，system升级完成了，开始升级vendor,我中断后起来继续升级就报错了，因为升vendor用了很多cache的空间，实际对比vendor也确实有很多不一样的， 单刷也正常开机了

结论就是恢复升级后执行new的部分写入流程有问题

解决问题中间一个朋友给了一份谷歌的patch

updater: Fix an issue when resuming an update.
We cannot skip "new" commands while resuming an update with
last_command_file, because they read in the data sequentially from the
package.
Bug: 69858743
Test: Interrupt an update that has new commands. Check the update log.
Change-Id: I05fb67246f5ea3ba2a0f78f10255c0d9b0bc2f5a
diff --git a/updater/blockimg.cpp b/updater/blockimg.cpp
index d767d44..7b98f7f 100644
--- a/updater/blockimg.cpp
+++ b/updater/blockimg.cpp
@@ -1730,8 +1730,12 @@
       continue;
     }
-    // Skip all commands before the saved last command index when resuming an update.
-    if (params.canwrite && params.cmdindex != -1 && params.cmdindex <= saved_last_command_index) {
+    std::string cmdname = std::string(params.cmdname);
+
+    // Skip all commands before the saved last command index when resuming an update, except for
+    // "new" command. Because new commands read in the data sequentially.
+    if (params.canwrite && params.cmdindex != -1 && params.cmdindex <= saved_last_command_index &&
+        cmdname != "new") {
       LOG(INFO) << "Skipping already executed command: " << params.cmdindex
                 << ", last executed command for previous update: " << saved_last_command_index;
       continue;
@@ -1748,7 +1752,6 @@
     if (!params.canwrite && saved_last_command_index != -1 && params.cmdindex != -1 &&
         params.cmdindex <= saved_last_command_index) {
       // TODO(xunchang) check that the cmdline of the saved index is correct.
-      std::string cmdname = std::string(params.cmdname);
       if ((cmdname == "move" || cmdname == "bsdiff" || cmdname == "imgdiff") &&
           !params.target_verified) {
         LOG(WARNING) << "Previously executed command " << saved_last_command_index << ": "

合入后测试发现这个问题解决了,显然我之前看updater部分的时候漏了比较重要的信息

1.调用install_package方法中retry=1,判定为恢复升级

2.校验阶段,会解析transfer.list,move.bisdiff部分如果校验发现已经是升级后的block,则判定校验通过,对于stash部分,优先从上次保存的stash数据中读取进行校验

3.写入阶段,依然会解析transfer.list,首次升级过程中保存了last_command_index,会从中断处继续执行写入,已经写入成功的部分会被跳过

这里的意思是 如果单行在transfer.list 在last_command_index之前，增加了如果是new的情况 不会跳过，会再执行一次

优化的方案显然与我最后分析的结果大致吻合,虽然没有看代码,大致意思相当于,执行new的部分会从system.new.dat文件中按顺序读取,如果在last_command_index之前new被跳过,后面的还是从头写入了,这样就全部写错了

实际在失败的last_log里也看到有这样一句打印

new data receiver is still available after executing all commands.执行完了所有的new发现还有剩余

四.总结

问题是解决了 ,只不过好像啥事都没做.对于这种dm-verify error的问题,如果没有遇到过还是两方面排查

1.失败后单刷,那个能起来 就是那个失败了

2.挨个回读进行确认,确认是那个镜像的问题

3.多做测试对比,概率性问题尽量找到必现路径