1 files changed, 42 insertions, 12 deletions

diff --git a/install.cpp b/install.cpp
index a7b59c3e7..9d2971c8c 100644
--- a/install.cpp
+++ b/install.cpp
@@ -23,9 +23,15 @@
 #include <sys/wait.h>
 #include <unistd.h>
 
+#include <chrono>
+#include <string>
 #include <vector>
 
+#include <android-base/stringprintf.h>
+#include <android-base/strings.h>
+
 #include "common.h"
+#include "error_code.h"
 #include "install.h"
 #include "minui/minui.h"
 #include "minzip/SysUtil.h"
@@ -49,7 +55,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<std::string>& log_buffer)
+{
     const ZipEntry* binary_entry =
             mzFindZipEntry(zip, ASSUMED_UPDATE_BINARY_NAME);
     if (binary_entry == NULL) {
@@ -182,6 +190,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);
         }
@@ -202,7 +214,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<std::string>& log_buffer)
 {
     ui->SetBackground(RecoveryUI::INSTALLING_UPDATE);
     ui->Print("Finding update package...\n");
@@ -228,6 +241,7 @@ really_install_package(const char *path, bool* wipe_cache, bool needs_mount)
         return INSTALL_CORRUPT;
     }
 
+    // Load keys.
     std::vector<Certificate> loadedKeys;
     if (!load_keys(PUBLIC_KEYS_FILE, loadedKeys)) {
         LOGE("Failed to load keys\n");
@@ -235,31 +249,35 @@ really_install_package(const char *path, bool* wipe_cache, bool needs_mount)
     }
     LOGI("%zu key(s) loaded from %s\n", loadedKeys.size(), PUBLIC_KEYS_FILE);
 
+    // Verify package.
     ui->Print("Verifying update package...\n");
-
+    auto t0 = std::chrono::system_clock::now();
     int err = verify_file(map.addr, map.length, loadedKeys);
-    LOGI("verify_file returned %d\n", err);
+    std::chrono::duration<double> duration = std::chrono::system_clock::now() - t0;
+    ui->Print("Update package verification took %.1f s (result %d).\n", duration.count(), err);
     if (err != VERIFY_SUCCESS) {
         LOGE("signature verification failed\n");
+        log_buffer.push_back(android::base::StringPrintf("error: %d", kZipVerificationFailure));
+
         sysReleaseMap(&map);
         return INSTALL_CORRUPT;
     }
 
-    /* Try to open the package.
-     */
+    // Try to open the package.
     ZipArchive zip;
     err = mzOpenZipArchive(map.addr, map.length, &zip);
     if (err != 0) {
         LOGE("Can't open %s\n(%s)\n", path, err != -1 ? strerror(err) : "bad");
+        log_buffer.push_back(android::base::StringPrintf("error: %d", kZipOpenFailure));
+
         sysReleaseMap(&map);
         return INSTALL_CORRUPT;
     }
 
-    /* Verify and install the contents of the package.
-     */
+    // 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");
 
@@ -270,9 +288,10 @@ really_install_package(const char *path, bool* wipe_cache, bool needs_mount)
 
 int
 install_package(const char* path, bool* wipe_cache, const char* install_file,
-                bool needs_mount)
+                bool needs_mount, int retry_count)
 {
     modified_flash = true;
+    auto start = std::chrono::system_clock::now();
 
     FILE* install_log = fopen_path(install_file, "w");
     if (install_log) {
@@ -282,15 +301,26 @@ 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<std::string> 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) {
+    if (install_log != nullptr) {
         fputc(result == INSTALL_SUCCESS ? '1' : '0', install_log);
         fputc('\n', install_log);
+        std::chrono::duration<double> duration = std::chrono::system_clock::now() - start;
+        int count = static_cast<int>(duration.count());
+        // Report the time spent to apply OTA update in seconds.
+        fprintf(install_log, "time_total: %d\n", count);
+        fprintf(install_log, "retry: %d\n", retry_count);
+
+        for (const auto& s : log_buffer) {
+            fprintf(install_log, "%s\n", s.c_str());
+        }
+
         fclose(install_log);
     }
     return result;