arc: Add DPS events to app install log.

This adds events CLOUDDPS_REQUEST/CLOUDDPS_RESPONSE to app install log.

Bug: b/73277923
Test: manual
Change-Id: I7ec87a7bbfa1bc358feb8a44481c34599012b32e
Reviewed-on: https://chromium-review.googlesource.com/952538Reviewed-by: Luis Hector Chavez <lhchavez@chromium.org>
Reviewed-by: Greg Kerr <kerrnel@chromium.org>
Reviewed-by: Bartosz Fabianowski <bartfab@chromium.org>
Commit-Queue: Yury Khmel <khmel@google.com>
Cr-Commit-Position: refs/heads/master@{#542937}

chrome/browser/chromeos/arc/policy/arc_policy_bridge.cc

@@ -5,7 +5,6 @@
 #include "chrome/browser/chromeos/arc/policy/arc_policy_bridge.h"
 
 #include <utility>
-#include <vector>
 
 #include "base/bind.h"
 #include "base/callback_helpers.h"
@@ -403,6 +402,31 @@ void ArcPolicyBridge::ReportCompliance(const std::string& request,
       base::Bind(&OnReportComplianceParseFailure, repeating_callback));
 }
 
+void ArcPolicyBridge::ReportCloudDpsRequested(
+    base::Time time,
+    const std::vector<std::string>& package_names) {
+  const std::set<std::string> packages_set(package_names.begin(),
+                                           package_names.end());
+  for (Observer& observer : observers_)
+    observer.OnCloudDpsRequested(time, packages_set);
+}
+
+void ArcPolicyBridge::ReportCloudDpsSucceeded(
+    base::Time time,
+    const std::vector<std::string>& package_names) {
+  const std::set<std::string> packages_set(package_names.begin(),
+                                           package_names.end());
+  for (Observer& observer : observers_)
+    observer.OnCloudDpsSucceeded(time, packages_set);
+}
+
+void ArcPolicyBridge::ReportCloudDpsFailed(base::Time time,
+                                           const std::string& package_name,
+                                           mojom::InstallErrorReason reason) {
+  for (Observer& observer : observers_)
+    observer.OnCloudDpsFailed(time, package_name, reason);
+}
+
 void ArcPolicyBridge::OnPolicyUpdated(const policy::PolicyNamespace& ns,
                                       const policy::PolicyMap& previous,
                                       const policy::PolicyMap& current) {

chrome/browser/chromeos/arc/policy/arc_policy_bridge.h

@@ -5,8 +5,12 @@
 #ifndef CHROME_BROWSER_CHROMEOS_ARC_POLICY_ARC_POLICY_BRIDGE_H_
 #define CHROME_BROWSER_CHROMEOS_ARC_POLICY_ARC_POLICY_BRIDGE_H_
 
+#include <stdint.h>
+
 #include <memory>
+#include <set>
 #include <string>
+#include <vector>
 
 #include "base/macros.h"
 #include "base/memory/weak_ptr.h"
@@ -51,11 +55,29 @@ class ArcPolicyBridge : public KeyedService,
   class Observer {
    public:
     // Called when policy is sent to CloudDPC.
-    virtual void OnPolicySent(const std::string& policy) = 0;
+    virtual void OnPolicySent(const std::string& policy) {}
 
     // Called when a compliance report is received from CloudDPC.
     virtual void OnComplianceReportReceived(
-        const base::Value* compliance_report) = 0;
+        const base::Value* compliance_report) {}
+
+    // Called when a request to install set of packages was sent to CloudDPS.
+    virtual void OnCloudDpsRequested(
+        base::Time time,
+        const std::set<std::string>& package_names) {}
+
+    // Called when CloudDPS successfully processed request for install for a
+    // set of packages. Note |package_names| may not match to what was
+    // requested.
+    virtual void OnCloudDpsSucceeded(
+        base::Time time,
+        const std::set<std::string>& package_names) {}
+
+    // Called when CloudDPS returned an error for the package installation
+    // request. |reason| defines the failure reason.
+    virtual void OnCloudDpsFailed(base::Time time,
+                                  const std::string& package_name,
+                                  mojom::InstallErrorReason reason) {}
 
    protected:
     Observer() = default;
@@ -91,6 +113,15 @@ class ArcPolicyBridge : public KeyedService,
   void GetPolicies(GetPoliciesCallback callback) override;
   void ReportCompliance(const std::string& request,
                         ReportComplianceCallback callback) override;
+  void ReportCloudDpsRequested(
+      base::Time time,
+      const std::vector<std::string>& package_names) override;
+  void ReportCloudDpsSucceeded(
+      base::Time time,
+      const std::vector<std::string>& package_names) override;
+  void ReportCloudDpsFailed(base::Time time,
+                            const std::string& package_name,
+                            mojom::InstallErrorReason reason) override;
 
   // PolicyService::Observer overrides.
   void OnPolicyUpdated(const policy::PolicyNamespace& ns,

chrome/browser/chromeos/policy/app_install_event_log_collector.cc

@@ -3,7 +3,9 @@
 // found in the LICENSE file.
 
 #include "chrome/browser/chromeos/policy/app_install_event_log_collector.h"
+
 #include "base/command_line.h"
+#include "base/time/time.h"
 #include "chrome/browser/browser_process.h"
 #include "chrome/common/pref_names.h"
 #include "chromeos/chromeos_switches.h"
@@ -46,6 +48,11 @@ bool GetOnlineState() {
   return false;
 }
 
+void SetTimestampFromTime(em::AppInstallReportLogEvent* event,
+                          base::Time time) {
+  event->set_timestamp((time - base::Time::UnixEpoch()).InMicroseconds());
+}
+
 }  // namespace
 
 AppInstallEventLogCollector::AppInstallEventLogCollector(
@@ -56,12 +63,23 @@ AppInstallEventLogCollector::AppInstallEventLogCollector(
   chromeos::DBusThreadManager::Get()->GetPowerManagerClient()->AddObserver(
       this);
   net::NetworkChangeNotifier::AddNetworkChangeObserver(this);
+  // Might not be available in unit test.
+  arc::ArcPolicyBridge* const policy_bridge =
+      arc::ArcPolicyBridge::GetForBrowserContext(profile_);
+  if (policy_bridge) {
+    policy_bridge->AddObserver(this);
+  }
 }
 
 AppInstallEventLogCollector::~AppInstallEventLogCollector() {
   chromeos::DBusThreadManager::Get()->GetPowerManagerClient()->RemoveObserver(
       this);
   net::NetworkChangeNotifier::RemoveNetworkChangeObserver(this);
+  arc::ArcPolicyBridge* const policy_bridge =
+      arc::ArcPolicyBridge::GetForBrowserContext(profile_);
+  if (policy_bridge) {
+    policy_bridge->RemoveObserver(this);
+  }
 }
 
 void AppInstallEventLogCollector::OnPendingPackagesChanged(
@@ -118,4 +136,41 @@ void AppInstallEventLogCollector::OnNetworkChanged(
   delegate_->AddForAllPackages(std::move(event));
 }
 
+void AppInstallEventLogCollector::OnCloudDpsRequested(
+    base::Time time,
+    const std::set<std::string>& package_names) {
+  for (const std::string& package_name : package_names) {
+    auto event = std::make_unique<em::AppInstallReportLogEvent>();
+    event->set_event_type(em::AppInstallReportLogEvent::CLOUDDPS_REQUEST);
+    SetTimestampFromTime(event.get(), time);
+    delegate_->Add(package_name, true /* gather_disk_space_info */,
+                   std::move(event));
+  }
+}
+
+void AppInstallEventLogCollector::OnCloudDpsSucceeded(
+    base::Time time,
+    const std::set<std::string>& package_names) {
+  for (const std::string& package_name : package_names) {
+    auto event = std::make_unique<em::AppInstallReportLogEvent>();
+    event->set_event_type(em::AppInstallReportLogEvent::CLOUDDPS_RESPONSE);
+    SetTimestampFromTime(event.get(), time);
+    // Leave clouddps_response untouched.
+    delegate_->Add(package_name, true /* gather_disk_space_info */,
+                   std::move(event));
+  }
+}
+
+void AppInstallEventLogCollector::OnCloudDpsFailed(
+    base::Time time,
+    const std::string& package_name,
+    arc::mojom::InstallErrorReason reason) {
+  auto event = std::make_unique<em::AppInstallReportLogEvent>();
+  event->set_event_type(em::AppInstallReportLogEvent::CLOUDDPS_RESPONSE);
+  SetTimestampFromTime(event.get(), time);
+  event->set_clouddps_response(static_cast<int>(reason));
+  delegate_->Add(package_name, true /* gather_disk_space_info */,
+                 std::move(event));
+}
+
 }  // namespace policy

chrome/browser/chromeos/policy/app_install_event_log_collector.h

@@ -5,14 +5,18 @@
 #ifndef CHROME_BROWSER_CHROMEOS_POLICY_APP_INSTALL_EVENT_LOG_COLLECTOR_H_
 #define CHROME_BROWSER_CHROMEOS_POLICY_APP_INSTALL_EVENT_LOG_COLLECTOR_H_
 
+#include <stdint.h>
+
 #include <memory>
 #include <set>
 #include <string>
 
 #include "base/logging.h"
 #include "base/macros.h"
+#include "chrome/browser/chromeos/arc/policy/arc_policy_bridge.h"
 #include "chrome/browser/profiles/profile.h"
 #include "chromeos/dbus/power_manager_client.h"
+#include "components/arc/common/policy.mojom.h"
 #include "net/base/network_change_notifier.h"
 
 class Profile;
@@ -25,6 +29,7 @@ namespace policy {
 // Listens for and logs events related to app push-installs.
 class AppInstallEventLogCollector
     : public chromeos::PowerManagerClient::Observer,
+      public arc::ArcPolicyBridge::Observer,
       public net::NetworkChangeNotifier::NetworkChangeObserver {
  public:
   // The delegate that events are forwarded to for inclusion in the log.
@@ -74,6 +79,15 @@ class AppInstallEventLogCollector
   void OnNetworkChanged(
       net::NetworkChangeNotifier::ConnectionType type) override;
 
+  // arc::ArcPolicyBridge::Observer:
+  void OnCloudDpsRequested(base::Time time,
+                           const std::set<std::string>& package_names) override;
+  void OnCloudDpsSucceeded(base::Time time,
+                           const std::set<std::string>& package_names) override;
+  void OnCloudDpsFailed(base::Time time,
+                        const std::string& package_name,
+                        arc::mojom::InstallErrorReason reason) override;
+
  private:
   Delegate* const delegate_;
   Profile* const profile_;

chrome/browser/chromeos/policy/app_install_event_log_collector_unittest.cc

@@ -4,10 +4,13 @@
 
 #include "chrome/browser/chromeos/policy/app_install_event_log_collector.h"
 
+#include <vector>
+
 #include "base/command_line.h"
 #include "base/macros.h"
 #include "base/memory/ptr_util.h"
 #include "base/run_loop.h"
+#include "base/time/time.h"
 #include "chrome/browser/browser_process.h"
 #include "chrome/browser/prefs/browser_prefs.h"
 #include "chrome/common/pref_names.h"
@@ -35,6 +38,7 @@ constexpr char kEthernetServicePath[] = "/service/eth1";
 constexpr char kWifiServicePath[] = "/service/wifi1";
 
 constexpr char kPackageName[] = "com.example.app";
+constexpr char kPackageName2[] = "com.example.app2";
 
 class FakeAppInstallEventLogCollectorDelegate
     : public AppInstallEventLogCollector::Delegate {
@@ -42,34 +46,59 @@ class FakeAppInstallEventLogCollectorDelegate
   FakeAppInstallEventLogCollectorDelegate() = default;
   ~FakeAppInstallEventLogCollectorDelegate() override = default;
 
+  struct Request {
+    Request(bool for_all,
+            bool add_disk_space_info,
+            const std::string& package_name,
+            const em::AppInstallReportLogEvent& event)
+        : for_all(for_all),
+          add_disk_space_info(add_disk_space_info),
+          package_name(package_name),
+          event(event) {}
+    const bool for_all;
+    const bool add_disk_space_info;
+    const std::string package_name;
+    const em::AppInstallReportLogEvent event;
+  };
+
   // AppInstallEventLogCollector::Delegate:
   void AddForAllPackages(
       std::unique_ptr<em::AppInstallReportLogEvent> event) override {
     ++add_for_all_count_;
-    last_event_ = *event;
+    requests_.emplace_back(true /* for_all */, false /* add_disk_space_info */,
+                           std::string() /* package_name */, *event);
   }
 
-  void Add(const std::string& package,
+  void Add(const std::string& package_name,
            bool add_disk_space_info,
            std::unique_ptr<em::AppInstallReportLogEvent> event) override {
     ++add_count_;
-    last_event_ = *event;
+    requests_.emplace_back(false /* for_all */, add_disk_space_info,
+                           package_name, *event);
   }
 
   int add_for_all_count() const { return add_for_all_count_; }
 
   int add_count() const { return add_count_; }
 
-  const em::AppInstallReportLogEvent& last_event() const { return last_event_; }
+  const em::AppInstallReportLogEvent& last_event() const {
+    return last_request().event;
+  }
+  const Request& last_request() const { return requests_.back(); }
+  const std::vector<Request>& requests() const { return requests_; }
 
  private:
   int add_for_all_count_ = 0;
   int add_count_ = 0;
-  em::AppInstallReportLogEvent last_event_;
+  std::vector<Request> requests_;
 
   DISALLOW_COPY_AND_ASSIGN(FakeAppInstallEventLogCollectorDelegate);
 };
 
+int64_t TimeToTimestamp(base::Time time) {
+  return (time - base::Time::UnixEpoch()).InMicroseconds();
+}
+
 }  // namespace
 
 class AppInstallEventLogCollectorTest : public testing::Test {
@@ -307,4 +336,53 @@ TEST_F(AppInstallEventLogCollectorTest, ConnectivityChanges) {
   EXPECT_EQ(0, delegate()->add_count());
 }
 
+// Validates sequence of CloudDPS events.
+TEST_F(AppInstallEventLogCollectorTest, CloudDPSEvent) {
+  std::unique_ptr<AppInstallEventLogCollector> collector =
+      std::make_unique<AppInstallEventLogCollector>(delegate(), profile(),
+                                                    packages_);
+
+  base::Time time = base::Time::Now();
+  collector->OnCloudDpsRequested(time, {kPackageName, kPackageName2});
+  ASSERT_EQ(2, delegate()->add_count());
+  ASSERT_EQ(0, delegate()->add_for_all_count());
+  EXPECT_EQ(TimeToTimestamp(time), delegate()->requests()[0].event.timestamp());
+  EXPECT_EQ(kPackageName, delegate()->requests()[0].package_name);
+  EXPECT_EQ(em::AppInstallReportLogEvent::CLOUDDPS_REQUEST,
+            delegate()->requests()[0].event.event_type());
+  EXPECT_FALSE(delegate()->requests()[0].event.has_clouddps_response());
+  EXPECT_EQ(TimeToTimestamp(time), delegate()->requests()[1].event.timestamp());
+  EXPECT_EQ(kPackageName2, delegate()->requests()[1].package_name);
+  EXPECT_EQ(em::AppInstallReportLogEvent::CLOUDDPS_REQUEST,
+            delegate()->requests()[1].event.event_type());
+  EXPECT_EQ(0, delegate()->requests()[1].event.clouddps_response());
+
+  // One package succeeded.
+  time += base::TimeDelta::FromSeconds(1);
+  collector->OnCloudDpsSucceeded(time, {kPackageName});
+  ASSERT_EQ(3, delegate()->add_count());
+  ASSERT_EQ(0, delegate()->add_for_all_count());
+  EXPECT_EQ(TimeToTimestamp(time),
+            delegate()->last_request().event.timestamp());
+  EXPECT_EQ(kPackageName, delegate()->last_request().package_name);
+  EXPECT_EQ(em::AppInstallReportLogEvent::CLOUDDPS_RESPONSE,
+            delegate()->last_request().event.event_type());
+  EXPECT_FALSE(delegate()->requests()[0].event.has_clouddps_response());
+
+  // One package failed.
+  time += base::TimeDelta::FromSeconds(1);
+  collector->OnCloudDpsFailed(time, kPackageName2,
+                              arc::mojom::InstallErrorReason::TIMEOUT);
+  ASSERT_EQ(4, delegate()->add_count());
+  ASSERT_EQ(0, delegate()->add_for_all_count());
+  EXPECT_EQ(TimeToTimestamp(time),
+            delegate()->last_request().event.timestamp());
+  EXPECT_EQ(kPackageName2, delegate()->last_request().package_name);
+  EXPECT_EQ(em::AppInstallReportLogEvent::CLOUDDPS_RESPONSE,
+            delegate()->last_request().event.event_type());
+  EXPECT_TRUE(delegate()->last_request().event.has_clouddps_response());
+  EXPECT_EQ(static_cast<int>(arc::mojom::InstallErrorReason::TIMEOUT),
+            delegate()->last_request().event.clouddps_response());
+}
+
 }  // namespace policy

components/arc/common/policy.mojom

@@ -2,10 +2,54 @@
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 //
-// Next MinVersion: 3
+// Next MinVersion: 4
 
 module arc.mojom;
 
+import "mojo/common/time.mojom";
+
+[Extensible]
+//See depot/google3/wireless/android/enterprise/clouddps/proto/clouddps.proto
+enum InstallErrorReason {
+    // If the reason is unspecified, this error should be treated as a
+    // non-transient error.
+    REASON_UNSPECIFIED = 0,
+
+    // The server didn't get a response from Play in time. The install may
+    // still succeed or may fail with any error.
+    TIMEOUT = 1,
+
+    // A potentially transient error, for example, the device is not found (due
+    // to replication delay), or Play was unavailable. A retry in a short amount
+    // of time is likely to succeed.
+    TRANSIENT_ERROR = 2,
+
+    // The app was not found in Play.
+    NOT_FOUND = 3,
+
+    // The app is incompatible with the device.
+    NOT_COMPATIBLE_WITH_DEVICE = 4,
+
+    // The app has not been approved by the admin.
+    NOT_APPROVED = 5,
+
+    // The app has new permissions that have not been accepted by the admin.
+    PERMISSIONS_NOT_ACCEPTED = 6,
+
+    // The app is not available in the user's country.
+    NOT_AVAILABLE_IN_COUNTRY = 7,
+
+    // There are no more licenses to assign to the user.
+    NO_LICENSES_REMAINING = 8,
+
+    // The enterprise is no longer enrolled with Play for Work or CloudDPC is
+    // not enabled for the enterprise.
+    NOT_ENROLLED = 9,
+
+    // The user is no longer valid. The user may have been deleted or disabled.
+    USER_INVALID = 10,
+};
+
 // Next Method ID: 2
 interface PolicyHost {
   // Get policies from Chrome OS, as JSON-encoded dictionary with the policies'
@@ -18,6 +62,18 @@ interface PolicyHost {
   // in JSON format as in CloudDps PolicyComplianceReportResponse.
   // ChromeOS always returns that it's compliant with the report.
   [MinVersion=1] ReportCompliance@1(string request) => (string response);
+
+  // Reports that request was sent to CloudDPS for set of packages.
+  [MinVersion=3] ReportCloudDpsRequested(mojo.common.mojom.Time time,
+                                         array<string> package_names);
+  // Reports that successful response was received from CloudDPS for set of
+  // packages.
+  [MinVersion=3] ReportCloudDpsSucceeded(mojo.common.mojom.Time time,
+                                         array<string> package_names);
+  // Reports that CloudDPS reports an error for packages.
+  [MinVersion=3] ReportCloudDpsFailed(mojo.common.mojom.Time time,
+                                      string package_name,
+                                      InstallErrorReason reason);
 };
 
 // Next Method ID: 3