Chromium Code Reviews
chromiumcodereview-hr@appspot.gserviceaccount.com (chromiumcodereview-hr) | Please choose your nickname with Settings | Help | Chromium Project | Gerrit Changes | Sign out
(144)

Side by Side Diff: components/startup_metric_utils/browser/startup_metric_utils.cc

Issue 1637493002: Add SameVersionStartupCounts suffix to startup HardFault and Temperature histograms. (Closed) Base URL: https://chromium.googlesource.com/chromium/src.git@b1_startup_count_metric
Patch Set: back to _COUNT instead of _MAX Created 4 years, 11 months ago
Use n/p to move between diff chunks; N/P to move between comments. Draft comments are only viewable by you.
Jump to:
View unified diff | Download patch
OLDNEW
1 // Copyright 2013 The Chromium Authors. All rights reserved. 1 // Copyright 2013 The Chromium Authors. All rights reserved.
2 // Use of this source code is governed by a BSD-style license that can be 2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file. 3 // found in the LICENSE file.
4 4
5 #include "components/startup_metric_utils/browser/startup_metric_utils.h" 5 #include "components/startup_metric_utils/browser/startup_metric_utils.h"
6 6
7 #include <stddef.h> 7 #include <stddef.h>
8 8
9 #include "base/containers/hash_tables.h" 9 #include "base/containers/hash_tables.h"
10 #include "base/environment.h" 10 #include "base/environment.h"
11 #include "base/lazy_instance.h" 11 #include "base/lazy_instance.h"
12 #include "base/logging.h" 12 #include "base/logging.h"
13 #include "base/metrics/histogram.h"
13 #include "base/metrics/histogram_macros.h" 14 #include "base/metrics/histogram_macros.h"
14 #include "base/prefs/pref_registry_simple.h" 15 #include "base/prefs/pref_registry_simple.h"
15 #include "base/prefs/pref_service.h" 16 #include "base/prefs/pref_service.h"
16 #include "base/process/process_info.h" 17 #include "base/process/process_info.h"
17 #include "base/strings/string_number_conversions.h" 18 #include "base/strings/string_number_conversions.h"
18 #include "base/sys_info.h" 19 #include "base/sys_info.h"
19 #include "base/threading/platform_thread.h" 20 #include "base/threading/platform_thread.h"
20 #include "base/trace_event/trace_event.h" 21 #include "base/trace_event/trace_event.h"
21 #include "build/build_config.h" 22 #include "build/build_config.h"
22 #include "components/startup_metric_utils/browser/pref_names.h" 23 #include "components/startup_metric_utils/browser/pref_names.h"
(...skipping 151 matching lines...) Expand 10 before | Expand all | Expand 10 after
174 GetSystemUptimeOnProcessLaunch(); 175 GetSystemUptimeOnProcessLaunch();
175 if (system_uptime_on_process_launch.is_zero()) 176 if (system_uptime_on_process_launch.is_zero())
176 return; 177 return;
177 178
178 UMA_HISTOGRAM_WITH_STARTUP_TEMPERATURE(UMA_HISTOGRAM_LONG_TIMES_100, 179 UMA_HISTOGRAM_WITH_STARTUP_TEMPERATURE(UMA_HISTOGRAM_LONG_TIMES_100,
179 "Startup.SystemUptime", 180 "Startup.SystemUptime",
180 GetSystemUptimeOnProcessLaunch()); 181 GetSystemUptimeOnProcessLaunch());
181 } 182 }
182 183
183 // On Windows, records the number of hard-faults that have occurred in the 184 // On Windows, records the number of hard-faults that have occurred in the
184 // current chrome.exe process since it was started. This is a nop on other 185 // current chrome.exe process since it was started. A version of the histograms
185 // platforms. 186 // recorded in this method suffixed by |same_version_startup_count| will also be
186 void RecordHardFaultHistogram(bool is_first_run) { 187 // recorded (unless |same_version_startup_count| is 0 which indicates it's
188 // unknown). This is a nop on other platforms.
189 void RecordHardFaultHistogram(int same_version_startup_count) {
187 #if defined(OS_WIN) 190 #if defined(OS_WIN)
188 uint32_t hard_fault_count = 0; 191 uint32_t hard_fault_count = 0;
189 192
190 // Don't log a histogram value if unable to get the hard fault count. 193 // Don't record histograms if unable to get the hard fault count.
191 if (!GetHardFaultCountForCurrentProcess(&hard_fault_count)) 194 if (!GetHardFaultCountForCurrentProcess(&hard_fault_count))
192 return; 195 return;
193 196
197 std::string same_version_startup_count_suffix;
198 if (same_version_startup_count != 0) {
199 // Histograms below will be suffixed by |same_version_startup_count| up to
200 // |kMaxSameVersionCountRecorded|, higher counts will be grouped in the
201 // ".Over" suffix. Make sure to reflect changes to
202 // kMaxSameVersionCountRecorded in the "SameVersionStartupCounts" histogram
203 // suffix.
204 const int kMaxSameVersionCountRecorded = 9;
205 same_version_startup_count_suffix.push_back('.');
206 DCHECK_GE(same_version_startup_count, 1);
207 if (same_version_startup_count <= kMaxSameVersionCountRecorded) {
208 same_version_startup_count_suffix.append(
209 base::IntToString(same_version_startup_count));
210 } else {
211 same_version_startup_count_suffix.append("Over");
212 }
213 }
214
194 // Hard fault counts are expected to be in the thousands range, 215 // Hard fault counts are expected to be in the thousands range,
195 // corresponding to faulting in ~10s of MBs of code ~10s of KBs at a time. 216 // corresponding to faulting in ~10s of MBs of code ~10s of KBs at a time.
196 // (Observed to vary from 1000 to 10000 on various test machines and 217 // (Observed to vary from 1000 to 10000 on various test machines and
197 // platforms.) 218 // platforms.)
198 if (is_first_run) { 219 const char kHardFaultCountHistogram[] =
199 UMA_HISTOGRAM_CUSTOM_COUNTS( 220 "Startup.BrowserMessageLoopStartHardFaultCount";
200 "Startup.BrowserMessageLoopStartHardFaultCount.FirstRun", 221 UMA_HISTOGRAM_CUSTOM_COUNTS(kHardFaultCountHistogram, hard_fault_count, 1,
201 hard_fault_count, 222 40000, 50);
202 0, 40000, 50); 223 // Also record the hard fault count histogram suffixed by the number of
203 } else { 224 // startups this specific version has been through.
204 UMA_HISTOGRAM_CUSTOM_COUNTS( 225 // Factory properties copied from UMA_HISTOGRAM_CUSTOM_COUNTS macro.
205 "Startup.BrowserMessageLoopStartHardFaultCount", 226 if (!same_version_startup_count_suffix.empty()) {
206 hard_fault_count, 227 base::Histogram::FactoryGet(
207 0, 40000, 50); 228 kHardFaultCountHistogram + same_version_startup_count_suffix, 1, 40000,
229 50, base::HistogramBase::kUmaTargetedHistogramFlag)
230 ->Add(hard_fault_count);
208 } 231 }
209 232
210 // Determine the startup type based on the number of observed hard faults. 233 // Determine the startup type based on the number of observed hard faults.
211 DCHECK_EQ(UNDETERMINED_STARTUP_TEMPERATURE, g_startup_temperature); 234 DCHECK_EQ(UNDETERMINED_STARTUP_TEMPERATURE, g_startup_temperature);
212 if (hard_fault_count < WARM_START_HARD_FAULT_COUNT_THRESHOLD) { 235 if (hard_fault_count < WARM_START_HARD_FAULT_COUNT_THRESHOLD) {
213 g_startup_temperature = WARM_STARTUP_TEMPERATURE; 236 g_startup_temperature = WARM_STARTUP_TEMPERATURE;
214 } else if (hard_fault_count >= COLD_START_HARD_FAULT_COUNT_THRESHOLD) { 237 } else if (hard_fault_count >= COLD_START_HARD_FAULT_COUNT_THRESHOLD) {
215 g_startup_temperature = COLD_STARTUP_TEMPERATURE; 238 g_startup_temperature = COLD_STARTUP_TEMPERATURE;
216 } else { 239 } else {
217 g_startup_temperature = LUKEWARM_STARTUP_TEMPERATURE; 240 g_startup_temperature = LUKEWARM_STARTUP_TEMPERATURE;
218 } 241 }
219 242
220 // Record the startup 'temperature'. 243 // Record the startup 'temperature'.
221 UMA_HISTOGRAM_ENUMERATION( 244 const char kStartupTemperatureHistogram[] = "Startup.Temperature";
222 "Startup.Temperature", g_startup_temperature, STARTUP_TEMPERATURE_COUNT); 245 UMA_HISTOGRAM_ENUMERATION(kStartupTemperatureHistogram, g_startup_temperature,
246 STARTUP_TEMPERATURE_COUNT);
247 // As well as its suffixed twin.
248 // Factory properties copied from UMA_HISTOGRAM_ENUMERATION macro.
249 if (!same_version_startup_count_suffix.empty()) {
250 base::LinearHistogram::FactoryGet(
251 kStartupTemperatureHistogram + same_version_startup_count_suffix, 1,
252 STARTUP_TEMPERATURE_COUNT, STARTUP_TEMPERATURE_COUNT + 1,
253 base::HistogramBase::kUmaTargetedHistogramFlag)
254 ->Add(g_startup_temperature);
255 }
223 #endif // defined(OS_WIN) 256 #endif // defined(OS_WIN)
224 } 257 }
225 258
226 // Converts a base::Time value to a base::TimeTicks value. The conversion isn't 259 // Converts a base::Time value to a base::TimeTicks value. The conversion isn't
227 // exact, but by capturing Time::Now() as early as possible, the likelihood of a 260 // exact, but by capturing Time::Now() as early as possible, the likelihood of a
228 // clock change between it and process start is as low as possible. There is 261 // clock change between it and process start is as low as possible. There is
229 // also the time taken to synchronously resolve base::Time::Now() and 262 // also the time taken to synchronously resolve base::Time::Now() and
230 // base::TimeTicks::Now() at play, but in practice it is pretty much instant 263 // base::TimeTicks::Now() at play, but in practice it is pretty much instant
231 // compared to multi-seconds startup timings. 264 // compared to multi-seconds startup timings.
232 base::TimeTicks StartupTimeToTimeTicks(const base::Time& time) { 265 base::TimeTicks StartupTimeToTimeTicks(const base::Time& time) {
(...skipping 103 matching lines...) Expand 10 before | Expand all | Expand 10 after
336 g_browser_main_entry_point_ticks.Get().ToInternalValue()); 369 g_browser_main_entry_point_ticks.Get().ToInternalValue());
337 370
338 if (!g_process_creation_ticks.Get().is_null()) 371 if (!g_process_creation_ticks.Get().is_null())
339 { 372 {
340 TRACE_EVENT_INSTANT_WITH_TIMESTAMP0( 373 TRACE_EVENT_INSTANT_WITH_TIMESTAMP0(
341 "startup", "Startup.BrowserProcessCreation", 0, 374 "startup", "Startup.BrowserProcessCreation", 0,
342 g_process_creation_ticks.Get().ToInternalValue()); 375 g_process_creation_ticks.Get().ToInternalValue());
343 } 376 }
344 } 377 }
345 378
379 // Logs the Startup.TimeSinceLastStartup histogram. Obtains the timestamp of the
380 // last startup from |pref_service| and overwrites it with the timestamp of the
381 // current startup. If the startup temperature has been set by
382 // RecordBrowserMainMessageLoopStart, the time since last startup is also logged
383 // to an histogram suffixed with the startup temperature.
384 void RecordTimeSinceLastStartup(PrefService* pref_service) {
385 #if defined(OS_MACOSX) || defined(OS_WIN) || defined(OS_LINUX)
386 DCHECK(pref_service);
387
388 // Get the timestamp of the current startup.
389 const base::Time process_start_time =
390 base::CurrentProcessInfo::CreationTime();
391
392 // Get the timestamp of the last startup from |pref_service|.
393 const int64_t last_startup_timestamp_internal =
394 pref_service->GetInt64(prefs::kLastStartupTimestamp);
395 if (last_startup_timestamp_internal != 0) {
396 // Log the Startup.TimeSinceLastStartup histogram.
397 const base::Time last_startup_timestamp =
398 base::Time::FromInternalValue(last_startup_timestamp_internal);
399 const base::TimeDelta time_since_last_startup =
400 process_start_time - last_startup_timestamp;
401 const int minutes_since_last_startup = time_since_last_startup.InMinutes();
402
403 // Ignore negative values, which can be caused by system clock changes.
404 if (minutes_since_last_startup >= 0) {
405 UMA_HISTOGRAM_WITH_STARTUP_TEMPERATURE(
406 UMA_HISTOGRAM_TIME_IN_MINUTES_MONTH_RANGE,
407 "Startup.TimeSinceLastStartup", minutes_since_last_startup);
408 }
409 }
410
411 // Write the timestamp of the current startup in |pref_service|.
412 pref_service->SetInt64(prefs::kLastStartupTimestamp,
413 process_start_time.ToInternalValue());
414 #endif // defined(OS_MACOSX) || defined(OS_WIN) || defined(OS_LINUX)
415 }
416
417 // Logs the Startup.SameVersionStartupCount histogram. Relies on |pref_service|
418 // to know information about the previous startups and store information for
419 // future ones. Returns the number of startups with the same version count that
420 // was logged.
421 int RecordSameVersionStartupCount(PrefService* pref_service) {
422 DCHECK(pref_service);
423
424 const std::string current_version = version_info::GetVersionNumber();
425
426 int startups_with_current_version = 0;
427 if (current_version == pref_service->GetString(prefs::kLastStartupVersion)) {
428 startups_with_current_version =
429 pref_service->GetInteger(prefs::kSameVersionStartupCount);
430 ++startups_with_current_version;
431 pref_service->SetInteger(prefs::kSameVersionStartupCount,
432 startups_with_current_version);
433 } else {
434 startups_with_current_version = 1;
435 pref_service->SetString(prefs::kLastStartupVersion, current_version);
436 pref_service->SetInteger(prefs::kSameVersionStartupCount, 1);
437 }
438
439 UMA_HISTOGRAM_COUNTS_100("Startup.SameVersionStartupCount",
440 startups_with_current_version);
441 return startups_with_current_version;
442 }
443
346 } // namespace 444 } // namespace
347 445
348 #if defined(OS_WIN) 446 #if defined(OS_WIN)
349 bool GetHardFaultCountForCurrentProcess(uint32_t* hard_fault_count) { 447 bool GetHardFaultCountForCurrentProcess(uint32_t* hard_fault_count) {
350 DCHECK(hard_fault_count); 448 DCHECK(hard_fault_count);
351 449
352 if (base::win::GetVersion() < base::win::VERSION_WIN7) 450 if (base::win::GetVersion() < base::win::VERSION_WIN7)
353 return false; 451 return false;
354 452
355 // Get the function pointer. 453 // Get the function pointer.
(...skipping 81 matching lines...) Expand 10 before | Expand all | Expand 10 after
437 } 535 }
438 536
439 void RecordExeMainEntryPointTime(const base::Time& time) { 537 void RecordExeMainEntryPointTime(const base::Time& time) {
440 const std::string exe_load_ticks = 538 const std::string exe_load_ticks =
441 base::Int64ToString(StartupTimeToTimeTicks(time).ToInternalValue()); 539 base::Int64ToString(StartupTimeToTimeTicks(time).ToInternalValue());
442 scoped_ptr<base::Environment> env(base::Environment::Create()); 540 scoped_ptr<base::Environment> env(base::Environment::Create());
443 env->SetVar(kChromeMainTicksEnvVar, exe_load_ticks); 541 env->SetVar(kChromeMainTicksEnvVar, exe_load_ticks);
444 } 542 }
445 543
446 void RecordBrowserMainMessageLoopStart(const base::TimeTicks& ticks, 544 void RecordBrowserMainMessageLoopStart(const base::TimeTicks& ticks,
447 bool is_first_run) { 545 bool is_first_run,
546 PrefService* pref_service) {
547 int same_version_startup_count = 0;
548 if (pref_service)
549 same_version_startup_count = RecordSameVersionStartupCount(pref_service);
550 // Keep RecordHardFaultHistogram() first as much as possible as many other
551 // histograms depend on it setting |g_startup_temperature|.
552 RecordHardFaultHistogram(same_version_startup_count);
448 AddStartupEventsForTelemetry(); 553 AddStartupEventsForTelemetry();
449 RecordHardFaultHistogram(is_first_run); 554 if (pref_service)
555 RecordTimeSinceLastStartup(pref_service);
450 RecordSystemUptimeHistogram(); 556 RecordSystemUptimeHistogram();
451 RecordMainEntryTimeHistogram(); 557 RecordMainEntryTimeHistogram();
452 558
453 const base::TimeTicks& process_creation_ticks = 559 const base::TimeTicks& process_creation_ticks =
454 g_process_creation_ticks.Get(); 560 g_process_creation_ticks.Get();
455 if (!is_first_run && !process_creation_ticks.is_null()) { 561 if (!is_first_run && !process_creation_ticks.is_null()) {
456 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 562 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE(
457 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.BrowserMessageLoopStartTime", 563 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.BrowserMessageLoopStartTime",
458 process_creation_ticks, ticks); 564 process_creation_ticks, ticks);
459 } 565 }
(...skipping 38 matching lines...) Expand 10 before | Expand all | Expand 10 after
498 604
499 // Process create to chrome.dll:main(). Reported as a histogram only as 605 // Process create to chrome.dll:main(). Reported as a histogram only as
500 // the other two events above are sufficient for tracing purposes. 606 // the other two events above are sufficient for tracing purposes.
501 UMA_HISTOGRAM_WITH_STARTUP_TEMPERATURE( 607 UMA_HISTOGRAM_WITH_STARTUP_TEMPERATURE(
502 UMA_HISTOGRAM_LONG_TIMES, "Startup.LoadTime.ProcessCreateToDllMain", 608 UMA_HISTOGRAM_LONG_TIMES, "Startup.LoadTime.ProcessCreateToDllMain",
503 g_browser_main_entry_point_ticks.Get() - process_creation_ticks); 609 g_browser_main_entry_point_ticks.Get() - process_creation_ticks);
504 } 610 }
505 } 611 }
506 } 612 }
507 613
508 void RecordTimeSinceLastStartup(PrefService* pref_service) {
509 #if defined(OS_MACOSX) || defined(OS_WIN) || defined(OS_LINUX)
510 DCHECK(pref_service);
511
512 // Get the timestamp of the current startup.
513 const base::Time process_start_time =
514 base::CurrentProcessInfo::CreationTime();
515
516 // Get the timestamp of the last startup from |pref_service|.
517 const int64_t last_startup_timestamp_internal =
518 pref_service->GetInt64(prefs::kLastStartupTimestamp);
519 if (last_startup_timestamp_internal != 0) {
520 // Log the Startup.TimeSinceLastStartup histogram.
521 const base::Time last_startup_timestamp =
522 base::Time::FromInternalValue(last_startup_timestamp_internal);
523 const base::TimeDelta time_since_last_startup =
524 process_start_time - last_startup_timestamp;
525 const int minutes_since_last_startup = time_since_last_startup.InMinutes();
526
527 // Ignore negative values, which can be caused by system clock changes.
528 if (minutes_since_last_startup >= 0) {
529 UMA_HISTOGRAM_WITH_STARTUP_TEMPERATURE(
530 UMA_HISTOGRAM_TIME_IN_MINUTES_MONTH_RANGE,
531 "Startup.TimeSinceLastStartup", minutes_since_last_startup);
532 }
533 }
534
535 // Write the timestamp of the current startup in |pref_service|.
536 pref_service->SetInt64(prefs::kLastStartupTimestamp,
537 process_start_time.ToInternalValue());
538 #endif // defined(OS_MACOSX) || defined(OS_WIN) || defined(OS_LINUX)
539 }
540
541 void RecordStartupCount(PrefService* pref_service) {
542 DCHECK(pref_service);
543
544 const std::string current_version = version_info::GetVersionNumber();
545
546 int startups_with_current_version = 0;
547 if (current_version == pref_service->GetString(prefs::kLastStartupVersion)) {
548 startups_with_current_version =
549 pref_service->GetInteger(prefs::kSameVersionStartupCount);
550 ++startups_with_current_version;
551 pref_service->SetInteger(prefs::kSameVersionStartupCount,
552 startups_with_current_version);
553 } else {
554 startups_with_current_version = 1;
555 pref_service->SetString(prefs::kLastStartupVersion, current_version);
556 pref_service->SetInteger(prefs::kSameVersionStartupCount, 1);
557 }
558
559 UMA_HISTOGRAM_COUNTS_100("Startup.SameVersionStartupCount",
560 startups_with_current_version);
561 }
562
563 void RecordBrowserWindowDisplay(const base::TimeTicks& ticks) { 614 void RecordBrowserWindowDisplay(const base::TimeTicks& ticks) {
564 static bool is_first_call = true; 615 static bool is_first_call = true;
565 if (!is_first_call || ticks.is_null()) 616 if (!is_first_call || ticks.is_null())
566 return; 617 return;
567 is_first_call = false; 618 is_first_call = false;
568 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null()) 619 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null())
569 return; 620 return;
570 621
571 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 622 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE(
572 UMA_HISTOGRAM_LONG_TIMES, "Startup.BrowserWindowDisplay", 623 UMA_HISTOGRAM_LONG_TIMES, "Startup.BrowserWindowDisplay",
(...skipping 79 matching lines...) Expand 10 before | Expand all | Expand 10 after
652 703
653 base::TimeTicks MainEntryPointTicks() { 704 base::TimeTicks MainEntryPointTicks() {
654 return g_browser_main_entry_point_ticks.Get(); 705 return g_browser_main_entry_point_ticks.Get();
655 } 706 }
656 707
657 StartupTemperature GetStartupTemperature() { 708 StartupTemperature GetStartupTemperature() {
658 return g_startup_temperature; 709 return g_startup_temperature;
659 } 710 }
660 711
661 } // namespace startup_metric_utils 712 } // namespace startup_metric_utils
OLDNEW
« no previous file with comments | « components/startup_metric_utils/browser/startup_metric_utils.h ('k') | tools/metrics/histograms/histograms.xml » ('j') | no next file with comments »

Powered by Google App Engine
This is Rietveld 408576698