Add collection of disk space info for log events

Adds information about total and free disk space to log events
for which it is relevant.

Bug: b/73277923
Test: unit_tests
Change-Id: I8448ae63ee15b4b4cacbb885bff111912c81ffa3
Reviewed-on: https://chromium-review.googlesource.com/951766Reviewed-by: Pavol Marko <pmarko@chromium.org>
Commit-Queue: Bartosz Fabianowski <bartfab@chromium.org>
Cr-Commit-Position: refs/heads/master@{#541810}

chrome/browser/chromeos/policy/app_install_event_log.cc

@@ -20,7 +20,7 @@ namespace em = enterprise_management;
 namespace policy {
 
 namespace {
-static const int64_t kLogFileVersion = 2;
+static const int64_t kLogFileVersion = 3;
 static const ssize_t kMaxLogs = 1024;
 }  // namespace
 

chrome/browser/chromeos/policy/app_install_event_log_collector.h

@@ -37,9 +37,12 @@ class AppInstallEventLogCollector
             event) = 0;
 
     // Adds a log entry for |package|. The |event|'s timestamp is set to the
-    // current time if not set yet.
+    // current time if not set yet. If |gather_disk_space_info| is |true|,
+    // information about total and free disk space is gathered in the background
+    // and added to |event| before adding it to the log.
     virtual void Add(
         const std::string& package,
+        bool gather_disk_space_info,
         std::unique_ptr<enterprise_management::AppInstallReportLogEvent>
             event) = 0;
 

chrome/browser/chromeos/policy/app_install_event_log_collector_unittest.cc

@@ -50,6 +50,7 @@ class FakeAppInstallEventLogCollectorDelegate
   }
 
   void Add(const std::string& package,
+           bool add_disk_space_info,
            std::unique_ptr<em::AppInstallReportLogEvent> event) override {
     ++add_count_;
     last_event_ = *event;

chrome/browser/chromeos/policy/app_install_event_logger.cc

@@ -4,16 +4,25 @@
 
 #include "chrome/browser/chromeos/policy/app_install_event_logger.h"
 
+#include <stdint.h>
+
 #include <algorithm>
 #include <iterator>
 
+#include "base/bind.h"
+#include "base/files/file_path.h"
 #include "base/json/json_reader.h"
+#include "base/location.h"
+#include "base/sys_info.h"
+#include "base/task_scheduler/post_task.h"
+#include "base/task_scheduler/task_traits.h"
 #include "base/time/time.h"
 #include "base/values.h"
 #include "chrome/browser/chromeos/arc/arc_util.h"
 #include "chrome/browser/policy/profile_policy_connector.h"
 #include "chrome/browser/policy/profile_policy_connector_factory.h"
 #include "chrome/browser/profiles/profile.h"
+#include "chromeos/disks/disk_mount_manager.h"
 #include "components/arc/arc_prefs.h"
 #include "components/policy/core/common/policy_map.h"
 #include "components/policy/core/common/policy_namespace.h"
@@ -87,6 +96,29 @@ std::set<std::string> GetDifference(const std::set<std::string>& first,
   return difference;
 }
 
+std::unique_ptr<em::AppInstallReportLogEvent> AddDiskSpaceInfoToEvent(
+    std::unique_ptr<em::AppInstallReportLogEvent> event) {
+  for (const auto& disk :
+       chromeos::disks::DiskMountManager::GetInstance()->disks()) {
+    if (!disk.second->IsStatefulPartition()) {
+      continue;
+    }
+    const base::FilePath stateful_path(disk.second->mount_path());
+    const int64_t stateful_total =
+        base::SysInfo::AmountOfTotalDiskSpace(stateful_path);
+    if (stateful_total >= 0) {
+      event->set_stateful_total(stateful_total);
+    }
+    const int64_t stateful_free =
+        base::SysInfo::AmountOfFreeDiskSpace(stateful_path);
+    if (stateful_free >= 0) {
+      event->set_stateful_free(stateful_free);
+    }
+    break;
+  }
+  return event;
+}
+
 void EnsureTimestampSet(em::AppInstallReportLogEvent* event) {
   if (!event->has_timestamp()) {
     event->set_timestamp(
@@ -94,11 +126,12 @@ void EnsureTimestampSet(em::AppInstallReportLogEvent* event) {
   }
 }
 
-em::AppInstallReportLogEvent CreateEvent(
+std::unique_ptr<em::AppInstallReportLogEvent> CreateEvent(
     em::AppInstallReportLogEvent::EventType type) {
-  em::AppInstallReportLogEvent event;
-  EnsureTimestampSet(&event);
-  event.set_event_type(type);
+  std::unique_ptr<em::AppInstallReportLogEvent> event =
+      std::make_unique<em::AppInstallReportLogEvent>();
+  EnsureTimestampSet(event.get());
+  event->set_event_type(type);
   return event;
 }
 
@@ -106,10 +139,11 @@ em::AppInstallReportLogEvent CreateEvent(
 
 AppInstallEventLogger::AppInstallEventLogger(Delegate* delegate,
                                              Profile* profile)
-    : delegate_(delegate), profile_(profile) {
+    : delegate_(delegate), profile_(profile), weak_factory_(this) {
   if (!arc::IsArcAllowedForProfile(profile_)) {
-    delegate_->Add(GetPackagesFromPref(arc::prefs::kArcPushInstallAppsPending),
-                   CreateEvent(em::AppInstallReportLogEvent::CANCELED));
+    AddForSetOfPackages(
+        GetPackagesFromPref(arc::prefs::kArcPushInstallAppsPending),
+        CreateEvent(em::AppInstallReportLogEvent::CANCELED));
     Clear(profile_);
     return;
   }
@@ -156,15 +190,21 @@ void AppInstallEventLogger::Clear(Profile* profile) {
 void AppInstallEventLogger::AddForAllPackages(
     std::unique_ptr<em::AppInstallReportLogEvent> event) {
   EnsureTimestampSet(event.get());
-  delegate_->Add(GetPackagesFromPref(arc::prefs::kArcPushInstallAppsPending),
-                 *event);
+  AddForSetOfPackages(
+      GetPackagesFromPref(arc::prefs::kArcPushInstallAppsPending),
+      std::move(event));
 }
 
 void AppInstallEventLogger::Add(
     const std::string& package,
+    bool gather_disk_space_info,
     std::unique_ptr<em::AppInstallReportLogEvent> event) {
   EnsureTimestampSet(event.get());
-  delegate_->Add({package}, *event);
+  if (gather_disk_space_info) {
+    AddForSetOfPackagesWithDiskSpaceInfo({package}, std::move(event));
+  } else {
+    AddForSetOfPackages({package}, std::move(event));
+  }
 }
 
 void AppInstallEventLogger::OnPolicyUpdated(const policy::PolicyNamespace& ns,
@@ -206,8 +246,8 @@ void AppInstallEventLogger::OnComplianceReportReceived(
       previous_pending, GetDifference(requested_in_arc_, pending_in_arc));
   const std::set<std::string> removed =
       GetDifference(previous_pending, current_pending);
-  // TODO(bartfab): Add SystemState.
-  delegate_->Add(removed, CreateEvent(em::AppInstallReportLogEvent::SUCCESS));
+  AddForSetOfPackagesWithDiskSpaceInfo(
+      removed, CreateEvent(em::AppInstallReportLogEvent::SUCCESS));
 
   if (removed.empty()) {
     return;
@@ -274,10 +314,10 @@ void AppInstallEventLogger::EvaluatePolicy(const policy::PolicyMap& policy,
       GetDifference(current_requested, previous_requested);
   const std::set<std::string> removed =
       GetDifference(previous_pending, current_requested);
-  // TODO: Add SystemState.
-  delegate_->Add(added,
-                 CreateEvent(em::AppInstallReportLogEvent::SERVER_REQUEST));
-  delegate_->Add(removed, CreateEvent(em::AppInstallReportLogEvent::CANCELED));
+  AddForSetOfPackagesWithDiskSpaceInfo(
+      added, CreateEvent(em::AppInstallReportLogEvent::SERVER_REQUEST));
+  AddForSetOfPackages(removed,
+                      CreateEvent(em::AppInstallReportLogEvent::CANCELED));
 
   const std::set<std::string> current_pending = GetDifference(
       current_requested, GetDifference(previous_requested, previous_pending));
@@ -296,4 +336,20 @@ void AppInstallEventLogger::EvaluatePolicy(const policy::PolicyMap& policy,
   }
 }
 
+void AppInstallEventLogger::AddForSetOfPackagesWithDiskSpaceInfo(
+    const std::set<std::string>& packages,
+    std::unique_ptr<em::AppInstallReportLogEvent> event) {
+  base::PostTaskWithTraitsAndReplyWithResult(
+      FROM_HERE, {base::MayBlock()},
+      base::BindOnce(&AddDiskSpaceInfoToEvent, std::move(event)),
+      base::BindOnce(&AppInstallEventLogger::AddForSetOfPackages,
+                     weak_factory_.GetWeakPtr(), packages));
+}
+
+void AppInstallEventLogger::AddForSetOfPackages(
+    const std::set<std::string>& packages,
+    std::unique_ptr<em::AppInstallReportLogEvent> event) {
+  delegate_->Add(packages, *event);
+}
+
 }  // namespace policy

chrome/browser/chromeos/policy/app_install_event_logger.h

@@ -10,6 +10,7 @@
 #include <string>
 
 #include "base/macros.h"
+#include "base/memory/weak_ptr.h"
 #include "chrome/browser/chromeos/arc/policy/arc_policy_bridge.h"
 #include "chrome/browser/chromeos/policy/app_install_event_log_collector.h"
 #include "components/policy/core/common/policy_service.h"
@@ -78,6 +79,7 @@ class AppInstallEventLogger : public AppInstallEventLogCollector::Delegate,
       std::unique_ptr<enterprise_management::AppInstallReportLogEvent> event)
       override;
   void Add(const std::string& package,
+           bool gather_disk_space_info,
            std::unique_ptr<enterprise_management::AppInstallReportLogEvent>
                event) override;
 
@@ -113,6 +115,17 @@ class AppInstallEventLogger : public AppInstallEventLogCollector::Delegate,
   // and updates the |log_collector_|.
   void EvaluatePolicy(const policy::PolicyMap& policy, bool initial);
 
+  // Adds information about total and free disk space to |event|, then adds
+  // |event| to the log for every app in |packages|.
+  void AddForSetOfPackagesWithDiskSpaceInfo(
+      const std::set<std::string>& packages,
+      std::unique_ptr<enterprise_management::AppInstallReportLogEvent> event);
+
+  // Adds |event| to the log for every app in |packages|.
+  void AddForSetOfPackages(
+      const std::set<std::string>& packages,
+      std::unique_ptr<enterprise_management::AppInstallReportLogEvent> event);
+
   // The delegate that events are forwarded to for inclusion in the log.
   Delegate* const delegate_;
 
@@ -131,6 +144,9 @@ class AppInstallEventLogger : public AppInstallEventLogCollector::Delegate,
   // app push-install requests.
   std::unique_ptr<AppInstallEventLogCollector> log_collector_;
 
+  // Weak factory used to reference |this| from background tasks.
+  base::WeakPtrFactory<AppInstallEventLogger> weak_factory_;
+
   DISALLOW_COPY_AND_ASSIGN(AppInstallEventLogger);
 };
 

chrome/browser/chromeos/policy/app_install_event_logger_unittest.cc

@@ -4,34 +4,261 @@
 
 #include "chrome/browser/chromeos/policy/app_install_event_logger.h"
 
+#include <stdint.h>
+
+#include "base/test/scoped_task_environment.h"
+#include "base/time/time.h"
 #include "base/values.h"
 #include "chrome/test/base/testing_profile.h"
+#include "chromeos/dbus/cros_disks_client.h"
+#include "chromeos/disks/disk_mount_manager.h"
+#include "chromeos/disks/mock_disk_mount_manager.h"
 #include "components/arc/arc_prefs.h"
+#include "components/policy/proto/device_management_backend.pb.h"
 #include "components/prefs/pref_service.h"
 #include "content/public/test/test_browser_thread_bundle.h"
+#include "testing/gmock/include/gmock/gmock.h"
 #include "testing/gtest/include/gtest/gtest.h"
 
-using AppInstallEventLoggerTest = testing::Test;
+using testing::Mock;
+using testing::_;
+
+namespace em = enterprise_management;
 
 namespace policy {
 
+namespace {
+
+constexpr char kStatefulMountPath[] = "/mnt/stateful_partition";
+constexpr char kPackageName[] = "com.example.app";
+const int kTimestamp = 123456;
+
+MATCHER_P(MatchProto, expected, "matches protobuf") {
+  return arg.SerializePartialAsString() == expected.SerializePartialAsString();
+}
+
+MATCHER_P(MatchEventExceptTimestamp, expected, "event matches") {
+  em::AppInstallReportLogEvent actual_event;
+  actual_event.MergeFrom(arg);
+  actual_event.clear_timestamp();
+
+  em::AppInstallReportLogEvent expected_event;
+  expected_event.MergeFrom(expected);
+  expected_event.clear_timestamp();
+
+  return actual_event.SerializePartialAsString() ==
+         expected_event.SerializePartialAsString();
+}
+
+ACTION_TEMPLATE(SaveTimestamp,
+                HAS_1_TEMPLATE_PARAMS(int, k),
+                AND_1_VALUE_PARAMS(out)) {
+  *out = testing::get<k>(args).timestamp();
+};
+
+int64_t GetCurrentTimestamp() {
+  return (base::Time::Now() - base::Time::UnixEpoch()).InMicroseconds();
+}
+
+class MockAppInstallEventLoggerDelegate
+    : public AppInstallEventLogger::Delegate {
+ public:
+  MockAppInstallEventLoggerDelegate() = default;
+
+  MOCK_METHOD2(Add,
+               void(const std::set<std::string>& packages,
+                    const em::AppInstallReportLogEvent& event));
+
+ private:
+  DISALLOW_COPY_AND_ASSIGN(MockAppInstallEventLoggerDelegate);
+};
+
+}  // namespace
+
+class AppInstallEventLoggerTest : public testing::Test {
+ protected:
+  AppInstallEventLoggerTest()
+      : scoped_task_environment_(
+            base::test::ScopedTaskEnvironment::MainThreadType::UI,
+            base::test::ScopedTaskEnvironment::ExecutionMode::QUEUED) {}
+
+  void SetUp() override {
+    disk_mount_manager_ = new chromeos::disks::MockDiskMountManager;
+    chromeos::disks::DiskMountManager::InitializeForTesting(
+        disk_mount_manager_);
+    disk_mount_manager_->CreateDiskEntryForMountDevice(
+        chromeos::disks::DiskMountManager::MountPointInfo(
+            "/dummy/device/usb", kStatefulMountPath,
+            chromeos::MOUNT_TYPE_DEVICE, chromeos::disks::MOUNT_CONDITION_NONE),
+        "device_id", "device_label", "vendor", "product",
+        chromeos::DEVICE_TYPE_UNKNOWN, 1 << 20 /* total_size_in_bytes */,
+        false /* is_parent */, false /* has_media */, true /* on_boot_device */,
+        true /* on_removable_device */, "ext4");
+  }
+
+  void TearDown() override {
+    logger_.reset();
+    scoped_task_environment_.RunUntilIdle();
+    chromeos::disks::DiskMountManager::Shutdown();
+  }
+
+  // Runs |function|, verifies that the expected event is added to the logs for
+  // all apps in |packages| and its timestamp is set to the time at which the
+  // |function| is run.
+  template <typename T>
+  void RunAndVerifyAdd(T function, const std::set<std::string>& packages) {
+    Mock::VerifyAndClearExpectations(&delegate_);
+
+    int64_t timestamp = 0;
+    EXPECT_CALL(delegate_, Add(packages, MatchEventExceptTimestamp(event_)))
+        .WillOnce(SaveTimestamp<1>(&timestamp));
+    const int64_t before = GetCurrentTimestamp();
+    function();
+    const int64_t after = GetCurrentTimestamp();
+    Mock::VerifyAndClearExpectations(&delegate_);
+
+    EXPECT_LE(before, timestamp);
+    EXPECT_GE(after, timestamp);
+  }
+
+  void CreateLogger() {
+    event_.set_event_type(em::AppInstallReportLogEvent::CANCELED);
+    RunAndVerifyAdd(
+        [&]() {
+          logger_ =
+              std::make_unique<AppInstallEventLogger>(&delegate_, &profile_);
+        },
+        {});
+    event_.set_event_type(em::AppInstallReportLogEvent::SUCCESS);
+  }
+
+  base::test::ScopedTaskEnvironment scoped_task_environment_;
+  content::TestBrowserThreadBundle browser_thread_bundle_;
+  TestingProfile profile_;
+  // Owned by chromeos::disks::DiskMountManager.
+  chromeos::disks::MockDiskMountManager* disk_mount_manager_ = nullptr;
+
+  MockAppInstallEventLoggerDelegate delegate_;
+
+  em::AppInstallReportLogEvent event_;
+
+  std::unique_ptr<AppInstallEventLogger> logger_;
+
+ private:
+  DISALLOW_COPY_AND_ASSIGN(AppInstallEventLoggerTest);
+};
+
 // Store lists of apps for which push-install has been requested and is still
 // pending. Clear all data related to app-install event log collection. Verify
 // that the lists are cleared.
 TEST_F(AppInstallEventLoggerTest, Clear) {
-  content::TestBrowserThreadBundle browser_thread_bundle;
-  TestingProfile profile;
   base::ListValue list;
   list.AppendString("test");
-  profile.GetPrefs()->Set(arc::prefs::kArcPushInstallAppsRequested, list);
-  profile.GetPrefs()->Set(arc::prefs::kArcPushInstallAppsPending, list);
-  AppInstallEventLogger::Clear(&profile);
-  EXPECT_TRUE(profile.GetPrefs()
+  profile_.GetPrefs()->Set(arc::prefs::kArcPushInstallAppsRequested, list);
+  profile_.GetPrefs()->Set(arc::prefs::kArcPushInstallAppsPending, list);
+  AppInstallEventLogger::Clear(&profile_);
+  EXPECT_TRUE(profile_.GetPrefs()
                   ->FindPreference(arc::prefs::kArcPushInstallAppsRequested)
                   ->IsDefaultValue());
-  EXPECT_TRUE(profile.GetPrefs()
+  EXPECT_TRUE(profile_.GetPrefs()
                   ->FindPreference(arc::prefs::kArcPushInstallAppsPending)
                   ->IsDefaultValue());
 }
 
+// Adds an event with a timestamp. Verifies that the event is added to the log
+// and the timestamp is not changed.
+TEST_F(AppInstallEventLoggerTest, Add) {
+  CreateLogger();
+
+  event_.set_timestamp(kTimestamp);
+  std::unique_ptr<em::AppInstallReportLogEvent> event =
+      std::make_unique<em::AppInstallReportLogEvent>();
+  event->MergeFrom(event_);
+
+  EXPECT_CALL(delegate_,
+              Add(std::set<std::string>{kPackageName}, MatchProto(event_)));
+  logger_->Add(kPackageName, false /* gather_disk_space_info */,
+               std::move(event));
+}
+
+// Adds an event without a timestamp. Verifies that the event is added to the
+// log and the timestamp is set to the current time.
+TEST_F(AppInstallEventLoggerTest, AddSetsTimestamp) {
+  CreateLogger();
+
+  std::unique_ptr<em::AppInstallReportLogEvent> event =
+      std::make_unique<em::AppInstallReportLogEvent>();
+  event->MergeFrom(event_);
+
+  RunAndVerifyAdd(
+      [&]() {
+        logger_->Add(kPackageName, false /* gather_disk_space_info */,
+                     std::move(event));
+      },
+      {kPackageName});
+}
+
+// Adds an event with a timestamp, requesting that disk space information be
+// added to it. Verifies that a background task is posted that consults the disk
+// mount manager. Then, verifies that after the background task has run, the
+// event is added.
+//
+// It is not possible to test that disk size information is retrieved correctly
+// as a mounted stateful partition cannot be simulated in unit tests.
+TEST_F(AppInstallEventLoggerTest, AddSetsDiskSpaceInfo) {
+  CreateLogger();
+
+  event_.set_timestamp(kTimestamp);
+  std::unique_ptr<em::AppInstallReportLogEvent> event =
+      std::make_unique<em::AppInstallReportLogEvent>();
+  event->MergeFrom(event_);
+
+  EXPECT_CALL(*disk_mount_manager_, disks()).Times(0);
+  EXPECT_CALL(delegate_, Add(_, _)).Times(0);
+  logger_->Add(kPackageName, true /* gather_disk_space_info */,
+               std::move(event));
+  Mock::VerifyAndClearExpectations(disk_mount_manager_);
+  Mock::VerifyAndClearExpectations(&delegate_);
+
+  EXPECT_CALL(*disk_mount_manager_, disks());
+  EXPECT_CALL(delegate_,
+              Add(std::set<std::string>{kPackageName}, MatchProto(event_)));
+  scoped_task_environment_.RunUntilIdle();
+}
+
+// Adds an event without a timestamp, requesting that disk space information be
+// added to it. Verifies that a background task is posted that consults the disk
+// mount manager. Then, verifies that after the background task has run, the
+// event is added and its timestamp is set to the current time before posting
+// the background task.
+//
+// It is not possible to test that disk size information is retrieved correctly
+// as a mounted stateful partition cannot be simulated in unit tests.
+TEST_F(AppInstallEventLoggerTest, AddSetsTimestampAndDiskSpaceInfo) {
+  CreateLogger();
+
+  std::unique_ptr<em::AppInstallReportLogEvent> event =
+      std::make_unique<em::AppInstallReportLogEvent>();
+  event->MergeFrom(event_);
+
+  EXPECT_CALL(*disk_mount_manager_, disks()).Times(0);
+  EXPECT_CALL(delegate_, Add(_, _)).Times(0);
+  const int64_t before = GetCurrentTimestamp();
+  logger_->Add(kPackageName, true /* gather_disk_space_info */,
+               std::move(event));
+  const int64_t after = GetCurrentTimestamp();
+  Mock::VerifyAndClearExpectations(disk_mount_manager_);
+  Mock::VerifyAndClearExpectations(&delegate_);
+
+  int64_t timestamp = 0;
+  EXPECT_CALL(*disk_mount_manager_, disks());
+  EXPECT_CALL(delegate_, Add(std::set<std::string>{kPackageName},
+                             MatchEventExceptTimestamp(event_)))
+      .WillOnce(SaveTimestamp<1>(&timestamp));
+  scoped_task_environment_.RunUntilIdle();
+
+  EXPECT_LE(before, timestamp);
+  EXPECT_GE(after, timestamp);
+}
+
 }  // namespace policy

components/policy/proto/device_management_backend.proto

@@ -1531,22 +1531,23 @@ message AppInstallReportLogEvent {
   // Event type. Set for all log events.
   optional EventType event_type = 2;
 
-  // System state. Set for event types SERVER_REQUEST,
-  // CLOUDDPS_RESPONSE and SUCCESS.
-  optional SystemState system_state = 3;
+  // Total and available space on the stateful partition, in bytes. Set for
+  // event types SERVER_REQUEST, CLOUDDPS_RESPONSE and SUCCESS.
+  optional int64 stateful_total = 3;
+  optional int64 stateful_free = 4;
 
   // CloudDPS response. Set for event type CLOUDDPS_RESPONSE.
-  optional int32 clouddps_response = 4;
+  optional int32 clouddps_response = 5;
 
   // Log line written by Phonesky. Set for event type PHONESKY_LOG.
-  optional string phonesky_log = 5;
+  optional string phonesky_log = 6;
 
   // Network state. Set for event type SESSION_STATE_CHANGE of type LOGIN and
   // CONNECTIVITY_CHANGE.
-  optional bool online = 6;
+  optional bool online = 7;
 
   // Type of session state change. Set for event type SESSION_STATE_CHANGE.
-  optional SessionStateChangeType session_state_change_type = 7;
+  optional SessionStateChangeType session_state_change_type = 8;
 }
 
 // Log bucket for an app.