Report substages of the CRX installation

We need to improve on installation time for the force installed
extensions. For this, we first need to investigate which stage takes
more time. After CRX has been downloaded, it's installation happens
in several stages (verifying, unpacking etc), and now
InstallStageTracker tracks these stages so that we could get a better
idea that which stage is more time consuming. This is a
prework for adding UMA statistics for reporting time taken for each
stage.

Bug: 1102806
Change-Id: I1a484363ef06f8f04787ddb8086dbb401523206f
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2283607
Commit-Queue: Swapnil Gupta <swapnilgupta@google.com>
Reviewed-by: Devlin <rdevlin.cronin@chromium.org>
Reviewed-by: Oleg Davydov <burunduk@chromium.org>
Cr-Commit-Position: refs/heads/master@{#790331}

chrome/browser/extensions/crx_installer.cc

@@ -51,6 +51,7 @@
 #include "extensions/browser/install/crx_install_error.h"
 #include "extensions/browser/install/extension_install_ui.h"
 #include "extensions/browser/install_flag.h"
+#include "extensions/browser/install_stage.h"
 #include "extensions/browser/notification_types.h"
 #include "extensions/browser/policy_check.h"
 #include "extensions/browser/preload_check_group.h"
@@ -523,6 +524,7 @@ void CrxInstaller::OnUnpackSuccess(
   extension_ = extension;
   temp_dir_ = temp_dir;
   ruleset_checksums_ = std::move(ruleset_checksums);
+  ReportInstallationStage(InstallationStage::kFinalizing);
 
   if (!install_icon.empty())
     install_icon_ = std::make_unique<SkBitmap>(install_icon);
@@ -574,6 +576,10 @@ void CrxInstaller::OnUnpackSuccess(
     NOTREACHED();
 }
 
+void CrxInstaller::OnStageChanged(InstallationStage stage) {
+  ReportInstallationStage(stage);
+}
+
 void CrxInstaller::CheckInstall() {
   DCHECK_CURRENTLY_ON(BrowserThread::UI);
   ExtensionService* service = service_weak_.get();
@@ -716,6 +722,7 @@ void CrxInstaller::OnInstallChecksComplete(const PreloadCheck::Errors& errors) {
 
 void CrxInstaller::ConfirmInstall() {
   DCHECK_CURRENTLY_ON(BrowserThread::UI);
+  ReportInstallationStage(InstallationStage::kComplete);
   ExtensionService* service = service_weak_.get();
   if (!service || service->browser_terminating())
     return;
@@ -1011,6 +1018,28 @@ void CrxInstaller::ReportSuccessFromUIThread() {
   NotifyCrxInstallComplete(base::nullopt);
 }
 
+void CrxInstaller::ReportInstallationStage(InstallationStage stage) {
+  if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) {
+    DCHECK(installer_task_runner_->RunsTasksInCurrentSequence());
+    if (!content::GetUIThreadTaskRunner({})->PostTask(
+            FROM_HERE, base::BindOnce(&CrxInstaller::ReportInstallationStage,
+                                      this, stage))) {
+      NOTREACHED();
+    }
+    return;
+  }
+
+  if (!service_weak_.get() || service_weak_->browser_terminating())
+    return;
+  // In case of force installed extensions, expected_id_ should always be set.
+  // We do not want to report in case of other extensions.
+  if (expected_id_.empty())
+    return;
+  InstallStageTracker* install_stage_tracker =
+      InstallStageTracker::Get(profile_);
+  install_stage_tracker->ReportCRXInstallationStage(expected_id_, stage);
+}
+
 void CrxInstaller::NotifyCrxInstallBegin() {
   InstallTrackerFactory::GetForBrowserContext(profile())
       ->OnBeginCrxInstall(expected_id_);

chrome/browser/extensions/crx_installer.h

@@ -42,6 +42,7 @@ namespace extensions {
 class CrxInstallError;
 class ExtensionService;
 class ExtensionUpdaterTest;
+enum class InstallationStage;
 class PreloadCheckGroup;
 
 // This class installs a crx file into a profile.
@@ -297,6 +298,7 @@ class CrxInstaller : public SandboxedUnpackerClient {
       const Extension* extension,
       const SkBitmap& install_icon,
       declarative_net_request::RulesetChecksums ruleset_checksums) override;
+  void OnStageChanged(InstallationStage stage) override;
 
   // Called on the UI thread to start the requirements, policy and blocklist
   // checks on the extension.
@@ -326,6 +328,8 @@ class CrxInstaller : public SandboxedUnpackerClient {
   void ReportFailureFromUIThread(const CrxInstallError& error);
   void ReportSuccessFromFileThread();
   void ReportSuccessFromUIThread();
+  // Always report from the UI thread.
+  void ReportInstallationStage(InstallationStage stage);
   void NotifyCrxInstallBegin();
   void NotifyCrxInstallComplete(const base::Optional<CrxInstallError>& error);
 

chrome/browser/extensions/forced_extensions/install_stage_tracker.cc

@@ -152,6 +152,16 @@ void InstallStageTracker::ReportDownloadingStage(
   }
 }
 
+void InstallStageTracker::ReportCRXInstallationStage(const ExtensionId& id,
+                                                     InstallationStage stage) {
+  DCHECK(!id.empty());
+  InstallationData& data = installation_data_map_[id];
+  data.installation_stage = stage;
+  for (auto& observer : observers_) {
+    observer.OnExtensionDataChangedForTesting(id, browser_context_, data);
+  }
+}
+
 void InstallStageTracker::ReportDownloadingCacheStatus(
     const ExtensionId& id,
     ExtensionDownloaderDelegate::CacheStatus cache_status) {

chrome/browser/extensions/forced_extensions/install_stage_tracker.h

@@ -14,6 +14,7 @@
 #include "components/keyed_service/core/keyed_service.h"
 #include "extensions/browser/install/crx_install_error.h"
 #include "extensions/browser/install/sandboxed_unpacker_failure_reason.h"
+#include "extensions/browser/install_stage.h"
 #include "extensions/browser/updater/extension_downloader_delegate.h"
 #include "extensions/browser/updater/safe_manifest_parser.h"
 #include "extensions/common/extension_id.h"
@@ -295,6 +296,8 @@ class InstallStageTracker : public KeyedService {
     // Time at which the update manifest is downloaded and successfully parsed
     // from the server.
     base::Optional<base::Time> download_manifest_finish_time;
+    // See InstallationStage enum.
+    base::Optional<InstallationStage> installation_stage;
   };
 
   class Observer : public base::CheckedObserver {
@@ -347,6 +350,8 @@ class InstallStageTracker : public KeyedService {
   void ReportFailure(const ExtensionId& id, FailureReason reason);
   void ReportDownloadingStage(const ExtensionId& id,
                               ExtensionDownloaderDelegate::Stage stage);
+  void ReportCRXInstallationStage(const ExtensionId& id,
+                                  InstallationStage stage);
   void ReportDownloadingCacheStatus(
       const ExtensionId& id,
       ExtensionDownloaderDelegate::CacheStatus cache_status);

extensions/browser/BUILD.gn

@@ -268,6 +268,7 @@ jumbo_source_set("browser_sources") {
     "info_map.cc",
     "info_map.h",
     "install_flag.h",
+    "install_stage.h",
     "json_file_sanitizer.cc",
     "json_file_sanitizer.h",
     "lazy_background_task_queue.cc",

extensions/browser/install_stage.h

+// Copyright 2020 The Chromium Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+#ifndef EXTENSIONS_BROWSER_INSTALL_STAGE_H_
+#define EXTENSIONS_BROWSER_INSTALL_STAGE_H_
+
+namespace extensions {
+
+// The different stages of the extension installation process.
+enum class InstallationStage {
+  // The validation of signature of the extensions is about to be started.
+  kVerification = 0,
+  // Extension archive is about to be copied into the working directory.
+  kCopying = 1,
+  // Extension archive is about to be unpacked.
+  kUnpacking = 2,
+  // Final checks before the installation is finished.
+  kFinalizing = 3,
+  kComplete = 4,
+};
+
+}  // namespace extensions
+
+#endif  // EXTENSIONS_BROWSER_INSTALL_STAGE_H_

extensions/browser/sandboxed_unpacker.cc

@@ -34,6 +34,7 @@
 #include "extensions/browser/extension_file_task_runner.h"
 #include "extensions/browser/install/crx_install_error.h"
 #include "extensions/browser/install/sandboxed_unpacker_failure_reason.h"
+#include "extensions/browser/install_stage.h"
 #include "extensions/browser/zipfile_installer.h"
 #include "extensions/common/api/declarative_net_request/dnr_manifest_data.h"
 #include "extensions/common/constants.h"
@@ -222,7 +223,7 @@ void SandboxedUnpacker::StartWithCrx(const CRXFileInfo& crx_info) {
   // We assume that we are started on the thread that the client wants us
   // to do file IO on.
   DCHECK(unpacker_io_task_runner_->RunsTasksInCurrentSequence());
-
+  client_->OnStageChanged(InstallationStage::kVerification);
   std::string expected_hash;
   if (!crx_info.expected_hash.empty() &&
       base::CommandLine::ForCurrentProcess()->HasSwitch(
@@ -242,6 +243,7 @@ void SandboxedUnpacker::StartWithCrx(const CRXFileInfo& crx_info) {
                              crx_info.required_format)))
     return;  // ValidateSignature() already reported the error.
 
+  client_->OnStageChanged(InstallationStage::kCopying);
   // Copy the crx file into our working directory.
   base::FilePath temp_crx_path =
       temp_dir_.GetPath().Append(crx_info.path.BaseName());
@@ -271,7 +273,7 @@ void SandboxedUnpacker::StartWithCrx(const CRXFileInfo& crx_info) {
         l10n_util::GetStringUTF16(IDS_EXTENSION_UNPACK_FAILED));
     return;
   }
-
+  client_->OnStageChanged(InstallationStage::kUnpacking);
   // Make sure to create the directory where the extension will be unzipped, as
   // the unzipper service requires it.
   base::FilePath unzipped_dir =

extensions/browser/sandboxed_unpacker.h

@@ -41,6 +41,7 @@ enum class VerifierFormat;
 namespace extensions {
 class Extension;
 enum class SandboxedUnpackerFailureReason;
+enum class InstallationStage;
 
 namespace declarative_net_request {
 struct IndexAndPersistJSONRulesetResult;
@@ -88,6 +89,9 @@ class SandboxedUnpackerClient
       declarative_net_request::RulesetChecksums ruleset_checksums) = 0;
   virtual void OnUnpackFailure(const CrxInstallError& error) = 0;
 
+  // Called after stage of installation is changed.
+  virtual void OnStageChanged(InstallationStage stage) {}
+
  protected:
   friend class base::RefCountedDeleteOnSequence<SandboxedUnpackerClient>;
   friend class base::DeleteHelper<SandboxedUnpackerClient>;