commit 84f507bec3b596756e04134fd0e4ece8d53e358b
author Sen Jiang <senj@google.com> Thu Apr 12 19:13:38 2018 -0700
committer Sen Jiang <senj@google.com> Fri Apr 13 15:17:59 2018 -0700
tree abea8b31a01f4f7f52ee5698c948743ec6707d4c
parent ed4c47d93deafcd5d9228c0ab0283b414247f83f

Improve logging when generating delta.

Measure the time took encoding each file, and added logging for
time and number of operations before and after FragmentOperations
and MergeOperations.

Bug: 77817425
Test: look at log
Change-Id: Idd087dfe29fb57a0ba667078efac08b2081e4e67

payload_generator/ab_generator.cc

diff --git a/payload_generator/ab_generator.cc b/payload_generator/ab_generator.cc
index 089dfd9..962118e 100644
--- a/payload_generator/ab_generator.cc
+++ b/payload_generator/ab_generator.cc
@@ -57,6 +57,7 @@
                                                        blob_file));
   LOG(INFO) << "done reading " << new_part.name;
 
+  LOG(INFO) << "Fragmenting " << aops->size() << " operations.";
   TEST_AND_RETURN_FALSE(
       FragmentOperations(config.version, aops, new_part.path, blob_file));
   SortOperationsByDestination(aops);
@@ -69,8 +70,10 @@
     merge_chunk_blocks = hard_chunk_blocks;
   }
 
+  LOG(INFO) << "Merging " << aops->size() << " operations.";
   TEST_AND_RETURN_FALSE(MergeOperations(
       aops, config.version, merge_chunk_blocks, new_part.path, blob_file));
+  LOG(INFO) << aops->size() << " operations after merge.";
 
   if (config.version.minor >= kOpSrcHashMinorPayloadVersion)
     TEST_AND_RETURN_FALSE(AddSourceHash(aops, old_part.path));

payload_generator/delta_diff_utils.cc

diff --git a/payload_generator/delta_diff_utils.cc b/payload_generator/delta_diff_utils.cc
index 5329dbf..c0962bf 100644
--- a/payload_generator/delta_diff_utils.cc
+++ b/payload_generator/delta_diff_utils.cc
@@ -40,6 +40,7 @@
 #include <base/strings/string_util.h>
 #include <base/strings/stringprintf.h>
 #include <base/threading/simple_thread.h>
+#include <base/time/time.h>
 #include <brillo/data_encoding.h>
 #include <bsdiff/bsdiff.h>
 #include <bsdiff/patch_writer_factory.h>
@@ -243,9 +244,7 @@
 
 void FileDeltaProcessor::Run() {
   TEST_AND_RETURN(blob_file_ != nullptr);
-
-  LOG(INFO) << "Encoding file " << name_ << " (" << new_extents_blocks_
-            << " blocks)";
+  base::Time start = base::Time::Now();
 
   if (!DeltaReadFile(&file_aops_,
                      old_part_,
@@ -261,6 +260,10 @@
     LOG(ERROR) << "Failed to generate delta for " << name_ << " ("
                << new_extents_blocks_ << " blocks)";
   }
+
+  LOG(INFO) << "Encoded file " << name_ << " (" << new_extents_blocks_
+            << " blocks) in " << (base::Time::Now() - start).InSecondsF()
+            << " seconds.";
 }
 
 void FileDeltaProcessor::MergeOperation(vector<AnnotatedOperation>* aops) {