前言: OTA U 盤升級壓測小機率出現 kNewRootfsVerificationError 錯誤，以下為問題分析與解決
一、問題描述
同一個 U 盤及 OTA 升級包進行升級壓測，小機率性出現 kNewRootfsVerificationError，錯誤 log：
update_engine: [1107/201558.235400:INFO:filesystem_verifier_action.cc(237)] Hash of system: 1O5p/gbJ4xXLtpD+NQ5zH96WXbfcMW1UT8rauSnrEMU=
update_engine: [1107/201558.236592:ERROR:filesystem_verifier_action.cc(243)] New 'system' partition verification failed.
update_engine: [1107/201558.615986:INFO:action_processor.cc(116)] ActionProcessor: finished FilesystemVerifierAction with code ErrorCode::kNewRootfsVerificationError
update_engine: [1107/201558.616372:INFO:action_processor.cc(121)] ActionProcessor: Aborting processing due to failure.
update_engine: [1107/201558.616439:INFO:update_attempter_android.cc(454)] Processing Done.
update_engine: [1107/201558.617735:INFO:update_attempter_android.cc(473)] Resetting update progress.
update_engine: [1107/201558.617803:INFO:dynamic_partition_control_android.cc(151)] Destroying [] from device mapper
二、問題分析
1. 排除 pac 包問題；檢查全部 logcat 信息，未出現 U 盤掛載或讀取問題；
2. 對比正常升級成功的 log，出錯的兩次 log 里都是直接從 0% 的 downloaded 跳到 100%，缺少 download 過程。
一、問題描述
同一個 U 盤及 OTA 升級包進行升級壓測，小機率性出現 kNewRootfsVerificationError，錯誤 log：
update_engine: [1107/201558.235400:INFO:filesystem_verifier_action.cc(237)] Hash of system: 1O5p/gbJ4xXLtpD+NQ5zH96WXbfcMW1UT8rauSnrEMU=
update_engine: [1107/201558.236592:ERROR:filesystem_verifier_action.cc(243)] New 'system' partition verification failed.
update_engine: [1107/201558.615986:INFO:action_processor.cc(116)] ActionProcessor: finished FilesystemVerifierAction with code ErrorCode::kNewRootfsVerificationError
update_engine: [1107/201558.616372:INFO:action_processor.cc(121)] ActionProcessor: Aborting processing due to failure.
update_engine: [1107/201558.616439:INFO:update_attempter_android.cc(454)] Processing Done.
update_engine: [1107/201558.617735:INFO:update_attempter_android.cc(473)] Resetting update progress.
update_engine: [1107/201558.617803:INFO:dynamic_partition_control_android.cc(151)] Destroying [] from device mapper
二、問題分析
1. 排除 pac 包問題；檢查全部 logcat 信息，未出現 U 盤掛載或讀取問題；
2. 對比正常升級成功的 log，出錯的兩次 log 里都是直接從 0% 的 downloaded 跳到 100%，缺少 download 過程。
出錯的 log：
update_engine: [1107/201528.912509:INFO:delta_performer.cc(208)] Completed 0/? operations, 16384/1073446317 bytes downloaded (0%), overall progress 0%
update_engine: [1107/201529.025158:INFO:delta_performer.cc(450)] PartitionInfo new dtbo sha256: d1iDX4k5BCj/fHbw8AvKnm6/9x4JWWnyffiHpdjSA6E= size: 4096
update_engine: [1107/201529.025269:INFO:delta_performer.cc(450)] PartitionInfo new boot sha256: nW478lJz+hLHuBqR/40PN4eN86Y9OLdt7yx7iK5b8Xo= size: 28717056
update_engine: [1107/201529.025321:INFO:delta_performer.cc(450)] PartitionInfo new system sha256: bMCfk5nH+L4gPAtgBXdtkmAdlMk9uOOYODPB+Aw3Sk0= size: 2684354560
...
update_engine: [1107/201529.025957:INFO:delta_performer.cc(450)] PartitionInfo new cluster_ramdisk sha256: qUpM7ZDSWE2fbrCvBxaI1RvFeTYGbK55O5ebFLoAoG0= size: 536870912
update_engine: [1107/201529.026005:INFO:delta_performer.cc(450)] PartitionInfo new res sha256: x2MAH6OwfFXRNpr/g00TMmWEU/teFw68AUkXzYKgyEI= size: 25165824
update_engine: [1107/201529.026051:INFO:delta_performer.cc(450)] PartitionInfo new safety_os sha256: hh4lQ59gkaWcNPvQ+wKE2Ct+NZDDD/Ucv24V7sGFfeY= size: 2097152
update_engine: [1107/201529.027171:INFO:delta_performer.cc(208)] Resuming after 2358/2358 operations (100%), 1073446317/1073446317 bytes downloaded (100%), overall progress 100%
update_engine: [1107/201529.027248:INFO:delta_performer.cc(654)] Starting to apply update payload operations
正常升級的 log：
update_engine: [1026/165234.648988:INFO:delta_performer.cc(221)] Completed 0/? operations, 16384/662444616 bytes downloaded (0%), overall progress 0%
update_engine: [1026/165238.062985:INFO:delta_performer.cc(413)] Applying 1024 operations to partition "system"
update_engine: [1026/165301.242425:INFO:delta_performer.cc(221)] Completed 139/2110 operations (6%), 92749824/662444616 bytes downloaded (14%), overall progress 10%
update_engine: [1026/165329.942379:INFO:delta_performer.cc(221)] Completed 276/2110 operations (13%), 185499648/662444616 bytes downloaded (28%), overall progress 20%
update_engine: [1026/165353.152242:INFO:delta_performer.cc(221)] Completed 422/2110 operations (20%), 271286272/662444616 bytes downloaded (40%), overall progress 30%
...
update_engine: [1026/165834.513929:INFO:delta_performer.cc(221)] Completed 2110/2110 operations (100%), 662444616/662444616 bytes downloaded (100%), overall progress 100%
update_engine: [1026/165238.062985:INFO:delta_performer.cc(413)] Applying 1024 operations to partition "system"
update_engine: [1026/165301.242425:INFO:delta_performer.cc(221)] Completed 139/2110 operations (6%), 92749824/662444616 bytes downloaded (14%), overall progress 10%
update_engine: [1026/165329.942379:INFO:delta_performer.cc(221)] Completed 276/2110 operations (13%), 185499648/662444616 bytes downloaded (28%), overall progress 20%
update_engine: [1026/165353.152242:INFO:delta_performer.cc(221)] Completed 422/2110 operations (20%), 271286272/662444616 bytes downloaded (40%), overall progress 30%
...
update_engine: [1026/165834.513929:INFO:delta_performer.cc(221)] Completed 2110/2110 operations (100%), 662444616/662444616 bytes downloaded (100%), overall progress 100%
3. Resuming 表明是在中斷點之後繼續執行，可能是之前升級某個階段出現了中斷或錯誤, 所以在下次升級時從斷點開始，跳過了中間的 download，導致 system 分區的哈希值（每次更新哈希值重新生成）不匹配。
三、解決方法
1. 進入 processing done 之後調用 prefs_->Delete(kPrefsUpdateCheckResponseHash); 清除保存的哈希值，在下次升級時不再和上次升級的哈希值進行比較，每次都是全新升級。
2. 出現錯誤後在應用層 retry mUpdateEngine.applyPayload 重新升級；
3. 修改後再進行壓測，未出現同樣問題。
總結：解決機率性出現 kNewRootfsVerificationError 問題的方法是 processing done 之後調用 prefs_->Delete(kPrefsUpdateCheckResponseHash); 清除保存的哈希值，在下次升級時不再和上次升級的哈希值進行比較，每次都是全新升級。
評論