OLD | NEW |
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 Loading... |
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 Loading... |
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 Loading... |
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 Loading... |
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 Loading... |
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 |
OLD | NEW |