From dd874b1c87eb04f28db0db2629df0adde568a74c Mon Sep 17 00:00:00 2001 From: Tianjie Xu Date: Fri, 13 May 2016 12:13:15 -0700 Subject: [PATCH] Add time and I/O info to last_install One example of last_install is: /sideload/package.zip 1 time_total: 101 bytes_written_system: 14574000 bytes_stashed_system: 100 bytes_written_vendor: 5107400 bytes_stashed_vendor: 0 Bug: 28658632 Change-Id: I4bf79ea71a609068d38fbce6b41bcb892524aa7a --- install.cpp | 27 +++++++++++++++++++++++---- updater/blockimg.cpp | 12 ++++++++++++ 2 files changed, 35 insertions(+), 4 deletions(-) diff --git a/install.cpp b/install.cpp index d009513c..d725c7b8 100644 --- a/install.cpp +++ b/install.cpp @@ -24,6 +24,7 @@ #include #include +#include #include #include "common.h" @@ -50,7 +51,9 @@ static const float DEFAULT_IMAGE_PROGRESS_FRACTION = 0.1; // If the package contains an update binary, extract it and run it. static int -try_update_binary(const char* path, ZipArchive* zip, bool* wipe_cache) { +try_update_binary(const char* path, ZipArchive* zip, bool* wipe_cache, + std::vector& log_buffer) +{ const ZipEntry* binary_entry = mzFindZipEntry(zip, ASSUMED_UPDATE_BINARY_NAME); if (binary_entry == NULL) { @@ -183,6 +186,10 @@ try_update_binary(const char* path, ZipArchive* zip, bool* wipe_cache) { ui->SetEnableReboot(true); } else if (strcmp(command, "retry_update") == 0) { retry_update = true; + } else if (strcmp(command, "log") == 0) { + // Save the logging request from updater and write to + // last_install later. + log_buffer.push_back(std::string(strtok(NULL, "\n"))); } else { LOGE("unknown command [%s]\n", command); } @@ -203,7 +210,8 @@ try_update_binary(const char* path, ZipArchive* zip, bool* wipe_cache) { } static int -really_install_package(const char *path, bool* wipe_cache, bool needs_mount) +really_install_package(const char *path, bool* wipe_cache, bool needs_mount, + std::vector& log_buffer) { ui->SetBackground(RecoveryUI::INSTALLING_UPDATE); ui->Print("Finding update package...\n"); @@ -261,7 +269,7 @@ really_install_package(const char *path, bool* wipe_cache, bool needs_mount) // Verify and install the contents of the package. ui->Print("Installing update...\n"); ui->SetEnableReboot(false); - int result = try_update_binary(path, &zip, wipe_cache); + int result = try_update_binary(path, &zip, wipe_cache, log_buffer); ui->SetEnableReboot(true); ui->Print("\n"); @@ -275,6 +283,7 @@ install_package(const char* path, bool* wipe_cache, const char* install_file, bool needs_mount) { modified_flash = true; + auto start = std::chrono::system_clock::now(); FILE* install_log = fopen_path(install_file, "w"); if (install_log) { @@ -284,15 +293,25 @@ install_package(const char* path, bool* wipe_cache, const char* install_file, LOGE("failed to open last_install: %s\n", strerror(errno)); } int result; + std::vector log_buffer; if (setup_install_mounts() != 0) { LOGE("failed to set up expected mounts for install; aborting\n"); result = INSTALL_ERROR; } else { - result = really_install_package(path, wipe_cache, needs_mount); + result = really_install_package(path, wipe_cache, needs_mount, log_buffer); } if (install_log) { fputc(result == INSTALL_SUCCESS ? '1' : '0', install_log); fputc('\n', install_log); + std::chrono::duration duration = std::chrono::system_clock::now() - start; + int count = static_cast(duration.count()); + // Report the time spent to apply OTA update in seconds. + fprintf(install_log, "time_total: %d\n", count); + + for (const auto& s : log_buffer) { + fprintf(install_log, "%s\n", s.c_str()); + } + fclose(install_log); } return result; diff --git a/updater/blockimg.cpp b/updater/blockimg.cpp index c20bad90..d67af664 100644 --- a/updater/blockimg.cpp +++ b/updater/blockimg.cpp @@ -373,6 +373,7 @@ struct CommandParameters { bool isunresumable; int version; size_t written; + size_t stashed; NewThreadInfo nti; pthread_t thread; std::vector buffer; @@ -777,6 +778,7 @@ static int SaveStash(CommandParameters& params, const std::string& base, } fprintf(stderr, "stashing %zu blocks to %s\n", blocks, id.c_str()); + params.stashed += blocks; return WriteStash(base, id, blocks, buffer, false, nullptr); } @@ -973,6 +975,7 @@ static int LoadSrcTgtVersion3(CommandParameters& params, RangeSet& tgt, size_t& return -1; } + params.stashed += src_blocks; // Can be deleted when the write has completed if (!stash_exists) { params.freestash = srchash; @@ -1517,8 +1520,17 @@ static Value* PerformBlockImageUpdate(const char* name, State* state, int /* arg pthread_join(params.thread, nullptr); fprintf(stderr, "wrote %zu blocks; expected %d\n", params.written, total_blocks); + fprintf(stderr, "stashed %zu blocks\n", params.stashed); fprintf(stderr, "max alloc needed was %zu\n", params.buffer.size()); + const char* partition = strrchr(blockdev_filename->data, '/'); + if (partition != nullptr && *(partition+1) != 0) { + fprintf(cmd_pipe, "log bytes_written_%s: %zu\n", partition + 1, + params.written * BLOCKSIZE); + fprintf(cmd_pipe, "log bytes_stashed_%s: %zu\n", partition + 1, + params.stashed * BLOCKSIZE); + fflush(cmd_pipe); + } // Delete stash only after successfully completing the update, as it // may contain blocks needed to complete the update later. DeleteStash(params.stashbase);