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

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: cr rkaplow 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
« no previous file with comments | « base/trace_event/common/trace_event_common.h ('k') | tools/metrics/histograms/histograms.xml » ('j') | no next file with comments »
Toggle Intra-line Diffs ('i') | Expand Comments ('e') | Collapse Comments ('c') | Show Comments Hide Comments ('s')
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.
112 // |type| is the histogram type, and corresponds to an UMA macro like 115 // |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 116 // UMA_HISTOGRAM_LONG_TIMES. It must itself be a macro that only takes two
114 // parameters. 117 // parameters.
115 // |basename| is the basename of the histogram. A histogram of this name will 118 // |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 119 // 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 120 // also be recorded to the histogram with name |basename| and suffix
118 // ".ColdStart" or ".WarmStart", as appropriate. 121 // ".ColdStart", ".WarmStart" or ".LukewarmStartup" as appropriate.
119 // |value_expr| is an expression evaluating to the value to be recorded. This 122 // |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. 123 // 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 124 // A metric logged using this macro must have an affected-histogram entry in the
122 // definition of the StartupTemperature suffix in histograms.xml. 125 // definition of the StartupTemperature suffix in histograms.xml.
123 // This macro must only be used in code that runs after |g_startup_temperature| 126 // This macro must only be used in code that runs after |g_startup_temperature|
124 // has been initialized. 127 // has been initialized.
125 #define UMA_HISTOGRAM_WITH_STARTUP_TEMPERATURE(type, basename, value_expr) \ 128 #define UMA_HISTOGRAM_WITH_TEMPERATURE(type, basename, value_expr) \
126 { \ 129 do { \
127 const auto kValue = value_expr; \ 130 const auto value = value_expr; \
128 /* Always record to the base histogram. */ \ 131 /* Always record to the base histogram. */ \
129 type(basename, kValue); \ 132 type(basename, value); \
130 /* Record to the cold/warm/lukewarm suffixed histogram as appropriate. */ \ 133 /* Record to the cold/warm/lukewarm suffixed histogram as appropriate. */ \
131 switch (g_startup_temperature) { \ 134 switch (g_startup_temperature) { \
132 case COLD_STARTUP_TEMPERATURE: \ 135 case COLD_STARTUP_TEMPERATURE: \
133 type(basename ".ColdStartup", kValue); \ 136 type(basename ".ColdStartup", value); \
134 break; \ 137 break; \
135 case WARM_STARTUP_TEMPERATURE: \ 138 case WARM_STARTUP_TEMPERATURE: \
136 type(basename ".WarmStartup", kValue); \ 139 type(basename ".WarmStartup", value); \
137 break; \ 140 break; \
138 case LUKEWARM_STARTUP_TEMPERATURE: \ 141 case LUKEWARM_STARTUP_TEMPERATURE: \
139 type(basename ".LukewarmStartup", kValue); \ 142 type(basename ".LukewarmStartup", value); \
140 break; \ 143 break; \
141 case UNDETERMINED_STARTUP_TEMPERATURE: \ 144 case UNDETERMINED_STARTUP_TEMPERATURE: \
142 break; \ 145 break; \
143 case STARTUP_TEMPERATURE_COUNT: \ 146 case STARTUP_TEMPERATURE_COUNT: \
144 NOTREACHED(); \ 147 NOTREACHED(); \
145 break; \ 148 break; \
146 } \ 149 } \
147 } 150 } while (0)
148 151
149 #define UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( \ 152 // Records |value_expr| to the histogram with name |basename| suffixed with the
150 type, basename, begin_ticks, end_ticks) \ 153 // number of startups with the current version in addition to all histograms
151 { \ 154 // recorded by UMA_HISTOGRAM_WITH_TEMPERATURE.
152 UMA_HISTOGRAM_WITH_STARTUP_TEMPERATURE(type, basename, \ 155 // A metric logged using this macro must have affected-histogram entries in the
153 end_ticks - begin_ticks) \ 156 // definition of the StartupTemperature and SameVersionStartupCounts suffixes in
157 // histograms.xml.
158 // This macro must only be used in code that runs after |g_startup_temperature|
159 // and |g_startups_with_current_version| have been initialized.
160 #define UMA_HISTOGRAM_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(type, basename, \
161 value_expr) \
162 do { \
163 const auto value_same_version_count = value_expr; \
164 /* Record to the base histogram and to a histogram suffixed with the \
165 startup temperature. */ \
166 UMA_HISTOGRAM_WITH_TEMPERATURE(type, basename, value_same_version_count); \
167 /* Record to a histogram suffixed with the number of startups for the \
168 current version. Since the number of startups for the current version \
169 is set once per process, using a histogram macro which expects a \
170 constant histogram name across invocations is fine. */ \
171 const auto same_version_startup_count_suffix = \
172 GetSameVersionStartupCountSuffix(); \
173 if (!same_version_startup_count_suffix.empty()) { \
174 type(basename + same_version_startup_count_suffix, \
175 value_same_version_count); \
176 } \
177 } while (0)
178
179 #define UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE(type, basename, begin_ticks, \
180 end_ticks) \
181 do { \
182 UMA_HISTOGRAM_WITH_TEMPERATURE(type, basename, end_ticks - begin_ticks); \
154 TRACE_EVENT_ASYNC_BEGIN_WITH_TIMESTAMP1( \ 183 TRACE_EVENT_ASYNC_BEGIN_WITH_TIMESTAMP1( \
155 "startup", basename, 0, begin_ticks.ToInternalValue(), "Temperature", \ 184 "startup", basename, 0, begin_ticks.ToInternalValue(), "Temperature", \
156 g_startup_temperature); \ 185 g_startup_temperature); \
157 TRACE_EVENT_ASYNC_END_WITH_TIMESTAMP1( \ 186 TRACE_EVENT_ASYNC_END_WITH_TIMESTAMP1( \
158 "startup", basename, 0, end_ticks.ToInternalValue(), "Temperature", \ 187 "startup", basename, 0, end_ticks.ToInternalValue(), "Temperature", \
159 g_startup_temperature); \ 188 g_startup_temperature); \
189 } while (0)
190
191 #define UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT( \
192 type, basename, begin_ticks, end_ticks) \
193 do { \
194 UMA_HISTOGRAM_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT( \
195 type, basename, end_ticks - begin_ticks); \
196 TRACE_EVENT_ASYNC_BEGIN_WITH_TIMESTAMP2( \
197 "startup", basename, 0, begin_ticks.ToInternalValue(), "Temperature", \
198 g_startup_temperature, "Startups with current version", \
199 g_startups_with_current_version); \
200 TRACE_EVENT_ASYNC_END_WITH_TIMESTAMP2( \
201 "startup", basename, 0, end_ticks.ToInternalValue(), "Temperature", \
202 g_startup_temperature, "Startups with current version", \
203 g_startups_with_current_version); \
204 } while (0)
205
206 std::string GetSameVersionStartupCountSuffix() {
207 // TODO(fdoray): Remove this once crbug.com/580207 is fixed.
208 if (g_startups_with_current_version ==
209 kUndeterminedStartupsWithCurrentVersion) {
210 return std::string();
160 } 211 }
161 212
213 // The suffix is |g_startups_with_current_version| up to
214 // |kMaxSameVersionCountRecorded|. Higher counts are grouped in the ".Over"
215 // suffix. Make sure to reflect changes to |kMaxSameVersionCountRecorded| in
216 // the "SameVersionStartupCounts" histogram suffix.
217 constexpr int kMaxSameVersionCountRecorded = 9;
218 DCHECK_GE(g_startups_with_current_version, 1);
219 if (g_startups_with_current_version > kMaxSameVersionCountRecorded)
220 return ".Over";
221 return std::string(".") + base::IntToString(g_startups_with_current_version);
222 }
223
162 // Returns the system uptime on process launch. 224 // Returns the system uptime on process launch.
163 base::TimeDelta GetSystemUptimeOnProcessLaunch() { 225 base::TimeDelta GetSystemUptimeOnProcessLaunch() {
164 // Process launch time is not available on Android. 226 // Process launch time is not available on Android.
165 if (g_process_creation_ticks.Get().is_null()) 227 if (g_process_creation_ticks.Get().is_null())
166 return base::TimeDelta(); 228 return base::TimeDelta();
167 229
168 // base::SysInfo::Uptime returns the time elapsed between system boot and now. 230 // 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 231 // Substract the time elapsed between process launch and now to get the time
170 // elapsed between system boot and process launch. 232 // elapsed between system boot and process launch.
171 return base::SysInfo::Uptime() - 233 return base::SysInfo::Uptime() -
172 (base::TimeTicks::Now() - g_process_creation_ticks.Get()); 234 (base::TimeTicks::Now() - g_process_creation_ticks.Get());
173 } 235 }
174 236
175 void RecordSystemUptimeHistogram() { 237 void RecordSystemUptimeHistogram() {
176 const base::TimeDelta system_uptime_on_process_launch = 238 const base::TimeDelta system_uptime_on_process_launch =
177 GetSystemUptimeOnProcessLaunch(); 239 GetSystemUptimeOnProcessLaunch();
178 if (system_uptime_on_process_launch.is_zero()) 240 if (system_uptime_on_process_launch.is_zero())
179 return; 241 return;
180 242
181 UMA_HISTOGRAM_WITH_STARTUP_TEMPERATURE(UMA_HISTOGRAM_LONG_TIMES_100, 243 UMA_HISTOGRAM_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
182 "Startup.SystemUptime", 244 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.SystemUptime",
183 GetSystemUptimeOnProcessLaunch()); 245 GetSystemUptimeOnProcessLaunch());
184 } 246 }
185 247
186 // On Windows, records the number of hard-faults that have occurred in the 248 // 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 249 // 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 250 // platforms.
189 // recorded. This is a nop on other platforms. 251 void RecordHardFaultHistogram() {
190 void RecordHardFaultHistogram(int same_version_startup_count) {
191 #if defined(OS_WIN) 252 #if defined(OS_WIN)
192 uint32_t hard_fault_count = 0; 253 uint32_t hard_fault_count = 0;
193 254
194 // Don't record histograms if unable to get the hard fault count. 255 // Don't record histograms if unable to get the hard fault count.
195 if (!GetHardFaultCountForCurrentProcess(&hard_fault_count)) 256 if (!GetHardFaultCountForCurrentProcess(&hard_fault_count))
196 return; 257 return;
197 258
198 // Histograms below will be suffixed by |same_version_startup_count| up to 259 const std::string same_version_startup_count_suffix(
199 // |kMaxSameVersionCountRecorded|, higher counts will be grouped in the 260 GetSameVersionStartupCountSuffix());
200 // ".Over" suffix. Make sure to reflect changes to
201 // kMaxSameVersionCountRecorded in the "SameVersionStartupCounts" histogram
202 // suffix.
203 std::string same_version_startup_count_suffix(".");
204 constexpr int kMaxSameVersionCountRecorded = 9;
205 DCHECK_GE(same_version_startup_count, 1);
206 if (same_version_startup_count <= kMaxSameVersionCountRecorded) {
207 same_version_startup_count_suffix.append(
208 base::IntToString(same_version_startup_count));
209 } else {
210 same_version_startup_count_suffix.append("Over");
211 }
212 261
213 // Hard fault counts are expected to be in the thousands range, 262 // Hard fault counts are expected to be in the thousands range,
214 // corresponding to faulting in ~10s of MBs of code ~10s of KBs at a time. 263 // corresponding to faulting in ~10s of MBs of code ~10s of KBs at a time.
215 // (Observed to vary from 1000 to 10000 on various test machines and 264 // (Observed to vary from 1000 to 10000 on various test machines and
216 // platforms.) 265 // platforms.)
217 const char kHardFaultCountHistogram[] = 266 const char kHardFaultCountHistogram[] =
218 "Startup.BrowserMessageLoopStartHardFaultCount"; 267 "Startup.BrowserMessageLoopStartHardFaultCount";
219 UMA_HISTOGRAM_CUSTOM_COUNTS(kHardFaultCountHistogram, hard_fault_count, 1, 268 UMA_HISTOGRAM_CUSTOM_COUNTS(kHardFaultCountHistogram, hard_fault_count, 1,
220 40000, 50); 269 40000, 50);
221 // Also record the hard fault count histogram suffixed by the number of 270 // Also record the hard fault count histogram suffixed by the number of
222 // startups this specific version has been through. 271 // startups this specific version has been through.
223 // Factory properties copied from UMA_HISTOGRAM_CUSTOM_COUNTS macro.
gab 2016/07/11 18:09:16 Leave this comment in since still using FactoryGet
fdoray 2016/07/18 14:54:39 Done.
224 if (!same_version_startup_count_suffix.empty()) { 272 if (!same_version_startup_count_suffix.empty()) {
225 base::Histogram::FactoryGet( 273 base::Histogram::FactoryGet(
226 kHardFaultCountHistogram + same_version_startup_count_suffix, 1, 40000, 274 kHardFaultCountHistogram + same_version_startup_count_suffix, 1, 40000,
227 50, base::HistogramBase::kUmaTargetedHistogramFlag) 275 50, base::HistogramBase::kUmaTargetedHistogramFlag)
228 ->Add(hard_fault_count); 276 ->Add(hard_fault_count);
229 } 277 }
230 278
231 // Determine the startup type based on the number of observed hard faults. 279 // Determine the startup type based on the number of observed hard faults.
232 DCHECK_EQ(UNDETERMINED_STARTUP_TEMPERATURE, g_startup_temperature); 280 DCHECK_EQ(UNDETERMINED_STARTUP_TEMPERATURE, g_startup_temperature);
233 if (hard_fault_count < WARM_START_HARD_FAULT_COUNT_THRESHOLD) { 281 if (hard_fault_count < WARM_START_HARD_FAULT_COUNT_THRESHOLD) {
234 g_startup_temperature = WARM_STARTUP_TEMPERATURE; 282 g_startup_temperature = WARM_STARTUP_TEMPERATURE;
235 } else if (hard_fault_count >= COLD_START_HARD_FAULT_COUNT_THRESHOLD) { 283 } else if (hard_fault_count >= COLD_START_HARD_FAULT_COUNT_THRESHOLD) {
236 g_startup_temperature = COLD_STARTUP_TEMPERATURE; 284 g_startup_temperature = COLD_STARTUP_TEMPERATURE;
237 } else { 285 } else {
238 g_startup_temperature = LUKEWARM_STARTUP_TEMPERATURE; 286 g_startup_temperature = LUKEWARM_STARTUP_TEMPERATURE;
239 } 287 }
240 288
241 // Record the startup 'temperature'. 289 // Record the startup 'temperature'.
242 const char kStartupTemperatureHistogram[] = "Startup.Temperature"; 290 const char kStartupTemperatureHistogram[] = "Startup.Temperature";
243 UMA_HISTOGRAM_ENUMERATION(kStartupTemperatureHistogram, g_startup_temperature, 291 UMA_HISTOGRAM_ENUMERATION(kStartupTemperatureHistogram, g_startup_temperature,
244 STARTUP_TEMPERATURE_COUNT); 292 STARTUP_TEMPERATURE_COUNT);
245 // As well as its suffixed twin. 293 // As well as its suffixed twin.
246 // Factory properties copied from UMA_HISTOGRAM_ENUMERATION macro.
gab 2016/07/11 18:09:16 Ditto
fdoray 2016/07/18 14:54:39 Done.
247 if (!same_version_startup_count_suffix.empty()) { 294 if (!same_version_startup_count_suffix.empty()) {
248 base::LinearHistogram::FactoryGet( 295 base::LinearHistogram::FactoryGet(
249 kStartupTemperatureHistogram + same_version_startup_count_suffix, 1, 296 kStartupTemperatureHistogram + same_version_startup_count_suffix, 1,
250 STARTUP_TEMPERATURE_COUNT, STARTUP_TEMPERATURE_COUNT + 1, 297 STARTUP_TEMPERATURE_COUNT, STARTUP_TEMPERATURE_COUNT + 1,
251 base::HistogramBase::kUmaTargetedHistogramFlag) 298 base::HistogramBase::kUmaTargetedHistogramFlag)
252 ->Add(g_startup_temperature); 299 ->Add(g_startup_temperature);
253 } 300 }
254 #endif // defined(OS_WIN) 301 #endif // defined(OS_WIN)
255 } 302 }
256 303
(...skipping 70 matching lines...) Expand 10 before | Expand all | Expand 10 after
327 374
328 // Record renderer main entry time histogram. 375 // Record renderer main entry time histogram.
329 void RecordRendererMainEntryHistogram() { 376 void RecordRendererMainEntryHistogram() {
330 const base::TimeTicks& browser_main_entry_point_ticks = 377 const base::TimeTicks& browser_main_entry_point_ticks =
331 g_browser_main_entry_point_ticks.Get(); 378 g_browser_main_entry_point_ticks.Get();
332 const base::TimeTicks& renderer_main_entry_point_ticks = 379 const base::TimeTicks& renderer_main_entry_point_ticks =
333 g_renderer_main_entry_point_ticks.Get(); 380 g_renderer_main_entry_point_ticks.Get();
334 381
335 if (!browser_main_entry_point_ticks.is_null() && 382 if (!browser_main_entry_point_ticks.is_null() &&
336 !renderer_main_entry_point_ticks.is_null()) { 383 !renderer_main_entry_point_ticks.is_null()) {
337 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 384 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
338 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.BrowserMainToRendererMain", 385 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.BrowserMainToRendererMain",
339 browser_main_entry_point_ticks, renderer_main_entry_point_ticks); 386 browser_main_entry_point_ticks, renderer_main_entry_point_ticks);
340 } 387 }
341 } 388 }
342 389
343 // Environment variable that stores the timestamp when the executable's main() 390 // Environment variable that stores the timestamp when the executable's main()
344 // function was entered in TimeTicks. This is required because chrome.exe and 391 // function was entered in TimeTicks. This is required because chrome.exe and
345 // chrome.dll don't share the same static storage. 392 // chrome.dll don't share the same static storage.
346 const char kChromeMainTicksEnvVar[] = "CHROME_MAIN_TICKS"; 393 const char kChromeMainTicksEnvVar[] = "CHROME_MAIN_TICKS";
347 394
(...skipping 22 matching lines...) Expand all
370 TRACE_EVENT_INSTANT_WITH_TIMESTAMP0( 417 TRACE_EVENT_INSTANT_WITH_TIMESTAMP0(
371 "startup", "Startup.BrowserProcessCreation", 0, 418 "startup", "Startup.BrowserProcessCreation", 0,
372 g_process_creation_ticks.Get().ToInternalValue()); 419 g_process_creation_ticks.Get().ToInternalValue());
373 } 420 }
374 } 421 }
375 422
376 // Logs the Startup.TimeSinceLastStartup histogram. Obtains the timestamp of the 423 // Logs the Startup.TimeSinceLastStartup histogram. Obtains the timestamp of the
377 // last startup from |pref_service| and overwrites it with the timestamp of the 424 // last startup from |pref_service| and overwrites it with the timestamp of the
378 // current startup. If the startup temperature has been set by 425 // current startup. If the startup temperature has been set by
379 // RecordBrowserMainMessageLoopStart, the time since last startup is also logged 426 // RecordBrowserMainMessageLoopStart, the time since last startup is also logged
380 // to an histogram suffixed with the startup temperature. 427 // to a histogram suffixed with the startup temperature.
381 void RecordTimeSinceLastStartup(PrefService* pref_service) { 428 void RecordTimeSinceLastStartup(PrefService* pref_service) {
382 #if defined(OS_MACOSX) || defined(OS_WIN) || defined(OS_LINUX) 429 #if defined(OS_MACOSX) || defined(OS_WIN) || defined(OS_LINUX)
383 DCHECK(pref_service); 430 DCHECK(pref_service);
384 431
385 // Get the timestamp of the current startup. 432 // Get the timestamp of the current startup.
386 const base::Time process_start_time = 433 const base::Time process_start_time =
387 base::CurrentProcessInfo::CreationTime(); 434 base::CurrentProcessInfo::CreationTime();
388 435
389 // Get the timestamp of the last startup from |pref_service|. 436 // Get the timestamp of the last startup from |pref_service|.
390 const int64_t last_startup_timestamp_internal = 437 const int64_t last_startup_timestamp_internal =
391 pref_service->GetInt64(prefs::kLastStartupTimestamp); 438 pref_service->GetInt64(prefs::kLastStartupTimestamp);
392 if (last_startup_timestamp_internal != 0) { 439 if (last_startup_timestamp_internal != 0) {
393 // Log the Startup.TimeSinceLastStartup histogram. 440 // Log the Startup.TimeSinceLastStartup histogram.
394 const base::Time last_startup_timestamp = 441 const base::Time last_startup_timestamp =
395 base::Time::FromInternalValue(last_startup_timestamp_internal); 442 base::Time::FromInternalValue(last_startup_timestamp_internal);
396 const base::TimeDelta time_since_last_startup = 443 const base::TimeDelta time_since_last_startup =
397 process_start_time - last_startup_timestamp; 444 process_start_time - last_startup_timestamp;
398 const int minutes_since_last_startup = time_since_last_startup.InMinutes(); 445 const int minutes_since_last_startup = time_since_last_startup.InMinutes();
399 446
400 // Ignore negative values, which can be caused by system clock changes. 447 // Ignore negative values, which can be caused by system clock changes.
401 if (minutes_since_last_startup >= 0) { 448 if (minutes_since_last_startup >= 0) {
402 UMA_HISTOGRAM_WITH_STARTUP_TEMPERATURE( 449 UMA_HISTOGRAM_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
403 UMA_HISTOGRAM_TIME_IN_MINUTES_MONTH_RANGE, 450 UMA_HISTOGRAM_TIME_IN_MINUTES_MONTH_RANGE,
404 "Startup.TimeSinceLastStartup", minutes_since_last_startup); 451 "Startup.TimeSinceLastStartup", minutes_since_last_startup);
405 } 452 }
406 } 453 }
407 454
408 // Write the timestamp of the current startup in |pref_service|. 455 // Write the timestamp of the current startup in |pref_service|.
409 pref_service->SetInt64(prefs::kLastStartupTimestamp, 456 pref_service->SetInt64(prefs::kLastStartupTimestamp,
410 process_start_time.ToInternalValue()); 457 process_start_time.ToInternalValue());
411 #endif // defined(OS_MACOSX) || defined(OS_WIN) || defined(OS_LINUX) 458 #endif // defined(OS_MACOSX) || defined(OS_WIN) || defined(OS_LINUX)
412 } 459 }
413 460
414 // Logs the Startup.SameVersionStartupCount histogram. Relies on |pref_service| 461 // Logs the Startup.SameVersionStartupCount histogram. Relies on |pref_service|
415 // to know information about the previous startups and store information for 462 // to know information about the previous startups and store information for
416 // future ones. Returns the number of startups with the same version count that 463 // future ones. Stores the logged value in |g_startups_with_current_version|.
417 // was logged. 464 void RecordSameVersionStartupCount(PrefService* pref_service) {
418 int RecordSameVersionStartupCount(PrefService* pref_service) {
419 DCHECK(pref_service); 465 DCHECK(pref_service);
466 DCHECK_EQ(kUndeterminedStartupsWithCurrentVersion,
467 g_startups_with_current_version);
420 468
421 const std::string current_version = version_info::GetVersionNumber(); 469 const std::string current_version = version_info::GetVersionNumber();
422 470
423 int startups_with_current_version = 0;
424 if (current_version == pref_service->GetString(prefs::kLastStartupVersion)) { 471 if (current_version == pref_service->GetString(prefs::kLastStartupVersion)) {
425 startups_with_current_version = 472 g_startups_with_current_version =
426 pref_service->GetInteger(prefs::kSameVersionStartupCount); 473 pref_service->GetInteger(prefs::kSameVersionStartupCount);
427 ++startups_with_current_version; 474 ++g_startups_with_current_version;
428 pref_service->SetInteger(prefs::kSameVersionStartupCount, 475 pref_service->SetInteger(prefs::kSameVersionStartupCount,
429 startups_with_current_version); 476 g_startups_with_current_version);
430 } else { 477 } else {
431 startups_with_current_version = 1; 478 g_startups_with_current_version = 1;
432 pref_service->SetString(prefs::kLastStartupVersion, current_version); 479 pref_service->SetString(prefs::kLastStartupVersion, current_version);
433 pref_service->SetInteger(prefs::kSameVersionStartupCount, 1); 480 pref_service->SetInteger(prefs::kSameVersionStartupCount, 1);
434 } 481 }
435 482
436 UMA_HISTOGRAM_COUNTS_100("Startup.SameVersionStartupCount", 483 UMA_HISTOGRAM_COUNTS_100("Startup.SameVersionStartupCount",
437 startups_with_current_version); 484 g_startups_with_current_version);
438 return startups_with_current_version;
439 } 485 }
440 486
441 } // namespace 487 } // namespace
442 488
443 #if defined(OS_WIN) 489 #if defined(OS_WIN)
444 bool GetHardFaultCountForCurrentProcess(uint32_t* hard_fault_count) { 490 bool GetHardFaultCountForCurrentProcess(uint32_t* hard_fault_count) {
445 DCHECK(hard_fault_count); 491 DCHECK(hard_fault_count);
446 492
447 if (base::win::GetVersion() < base::win::VERSION_WIN7) 493 if (base::win::GetVersion() < base::win::VERSION_WIN7)
448 return false; 494 return false;
(...skipping 87 matching lines...) Expand 10 before | Expand all | Expand 10 after
536 base::Int64ToString(StartupTimeToTimeTicks(time).ToInternalValue()); 582 base::Int64ToString(StartupTimeToTimeTicks(time).ToInternalValue());
537 std::unique_ptr<base::Environment> env(base::Environment::Create()); 583 std::unique_ptr<base::Environment> env(base::Environment::Create());
538 env->SetVar(kChromeMainTicksEnvVar, exe_load_ticks); 584 env->SetVar(kChromeMainTicksEnvVar, exe_load_ticks);
539 } 585 }
540 586
541 void RecordBrowserMainMessageLoopStart(const base::TimeTicks& ticks, 587 void RecordBrowserMainMessageLoopStart(const base::TimeTicks& ticks,
542 bool is_first_run, 588 bool is_first_run,
543 PrefService* pref_service) { 589 PrefService* pref_service) {
544 DCHECK(pref_service); 590 DCHECK(pref_service);
545 591
546 const int same_version_startup_count = 592 RecordSameVersionStartupCount(pref_service);
547 RecordSameVersionStartupCount(pref_service);
548 // Keep RecordHardFaultHistogram() first as much as possible as many other 593 // Keep RecordHardFaultHistogram() first as much as possible as many other
549 // histograms depend on it setting |g_startup_temperature|. 594 // histograms depend on it setting |g_startup_temperature|.
550 RecordHardFaultHistogram(same_version_startup_count); 595 RecordHardFaultHistogram();
551 AddStartupEventsForTelemetry(); 596 AddStartupEventsForTelemetry();
552 RecordTimeSinceLastStartup(pref_service); 597 RecordTimeSinceLastStartup(pref_service);
553 RecordSystemUptimeHistogram(); 598 RecordSystemUptimeHistogram();
554 RecordMainEntryTimeHistogram(); 599 RecordMainEntryTimeHistogram();
555 600
556 const base::TimeTicks& process_creation_ticks = 601 const base::TimeTicks& process_creation_ticks =
557 g_process_creation_ticks.Get(); 602 g_process_creation_ticks.Get();
558 if (!is_first_run && !process_creation_ticks.is_null()) { 603 if (!is_first_run && !process_creation_ticks.is_null()) {
559 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 604 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
560 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.BrowserMessageLoopStartTime", 605 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.BrowserMessageLoopStartTime",
561 process_creation_ticks, ticks); 606 process_creation_ticks, ticks);
562 } 607 }
563 608
564 // Bail if uptime < 7 minutes, to filter out cases where Chrome may have been 609 // Bail if uptime < 7 minutes, to filter out cases where Chrome may have been
565 // autostarted and the machine is under io pressure. 610 // autostarted and the machine is under io pressure.
566 if (base::SysInfo::Uptime() < base::TimeDelta::FromMinutes(7)) 611 if (base::SysInfo::Uptime() < base::TimeDelta::FromMinutes(7))
567 return; 612 return;
568 613
569 // The Startup.BrowserMessageLoopStartTime histogram exhibits instability in 614 // The Startup.BrowserMessageLoopStartTime histogram exhibits instability in
570 // the field which limits its usefulness in all scenarios except when we have 615 // the field which limits its usefulness in all scenarios except when we have
571 // a very large sample size. Attempt to mitigate this with a new metric: 616 // a very large sample size. Attempt to mitigate this with a new metric:
572 // * Measure time from main entry rather than the OS' notion of process start. 617 // * Measure time from main entry rather than the OS' notion of process start.
573 // * Only measure launches that occur 7 minutes after boot to try to avoid 618 // * Only measure launches that occur 7 minutes after boot to try to avoid
574 // cases where Chrome is auto-started and IO is heavily loaded. 619 // cases where Chrome is auto-started and IO is heavily loaded.
575 if (is_first_run) { 620 if (is_first_run) {
576 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 621 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE(
577 UMA_HISTOGRAM_LONG_TIMES, 622 UMA_HISTOGRAM_LONG_TIMES,
578 "Startup.BrowserMessageLoopStartTimeFromMainEntry.FirstRun", 623 "Startup.BrowserMessageLoopStartTimeFromMainEntry.FirstRun",
579 g_browser_main_entry_point_ticks.Get(), ticks); 624 g_browser_main_entry_point_ticks.Get(), ticks);
580 } else { 625 } else {
581 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 626 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
582 UMA_HISTOGRAM_LONG_TIMES, 627 UMA_HISTOGRAM_LONG_TIMES,
583 "Startup.BrowserMessageLoopStartTimeFromMainEntry", 628 "Startup.BrowserMessageLoopStartTimeFromMainEntry",
584 g_browser_main_entry_point_ticks.Get(), ticks); 629 g_browser_main_entry_point_ticks.Get(), ticks);
585 } 630 }
586 631
587 // Record timings between process creation, the main() in the executable being 632 // Record timings between process creation, the main() in the executable being
588 // reached and the main() in the shared library being reached. 633 // reached and the main() in the shared library being reached.
589 if (!process_creation_ticks.is_null()) { 634 if (!process_creation_ticks.is_null()) {
590 const base::TimeTicks exe_main_ticks = ExeMainEntryPointTicks(); 635 const base::TimeTicks exe_main_ticks = ExeMainEntryPointTicks();
591 if (!exe_main_ticks.is_null()) { 636 if (!exe_main_ticks.is_null()) {
592 // Process create to chrome.exe:main(). 637 // Process create to chrome.exe:main().
593 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 638 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
594 UMA_HISTOGRAM_LONG_TIMES, "Startup.LoadTime.ProcessCreateToExeMain", 639 UMA_HISTOGRAM_LONG_TIMES, "Startup.LoadTime.ProcessCreateToExeMain",
595 process_creation_ticks, exe_main_ticks); 640 process_creation_ticks, exe_main_ticks);
596 641
597 // chrome.exe:main() to chrome.dll:main(). 642 // chrome.exe:main() to chrome.dll:main().
598 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 643 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
599 UMA_HISTOGRAM_LONG_TIMES, "Startup.LoadTime.ExeMainToDllMain", 644 UMA_HISTOGRAM_LONG_TIMES, "Startup.LoadTime.ExeMainToDllMain",
600 exe_main_ticks, g_browser_main_entry_point_ticks.Get()); 645 exe_main_ticks, g_browser_main_entry_point_ticks.Get());
601 646
602 // Process create to chrome.dll:main(). Reported as a histogram only as 647 // Process create to chrome.dll:main(). Reported as a histogram only as
603 // the other two events above are sufficient for tracing purposes. 648 // the other two events above are sufficient for tracing purposes.
604 UMA_HISTOGRAM_WITH_STARTUP_TEMPERATURE( 649 UMA_HISTOGRAM_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
605 UMA_HISTOGRAM_LONG_TIMES, "Startup.LoadTime.ProcessCreateToDllMain", 650 UMA_HISTOGRAM_LONG_TIMES, "Startup.LoadTime.ProcessCreateToDllMain",
606 g_browser_main_entry_point_ticks.Get() - process_creation_ticks); 651 g_browser_main_entry_point_ticks.Get() - process_creation_ticks);
607 } 652 }
608 } 653 }
609 } 654 }
610 655
611 void RecordBrowserWindowDisplay(const base::TimeTicks& ticks) { 656 void RecordBrowserWindowDisplay(const base::TimeTicks& ticks) {
612 static bool is_first_call = true; 657 static bool is_first_call = true;
613 if (!is_first_call || ticks.is_null()) 658 if (!is_first_call || ticks.is_null())
614 return; 659 return;
615 is_first_call = false; 660 is_first_call = false;
616 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null()) 661 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null())
617 return; 662 return;
618 663
619 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 664 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
620 UMA_HISTOGRAM_LONG_TIMES, "Startup.BrowserWindowDisplay", 665 UMA_HISTOGRAM_LONG_TIMES, "Startup.BrowserWindowDisplay",
621 g_process_creation_ticks.Get(), ticks); 666 g_process_creation_ticks.Get(), ticks);
622 } 667 }
623 668
624 void RecordBrowserOpenTabsDelta(const base::TimeDelta& delta) { 669 void RecordBrowserOpenTabsDelta(const base::TimeDelta& delta) {
625 static bool is_first_call = true; 670 static bool is_first_call = true;
626 if (!is_first_call) 671 if (!is_first_call)
627 return; 672 return;
628 is_first_call = false; 673 is_first_call = false;
629 674
630 UMA_HISTOGRAM_WITH_STARTUP_TEMPERATURE(UMA_HISTOGRAM_LONG_TIMES_100, 675 UMA_HISTOGRAM_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
631 "Startup.BrowserOpenTabs", delta); 676 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.BrowserOpenTabs", delta);
632 } 677 }
633 678
634 void RecordRendererMainEntryTime(const base::TimeTicks& ticks) { 679 void RecordRendererMainEntryTime(const base::TimeTicks& ticks) {
635 // Record the renderer main entry time, but don't log the UMA metric 680 // Record the renderer main entry time, but don't log the UMA metric
636 // immediately because the startup temperature is not known yet. 681 // immediately because the startup temperature is not known yet.
637 if (g_renderer_main_entry_point_ticks.Get().is_null()) 682 if (g_renderer_main_entry_point_ticks.Get().is_null())
638 g_renderer_main_entry_point_ticks.Get() = ticks; 683 g_renderer_main_entry_point_ticks.Get() = ticks;
639 } 684 }
640 685
641 void RecordFirstWebContentsMainFrameLoad(const base::TimeTicks& ticks) { 686 void RecordFirstWebContentsMainFrameLoad(const base::TimeTicks& ticks) {
642 static bool is_first_call = true; 687 static bool is_first_call = true;
643 if (!is_first_call || ticks.is_null()) 688 if (!is_first_call || ticks.is_null())
644 return; 689 return;
645 is_first_call = false; 690 is_first_call = false;
646 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null()) 691 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null())
647 return; 692 return;
648 693
649 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 694 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
650 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.FirstWebContents.MainFrameLoad2", 695 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.FirstWebContents.MainFrameLoad2",
651 g_process_creation_ticks.Get(), ticks); 696 g_process_creation_ticks.Get(), ticks);
652 } 697 }
653 698
654 void RecordFirstWebContentsNonEmptyPaint(const base::TimeTicks& ticks) { 699 void RecordFirstWebContentsNonEmptyPaint(const base::TimeTicks& ticks) {
655 static bool is_first_call = true; 700 static bool is_first_call = true;
656 if (!is_first_call || ticks.is_null()) 701 if (!is_first_call || ticks.is_null())
657 return; 702 return;
658 is_first_call = false; 703 is_first_call = false;
659 704
660 // Log Startup.BrowserMainToRendererMain now that the first renderer main 705 // Log Startup.BrowserMainToRendererMain now that the first renderer main
661 // entry time and the startup temperature are known. 706 // entry time and the startup temperature are known.
662 RecordRendererMainEntryHistogram(); 707 RecordRendererMainEntryHistogram();
663 708
664 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null()) 709 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null())
665 return; 710 return;
666 711
667 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 712 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
668 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.FirstWebContents.NonEmptyPaint2", 713 UMA_HISTOGRAM_LONG_TIMES_100, "Startup.FirstWebContents.NonEmptyPaint2",
669 g_process_creation_ticks.Get(), ticks); 714 g_process_creation_ticks.Get(), ticks);
670 } 715 }
671 716
672 void RecordFirstWebContentsMainNavigationStart(const base::TimeTicks& ticks) { 717 void RecordFirstWebContentsMainNavigationStart(const base::TimeTicks& ticks) {
673 static bool is_first_call = true; 718 static bool is_first_call = true;
674 if (!is_first_call || ticks.is_null()) 719 if (!is_first_call || ticks.is_null())
675 return; 720 return;
676 is_first_call = false; 721 is_first_call = false;
677 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null()) 722 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null())
678 return; 723 return;
679 724
680 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 725 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
681 UMA_HISTOGRAM_LONG_TIMES_100, 726 UMA_HISTOGRAM_LONG_TIMES_100,
682 "Startup.FirstWebContents.MainNavigationStart", 727 "Startup.FirstWebContents.MainNavigationStart",
683 g_process_creation_ticks.Get(), ticks); 728 g_process_creation_ticks.Get(), ticks);
684 } 729 }
685 730
686 void RecordFirstWebContentsMainNavigationFinished( 731 void RecordFirstWebContentsMainNavigationFinished(
687 const base::TimeTicks& ticks) { 732 const base::TimeTicks& ticks) {
688 static bool is_first_call = true; 733 static bool is_first_call = true;
689 if (!is_first_call || ticks.is_null()) 734 if (!is_first_call || ticks.is_null())
690 return; 735 return;
691 is_first_call = false; 736 is_first_call = false;
692 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null()) 737 if (WasNonBrowserUIDisplayed() || g_process_creation_ticks.Get().is_null())
693 return; 738 return;
694 739
695 UMA_HISTOGRAM_AND_TRACE_WITH_STARTUP_TEMPERATURE( 740 UMA_HISTOGRAM_AND_TRACE_WITH_TEMPERATURE_AND_SAME_VERSION_COUNT(
696 UMA_HISTOGRAM_LONG_TIMES_100, 741 UMA_HISTOGRAM_LONG_TIMES_100,
697 "Startup.FirstWebContents.MainNavigationFinished", 742 "Startup.FirstWebContents.MainNavigationFinished",
698 g_process_creation_ticks.Get(), ticks); 743 g_process_creation_ticks.Get(), ticks);
699 } 744 }
700 745
701 base::TimeTicks MainEntryPointTicks() { 746 base::TimeTicks MainEntryPointTicks() {
702 return g_browser_main_entry_point_ticks.Get(); 747 return g_browser_main_entry_point_ticks.Get();
703 } 748 }
704 749
705 StartupTemperature GetStartupTemperature() { 750 StartupTemperature GetStartupTemperature() {
706 return g_startup_temperature; 751 return g_startup_temperature;
707 } 752 }
708 753
709 } // namespace startup_metric_utils 754 } // namespace startup_metric_utils
OLDNEW
« no previous file with comments | « base/trace_event/common/trace_event_common.h ('k') | tools/metrics/histograms/histograms.xml » ('j') | no next file with comments »

Powered by Google App Engine
This is Rietveld 408576698