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