Move the parse of last_install to recovery-persist

The recovery-persist used to look for the related recovery logs in
persist storage, and copy them under /data/misc/recovery during the
normal boot process.

As we also want to find out the sideload information from last_install,
it makes more sense to move the parse & report of non-a/b metrics to
recovery-persist. Thus we can avoid the race condition of the file
system between the native code and RecoverySystem.

Bug: 114278989
Test: unit test pass, check the event buffer for metrics report
Change-Id: I32d7b2b831bc74a61a70af9a2f0b8a7e9b3e36ee

Android.bp

@@ -256,6 +256,7 @@ cc_binary {
     shared_libs: [
         "libbase",
         "liblog",
+        "libmetricslogger",
     ],
 
     static_libs: [

Android.mk

@@ -71,10 +71,13 @@ LOCAL_REQUIRED_MODULES += \
 endif
 endif
 
+# On A/B devices recovery-persist reads the recovery related file from the persist storage and
+# copies them into /data/misc/recovery. Then, for both A/B and non-A/B devices, recovery-persist
+# parses the last_install file and reports the embedded update metrics. Also, the last_install file
+# will be deteleted after the report.
+LOCAL_REQUIRED_MODULES += recovery-persist
 ifeq ($(BOARD_CACHEIMAGE_PARTITION_SIZE),)
-LOCAL_REQUIRED_MODULES += \
-    recovery-persist \
-    recovery-refresh
+LOCAL_REQUIRED_MODULES += recovery-refresh
 endif
 
 include $(BUILD_PHONY_PACKAGE)

logging.cpp

@@ -221,6 +221,7 @@ void copy_logs(bool modified_flash, bool has_cache) {
   chown(LAST_KMSG_FILE, AID_SYSTEM, AID_SYSTEM);
   chmod(LAST_LOG_FILE, 0640);
   chmod(LAST_INSTALL_FILE, 0644);
+  chown(LAST_INSTALL_FILE, AID_SYSTEM, AID_SYSTEM);
   sync();
 }
 

otautil/Android.bp

@@ -41,6 +41,7 @@ cc_library_static {
             srcs: [
                 "dirutil.cpp",
                 "mounts.cpp",
+                "parse_install_logs.cpp",
                 "sysutil.cpp",
                 "thermalutil.cpp",
             ],

otautil/include/otautil/parse_install_logs.h

@@ -0,0 +1,33 @@
+/*
+ * Copyright (C) 2018 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#pragma once
+
+#include <stdint.h>
+
+#include <map>
+#include <string>
+#include <vector>
+
+constexpr const char* LAST_INSTALL_FILE = "/data/misc/recovery/last_install";
+constexpr const char* LAST_INSTALL_FILE_IN_CACHE = "/cache/recovery/last_install";
+
+// Parses the metrics of update applied under recovery mode in |lines|, and returns a map with
+// "name: value".
+std::map<std::string, int64_t> ParseRecoveryUpdateMetrics(const std::vector<std::string>& lines);
+// Parses the sideload history and update metrics in the last_install file. Returns a map with
+// entries as "metrics_name: value". If no such file exists, returns an empty map.
+std::map<std::string, int64_t> ParseLastInstall(const std::string& file_name);

otautil/parse_install_logs.cpp

@@ -0,0 +1,114 @@
+/*
+ * Copyright (C) 2018 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#include "otautil/parse_install_logs.h"
+
+#include <unistd.h>
+
+#include <optional>
+
+#include <android-base/file.h>
+#include <android-base/logging.h>
+#include <android-base/parseint.h>
+#include <android-base/properties.h>
+#include <android-base/strings.h>
+
+constexpr const char* OTA_SIDELOAD_METRICS = "ota_sideload";
+
+// Here is an example of lines in last_install:
+// ...
+// time_total: 101
+// bytes_written_vendor: 51074
+// bytes_stashed_vendor: 200
+std::map<std::string, int64_t> ParseRecoveryUpdateMetrics(const std::vector<std::string>& lines) {
+  constexpr unsigned int kMiB = 1024 * 1024;
+  std::optional<int64_t> bytes_written_in_mib;
+  std::optional<int64_t> bytes_stashed_in_mib;
+  std::map<std::string, int64_t> metrics;
+  for (const auto& line : lines) {
+    size_t num_index = line.find(':');
+    if (num_index == std::string::npos) {
+      LOG(WARNING) << "Skip parsing " << line;
+      continue;
+    }
+
+    std::string num_string = android::base::Trim(line.substr(num_index + 1));
+    int64_t parsed_num;
+    if (!android::base::ParseInt(num_string, &parsed_num)) {
+      LOG(ERROR) << "Failed to parse numbers in " << line;
+      continue;
+    }
+
+    if (android::base::StartsWith(line, "bytes_written")) {
+      bytes_written_in_mib = bytes_written_in_mib.value_or(0) + parsed_num / kMiB;
+    } else if (android::base::StartsWith(line, "bytes_stashed")) {
+      bytes_stashed_in_mib = bytes_stashed_in_mib.value_or(0) + parsed_num / kMiB;
+    } else if (android::base::StartsWith(line, "time")) {
+      metrics.emplace("ota_time_total", parsed_num);
+    } else if (android::base::StartsWith(line, "uncrypt_time")) {
+      metrics.emplace("ota_uncrypt_time", parsed_num);
+    } else if (android::base::StartsWith(line, "source_build")) {
+      metrics.emplace("ota_source_version", parsed_num);
+    } else if (android::base::StartsWith(line, "temperature_start")) {
+      metrics.emplace("ota_temperature_start", parsed_num);
+    } else if (android::base::StartsWith(line, "temperature_end")) {
+      metrics.emplace("ota_temperature_end", parsed_num);
+    } else if (android::base::StartsWith(line, "temperature_max")) {
+      metrics.emplace("ota_temperature_max", parsed_num);
+    } else if (android::base::StartsWith(line, "error")) {
+      metrics.emplace("ota_non_ab_error_code", parsed_num);
+    } else if (android::base::StartsWith(line, "cause")) {
+      metrics.emplace("ota_non_ab_cause_code", parsed_num);
+    }
+  }
+
+  if (bytes_written_in_mib) {
+    metrics.emplace("ota_written_in_MiBs", bytes_written_in_mib.value());
+  }
+  if (bytes_stashed_in_mib) {
+    metrics.emplace("ota_stashed_in_MiBs", bytes_stashed_in_mib.value());
+  }
+
+  return metrics;
+}
+
+std::map<std::string, int64_t> ParseLastInstall(const std::string& file_name) {
+  if (access(file_name.c_str(), F_OK) != 0) {
+    return {};
+  }
+
+  std::string content;
+  if (!android::base::ReadFileToString(file_name, &content)) {
+    PLOG(ERROR) << "Failed to read " << file_name;
+    return {};
+  }
+
+  if (content.empty()) {
+    LOG(INFO) << "Empty last_install file";
+    return {};
+  }
+
+  std::vector<std::string> lines = android::base::Split(content, "\n");
+  auto metrics = ParseRecoveryUpdateMetrics(lines);
+
+  // LAST_INSTALL starts with "/sideload/package.zip" after a sideload.
+  if (android::base::Trim(lines[0]) == "/sideload/package.zip") {
+    int type = (android::base::GetProperty("ro.build.type", "") == "user") ? 1 : 0;
+    metrics.emplace(OTA_SIDELOAD_METRICS, type);
+  }
+
+  return metrics;
+}

recovery-persist.cpp

@@ -35,19 +35,22 @@
 #include <string.h>
 #include <unistd.h>
 
+#include <limits>
 #include <string>
 
 #include <android-base/file.h>
 #include <android-base/logging.h>
+#include <metricslogger/metrics_logger.h>
 #include <private/android_logger.h> /* private pmsg functions */
 
 #include "logging.h"
+#include "otautil/parse_install_logs.h"
 
-static const char *LAST_LOG_FILE = "/data/misc/recovery/last_log";
-static const char *LAST_PMSG_FILE = "/sys/fs/pstore/pmsg-ramoops-0";
-static const char *LAST_KMSG_FILE = "/data/misc/recovery/last_kmsg";
-static const char *LAST_CONSOLE_FILE = "/sys/fs/pstore/console-ramoops-0";
-static const char *ALT_LAST_CONSOLE_FILE = "/sys/fs/pstore/console-ramoops";
+constexpr const char* LAST_LOG_FILE = "/data/misc/recovery/last_log";
+constexpr const char* LAST_PMSG_FILE = "/sys/fs/pstore/pmsg-ramoops-0";
+constexpr const char* LAST_KMSG_FILE = "/data/misc/recovery/last_kmsg";
+constexpr const char* LAST_CONSOLE_FILE = "/sys/fs/pstore/console-ramoops-0";
+constexpr const char* ALT_LAST_CONSOLE_FILE = "/sys/fs/pstore/console-ramoops";
 
 // close a file, log an error if the error indicator is set
 static void check_and_fclose(FILE *fp, const char *name) {
@@ -109,6 +112,20 @@ ssize_t logsave(
     return android::base::WriteStringToFile(buffer, destination.c_str());
 }
 
+// Parses the LAST_INSTALL file and reports the update metrics saved under recovery mode.
+static void report_metrics_from_last_install(const std::string& file_name) {
+  auto metrics = ParseLastInstall(file_name);
+  // TODO(xunchang) report the installation result.
+  for (const auto& [event, value] : metrics) {
+    if (value > std::numeric_limits<int>::max()) {
+      LOG(WARNING) << event << " (" << value << ") exceeds integer max.";
+    } else {
+      LOG(INFO) << "Uploading " << value << " to " << event;
+      android::metricslogger::LogHistogram(event, value);
+    }
+  }
+}
+
 int main(int argc, char **argv) {
 
     /* Is /cache a mount?, we have been delivered where we are not wanted */
@@ -138,14 +155,18 @@ int main(int argc, char **argv) {
     }
 
     if (has_cache) {
-        /*
-         * TBD: Future location to move content from
-         * /cache/recovery to /data/misc/recovery/
-         */
-        /* if --force-persist flag, then transfer pmsg data anyways */
-        if ((argc <= 1) || !argv[1] || strcmp(argv[1], "--force-persist")) {
-            return 0;
-        }
+      // Collects and reports the non-a/b update metrics from last_install; and removes the file
+      // to avoid duplicate report.
+      report_metrics_from_last_install(LAST_INSTALL_FILE_IN_CACHE);
+      if (unlink(LAST_INSTALL_FILE_IN_CACHE) == -1) {
+        PLOG(ERROR) << "Failed to unlink " << LAST_INSTALL_FILE_IN_CACHE;
+      }
+
+      // TBD: Future location to move content from /cache/recovery to /data/misc/recovery/
+      // if --force-persist flag, then transfer pmsg data anyways
+      if ((argc <= 1) || !argv[1] || strcmp(argv[1], "--force-persist")) {
+        return 0;
+      }
     }
 
     /* Is there something in pmsg? */
@@ -157,6 +178,15 @@ int main(int argc, char **argv) {
     __android_log_pmsg_file_read(
         LOG_ID_SYSTEM, ANDROID_LOG_INFO, "recovery/", logsave, NULL);
 
+    // For those device without /cache, the last_install file has been copied to
+    // /data/misc/recovery from pmsg. Looks for the sideload history only.
+    if (!has_cache) {
+      report_metrics_from_last_install(LAST_INSTALL_FILE);
+      if (unlink(LAST_INSTALL_FILE) == -1) {
+        PLOG(ERROR) << "Failed to unlink " << LAST_INSTALL_FILE;
+      }
+    }
+
     /* Is there a last console log too? */
     if (rotated) {
         if (!access(LAST_CONSOLE_FILE, R_OK)) {

tests/unit/parse_install_logs_test.cpp

@@ -0,0 +1,75 @@
+/*
+ * Copyright (C) 2018 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#include <map>
+#include <string>
+#include <vector>
+
+#include <android-base/file.h>
+#include <android-base/strings.h>
+#include <android-base/test_utils.h>
+#include <gtest/gtest.h>
+
+#include "otautil/parse_install_logs.h"
+
+TEST(ParseInstallLogsTest, EmptyFile) {
+  TemporaryFile last_install;
+
+  auto metrics = ParseLastInstall(last_install.path);
+  ASSERT_TRUE(metrics.empty());
+}
+
+TEST(ParseInstallLogsTest, SideloadSmoke) {
+  TemporaryFile last_install;
+  ASSERT_TRUE(android::base::WriteStringToFile("/cache/recovery/ota.zip\n0\n", last_install.path));
+  auto metrics = ParseLastInstall(last_install.path);
+  ASSERT_EQ(metrics.end(), metrics.find("ota_sideload"));
+
+  ASSERT_TRUE(android::base::WriteStringToFile("/sideload/package.zip\n0\n", last_install.path));
+  metrics = ParseLastInstall(last_install.path);
+  ASSERT_NE(metrics.end(), metrics.find("ota_sideload"));
+}
+
+TEST(ParseInstallLogsTest, ParseRecoveryUpdateMetrics) {
+  std::vector<std::string> lines = {
+    "/sideload/package.zip",
+    "0",
+    "time_total: 300",
+    "uncrypt_time: 40",
+    "source_build: 4973410",
+    "bytes_written_system: " + std::to_string(1200 * 1024 * 1024),
+    "bytes_stashed_system: " + std::to_string(300 * 1024 * 1024),
+    "bytes_written_vendor: " + std::to_string(40 * 1024 * 1024),
+    "bytes_stashed_vendor: " + std::to_string(50 * 1024 * 1024),
+    "temperature_start: 37000",
+    "temperature_end: 38000",
+    "temperature_max: 39000",
+    "error: 22",
+    "cause: 55",
+  };
+
+  auto metrics = ParseRecoveryUpdateMetrics(lines);
+
+  std::map<std::string, int64_t> expected_result = {
+    { "ota_time_total", 300 },         { "ota_uncrypt_time", 40 },
+    { "ota_source_version", 4973410 }, { "ota_written_in_MiBs", 1240 },
+    { "ota_stashed_in_MiBs", 350 },    { "ota_temperature_start", 37000 },
+    { "ota_temperature_end", 38000 },  { "ota_temperature_max", 39000 },
+    { "ota_non_ab_error_code", 22 },   { "ota_non_ab_cause_code", 55 },
+  };
+
+  ASSERT_EQ(expected_result, metrics);
+}