commit 8ddadd37a2d6e73803d75a2a7881ef0861710c0e
author Kelvin Zhang <zhangkelvin@google.com> Tue Dec 12 12:54:30 2023 -0800
committer Kelvin Zhang <zhangkelvin@google.com> Thu Dec 14 13:54:06 2023 -0800
tree a598b155f739caacf98d089272c0047baf0977ee
parent 944cdac341ac91bc467765c4b89520ffbcfbc721

Logging improvements

Test: th
Change-Id: I032df7edb102769845e798abad21a98fa167b6f3

payload_consumer/delta_performer.cc

diff --git a/payload_consumer/delta_performer.cc b/payload_consumer/delta_performer.cc
index 8a820f9..dcbf2cc 100644
--- a/payload_consumer/delta_performer.cc
+++ b/payload_consumer/delta_performer.cc
@@ -16,12 +16,11 @@
 
 #include "update_engine/payload_consumer/delta_performer.h"
 
-#include <errno.h>
 #include <linux/fs.h>
 
 #include <algorithm>
+#include <chrono>
 #include <cstring>
-#include <map>
 #include <memory>
 #include <set>
 #include <string>
@@ -791,10 +790,17 @@
     }
   }
 
+  const auto start = std::chrono::system_clock::now();
   if (!install_plan_->ParsePartitions(
           partitions_, boot_control_, block_size_, error)) {
     return false;
   }
+  const auto duration = std::chrono::system_clock::now() - start;
+  LOG(INFO)
+      << "ParsePartitions done. took "
+      << std::chrono::duration_cast<std::chrono::milliseconds>(duration).count()
+      << " ms";
+
   auto&& has_verity = [](const auto& part) {
     return part.fec_extent().num_blocks() > 0 ||
            part.hash_tree_extent().num_blocks() > 0;
@@ -848,6 +854,7 @@
     ResetUpdateProgress(prefs, false);
   }
 
+  const auto start = std::chrono::system_clock::now();
   if (!boot_control->GetDynamicPartitionControl()->PreparePartitionsForUpdate(
           boot_control->GetCurrentSlot(),
           target_slot,
@@ -860,10 +867,14 @@
                << utils::ErrorCodeToString(*error);
     return false;
   }
+  const auto duration = std::chrono::system_clock::now() - start;
 
   TEST_AND_RETURN_FALSE(prefs->SetString(kPrefsDynamicPartitionMetadataUpdated,
                                          update_check_response_hash));
-  LOG(INFO) << "PreparePartitionsForUpdate done.";
+  LOG(INFO)
+      << "PreparePartitionsForUpdate done. took "
+      << std::chrono::duration_cast<std::chrono::milliseconds>(duration).count()
+      << " ms";
 
   return true;
 }
@@ -1342,7 +1353,8 @@
   if (prefs->GetInt64(kPrefsResumedUpdateFailures, &resumed_update_failures) &&
       resumed_update_failures > kMaxResumedUpdateFailures) {
     LOG(WARNING) << "Failed to resume update " << kPrefsResumedUpdateFailures
-                 << " invalid: " << resumed_update_failures;
+                 << " has value " << resumed_update_failures
+                 << " is over the limit " << kMaxResumedUpdateFailures;
     return false;
   }