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 <memory> | 9 #include <memory> |
10 | 10 |
(...skipping 38 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
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 Loading... | |
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 Loading... | |
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 Loading... | |
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 Loading... | |
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 |
OLD | NEW |