crostini: log .tini export statistics

BUG=992293

Change-Id: Id54f0b0f26e06b1ce5c2c7c4e725889867e88334
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1750516
Commit-Queue: Julian Watson <juwa@google.com>
Auto-Submit: Julian Watson <juwa@google.com>
Reviewed-by: Joel Hockey <joelhockey@chromium.org>
Cr-Commit-Position: refs/heads/master@{#686355}

chrome/browser/chromeos/crostini/crostini_export_import.cc

@@ -8,6 +8,7 @@
 
 #include "base/bind.h"
 #include "base/files/file_util.h"
+#include "base/metrics/histogram_functions.h"
 #include "base/metrics/histogram_macros.h"
 #include "base/strings/stringprintf.h"
 #include "base/task/post_task.h"
@@ -239,7 +240,8 @@ void CrostiniExportImport::OnExportComplete(
     const base::Time& start,
     const ContainerId& container_id,
     CrostiniManager::CrostiniResultCallback callback,
-    CrostiniResult result) {
+    CrostiniResult result,
+    uint64_t container_size) {
   auto it = notifications_.find(container_id);
   DCHECK(it != notifications_.end())
       << ContainerIdToString(container_id) << " has no notification to update";
@@ -262,6 +264,43 @@ void CrostiniExportImport::OnExportComplete(
       case CrostiniExportImportNotification::Status::RUNNING:
         UMA_HISTOGRAM_LONG_TIMES("Crostini.BackupTimeSuccess",
                                  base::Time::Now() - start);
+        // Log backup size statistics.
+        // TODO(juwa): Send compressed bytes written in progress message from
+        // tremplin, to remove the need to read the file's size.
+        base::PostTask(
+            FROM_HERE,
+            {base::ThreadPool(), base::MayBlock(),
+             base::TaskPriority::BEST_EFFORT},
+            base::BindOnce(
+                [](const base::FilePath& path, uint64_t size) {
+                  if (size == 0) {
+                    LOG(ERROR) << "Uncompressed container size from export "
+                                  "progress is zero.";
+                    NOTREACHED();
+                    return;
+                  }
+                  uint64_t compressed_size{};
+                  {
+                    int64_t file_size;
+                    if (!base::GetFileSize(path, &file_size) || file_size < 0) {
+                      LOG(ERROR) << "Couldn't get exported file size for "
+                                    "histogram";
+                      return;
+                    }
+                    compressed_size = static_cast<uint64_t>(file_size);
+                  }
+
+                  base::UmaHistogramCustomCounts(
+                      "Crostini.BackupUncompressedSizeLog2",
+                      std::round(std::log2(size)), 0, 50, 50);
+                  base::UmaHistogramCustomCounts(
+                      "Crostini.BackupCompressedSizeLog2",
+                      std::round(std::log2(compressed_size)), 0, 50, 50);
+                  base::UmaHistogramPercentage(
+                      "Crostini.BackupCompressionRatio",
+                      std::round(compressed_size * 100.0 / size));
+                },
+                it->second->path(), container_size));
         RemoveNotification(it).SetStatusDone();
         break;
       default:

chrome/browser/chromeos/crostini/crostini_export_import.h

@@ -164,7 +164,8 @@ class CrostiniExportImport : public KeyedService,
   void OnExportComplete(const base::Time& start,
                         const ContainerId& container_id,
                         CrostiniManager::CrostiniResultCallback callback,
-                        CrostiniResult result);
+                        CrostiniResult result,
+                        uint64_t container_size);
 
   void ImportAfterSharing(const ContainerId& container_id,
                           CrostiniManager::CrostiniResultCallback callback,

chrome/browser/chromeos/crostini/crostini_manager.cc

@@ -82,16 +82,16 @@ void OnConciergeServiceAvailable(CrostiniManager::BoolCallback callback,
   GetCiceroneClient()->WaitForServiceToBeAvailable(std::move(callback));
 }
 
-// Find any callbacks for the specified |vm_name|, invoke them with |result|
-// and erase them from the map.
+// Find any callbacks for the specified |vm_name|, invoke them with
+// |arguments|... and erase them from the map.
+template <typename... Arguments>
 void InvokeAndErasePendingCallbacks(
-    std::map<ContainerId, CrostiniManager::CrostiniResultCallback>*
-        vm_keyed_map,
+    std::map<ContainerId, base::OnceCallback<void(Arguments...)>>* vm_keyed_map,
     const std::string& vm_name,
-    CrostiniResult result) {
+    Arguments&&... arguments) {
   for (auto it = vm_keyed_map->begin(); it != vm_keyed_map->end();) {
     if (it->first.first == vm_name) {
-      std::move(it->second).Run(result);
+      std::move(it->second).Run(arguments...);
       vm_keyed_map->erase(it++);
     } else {
       ++it;
@@ -1096,23 +1096,25 @@ void CrostiniManager::SetUpLxdContainerUser(std::string vm_name,
                      request.container_name(), std::move(callback)));
 }
 
-void CrostiniManager::ExportLxdContainer(std::string vm_name,
-                                         std::string container_name,
-                                         base::FilePath export_path,
-                                         CrostiniResultCallback callback) {
+void CrostiniManager::ExportLxdContainer(
+    std::string vm_name,
+    std::string container_name,
+    base::FilePath export_path,
+    base::OnceCallback<void(CrostiniResult success, uint64_t container_size)>
+        callback) {
   if (vm_name.empty()) {
     LOG(ERROR) << "vm_name is required";
-    std::move(callback).Run(CrostiniResult::CLIENT_ERROR);
+    std::move(callback).Run(CrostiniResult::CLIENT_ERROR, 0);
     return;
   }
   if (container_name.empty()) {
     LOG(ERROR) << "container_name is required";
-    std::move(callback).Run(CrostiniResult::CLIENT_ERROR);
+    std::move(callback).Run(CrostiniResult::CLIENT_ERROR, 0);
     return;
   }
   if (export_path.empty()) {
     LOG(ERROR) << "export_path is required";
-    std::move(callback).Run(CrostiniResult::CLIENT_ERROR);
+    std::move(callback).Run(CrostiniResult::CLIENT_ERROR, 0);
     return;
   }
 
@@ -1121,7 +1123,7 @@ void CrostiniManager::ExportLxdContainer(std::string vm_name,
       export_lxd_container_callbacks_.end()) {
     LOG(ERROR) << "Export currently in progress for " << vm_name << ", "
                << container_name;
-    std::move(callback).Run(CrostiniResult::CONTAINER_EXPORT_IMPORT_FAILED);
+    std::move(callback).Run(CrostiniResult::CONTAINER_EXPORT_IMPORT_FAILED, 0);
     return;
   }
   export_lxd_container_callbacks_.emplace(key, std::move(callback));
@@ -1777,7 +1779,7 @@ void CrostiniManager::OnStartTerminaVm(
   // be marked as failed.
   InvokeAndErasePendingCallbacks(
       &export_lxd_container_callbacks_, vm_name,
-      CrostiniResult::CONTAINER_EXPORT_IMPORT_FAILED_VM_STARTED);
+      CrostiniResult::CONTAINER_EXPORT_IMPORT_FAILED_VM_STARTED, uint64_t{0});
   InvokeAndErasePendingCallbacks(
       &import_lxd_container_callbacks_, vm_name,
       CrostiniResult::CONTAINER_EXPORT_IMPORT_FAILED_VM_STARTED);
@@ -1857,7 +1859,7 @@ void CrostiniManager::OnStopVm(
   running_containers_.erase(vm_name);
   InvokeAndErasePendingCallbacks(
       &export_lxd_container_callbacks_, vm_name,
-      CrostiniResult::CONTAINER_EXPORT_IMPORT_FAILED_VM_STOPPED);
+      CrostiniResult::CONTAINER_EXPORT_IMPORT_FAILED_VM_STOPPED, uint64_t{0});
   InvokeAndErasePendingCallbacks(
       &import_lxd_container_callbacks_, vm_name,
       CrostiniResult::CONTAINER_EXPORT_IMPORT_FAILED_VM_STOPPED);
@@ -2443,7 +2445,8 @@ void CrostiniManager::OnExportLxdContainer(
 
   if (!response) {
     LOG(ERROR) << "Failed to export lxd container. Empty response.";
-    std::move(it->second).Run(CrostiniResult::CONTAINER_EXPORT_IMPORT_FAILED);
+    std::move(it->second)
+        .Run(CrostiniResult::CONTAINER_EXPORT_IMPORT_FAILED, 0);
     export_lxd_container_callbacks_.erase(it);
     return;
   }
@@ -2455,7 +2458,8 @@ void CrostiniManager::OnExportLxdContainer(
       vm_tools::cicerone::ExportLxdContainerResponse::EXPORTING) {
     LOG(ERROR) << "Failed to export container: status=" << response->status()
                << ", failure_reason=" << response->failure_reason();
-    std::move(it->second).Run(CrostiniResult::CONTAINER_EXPORT_IMPORT_FAILED);
+    std::move(it->second)
+        .Run(CrostiniResult::CONTAINER_EXPORT_IMPORT_FAILED, 0);
     export_lxd_container_callbacks_.erase(it);
   }
 }
@@ -2516,7 +2520,7 @@ void CrostiniManager::OnExportLxdContainerProgress(
                << signal.container_name();
     return;
   }
-  std::move(it->second).Run(result);
+  std::move(it->second).Run(result, signal.input_bytes_streamed());
   export_lxd_container_callbacks_.erase(it);
 }
 

chrome/browser/chromeos/crostini/crostini_manager.h

@@ -255,10 +255,12 @@ class CrostiniManager : public KeyedService,
   // Checks the arguments for exporting an Lxd container via
   // CiceroneClient::ExportLxdContainer. |callback| is called immediately if the
   // arguments are bad, or after the method call finishes.
-  void ExportLxdContainer(std::string vm_name,
-                          std::string container_name,
-                          base::FilePath export_path,
-                          CrostiniResultCallback callback);
+  void ExportLxdContainer(
+      std::string vm_name,
+      std::string container_name,
+      base::FilePath export_path,
+      base::OnceCallback<void(CrostiniResult result, uint64_t container_size)>
+          callback);
 
   // Checks the arguments for importing an Lxd container via
   // CiceroneClient::ImportLxdContainer. |callback| is called immediately if the
@@ -716,7 +718,10 @@ class CrostiniManager : public KeyedService,
   std::multimap<ContainerId, CrostiniResultCallback>
       create_lxd_container_callbacks_;
   std::multimap<ContainerId, BoolCallback> delete_lxd_container_callbacks_;
-  std::map<ContainerId, CrostiniResultCallback> export_lxd_container_callbacks_;
+  std::map<
+      ContainerId,
+      base::OnceCallback<void(CrostiniResult result, uint64_t container_size)>>
+      export_lxd_container_callbacks_;
   std::map<ContainerId, CrostiniResultCallback> import_lxd_container_callbacks_;
 
   // Callbacks to run after Tremplin is started, keyed by vm_name. These are

chrome/browser/chromeos/crostini/crostini_manager_unittest.cc

@@ -55,6 +55,16 @@ void ExpectCrostiniResult(base::OnceClosure closure,
   std::move(closure).Run();
 }
 
+void ExpectCrostiniExportResult(base::OnceClosure closure,
+                                CrostiniResult expected_result,
+                                uint64_t expected_container_size,
+                                CrostiniResult result,
+                                uint64_t container_size) {
+  EXPECT_EQ(expected_result, result);
+  EXPECT_EQ(expected_container_size, container_size);
+  std::move(closure).Run();
+}
+
 }  // namespace
 
 class CrostiniManagerTest : public testing::Test {
@@ -1103,8 +1113,8 @@ TEST_F(CrostiniManagerEnterpriseReportingTest,
 TEST_F(CrostiniManagerTest, ExportContainerSuccess) {
   crostini_manager()->ExportLxdContainer(
       kVmName, kContainerName, base::FilePath("export_path"),
-      base::BindOnce(&ExpectCrostiniResult, run_loop()->QuitClosure(),
-                     CrostiniResult::SUCCESS));
+      base::BindOnce(&ExpectCrostiniExportResult, run_loop()->QuitClosure(),
+                     CrostiniResult::SUCCESS, 123));
 
   // Send signals, PACK, DOWNLOAD, DONE.
   vm_tools::cicerone::ExportLxdContainerProgressSignal signal;
@@ -1122,6 +1132,7 @@ TEST_F(CrostiniManagerTest, ExportContainerSuccess) {
 
   signal.set_status(
       vm_tools::cicerone::ExportLxdContainerProgressSignal_Status_DONE);
+  signal.set_input_bytes_streamed(123);
   fake_cicerone_client_->NotifyExportLxdContainerProgress(signal);
 
   run_loop()->Run();
@@ -1131,14 +1142,14 @@ TEST_F(CrostiniManagerTest, ExportContainerFailInProgress) {
   // 1st call succeeds.
   crostini_manager()->ExportLxdContainer(
       kVmName, kContainerName, base::FilePath("export_path"),
-      base::BindOnce(&ExpectCrostiniResult, run_loop()->QuitClosure(),
-                     CrostiniResult::SUCCESS));
+      base::BindOnce(&ExpectCrostiniExportResult, run_loop()->QuitClosure(),
+                     CrostiniResult::SUCCESS, 123));
 
   // 2nd call fails since 1st call is in progress.
   crostini_manager()->ExportLxdContainer(
       kVmName, kContainerName, base::FilePath("export_path"),
-      base::BindOnce(&ExpectCrostiniResult, base::DoNothing::Once(),
-                     CrostiniResult::CONTAINER_EXPORT_IMPORT_FAILED));
+      base::BindOnce(&ExpectCrostiniExportResult, base::DoNothing::Once(),
+                     CrostiniResult::CONTAINER_EXPORT_IMPORT_FAILED, 0));
 
   // Send signal to indicate 1st call is done.
   vm_tools::cicerone::ExportLxdContainerProgressSignal signal;
@@ -1147,6 +1158,7 @@ TEST_F(CrostiniManagerTest, ExportContainerFailInProgress) {
   signal.set_container_name(kContainerName);
   signal.set_status(
       vm_tools::cicerone::ExportLxdContainerProgressSignal_Status_DONE);
+  signal.set_input_bytes_streamed(123);
   fake_cicerone_client_->NotifyExportLxdContainerProgress(signal);
 
   run_loop()->Run();
@@ -1155,8 +1167,8 @@ TEST_F(CrostiniManagerTest, ExportContainerFailInProgress) {
 TEST_F(CrostiniManagerTest, ExportContainerFailFromSignal) {
   crostini_manager()->ExportLxdContainer(
       kVmName, kContainerName, base::FilePath("export_path"),
-      base::BindOnce(&ExpectCrostiniResult, run_loop()->QuitClosure(),
-                     CrostiniResult::CONTAINER_EXPORT_IMPORT_FAILED));
+      base::BindOnce(&ExpectCrostiniExportResult, run_loop()->QuitClosure(),
+                     CrostiniResult::CONTAINER_EXPORT_IMPORT_FAILED, 123));
 
   // Send signal with FAILED.
   vm_tools::cicerone::ExportLxdContainerProgressSignal signal;
@@ -1165,6 +1177,7 @@ TEST_F(CrostiniManagerTest, ExportContainerFailFromSignal) {
   signal.set_container_name(kContainerName);
   signal.set_status(
       vm_tools::cicerone::ExportLxdContainerProgressSignal_Status_FAILED);
+  signal.set_input_bytes_streamed(123);
   fake_cicerone_client_->NotifyExportLxdContainerProgress(signal);
 
   run_loop()->Run();
@@ -1174,9 +1187,9 @@ TEST_F(CrostiniManagerTest, ExportContainerFailOnVmStop) {
   crostini_manager()->AddRunningVmForTesting(kVmName);
   crostini_manager()->ExportLxdContainer(
       kVmName, kContainerName, base::FilePath("export_path"),
-      base::BindOnce(
-          &ExpectCrostiniResult, run_loop()->QuitClosure(),
-          CrostiniResult::CONTAINER_EXPORT_IMPORT_FAILED_VM_STOPPED));
+      base::BindOnce(&ExpectCrostiniExportResult, run_loop()->QuitClosure(),
+                     CrostiniResult::CONTAINER_EXPORT_IMPORT_FAILED_VM_STOPPED,
+                     0));
   crostini_manager()->StopVm(kVmName, base::DoNothing());
   run_loop()->Run();
 }