目录
android OTA执行update_engine_client命令报错ErrorCode::kDownloadInvalidMetadataSize (32)
手动执行update_engine_client
命令失败,多次打OTA包尝试也没有效果,依旧时下面报错
[INFO:update_engine_client_android.cc(90)] onStatusUpdate(UPDATE_STATUS_IDLE (0), 0)
[INFO:update_engine_client_android.cc(90)] onStatusUpdate(UPDATE_STATUS_UPDATE_AVAILABLE (2), 0)
[INFO:update_engine_client_android.cc(90)] onStatusUpdate(UPDATE_STATUS_DOWNLOADING (3), 4.4213e-05)
[INFO:update_engine_client_android.cc(90)] onStatusUpdate(UPDATE_STATUS_IDLE (0), 0)
[INFO:update_engine_client_android.cc(98)] onPayloadApplicationComplete(ErrorCode::kDownloadInvalidMetadataSize (32))
最终找到原因是没换行!(emmmmmm…)
大家注意这里的--headers
参数,这里一定要用换行符分隔。(原因见下方分析)
update_engine_client \
--update \
--follow \
--payload=file:///data/ota_package/update.zip \
--offset=9053 \
--size=555750616 \
--headers="FILE_HASH=BMYgJY7CIoJCsowiXgi3L4kK4Og+aGOdfpzUGURCDvY=
FILE_SIZE=555750616
METADATA_HASH=33c52T0k5Xi7Q3kSx8tJszDtTzNNYQRTZTLiEUTbkLs=
METADATA_SIZE=87205"
分析过程如下
分析过程写的比较啰嗦,主要是想记录下自己排除问题的思路是怎么变化。
1. 换机器尝试,排除机器问题
换机后问题依旧存在,非设备问题
2. 多次打OTA包,并测试,初步排除OTA包问题
1.make dist
方式打ota包
2.make otapackage
方式打ota包
3../build/tools/releasetools/ota_from_target_files
方式手动打ota包
更换lunch combo尝试,也没效果,似乎不是打包问题
3. 检查ota.py
#!/usr/bin/env python
# -*- coding=utf8 -*-
import sys
import zipfile
def main():
if len(sys.argv) != 2:
sys.stderr.write('Use: %s <ota_file.zip>\n' % sys.argv[0])
return 1
otazip = zipfile.ZipFile(sys.argv[1], 'r')
payload_info = otazip.getinfo('payload.bin')
payload_offset = payload_info.header_offset + len(payload_info.FileHeader())
payload_size = payload_info.file_size
payload_localtion = '/data/ota_package/update.zip'
headers = otazip.read("payload_properties.txt")
print(
'update_engine_client --update --follow --payload=file://{payload_localtion}'
' --offset={payload_offset} --size={payload_size}'
' --headers="{headers}"').format(**locals())
return 0
if __name__ == '__main__':
sys.exit(main())
手动解压ota包,打开payload_properties.txt
文件查看
$ ls
care_map.txt compatibility.zip META-INF payload.bin payload_properties.txt
$ cat payload_properties.txt
FILE_HASH=BMYgJY7CIoJCsowiXgi3L4kK4Og+aGOdfpzUGURCDvY=
FILE_SIZE=555750616
METADATA_HASH=33c52T0k5Xi7Q3kSx8tJszDtTzNNYQRTZTLiEUTbkLs=
METADATA_SIZE=87205
参数没有解析错误
4. 尝试其他方式ota刷机
进入recovery尝试,失败(原因未知)
5. 抓执行update_engine_client
命令失败的logcat分析
07-20 02:53:42.184 1011 1011 W update_engine: [0720/025342.184628:WARNING:update_attempter_android.cc(181)] Unable to decode base64 file hash: BMYgJY7CIoJCsowiXgi3L4kK4Og+aGOdfpzUGURCDvY= FILE_SIZE=555750616 METADATA_HASH=33c52T0k5Xi7Q3kSx8tJszDtTzNNYQRTZTLiEUTbkLs= METADATA_SIZE=87205
07-20 02:53:42.187 1011 1011 I update_engine: [0720/025342.187518:INFO:update_attempter_android.cc(246)] Using this install plan:
07-20 02:53:42.187 1011 1011 I update_engine: [0720/025342.187676:INFO:install_plan.cc(83)] InstallPlan: new_update, version: , source_slot: A, target_slot: B, url: file:///data/ota_package/update.zip, payload: (size: 555750616, metadata_size: 0, metadata signature: , hash: , payload type: unknown), hash_checks_mandatory: true, powerwash_required: false, switch_slot_on_reboot: true, run_post_install: true
07-20 02:53:42.187 1011 1011 I update_engine: [0720/025342.187840:INFO:update_attempter_android.cc(542)] Already updated boot flags. Skipping.
07-20 02:53:42.187 1011 1011 I update_engine: [0720/025342.187892:INFO:update_attempter_android.cc(562)] Scheduling an action processor start.
07-20 02:53:42.189 1011 1011 I update_engine: [0720/025342.189407:INFO:metrics_utils.cc(336)] Number of Reboots during current update attempt = 0
07-20 02:53:42.189 1011 1011 I update_engine: [0720/025342.189855:INFO:metrics_utils.cc(344)] Payload Attempt Number = 1
07-20 02:53:42.190 1011 1011 I update_engine: [0720/025342.190252:INFO:metrics_utils.cc(361)] Update Timestamp Start = 1/1/1970 0:44:02 GMT
07-20 02:53:42.190 1011 1011 I update_engine: [0720/025342.190612:INFO:action_processor.cc(46)] ActionProcessor: starting InstallPlanAction
07-20 02:53:42.190 1011 1011 I update_engine: [0720/025342.190686:INFO:action_processor.cc(116)] ActionProcessor: finished InstallPlanAction with code ErrorCode::kSuccess
07-20 02:53:42.190 1011 1011 I update_engine: [0720/025342.190737:INFO:action_processor.cc(143)] ActionProcessor: starting DownloadAction
07-20 02:53:42.190 1011 1011 I update_engine: [0720/025342.190794:INFO:install_plan.cc(83)] InstallPlan: new_update, version: , source_slot: A, target_slot: B, url: file:///data/ota_package/update.zip, payload: (size: 555750616, metadata_size: 0, metadata signature: , hash: , payload type: unknown), hash_checks_mandatory: true, powerwash_required: false, switch_slot_on_reboot: true, run_post_install: true
07-20 02:53:42.190 1011 1011 I update_engine: [0720/025342.190865:INFO:download_action.cc(200)] Marking new slot as unbootable
07-20 02:53:42.191 8304 8304 I update_engine_client: [INFO:update_engine_client_android.cc(90)] onStatusUpdate(UPDATE_STATUS_IDLE (0), 0)
07-20 02:53:42.192 8304 8304 I update_engine_client: [INFO:update_engine_client_android.cc(90)] onStatusUpdate(UPDATE_STATUS_UPDATE_AVAILABLE (2), 0)
07-20 02:53:42.196 1011 1011 I update_engine: [0720/025342.196508:INFO:multi_range_http_fetcher.cc(45)] starting first transfer
07-20 02:53:42.196 1011 1011 I update_engine: [0720/025342.196731:INFO:multi_range_http_fetcher.cc(74)] starting transfer of range 9053+555750616
07-20 02:53:42.197 8304 8304 I update_engine_client: [INFO:update_engine_client_android.cc(90)] onStatusUpdate(UPDATE_STATUS_DOWNLOADING (3), 4.57705e-05)
07-20 02:53:42.198 1011 1011 I update_engine: [0720/025342.198474:INFO:delta_performer.cc(210)] Completed 0/? operations, 16384/555750616 bytes downloaded (0%), overall progress 0%
07-20 02:53:42.198 1011 1011 E update_engine: [0720/025342.198630:ERROR:delta_performer.cc(451)] Mandatory metadata size in Omaha response (0) is missing/incorrect, actual = 87205
07-20 02:53:42.198 1011 1011 E update_engine: [0720/025342.198698:ERROR:download_action.cc(337)] Error ErrorCode::kDownloadInvalidMetadataSize (32) in DeltaPerformer's Write method when processing the received payload -- Terminating processing
07-20 02:53:42.198 1011 1011 I update_engine: [0720/025342.198769:INFO:delta_performer.cc(314)] Discarding 24 unused downloaded bytes
07-20 02:53:42.198 1011 1011 I update_engine: [0720/025342.198842:INFO:multi_range_http_fetcher.cc(172)] Received transfer terminated.
07-20 02:53:42.198 1011 1011 I update_engine: [0720/025342.198889:INFO:multi_range_http_fetcher.cc(124)] TransferEnded w/ code 200
07-20 02:53:42.198 1011 1011 I update_engine: [0720/025342.198936:INFO:multi_range_http_fetcher.cc(126)] Terminating.
07-20 02:53:42.199 1011 1011 I update_engine: [0720/025342.198988:INFO:action_processor.cc(116)] ActionProcessor: finished DownloadAction with code ErrorCode::kDownloadInvalidMetadataSize
07-20 02:53:42.199 1011 1011 I update_engine: [0720/025342.199048:INFO:action_processor.cc(121)] ActionProcessor: Aborting processing due to failure.
07-20 02:53:42.199 1011 1011 I update_engine: [0720/025342.199095:INFO:update_attempter_android.cc(431)] Processing Done.
07-20 02:53:42.199 1011 1011 I sysui_multi_action: [757,804,799,ota_update_engine_attempt_number,801,1,802,1]
07-20 02:53:42.199 1011 1011 I update_engine: [0720/025342.199480:INFO:metrics_reporter_android.cc(29)] uploading 1 to histogram for metric ota_update_engine_attempt_number
07-20 02:53:42.199 1011 1011 I sysui_multi_action: [757,804,799,ota_update_engine_attempt_payload_type,801,0,802,1]
07-20 02:53:42.199 1011 1011 I update_engine: [0720/025342.199578:INFO:metrics_reporter_android.cc(29)] uploading 0 to histogram for metric ota_update_engine_attempt_payload_type
07-20 02:53:42.199 8304 8304 I update_engine_client: [INFO:update_engine_client_android.cc(90)] onStatusUpdate(UPDATE_STATUS_IDLE (0), 0)
07-20 02:53:42.199 1011 1011 I sysui_multi_action: [757,804,799,ota_update_engine_attempt_duration_boottime_in_minutes,801,0,802,1]
07-20 02:53:42.199 8304 8304 I update_engine_client: [INFO:update_engine_client_android.cc(98)] onPayloadApplicationComplete(ErrorCode::kDownloadInvalidMetadataSize (32))
07-20 02:53:42.199 1011 1011 I update_engine: [0720/025342.199755:INFO:metrics_reporter_android.cc(29)] uploading 0 to histogram for metric ota_update_engine_attempt_duration_boottime_in_minutes
07-20 02:53:42.199 1011 1011 I sysui_multi_action: [757,804,799,ota_update_engine_attempt_duration_monotonic_in_minutes,801,0,802,1]
07-20 02:53:42.199 1011 1011 I update_engine: [0720/025342.199837:INFO:metrics_reporter_android.cc(29)] uploading 0 to histogram for metric ota_update_engine_attempt_duration_monotonic_in_minutes
07-20 02:53:42.199 1011 1011 I sysui_multi_action: [757,804,799,ota_update_engine_attempt_payload_size_mib,801,530,802,1]
07-20 02:53:42.199 1011 1011 I update_engine: [0720/025342.199898:INFO:metrics_reporter_android.cc(29)] uploading 530 to histogram for metric ota_update_engine_attempt_payload_size_mib
07-20 02:53:42.199 1011 1011 I sysui_multi_action: [757,804,799,ota_update_engine_attempt_result,801,3,802,1]
07-20 02:53:42.200 1011 1011 I update_engine: [0720/025342.200026:INFO:metrics_reporter_android.cc(29)] uploading 3 to histogram for metric ota_update_engine_attempt_result
07-20 02:53:42.200 1011 1011 I sysui_multi_action: [757,804,799,ota_update_engine_attempt_error_code,801,32,802,1]
07-20 02:53:42.200 1011 1011 I update_engine: [0720/025342.200085:INFO:metrics_reporter_android.cc(29)] uploading 32 to histogram for metric ota_update_engine_attempt_error_code
07-20 02:53:42.200 1011 1011 I sysui_multi_action: [757,804,799,ota_update_engine_attempt_current_bytes_downloaded_mib,801,16384,802,1]
07-20 02:53:42.200 1011 1011 I update_engine: [0720/025342.200232:INFO:metrics_reporter_android.cc(29)] uploading 16384 to histogram for metric ota_update_engine_attempt_current_bytes_downloaded_mib
log中的这两行给了我线索
第一行的警告,这里的base64的hash有问题,似乎是分隔字符串时出错了
07-20 02:53:42.184 1011 1011 W update_engine: [0720/025342.184628:WARNING:update_attempter_android.cc(181)] Unable to decode base64 file hash: BMYgJY7CIoJCsowiXgi3L4kK4Og+aGOdfpzUGURCDvY= FILE_SIZE=555750616 METADATA_HASH=33c52T0k5Xi7Q3kSx8tJszDtTzNNYQRTZTLiEUTbkLs= METADATA_SIZE=87205
下面这行进一步说明(第二行),没有解析成功(hash值是空的)
07-20 02:53:42.187 1011 1011 I update_engine: [0720/025342.187676:INFO:install_plan.cc(83)] InstallPlan: new_update, version: , source_slot: A, target_slot: B, url: file:///data/ota_package/update.zip, payload: (size: 555750616, metadata_size: 0, metadata signature: , hash: , payload type: unknown), hash_checks_mandatory: true, powerwash_required: false, switch_slot_on_reboot: true, run_post_install: true
查找第一行log对应的代码
system/update_engine/update_attempter_android.cc
bool UpdateAttempterAndroid::ApplyPayload(
const string& payload_url,
int64_t payload_offset,
int64_t payload_size,
const vector<string>& key_value_pair_headers,
brillo::ErrorPtr* error) {
...//省略
std::map<string, string> headers;
for (const string& key_value_pair : key_value_pair_headers) {
string key;
string value;
if (!brillo::string_utils::SplitAtFirst(
key_value_pair, "=", &key, &value, false)) {
return LogAndSetError(
error, FROM_HERE, "Passed invalid header: " + key_value_pair);
}
if (!headers.emplace(key, value).second)
return LogAndSetError(error, FROM_HERE, "Passed repeated key: " + key);
}
...//省略
if (!brillo::data_encoding::Base64Decode(headers[kPayloadPropertyFileHash],
&payload.hash)) {
LOG(WARNING) << "Unable to decode base64 file hash: "
<< headers[kPayloadPropertyFileHash];
}
找到调用ApplyPayload
函数的地方,一层层往上找
int UpdateEngineClientAndroid::OnInit() {}--->
Status BinderUpdateEngineAndroidService::applyPayload(...) --->
bool UpdateAttempterAndroid::ApplyPayload(...)
在int UpdateEngineClientAndroid::OnInit() {}
函数中发现,命令行的--headers=
传参,是在这里通过\n
进行分割的,所以这里必须用换行隔开参数。
问题点找到了。
if (FLAGS_update) {
std::vector<std::string> headers = base::SplitString(
FLAGS_headers, "\n", base::KEEP_WHITESPACE, base::SPLIT_WANT_NONEMPTY);
std::vector<android::String16> and_headers;
for (const auto& header : headers) {
and_headers.push_back(android::String16{header.data(), header.size()});
}
Status status = service_->applyPayload(
android::String16{FLAGS_payload.data(), FLAGS_payload.size()},
FLAGS_offset,
FLAGS_size,
and_headers);
if (!status.isOk())
return ExitWhenIdle(status);
}