1 // Copyright 2020 The Chromium Authors. All rights reserved.
2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file.
4 
5 #include "chrome/browser/extensions/forced_extensions/force_installed_metrics.h"
6 
7 #include <set>
8 
9 #include "base/bind.h"
10 #include "base/metrics/histogram_functions.h"
11 #include "base/metrics/histogram_macros.h"
12 #include "chrome/browser/extensions/forced_extensions/install_stage_tracker.h"
13 #include "chrome/browser/profiles/profile.h"
14 #include "components/prefs/pref_service.h"
15 #include "extensions/browser/disable_reason.h"
16 #include "extensions/browser/extension_prefs.h"
17 #include "extensions/browser/install/crx_install_error.h"
18 #include "extensions/browser/updater/extension_downloader.h"
19 
20 #if defined(OS_CHROMEOS)
21 #include "chrome/browser/chromeos/profiles/profile_helper.h"
22 #endif  // defined(OS_CHROMEOS)
23 
24 namespace extensions {
25 
26 using ExtensionStatus = ForceInstalledTracker::ExtensionStatus;
27 using FailureReason = InstallStageTracker::FailureReason;
28 
29 namespace {
30 // Timeout to report UMA if not all force-installed extension were loaded.
31 constexpr base::TimeDelta kInstallationTimeout =
32     base::TimeDelta::FromMinutes(5);
33 
34 constexpr char kManifestFetchFailedNetworkErrorCode[] =
35     "Extensions.ForceInstalledManifestFetchFailedNetworkErrorCode";
36 constexpr char kManifestFetchFailedHttpErrorCode[] =
37     "Extensions.ForceInstalledManifestFetchFailedHttpErrorCode2";
38 constexpr char kManifestFetchFailedFetchTries[] =
39     "Extensions.ForceInstalledManifestFetchFailedFetchTries";
40 constexpr char kCrxFetchFailedNetworkErrorCode[] =
41     "Extensions.ForceInstalledNetworkErrorCode";
42 constexpr char kCrxFetchFailedHttpErrorCode[] =
43     "Extensions.ForceInstalledHttpErrorCode2";
44 constexpr char kCrxFetchFailedFetchTries[] =
45     "Extensions.ForceInstalledFetchTries";
46 
47 #if defined(OS_CHROMEOS)
48 // Helper method to convert user_manager::UserType to
49 // InstallStageTracker::UserType for histogram purposes.
ConvertUserType(InstallStageTracker::UserInfo user_info)50 ForceInstalledMetrics::UserType ConvertUserType(
51     InstallStageTracker::UserInfo user_info) {
52   switch (user_info.user_type) {
53     case user_manager::USER_TYPE_REGULAR: {
54       if (user_info.is_new_user)
55         return ForceInstalledMetrics::UserType::USER_TYPE_REGULAR_NEW;
56       return ForceInstalledMetrics::UserType::USER_TYPE_REGULAR_EXISTING;
57     }
58     case user_manager::USER_TYPE_GUEST:
59       return ForceInstalledMetrics::UserType::USER_TYPE_GUEST;
60     case user_manager::USER_TYPE_PUBLIC_ACCOUNT:
61       return ForceInstalledMetrics::UserType::USER_TYPE_PUBLIC_ACCOUNT;
62     case user_manager::USER_TYPE_SUPERVISED:
63       return ForceInstalledMetrics::UserType::USER_TYPE_SUPERVISED;
64     case user_manager::USER_TYPE_KIOSK_APP:
65       return ForceInstalledMetrics::UserType::USER_TYPE_KIOSK_APP;
66     case user_manager::USER_TYPE_CHILD:
67       return ForceInstalledMetrics::UserType::USER_TYPE_CHILD;
68     case user_manager::USER_TYPE_ARC_KIOSK_APP:
69       return ForceInstalledMetrics::UserType::USER_TYPE_ARC_KIOSK_APP;
70     case user_manager::USER_TYPE_ACTIVE_DIRECTORY:
71       return ForceInstalledMetrics::UserType::USER_TYPE_ACTIVE_DIRECTORY;
72     case user_manager::USER_TYPE_WEB_KIOSK_APP:
73       return ForceInstalledMetrics::UserType::USER_TYPE_WEB_KIOSK_APP;
74     default:
75       NOTREACHED();
76   }
77   return ForceInstalledMetrics::UserType::kMaxValue;
78 }
79 #endif  // defined(OS_CHROMEOS)
80 
81 // Reports time taken for force installed extension during different
82 // installation stages.
ReportInstallationStageTimes(const ExtensionId & extension_id,const InstallStageTracker::InstallationData & installation)83 void ReportInstallationStageTimes(
84     const ExtensionId& extension_id,
85     const InstallStageTracker::InstallationData& installation) {
86   if (installation.download_manifest_finish_time &&
87       installation.download_manifest_started_time) {
88     base::UmaHistogramLongTimes(
89         "Extensions.ForceInstalledTime.DownloadingStartTo."
90         "ManifestDownloadComplete",
91         installation.download_manifest_finish_time.value() -
92             installation.download_manifest_started_time.value());
93   }
94   // Report the download time for CRX only when
95   // installation.download_CRX_started_time is set because in other case CRX
96   // is fetched from cache and the download was not started.
97   if (installation.download_CRX_finish_time &&
98       installation.download_CRX_started_time) {
99     base::UmaHistogramLongTimes(
100         "Extensions.ForceInstalledTime.ManifestDownloadCompleteTo."
101         "CRXDownloadComplete",
102         installation.download_CRX_finish_time.value() -
103             installation.download_CRX_started_time.value());
104   }
105   if (installation.copying_started_time) {
106     DCHECK(installation.verification_started_time);
107     base::UmaHistogramLongTimes(
108         "Extensions.ForceInstalledTime.VerificationStartTo.CopyingStart",
109         installation.copying_started_time.value() -
110             installation.verification_started_time.value());
111   }
112   if (installation.unpacking_started_time &&
113       installation.copying_started_time) {
114     base::UmaHistogramLongTimes(
115         "Extensions.ForceInstalledTime.CopyingStartTo.UnpackingStart",
116         installation.unpacking_started_time.value() -
117             installation.copying_started_time.value());
118   }
119   if (installation.checking_expectations_started_time &&
120       installation.unpacking_started_time) {
121     base::UmaHistogramLongTimes(
122         "Extensions.ForceInstalledTime.UnpackingStartTo."
123         "CheckingExpectationsStart",
124         installation.checking_expectations_started_time.value() -
125             installation.unpacking_started_time.value());
126   }
127   if (installation.finalizing_started_time &&
128       installation.checking_expectations_started_time) {
129     base::UmaHistogramLongTimes(
130         "Extensions.ForceInstalledTime.CheckingExpectationsStartTo."
131         "FinalizingStart",
132         installation.finalizing_started_time.value() -
133             installation.checking_expectations_started_time.value());
134   }
135   if (installation.installation_complete_time &&
136       installation.finalizing_started_time) {
137     base::UmaHistogramLongTimes(
138         "Extensions.ForceInstalledTime.FinalizingStartTo."
139         "CRXInstallComplete",
140         installation.installation_complete_time.value() -
141             installation.finalizing_started_time.value());
142   }
143 }
144 
145 // Reports the network error code, HTTP error code and number of fetch tries
146 // made when extension fails to install with MANIFEST_FETCH_FAILED or
147 // CRX_FETCH_FAILED.
ReportErrorCodes(const InstallStageTracker::InstallationData & installation,const std::string & network_error_code_histogram,const std::string & http_error_code_histogram,const std::string & fetch_tries_histogram)148 void ReportErrorCodes(const InstallStageTracker::InstallationData& installation,
149                       const std::string& network_error_code_histogram,
150                       const std::string& http_error_code_histogram,
151                       const std::string& fetch_tries_histogram) {
152   base::UmaHistogramSparse(network_error_code_histogram,
153                            installation.network_error_code.value());
154 
155   if (installation.response_code) {
156     base::UmaHistogramSparse(http_error_code_histogram,
157                              installation.response_code.value());
158   }
159   base::UmaHistogramExactLinear(fetch_tries_histogram,
160                                 installation.fetch_tries.value(),
161                                 ExtensionDownloader::kMaxRetries);
162 }
163 
164 // Reports installation stage and downloading stage for extensions which are
165 // currently in progress of the installation.
ReportCurrentStage(const InstallStageTracker::InstallationData & installation)166 void ReportCurrentStage(
167     const InstallStageTracker::InstallationData& installation) {
168   InstallStageTracker::Stage install_stage = installation.install_stage.value();
169   base::UmaHistogramEnumeration("Extensions.ForceInstalledStage2",
170                                 install_stage);
171   if (install_stage == InstallStageTracker::Stage::CREATED) {
172     DCHECK(installation.install_creation_stage);
173     InstallStageTracker::InstallCreationStage install_creation_stage =
174         installation.install_creation_stage.value();
175     base::UmaHistogramEnumeration("Extensions.ForceInstalledCreationStage",
176                                   install_creation_stage);
177   }
178   if (install_stage == InstallStageTracker::Stage::DOWNLOADING) {
179     DCHECK(installation.downloading_stage);
180     ExtensionDownloaderDelegate::Stage downloading_stage =
181         installation.downloading_stage.value();
182     base::UmaHistogramEnumeration("Extensions.ForceInstalledDownloadingStage",
183                                   downloading_stage);
184   }
185 }
186 
187 // Reports detailed failure reason for the extensions which failed to install
188 // after 5 minutes.
ReportDetailedFailureReasons(const InstallStageTracker::InstallationData & installation,const bool is_from_store)189 void ReportDetailedFailureReasons(
190     const InstallStageTracker::InstallationData& installation,
191     const bool is_from_store) {
192   FailureReason failure_reason =
193       installation.failure_reason.value_or(FailureReason::UNKNOWN);
194 
195   // In case of CRX_FETCH_FAILURE, report the network error code, HTTP
196   // error code and number of fetch tries made.
197   if (failure_reason == FailureReason::CRX_FETCH_FAILED)
198     ReportErrorCodes(installation, kCrxFetchFailedNetworkErrorCode,
199                      kCrxFetchFailedHttpErrorCode, kCrxFetchFailedFetchTries);
200 
201   // In case of MANIFEST_FETCH_FAILURE, report the network error code,
202   // HTTP error code and number of fetch tries made.
203   if (failure_reason == FailureReason::MANIFEST_FETCH_FAILED)
204     ReportErrorCodes(installation, kManifestFetchFailedNetworkErrorCode,
205                      kManifestFetchFailedHttpErrorCode,
206                      kManifestFetchFailedFetchTries);
207 
208   if (installation.install_error_detail) {
209     CrxInstallErrorDetail detail = installation.install_error_detail.value();
210     base::UmaHistogramEnumeration(
211         "Extensions.ForceInstalledFailureCrxInstallError", detail);
212   }
213   if (installation.unpacker_failure_reason) {
214     base::UmaHistogramEnumeration(
215         "Extensions.ForceInstalledFailureSandboxUnpackFailureReason",
216         installation.unpacker_failure_reason.value(),
217         SandboxedUnpackerFailureReason::NUM_FAILURE_REASONS);
218   }
219   if (failure_reason == FailureReason::CRX_FETCH_URL_EMPTY) {
220     DCHECK(installation.no_updates_info);
221     base::UmaHistogramEnumeration(
222         "Extensions."
223         "ForceInstalledFailureNoUpdatesInfo",
224         installation.no_updates_info.value());
225   }
226   if (installation.manifest_invalid_error) {
227     DCHECK_EQ(failure_reason, FailureReason::MANIFEST_INVALID);
228     base::UmaHistogramEnumeration(
229         "Extensions.ForceInstalledFailureManifestInvalidErrorDetail2",
230         installation.manifest_invalid_error.value());
231     if (installation.app_status_error) {
232       base::UmaHistogramEnumeration(
233           "Extensions.ForceInstalledFailureManifestInvalidAppStatusError",
234           installation.app_status_error.value());
235     }
236   }
237   if (installation.unpacker_failure_reason &&
238       installation.unpacker_failure_reason.value() ==
239           SandboxedUnpackerFailureReason::CRX_HEADER_INVALID) {
240     base::UmaHistogramBoolean(
241         "Extensions.ForceInstalledFailureWithCrxHeaderInvalidIsCWS",
242         is_from_store);
243     base::UmaHistogramBoolean(
244         "Extensions.ForceInstalledFailureWithCrxHeaderInvalidIsFromCache",
245         ForceInstalledTracker::IsExtensionFetchedFromCache(
246             installation.downloading_cache_status));
247   }
248 }
249 }  // namespace
250 
ForceInstalledMetrics(ExtensionRegistry * registry,Profile * profile,ForceInstalledTracker * tracker,std::unique_ptr<base::OneShotTimer> timer)251 ForceInstalledMetrics::ForceInstalledMetrics(
252     ExtensionRegistry* registry,
253     Profile* profile,
254     ForceInstalledTracker* tracker,
255     std::unique_ptr<base::OneShotTimer> timer)
256     : registry_(registry),
257       profile_(profile),
258       tracker_(tracker),
259       start_time_(base::Time::Now()),
260       timer_(std::move(timer)) {
261   timer_->Start(
262       FROM_HERE, kInstallationTimeout,
263       base::BindOnce(&ForceInstalledMetrics::OnForceInstalledExtensionsLoaded,
264                      base::Unretained(this)));
265   if (tracker_->IsDoneLoading())
266     OnForceInstalledExtensionsLoaded();
267   else
268     tracker_observer_.Add(tracker_);
269 }
270 
271 ForceInstalledMetrics::~ForceInstalledMetrics() = default;
272 
IsStatusGood(ExtensionStatus status)273 bool ForceInstalledMetrics::IsStatusGood(ExtensionStatus status) {
274   switch (status) {
275     case ExtensionStatus::PENDING:
276       return false;
277     case ExtensionStatus::LOADED:
278       return true;
279     case ExtensionStatus::READY:
280       return true;
281     case ExtensionStatus::FAILED:
282       return false;
283     default:
284       NOTREACHED();
285   }
286   return false;
287 }
288 
ReportDisableReason(const ExtensionId & extension_id)289 void ForceInstalledMetrics::ReportDisableReason(
290     const ExtensionId& extension_id) {
291   int disable_reasons =
292       ExtensionPrefs::Get(profile_)->GetDisableReasons(extension_id);
293   // Choose any disable reason among the disable reasons for this extension.
294   disable_reasons = disable_reasons & ~(disable_reasons - 1);
295   base::UmaHistogramSparse("Extensions.ForceInstalledNotLoadedDisableReason",
296                            disable_reasons);
297 }
298 
ReportMetricsOnExtensionsReady()299 void ForceInstalledMetrics::ReportMetricsOnExtensionsReady() {
300   for (const auto& extension : tracker_->extensions()) {
301     if (extension.second.status != ExtensionStatus::READY)
302       return;
303   }
304   base::UmaHistogramLongTimes("Extensions.ForceInstalledReadyTime",
305                               base::Time::Now() - start_time_);
306 }
307 
ReportMetrics()308 void ForceInstalledMetrics::ReportMetrics() {
309   base::UmaHistogramCounts100("Extensions.ForceInstalledTotalCandidateCount",
310                               tracker_->extensions().size());
311   std::set<ExtensionId> missing_forced_extensions;
312   InstallStageTracker* install_stage_tracker =
313       InstallStageTracker::Get(profile_);
314   for (const auto& extension : tracker_->extensions()) {
315     if (!IsStatusGood(extension.second.status)) {
316       missing_forced_extensions.insert(extension.first);
317     } else {
318       InstallStageTracker::InstallationData installation =
319           install_stage_tracker->Get(extension.first);
320       ReportInstallationStageTimes(extension.first, installation);
321     }
322   }
323   if (missing_forced_extensions.empty()) {
324     base::UmaHistogramLongTimes("Extensions.ForceInstalledLoadTime",
325                                 base::Time::Now() - start_time_);
326     // TODO(burunduk): Remove VLOGs after resolving crbug/917700 and
327     // crbug/904600.
328     VLOG(2) << "All forced extensions seem to be installed";
329     return;
330   }
331   size_t enabled_missing_count = missing_forced_extensions.size();
332   size_t blocklisted_count = 0;
333   auto installed_extensions = registry_->GenerateInstalledExtensionsSet();
334   auto blocklisted_extensions = registry_->GenerateInstalledExtensionsSet(
335       ExtensionRegistry::IncludeFlag::BLOCKLISTED);
336   for (const auto& entry : *installed_extensions) {
337     if (missing_forced_extensions.count(entry->id())) {
338       missing_forced_extensions.erase(entry->id());
339       ReportDisableReason(entry->id());
340       if (blocklisted_extensions->Contains(entry->id()))
341         blocklisted_count++;
342     }
343   }
344   size_t misconfigured_extensions = 0;
345   size_t installed_missing_count = missing_forced_extensions.size();
346 
347   base::UmaHistogramCounts100("Extensions.ForceInstalledTimedOutCount",
348                               enabled_missing_count);
349   base::UmaHistogramCounts100(
350       "Extensions.ForceInstalledTimedOutAndNotInstalledCount",
351       installed_missing_count);
352   base::UmaHistogramCounts100("Extensions.ForceInstalledAndBlackListed",
353                               blocklisted_count);
354   VLOG(2) << "Failed to install " << installed_missing_count
355           << " forced extensions.";
356   for (const auto& extension_id : missing_forced_extensions) {
357     InstallStageTracker::InstallationData installation =
358         install_stage_tracker->Get(extension_id);
359     base::UmaHistogramEnumeration(
360         "Extensions.ForceInstalledFailureCacheStatus",
361         installation.downloading_cache_status.value_or(
362             ExtensionDownloaderDelegate::CacheStatus::CACHE_UNKNOWN));
363     if (!installation.failure_reason && installation.install_stage) {
364       installation.failure_reason = FailureReason::IN_PROGRESS;
365       ReportCurrentStage(installation);
366     }
367     if (tracker_->IsMisconfiguration(installation, extension_id))
368       misconfigured_extensions++;
369     FailureReason failure_reason =
370         installation.failure_reason.value_or(FailureReason::UNKNOWN);
371     base::UmaHistogramEnumeration("Extensions.ForceInstalledFailureReason3",
372                                   failure_reason);
373     bool is_from_store = tracker_->extensions().at(extension_id).is_from_store;
374     if (is_from_store) {
375       base::UmaHistogramEnumeration(
376           "Extensions.WebStore_ForceInstalledFailureReason3", failure_reason);
377     } else {
378       base::UmaHistogramEnumeration(
379           "Extensions.OffStore_ForceInstalledFailureReason3", failure_reason);
380     }
381 
382 #if defined(OS_CHROMEOS)
383     // Report type of user in case Force Installed Extensions fail to
384     // install only if there is a user corresponding to given profile. There can
385     // be extensions on the login screen. There is no user on the login screen
386     // and thus we would not report in that case.
387     if (chromeos::ProfileHelper::Get()->GetUserByProfile(profile_)) {
388       InstallStageTracker::UserInfo user_info =
389           InstallStageTracker::GetUserInfo(profile_);
390       base::UmaHistogramEnumeration(
391           "Extensions.ForceInstalledFailureSessionType",
392           ConvertUserType(user_info));
393     }
394 #endif  // defined(OS_CHROMEOS)
395     VLOG(2) << "Forced extension " << extension_id
396             << " failed to install with data="
397             << InstallStageTracker::GetFormattedInstallationData(installation);
398     ReportDetailedFailureReasons(installation, is_from_store);
399   }
400   bool non_misconfigured_failure_occurred =
401       misconfigured_extensions != missing_forced_extensions.size();
402   base::UmaHistogramBoolean(
403       "Extensions."
404       "ForceInstalledSessionsWithNonMisconfigurationFailureOccured",
405       non_misconfigured_failure_occurred);
406 }
407 
OnForceInstalledExtensionsLoaded()408 void ForceInstalledMetrics::OnForceInstalledExtensionsLoaded() {
409   if (load_reported_)
410     return;
411   // Report only if there was non-empty list of force-installed extensions.
412   if (!tracker_->extensions().empty())
413     ReportMetrics();
414   load_reported_ = true;
415   timer_->Stop();
416 }
417 
OnForceInstalledExtensionsReady()418 void ForceInstalledMetrics::OnForceInstalledExtensionsReady() {
419   if (ready_reported_)
420     return;
421   // Report only if there was non-empty list of force-installed extensions.
422   if (!tracker_->extensions().empty())
423     ReportMetricsOnExtensionsReady();
424   ready_reported_ = true;
425 }
426 
OnExtensionDownloadCacheStatusRetrieved(const ExtensionId & id,ExtensionDownloaderDelegate::CacheStatus cache_status)427 void ForceInstalledMetrics::OnExtensionDownloadCacheStatusRetrieved(
428     const ExtensionId& id,
429     ExtensionDownloaderDelegate::CacheStatus cache_status) {
430   UMA_HISTOGRAM_ENUMERATION("Extensions.ForceInstalledCacheStatus",
431                             cache_status);
432 }
433 
434 }  //  namespace extensions
435