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

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

Issue 2117373003: Add SameVersionStartupCounts suffix to multiple startup histograms. (Closed) Base URL: https://chromium.googlesource.com/chromium/src.git@master
Patch Set: self-review Created 4 years, 5 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 <memory> 9 #include <memory>
10 10
(...skipping 38 matching lines...) Expand 10 before | Expand all | Expand 10 after
49 LAZY_INSTANCE_INITIALIZER; 49 LAZY_INSTANCE_INITIALIZER;
50 50
51 // Only used by RecordMainEntryTimeHistogram(), should go away with it (do not 51 // Only used by RecordMainEntryTimeHistogram(), should go away with it (do not
52 // add new uses of this), see crbug.com/317481 for discussion on why it was kept 52 // add new uses of this), see crbug.com/317481 for discussion on why it was kept
53 // as-is for now. 53 // as-is for now.
54 base::LazyInstance<base::Time>::Leaky g_browser_main_entry_point_time = 54 base::LazyInstance<base::Time>::Leaky g_browser_main_entry_point_time =
55 LAZY_INSTANCE_INITIALIZER; 55 LAZY_INSTANCE_INITIALIZER;
56 56
57 StartupTemperature g_startup_temperature = UNDETERMINED_STARTUP_TEMPERATURE; 57 StartupTemperature g_startup_temperature = UNDETERMINED_STARTUP_TEMPERATURE;
58 58
59 constexpr int kUndeterminedStartupsWithCurrentVersion = 0;
60 int g_startups_with_current_version = kUndeterminedStartupsWithCurrentVersion;
61
59 #if defined(OS_WIN) 62 #if defined(OS_WIN)
60 63
61 // These values are taken from the Startup.BrowserMessageLoopStartHardFaultCount 64 // These values are taken from the Startup.BrowserMessageLoopStartHardFaultCount
62 // histogram. If the cold start histogram starts looking strongly bimodal it may 65 // histogram. If the cold start histogram starts looking strongly bimodal it may
63 // be because the binary/resource sizes have grown significantly larger than 66 // be because the binary/resource sizes have grown significantly larger than
64 // when these values were set. In this case the new values need to be chosen 67 // when these values were set. In this case the new values need to be chosen
65 // from the original histogram. 68 // from the original histogram.
66 // 69 //
67 // Maximum number of hard faults tolerated for a startup to be classified as a 70 // Maximum number of hard faults tolerated for a startup to be classified as a
68 // warm start. Set at roughly the 40th percentile of the HardFaultCount 71 // warm start. Set at roughly the 40th percentile of the HardFaultCount
(...skipping 32 matching lines...) Expand 10 before | Expand all | Expand 10 after
101 104
102 // The signature of the NtQuerySystemInformation function. 105 // The signature of the NtQuerySystemInformation function.
103 typedef NTSTATUS (WINAPI *NtQuerySystemInformationPtr)( 106 typedef NTSTATUS (WINAPI *NtQuerySystemInformationPtr)(
104 SYSTEM_INFORMATION_CLASS, PVOID, ULONG, PULONG); 107 SYSTEM_INFORMATION_CLASS, PVOID, ULONG, PULONG);
105 #endif // defined(OS_WIN) 108 #endif // defined(OS_WIN)
106 109
107 #define UMA_HISTOGRAM_TIME_IN_MINUTES_MONTH_RANGE(name, sample) \ 110 #define UMA_HISTOGRAM_TIME_IN_MINUTES_MONTH_RANGE(name, sample) \
108 UMA_HISTOGRAM_CUSTOM_COUNTS(name, sample, 1, \ 111 UMA_HISTOGRAM_CUSTOM_COUNTS(name, sample, 1, \
109 base::TimeDelta::FromDays(30).InMinutes(), 50) 112 base::TimeDelta::FromDays(30).InMinutes(), 50)
110 113
111 // Helper macro for splitting out an UMA histogram based on cold or warm start. 114 // Helper macro for splitting out an UMA histogram based on startup temperature
115 // and number of startups with the same version.
112 // |type| is the histogram type, and corresponds to an UMA macro like 116 // |type| is the histogram type, and corresponds to an UMA macro like
113 // UMA_HISTOGRAM_LONG_TIMES. It must itself be a macro that only takes two 117 // UMA_HISTOGRAM_LONG_TIMES. It must itself be a macro that only takes two
114 // parameters. 118 // parameters.
115 // |basename| is the basename of the histogram. A histogram of this name will 119 // |basename| is the basename of the histogram. A histogram of this name will
116 // always be recorded to. If the startup is either cold or warm then a value 120 // always be recorded to. If the startup temperature is known then a value will
117 // will also be recorded to the histogram with name |basename| and suffix 121 // also be recorded to the histogram with name |basename| and suffix
118 // ".ColdStart" or ".WarmStart", as appropriate. 122 // ".ColdStart", ".WarmStart" or ".LukewarmStartup" as appropriate. If the
123 // number of startups with the current version is known then a value will also
124 // be recorded to the histogram with name |basename| and a suffix indicating the
125 // number of startups with the current version.
119 // |value_expr| is an expression evaluating to the value to be recorded. This 126 // |value_expr| is an expression evaluating to the value to be recorded. This
120 // will be evaluated exactly once and cached, so side effects are not an issue. 127 // will be evaluated exactly once and cached, so side effects are not an issue.
121 // A metric logged using this macro must have an affected-histogram entry in the 128 // A metric logged using this macro must have affected-histogram entries in the
122 // definition of the StartupTemperature suffix in histograms.xml. 129 // definition of the StartupTemperature and SameVersionStartupCounts suffixes in
130 // histograms.xml.
123 // This macro must only be used in code that runs after |g_startup_temperature| 131 // This macro must only be used in code that runs after |g_startup_temperature|
124 // has been initialized. 132 // and |g_startups_with_current_version| have been initialized.
125 #define UMA_HISTOGRAM_WITH_STARTUP_TEMPERATURE(type, basename, value_expr) \ 133 #define UMA_HISTOGRAM_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(type, basename, \
126 { \ 134 value_expr) \
127 const auto kValue = value_expr; \ 135 do { \
136 const auto value = value_expr; \
128 /* Always record to the base histogram. */ \ 137 /* Always record to the base histogram. */ \
129 type(basename, kValue); \ 138 type(basename, value); \
130 /* Record to the cold/warm/lukewarm suffixed histogram as appropriate. */ \ 139 /* Record to the cold/warm/lukewarm suffixed histogram as appropriate. */ \
131 switch (g_startup_temperature) { \ 140 switch (g_startup_temperature) { \
132 case COLD_STARTUP_TEMPERATURE: \ 141 case COLD_STARTUP_TEMPERATURE: \
133 type(basename ".ColdStartup", kValue); \ 142 type(basename ".ColdStartup", value); \
134 break; \ 143 break; \
135 case WARM_STARTUP_TEMPERATURE: \ 144 case WARM_STARTUP_TEMPERATURE: \
136 type(basename ".WarmStartup", kValue); \ 145 type(basename ".WarmStartup", value); \
137 break; \ 146 break; \
138 case LUKEWARM_STARTUP_TEMPERATURE: \ 147 case LUKEWARM_STARTUP_TEMPERATURE: \
139 type(basename ".LukewarmStartup", kValue); \ 148 type(basename ".LukewarmStartup", value); \
140 break; \ 149 break; \
141 case UNDETERMINED_STARTUP_TEMPERATURE: \ 150 case UNDETERMINED_STARTUP_TEMPERATURE: \
142 break; \ 151 break; \
143 case STARTUP_TEMPERATURE_COUNT: \ 152 case STARTUP_TEMPERATURE_COUNT: \
144 NOTREACHED(); \ 153 NOTREACHED(); \
145 break; \ 154 break; \
146 } \ 155 } \
156 /* Record to an histogram suffixed with the number of startups for the \
gab 2016/07/07 15:41:56 *a* histogram (below as well)
fdoray 2016/07/08 14:52:51 Done.
157 current version. Since the number of startups is set once per process, \
158 the requirement that the name provided to an histogram macro doesn't \
159 vary across invocations is met. */ \
160 const auto same_version_startup_count_suffix = \
161 GetSameVersionStartupCountSuffix(); \
162 if (!same_version_startup_count_suffix.empty()) \
163 type(basename + same_version_startup_count_suffix, value); \
gab 2016/07/07 15:41:55 Since |type| is a macro and is thus not guaranteed
fdoray 2016/07/08 14:52:51 Done.
164 } while (0)
165
166 #define UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT( \
167 type, basename, begin_ticks, end_ticks) \
168 do { \
169 UMA_HISTOGRAM_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT( \
170 type, basename, end_ticks - begin_ticks); \
171 TRACE_EVENT_ASYNC_BEGIN_WITH_TIMESTAMP2( \
172 "startup", basename, 0, begin_ticks.ToInternalValue(), "Temperature", \
173 g_startup_temperature, "Startups with current version", \
174 g_startups_with_current_version); \
175 TRACE_EVENT_ASYNC_END_WITH_TIMESTAMP2( \
176 "startup", basename, 0, end_ticks.ToInternalValue(), "Temperature", \
177 g_startup_temperature, "Startups with current version", \
178 g_startups_with_current_version); \
179 } while (0)
180
181 std::string GetSameVersionStartupCountSuffix() {
182 if (g_startups_with_current_version ==
183 kUndeterminedStartupsWithCurrentVersion) {
gab 2016/07/07 15:41:56 When would this be empty? When |pref_service| is n
fdoray 2016/07/08 14:52:51 DCHECK(pref_service) in a separate CL: Done. g_st
gab 2016/07/08 19:56:18 Perfect, thanks, feel free to take ownership of bo
184 return std::string();
147 } 185 }
148 186
149 #define UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( \ 187 // The suffix is |g_startups_with_current_version| up to
150 type, basename, begin_ticks, end_ticks) \ 188 // |kMaxSameVersionCountRecorded|. Higher counts are grouped in the ".Over"
151 { \ 189 // suffix. Make sure to reflect changes to |kMaxSameVersionCountRecorded| in
152 UMA_HISTOGRAM_WITH_STARTUP_TEMPERATURE(type, basename, \ 190 // the "SameVersionStartupCounts" histogram suffix.
153 end_ticks - begin_ticks) \ 191 const int kMaxSameVersionCountRecorded = 9;
gab 2016/07/07 15:41:55 constexpr
fdoray 2016/07/08 14:52:51 Done.
154 TRACE_EVENT_ASYNC_BEGIN_WITH_TIMESTAMP1( \ 192 DCHECK_GE(g_startups_with_current_version, 1);
155 "startup", basename, 0, begin_ticks.ToInternalValue(), "Temperature", \ 193 if (g_startups_with_current_version > kMaxSameVersionCountRecorded)
156 g_startup_temperature); \ 194 return ".Over";
157 TRACE_EVENT_ASYNC_END_WITH_TIMESTAMP1( \ 195 return std::string(".") + base::IntToString(g_startups_with_current_version);
158 "startup", basename, 0, end_ticks.ToInternalValue(), "Temperature", \ 196 }
159 g_startup_temperature); \
160 }
161 197
162 // Returns the system uptime on process launch. 198 // Returns the system uptime on process launch.
163 base::TimeDelta GetSystemUptimeOnProcessLaunch() { 199 base::TimeDelta GetSystemUptimeOnProcessLaunch() {
164 // Process launch time is not available on Android. 200 // Process launch time is not available on Android.
165 if (g_process_creation_ticks.Get().is_null()) 201 if (g_process_creation_ticks.Get().is_null())
166 return base::TimeDelta(); 202 return base::TimeDelta();
167 203
168 // base::SysInfo::Uptime returns the time elapsed between system boot and now. 204 // base::SysInfo::Uptime returns the time elapsed between system boot and now.
169 // Substract the time elapsed between process launch and now to get the time 205 // Substract the time elapsed between process launch and now to get the time
170 // elapsed between system boot and process launch. 206 // elapsed between system boot and process launch.
171 return base::SysInfo::Uptime() - 207 return base::SysInfo::Uptime() -
172 (base::TimeTicks::Now() - g_process_creation_ticks.Get()); 208 (base::TimeTicks::Now() - g_process_creation_ticks.Get());
173 } 209 }
174 210
175 void RecordSystemUptimeHistogram() { 211 void RecordSystemUptimeHistogram() {
176 const base::TimeDelta system_uptime_on_process_launch = 212 const base::TimeDelta system_uptime_on_process_launch =
177 GetSystemUptimeOnProcessLaunch(); 213 GetSystemUptimeOnProcessLaunch();
178 if (system_uptime_on_process_launch.is_zero()) 214 if (system_uptime_on_process_launch.is_zero())
179 return; 215 return;
180 216
181 UMA_HISTOGRAM_WITH_STARTUP_TEMPERATURE(UMA_HISTOGRAM_LONG_TIMES_100, 217 UMA_HISTOGRAM_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
182 "Startup.SystemUptime", 218 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.SystemUptime",
183 GetSystemUptimeOnProcessLaunch()); 219 GetSystemUptimeOnProcessLaunch());
184 } 220 }
185 221
186 // On Windows, records the number of hard-faults that have occurred in the 222 // On Windows, records the number of hard-faults that have occurred in the
187 // current chrome.exe process since it was started. A version of the histograms 223 // current chrome.exe process since it was started. This is a nop on other
188 // recorded in this method suffixed by |same_version_startup_count| will also be 224 // platforms.
189 // recorded (unless |same_version_startup_count| is 0 which indicates it's 225 void RecordHardFaultHistogram() {
190 // unknown). This is a nop on other platforms.
191 void RecordHardFaultHistogram(int same_version_startup_count) {
192 #if defined(OS_WIN) 226 #if defined(OS_WIN)
193 uint32_t hard_fault_count = 0; 227 uint32_t hard_fault_count = 0;
194 228
195 // Don't record histograms if unable to get the hard fault count. 229 // Don't record histograms if unable to get the hard fault count.
196 if (!GetHardFaultCountForCurrentProcess(&hard_fault_count)) 230 if (!GetHardFaultCountForCurrentProcess(&hard_fault_count))
197 return; 231 return;
198 232
199 std::string same_version_startup_count_suffix; 233 const std::string same_version_startup_count_suffix(
200 if (same_version_startup_count != 0) { 234 GetSameVersionStartupCountSuffix());
201 // Histograms below will be suffixed by |same_version_startup_count| up to
202 // |kMaxSameVersionCountRecorded|, higher counts will be grouped in the
203 // ".Over" suffix. Make sure to reflect changes to
204 // kMaxSameVersionCountRecorded in the "SameVersionStartupCounts" histogram
205 // suffix.
206 const int kMaxSameVersionCountRecorded = 9;
207 same_version_startup_count_suffix.push_back('.');
208 DCHECK_GE(same_version_startup_count, 1);
209 if (same_version_startup_count <= kMaxSameVersionCountRecorded) {
210 same_version_startup_count_suffix.append(
211 base::IntToString(same_version_startup_count));
212 } else {
213 same_version_startup_count_suffix.append("Over");
214 }
215 }
216 235
217 // Hard fault counts are expected to be in the thousands range, 236 // Hard fault counts are expected to be in the thousands range,
218 // corresponding to faulting in ~10s of MBs of code ~10s of KBs at a time. 237 // corresponding to faulting in ~10s of MBs of code ~10s of KBs at a time.
219 // (Observed to vary from 1000 to 10000 on various test machines and 238 // (Observed to vary from 1000 to 10000 on various test machines and
220 // platforms.) 239 // platforms.)
221 const char kHardFaultCountHistogram[] = 240 const char kHardFaultCountHistogram[] =
222 "Startup.BrowserMessageLoopStartHardFaultCount"; 241 "Startup.BrowserMessageLoopStartHardFaultCount";
223 UMA_HISTOGRAM_CUSTOM_COUNTS(kHardFaultCountHistogram, hard_fault_count, 1, 242 UMA_HISTOGRAM_CUSTOM_COUNTS(kHardFaultCountHistogram, hard_fault_count, 1,
224 40000, 50); 243 40000, 50);
225 // Also record the hard fault count histogram suffixed by the number of 244 // Also record the hard fault count histogram suffixed by the number of
226 // startups this specific version has been through. 245 // startups this specific version has been through.
227 // Factory properties copied from UMA_HISTOGRAM_CUSTOM_COUNTS macro.
228 if (!same_version_startup_count_suffix.empty()) { 246 if (!same_version_startup_count_suffix.empty()) {
229 base::Histogram::FactoryGet( 247 UMA_HISTOGRAM_CUSTOM_COUNTS(
gab 2016/07/07 15:41:56 Add a comment that this method should only be call
fdoray 2016/07/08 14:52:51 Done.
230 kHardFaultCountHistogram + same_version_startup_count_suffix, 1, 40000, 248 kHardFaultCountHistogram + same_version_startup_count_suffix,
231 50, base::HistogramBase::kUmaTargetedHistogramFlag) 249 hard_fault_count, 1, 40000, 50);
232 ->Add(hard_fault_count);
233 } 250 }
234 251
235 // Determine the startup type based on the number of observed hard faults. 252 // Determine the startup type based on the number of observed hard faults.
236 DCHECK_EQ(UNDETERMINED_STARTUP_TEMPERATURE, g_startup_temperature); 253 DCHECK_EQ(UNDETERMINED_STARTUP_TEMPERATURE, g_startup_temperature);
237 if (hard_fault_count < WARM_START_HARD_FAULT_COUNT_THRESHOLD) { 254 if (hard_fault_count < WARM_START_HARD_FAULT_COUNT_THRESHOLD) {
238 g_startup_temperature = WARM_STARTUP_TEMPERATURE; 255 g_startup_temperature = WARM_STARTUP_TEMPERATURE;
239 } else if (hard_fault_count >= COLD_START_HARD_FAULT_COUNT_THRESHOLD) { 256 } else if (hard_fault_count >= COLD_START_HARD_FAULT_COUNT_THRESHOLD) {
240 g_startup_temperature = COLD_STARTUP_TEMPERATURE; 257 g_startup_temperature = COLD_STARTUP_TEMPERATURE;
241 } else { 258 } else {
242 g_startup_temperature = LUKEWARM_STARTUP_TEMPERATURE; 259 g_startup_temperature = LUKEWARM_STARTUP_TEMPERATURE;
243 } 260 }
244 261
245 // Record the startup 'temperature'. 262 // Record the startup 'temperature'.
246 const char kStartupTemperatureHistogram[] = "Startup.Temperature"; 263 const char kStartupTemperatureHistogram[] = "Startup.Temperature";
247 UMA_HISTOGRAM_ENUMERATION(kStartupTemperatureHistogram, g_startup_temperature, 264 UMA_HISTOGRAM_ENUMERATION(kStartupTemperatureHistogram, g_startup_temperature,
248 STARTUP_TEMPERATURE_COUNT); 265 STARTUP_TEMPERATURE_COUNT);
249 // As well as its suffixed twin. 266 // As well as its suffixed twin.
250 // Factory properties copied from UMA_HISTOGRAM_ENUMERATION macro.
251 if (!same_version_startup_count_suffix.empty()) { 267 if (!same_version_startup_count_suffix.empty()) {
252 base::LinearHistogram::FactoryGet( 268 UMA_HISTOGRAM_ENUMERATION(
253 kStartupTemperatureHistogram + same_version_startup_count_suffix, 1, 269 kStartupTemperatureHistogram + same_version_startup_count_suffix,
254 STARTUP_TEMPERATURE_COUNT, STARTUP_TEMPERATURE_COUNT + 1, 270 g_startup_temperature, STARTUP_TEMPERATURE_COUNT);
255 base::HistogramBase::kUmaTargetedHistogramFlag)
256 ->Add(g_startup_temperature);
257 } 271 }
258 #endif // defined(OS_WIN) 272 #endif // defined(OS_WIN)
259 } 273 }
260 274
261 // Converts a base::Time value to a base::TimeTicks value. The conversion isn't 275 // Converts a base::Time value to a base::TimeTicks value. The conversion isn't
262 // exact, but by capturing Time::Now() as early as possible, the likelihood of a 276 // exact, but by capturing Time::Now() as early as possible, the likelihood of a
263 // clock change between it and process start is as low as possible. There is 277 // clock change between it and process start is as low as possible. There is
264 // also the time taken to synchronously resolve base::Time::Now() and 278 // also the time taken to synchronously resolve base::Time::Now() and
265 // base::TimeTicks::Now() at play, but in practice it is pretty much instant 279 // base::TimeTicks::Now() at play, but in practice it is pretty much instant
266 // compared to multi-seconds startup timings. 280 // compared to multi-seconds startup timings.
(...skipping 64 matching lines...) Expand 10 before | Expand all | Expand 10 after
331 345
332 // Record renderer main entry time histogram. 346 // Record renderer main entry time histogram.
333 void RecordRendererMainEntryHistogram() { 347 void RecordRendererMainEntryHistogram() {
334 const base::TimeTicks& browser_main_entry_point_ticks = 348 const base::TimeTicks& browser_main_entry_point_ticks =
335 g_browser_main_entry_point_ticks.Get(); 349 g_browser_main_entry_point_ticks.Get();
336 const base::TimeTicks& renderer_main_entry_point_ticks = 350 const base::TimeTicks& renderer_main_entry_point_ticks =
337 g_renderer_main_entry_point_ticks.Get(); 351 g_renderer_main_entry_point_ticks.Get();
338 352
339 if (!browser_main_entry_point_ticks.is_null() && 353 if (!browser_main_entry_point_ticks.is_null() &&
340 !renderer_main_entry_point_ticks.is_null()) { 354 !renderer_main_entry_point_ticks.is_null()) {
341 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 355 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
342 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.BrowserMainToRendererMain", 356 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.BrowserMainToRendererMain",
343 browser_main_entry_point_ticks, renderer_main_entry_point_ticks); 357 browser_main_entry_point_ticks, renderer_main_entry_point_ticks);
344 } 358 }
345 } 359 }
346 360
347 // Environment variable that stores the timestamp when the executable's main() 361 // Environment variable that stores the timestamp when the executable's main()
348 // function was entered in TimeTicks. This is required because chrome.exe and 362 // function was entered in TimeTicks. This is required because chrome.exe and
349 // chrome.dll don't share the same static storage. 363 // chrome.dll don't share the same static storage.
350 const char kChromeMainTicksEnvVar[] = "CHROME_MAIN_TICKS"; 364 const char kChromeMainTicksEnvVar[] = "CHROME_MAIN_TICKS";
351 365
(...skipping 44 matching lines...) Expand 10 before | Expand all | Expand 10 after
396 if (last_startup_timestamp_internal != 0) { 410 if (last_startup_timestamp_internal != 0) {
397 // Log the Startup.TimeSinceLastStartup histogram. 411 // Log the Startup.TimeSinceLastStartup histogram.
398 const base::Time last_startup_timestamp = 412 const base::Time last_startup_timestamp =
399 base::Time::FromInternalValue(last_startup_timestamp_internal); 413 base::Time::FromInternalValue(last_startup_timestamp_internal);
400 const base::TimeDelta time_since_last_startup = 414 const base::TimeDelta time_since_last_startup =
401 process_start_time - last_startup_timestamp; 415 process_start_time - last_startup_timestamp;
402 const int minutes_since_last_startup = time_since_last_startup.InMinutes(); 416 const int minutes_since_last_startup = time_since_last_startup.InMinutes();
403 417
404 // Ignore negative values, which can be caused by system clock changes. 418 // Ignore negative values, which can be caused by system clock changes.
405 if (minutes_since_last_startup >= 0) { 419 if (minutes_since_last_startup >= 0) {
406 UMA_HISTOGRAM_WITH_STARTUP_TEMPERATURE( 420 UMA_HISTOGRAM_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
407 UMA_HISTOGRAM_TIME_IN_MINUTES_MONTH_RANGE, 421 UMA_HISTOGRAM_TIME_IN_MINUTES_MONTH_RANGE,
408 "Startup.TimeSinceLastStartup", minutes_since_last_startup); 422 "Startup.TimeSinceLastStartup", minutes_since_last_startup);
409 } 423 }
410 } 424 }
411 425
412 // Write the timestamp of the current startup in |pref_service|. 426 // Write the timestamp of the current startup in |pref_service|.
413 pref_service->SetInt64(prefs::kLastStartupTimestamp, 427 pref_service->SetInt64(prefs::kLastStartupTimestamp,
414 process_start_time.ToInternalValue()); 428 process_start_time.ToInternalValue());
415 #endif // defined(OS_MACOSX) || defined(OS_WIN) || defined(OS_LINUX) 429 #endif // defined(OS_MACOSX) || defined(OS_WIN) || defined(OS_LINUX)
416 } 430 }
417 431
418 // Logs the Startup.SameVersionStartupCount histogram. Relies on |pref_service| 432 // Logs the Startup.SameVersionStartupCount histogram. Relies on |pref_service|
419 // to know information about the previous startups and store information for 433 // to know information about the previous startups and store information for
420 // future ones. Returns the number of startups with the same version count that 434 // future ones. Stores the logged value in |g_startups_with_current_version|.
421 // was logged. 435 void RecordSameVersionStartupCount(PrefService* pref_service) {
422 int RecordSameVersionStartupCount(PrefService* pref_service) {
423 DCHECK(pref_service); 436 DCHECK(pref_service);
437 DCHECK_EQ(kUndeterminedStartupsWithCurrentVersion,
438 g_startups_with_current_version);
424 439
425 const std::string current_version = version_info::GetVersionNumber(); 440 const std::string current_version = version_info::GetVersionNumber();
426 441
427 int startups_with_current_version = 0;
428 if (current_version == pref_service->GetString(prefs::kLastStartupVersion)) { 442 if (current_version == pref_service->GetString(prefs::kLastStartupVersion)) {
429 startups_with_current_version = 443 g_startups_with_current_version =
430 pref_service->GetInteger(prefs::kSameVersionStartupCount); 444 pref_service->GetInteger(prefs::kSameVersionStartupCount);
431 ++startups_with_current_version; 445 ++g_startups_with_current_version;
432 pref_service->SetInteger(prefs::kSameVersionStartupCount, 446 pref_service->SetInteger(prefs::kSameVersionStartupCount,
433 startups_with_current_version); 447 g_startups_with_current_version);
434 } else { 448 } else {
435 startups_with_current_version = 1; 449 g_startups_with_current_version = 1;
436 pref_service->SetString(prefs::kLastStartupVersion, current_version); 450 pref_service->SetString(prefs::kLastStartupVersion, current_version);
437 pref_service->SetInteger(prefs::kSameVersionStartupCount, 1); 451 pref_service->SetInteger(prefs::kSameVersionStartupCount, 1);
438 } 452 }
439 453
440 UMA_HISTOGRAM_COUNTS_100("Startup.SameVersionStartupCount", 454 UMA_HISTOGRAM_COUNTS_100("Startup.SameVersionStartupCount",
441 startups_with_current_version); 455 g_startups_with_current_version);
442 return startups_with_current_version;
443 } 456 }
444 457
445 } // namespace 458 } // namespace
446 459
447 #if defined(OS_WIN) 460 #if defined(OS_WIN)
448 bool GetHardFaultCountForCurrentProcess(uint32_t* hard_fault_count) { 461 bool GetHardFaultCountForCurrentProcess(uint32_t* hard_fault_count) {
449 DCHECK(hard_fault_count); 462 DCHECK(hard_fault_count);
450 463
451 if (base::win::GetVersion() < base::win::VERSION_WIN7) 464 if (base::win::GetVersion() < base::win::VERSION_WIN7)
452 return false; 465 return false;
(...skipping 85 matching lines...) Expand 10 before | Expand all | Expand 10 after
538 void RecordExeMainEntryPointTime(const base::Time& time) { 551 void RecordExeMainEntryPointTime(const base::Time& time) {
539 const std::string exe_load_ticks = 552 const std::string exe_load_ticks =
540 base::Int64ToString(StartupTimeToTimeTicks(time).ToInternalValue()); 553 base::Int64ToString(StartupTimeToTimeTicks(time).ToInternalValue());
541 std::unique_ptr<base::Environment> env(base::Environment::Create()); 554 std::unique_ptr<base::Environment> env(base::Environment::Create());
542 env->SetVar(kChromeMainTicksEnvVar, exe_load_ticks); 555 env->SetVar(kChromeMainTicksEnvVar, exe_load_ticks);
543 } 556 }
544 557
545 void RecordBrowserMainMessageLoopStart(const base::TimeTicks& ticks, 558 void RecordBrowserMainMessageLoopStart(const base::TimeTicks& ticks,
546 bool is_first_run, 559 bool is_first_run,
547 PrefService* pref_service) { 560 PrefService* pref_service) {
548 int same_version_startup_count = 0;
549 if (pref_service) 561 if (pref_service)
550 same_version_startup_count = RecordSameVersionStartupCount(pref_service); 562 RecordSameVersionStartupCount(pref_service);
551 // Keep RecordHardFaultHistogram() first as much as possible as many other 563 // Keep RecordHardFaultHistogram() first as much as possible as many other
552 // histograms depend on it setting |g_startup_temperature|. 564 // histograms depend on it setting |g_startup_temperature|.
553 RecordHardFaultHistogram(same_version_startup_count); 565 RecordHardFaultHistogram();
554 AddStartupEventsForTelemetry(); 566 AddStartupEventsForTelemetry();
555 if (pref_service) 567 if (pref_service)
556 RecordTimeSinceLastStartup(pref_service); 568 RecordTimeSinceLastStartup(pref_service);
557 RecordSystemUptimeHistogram(); 569 RecordSystemUptimeHistogram();
558 RecordMainEntryTimeHistogram(); 570 RecordMainEntryTimeHistogram();
559 571
560 const base::TimeTicks& process_creation_ticks = 572 const base::TimeTicks& process_creation_ticks =
561 g_process_creation_ticks.Get(); 573 g_process_creation_ticks.Get();
562 if (!is_first_run && !process_creation_ticks.is_null()) { 574 if (!is_first_run && !process_creation_ticks.is_null()) {
563 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 575 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
564 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.BrowserMessageLoopStartTime", 576 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.BrowserMessageLoopStartTime",
565 process_creation_ticks, ticks); 577 process_creation_ticks, ticks);
566 } 578 }
567 579
568 // Bail if uptime < 7 minutes, to filter out cases where Chrome may have been 580 // Bail if uptime < 7 minutes, to filter out cases where Chrome may have been
569 // autostarted and the machine is under io pressure. 581 // autostarted and the machine is under io pressure.
570 if (base::SysInfo::Uptime() < base::TimeDelta::FromMinutes(7)) 582 if (base::SysInfo::Uptime() < base::TimeDelta::FromMinutes(7))
571 return; 583 return;
572 584
573 // The Startup.BrowserMessageLoopStartTime histogram exhibits instability in 585 // The Startup.BrowserMessageLoopStartTime histogram exhibits instability in
574 // the field which limits its usefulness in all scenarios except when we have 586 // the field which limits its usefulness in all scenarios except when we have
575 // a very large sample size. Attempt to mitigate this with a new metric: 587 // a very large sample size. Attempt to mitigate this with a new metric:
576 // * Measure time from main entry rather than the OS' notion of process start. 588 // * Measure time from main entry rather than the OS' notion of process start.
577 // * Only measure launches that occur 7 minutes after boot to try to avoid 589 // * Only measure launches that occur 7 minutes after boot to try to avoid
578 // cases where Chrome is auto-started and IO is heavily loaded. 590 // cases where Chrome is auto-started and IO is heavily loaded.
579 if (is_first_run) { 591 if (is_first_run) {
580 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 592 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
581 UMA_HISTOGRAM_LONG_TIMES, 593 UMA_HISTOGRAM_LONG_TIMES,
582 "Startup.BrowserMessageLoopStartTimeFromMainEntry.FirstRun", 594 "Startup.BrowserMessageLoopStartTimeFromMainEntry.FirstRun",
583 g_browser_main_entry_point_ticks.Get(), ticks); 595 g_browser_main_entry_point_ticks.Get(), ticks);
584 } else { 596 } else {
585 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 597 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
586 UMA_HISTOGRAM_LONG_TIMES, 598 UMA_HISTOGRAM_LONG_TIMES,
587 "Startup.BrowserMessageLoopStartTimeFromMainEntry", 599 "Startup.BrowserMessageLoopStartTimeFromMainEntry",
588 g_browser_main_entry_point_ticks.Get(), ticks); 600 g_browser_main_entry_point_ticks.Get(), ticks);
589 } 601 }
590 602
591 // Record timings between process creation, the main() in the executable being 603 // Record timings between process creation, the main() in the executable being
592 // reached and the main() in the shared library being reached. 604 // reached and the main() in the shared library being reached.
593 if (!process_creation_ticks.is_null()) { 605 if (!process_creation_ticks.is_null()) {
594 const base::TimeTicks exe_main_ticks = ExeMainEntryPointTicks(); 606 const base::TimeTicks exe_main_ticks = ExeMainEntryPointTicks();
595 if (!exe_main_ticks.is_null()) { 607 if (!exe_main_ticks.is_null()) {
596 // Process create to chrome.exe:main(). 608 // Process create to chrome.exe:main().
597 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 609 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
598 UMA_HISTOGRAM_LONG_TIMES, "Startup.LoadTime.ProcessCreateToExeMain", 610 UMA_HISTOGRAM_LONG_TIMES, "Startup.LoadTime.ProcessCreateToExeMain",
599 process_creation_ticks, exe_main_ticks); 611 process_creation_ticks, exe_main_ticks);
600 612
601 // chrome.exe:main() to chrome.dll:main(). 613 // chrome.exe:main() to chrome.dll:main().
602 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 614 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
603 UMA_HISTOGRAM_LONG_TIMES, "Startup.LoadTime.ExeMainToDllMain", 615 UMA_HISTOGRAM_LONG_TIMES, "Startup.LoadTime.ExeMainToDllMain",
604 exe_main_ticks, g_browser_main_entry_point_ticks.Get()); 616 exe_main_ticks, g_browser_main_entry_point_ticks.Get());
605 617
606 // Process create to chrome.dll:main(). Reported as a histogram only as 618 // Process create to chrome.dll:main(). Reported as a histogram only as
607 // the other two events above are sufficient for tracing purposes. 619 // the other two events above are sufficient for tracing purposes.
608 UMA_HISTOGRAM_WITH_STARTUP_TEMPERATURE( 620 UMA_HISTOGRAM_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
609 UMA_HISTOGRAM_LONG_TIMES, "Startup.LoadTime.ProcessCreateToDllMain", 621 UMA_HISTOGRAM_LONG_TIMES, "Startup.LoadTime.ProcessCreateToDllMain",
610 g_browser_main_entry_point_ticks.Get() - process_creation_ticks); 622 g_browser_main_entry_point_ticks.Get() - process_creation_ticks);
611 } 623 }
612 } 624 }
613 } 625 }
614 626
615 void RecordBrowserWindowDisplay(const base::TimeTicks& ticks) { 627 void RecordBrowserWindowDisplay(const base::TimeTicks& ticks) {
616 static bool is_first_call = true; 628 static bool is_first_call = true;
617 if (!is_first_call || ticks.is_null()) 629 if (!is_first_call || ticks.is_null())
618 return; 630 return;
619 is_first_call = false; 631 is_first_call = false;
620 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null()) 632 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null())
621 return; 633 return;
622 634
623 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 635 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
624 UMA_HISTOGRAM_LONG_TIMES, "Startup.BrowserWindowDisplay", 636 UMA_HISTOGRAM_LONG_TIMES, "Startup.BrowserWindowDisplay",
625 g_process_creation_ticks.Get(), ticks); 637 g_process_creation_ticks.Get(), ticks);
626 } 638 }
627 639
628 void RecordBrowserOpenTabsDelta(const base::TimeDelta& delta) { 640 void RecordBrowserOpenTabsDelta(const base::TimeDelta& delta) {
629 static bool is_first_call = true; 641 static bool is_first_call = true;
630 if (!is_first_call) 642 if (!is_first_call)
631 return; 643 return;
632 is_first_call = false; 644 is_first_call = false;
633 645
634 UMA_HISTOGRAM_WITH_STARTUP_TEMPERATURE(UMA_HISTOGRAM_LONG_TIMES_100, 646 UMA_HISTOGRAM_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
635 "Startup.BrowserOpenTabs", delta); 647 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.BrowserOpenTabs", delta);
636 } 648 }
637 649
638 void RecordRendererMainEntryTime(const base::TimeTicks& ticks) { 650 void RecordRendererMainEntryTime(const base::TimeTicks& ticks) {
639 // Record the renderer main entry time, but don't log the UMA metric 651 // Record the renderer main entry time, but don't log the UMA metric
640 // immediately because the startup temperature is not known yet. 652 // immediately because the startup temperature is not known yet.
641 if (g_renderer_main_entry_point_ticks.Get().is_null()) 653 if (g_renderer_main_entry_point_ticks.Get().is_null())
642 g_renderer_main_entry_point_ticks.Get() = ticks; 654 g_renderer_main_entry_point_ticks.Get() = ticks;
643 } 655 }
644 656
645 void RecordFirstWebContentsMainFrameLoad(const base::TimeTicks& ticks) { 657 void RecordFirstWebContentsMainFrameLoad(const base::TimeTicks& ticks) {
646 static bool is_first_call = true; 658 static bool is_first_call = true;
647 if (!is_first_call || ticks.is_null()) 659 if (!is_first_call || ticks.is_null())
648 return; 660 return;
649 is_first_call = false; 661 is_first_call = false;
650 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null()) 662 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null())
651 return; 663 return;
652 664
653 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 665 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
654 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.FirstWebContents.MainFrameLoad2", 666 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.FirstWebContents.MainFrameLoad2",
655 g_process_creation_ticks.Get(), ticks); 667 g_process_creation_ticks.Get(), ticks);
656 } 668 }
657 669
658 void RecordFirstWebContentsNonEmptyPaint(const base::TimeTicks& ticks) { 670 void RecordFirstWebContentsNonEmptyPaint(const base::TimeTicks& ticks) {
659 static bool is_first_call = true; 671 static bool is_first_call = true;
660 if (!is_first_call || ticks.is_null()) 672 if (!is_first_call || ticks.is_null())
661 return; 673 return;
662 is_first_call = false; 674 is_first_call = false;
663 675
664 // Log Startup.BrowserMainToRendererMain now that the first renderer main 676 // Log Startup.BrowserMainToRendererMain now that the first renderer main
665 // entry time and the startup temperature are known. 677 // entry time and the startup temperature are known.
666 RecordRendererMainEntryHistogram(); 678 RecordRendererMainEntryHistogram();
667 679
668 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null()) 680 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null())
669 return; 681 return;
670 682
671 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 683 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
672 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.FirstWebContents.NonEmptyPaint2", 684 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.FirstWebContents.NonEmptyPaint2",
673 g_process_creation_ticks.Get(), ticks); 685 g_process_creation_ticks.Get(), ticks);
674 } 686 }
675 687
676 void RecordFirstWebContentsMainNavigationStart(const base::TimeTicks& ticks) { 688 void RecordFirstWebContentsMainNavigationStart(const base::TimeTicks& ticks) {
677 static bool is_first_call = true; 689 static bool is_first_call = true;
678 if (!is_first_call || ticks.is_null()) 690 if (!is_first_call || ticks.is_null())
679 return; 691 return;
680 is_first_call = false; 692 is_first_call = false;
681 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null()) 693 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null())
682 return; 694 return;
683 695
684 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 696 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
685 UMA_HISTOGRAM_LONG_TIMES_100, 697 UMA_HISTOGRAM_LONG_TIMES_100,
686 "Startup.FirstWebContents.MainNavigationStart", 698 "Startup.FirstWebContents.MainNavigationStart",
687 g_process_creation_ticks.Get(), ticks); 699 g_process_creation_ticks.Get(), ticks);
688 } 700 }
689 701
690 void RecordFirstWebContentsMainNavigationFinished( 702 void RecordFirstWebContentsMainNavigationFinished(
691 const base::TimeTicks& ticks) { 703 const base::TimeTicks& ticks) {
692 static bool is_first_call = true; 704 static bool is_first_call = true;
693 if (!is_first_call || ticks.is_null()) 705 if (!is_first_call || ticks.is_null())
694 return; 706 return;
695 is_first_call = false; 707 is_first_call = false;
696 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null()) 708 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null())
697 return; 709 return;
698 710
699 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 711 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
700 UMA_HISTOGRAM_LONG_TIMES_100, 712 UMA_HISTOGRAM_LONG_TIMES_100,
701 "Startup.FirstWebContents.MainNavigationFinished", 713 "Startup.FirstWebContents.MainNavigationFinished",
702 g_process_creation_ticks.Get(), ticks); 714 g_process_creation_ticks.Get(), ticks);
703 } 715 }
704 716
705 base::TimeTicks MainEntryPointTicks() { 717 base::TimeTicks MainEntryPointTicks() {
706 return g_browser_main_entry_point_ticks.Get(); 718 return g_browser_main_entry_point_ticks.Get();
707 } 719 }
708 720
709 StartupTemperature GetStartupTemperature() { 721 StartupTemperature GetStartupTemperature() {
710 return g_startup_temperature; 722 return g_startup_temperature;
711 } 723 }
712 724
713 } // namespace startup_metric_utils 725 } // namespace startup_metric_utils
OLDNEW

Powered by Google App Engine
This is Rietveld 408576698