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/startup_metric_utils.h" | 5 #include "components/startup_metric_utils/startup_metric_utils.h" |
6 | 6 |
7 #include "base/containers/hash_tables.h" | 7 #include "base/containers/hash_tables.h" |
8 #include "base/environment.h" | 8 #include "base/environment.h" |
9 #include "base/logging.h" | 9 #include "base/logging.h" |
10 #include "base/metrics/histogram.h" | 10 #include "base/metrics/histogram.h" |
11 #include "base/metrics/histogram_base.h" | 11 #include "base/metrics/histogram_base.h" |
12 #include "base/metrics/statistics_recorder.h" | 12 #include "base/metrics/statistics_recorder.h" |
13 #include "base/process/process_info.h" | 13 #include "base/process/process_info.h" |
14 #include "base/strings/string_number_conversions.h" | 14 #include "base/strings/string_number_conversions.h" |
15 #include "base/synchronization/lock.h" | 15 #include "base/synchronization/lock.h" |
16 #include "base/sys_info.h" | 16 #include "base/sys_info.h" |
17 #include "base/time/time.h" | 17 #include "base/time/time.h" |
18 | 18 |
19 #if defined(OS_WIN) | |
20 #include <winternl.h> | |
21 #endif | |
22 | |
19 namespace { | 23 namespace { |
20 | 24 |
21 // Mark as volatile to defensively make sure usage is thread-safe. | 25 // Mark as volatile to defensively make sure usage is thread-safe. |
22 // Note that at the time of this writing, access is only on the UI thread. | 26 // Note that at the time of this writing, access is only on the UI thread. |
23 volatile bool g_non_browser_ui_displayed = false; | 27 volatile bool g_non_browser_ui_displayed = false; |
24 | 28 |
25 base::Time* MainEntryPointTimeInternal() { | 29 base::Time* MainEntryPointTimeInternal() { |
26 static base::Time main_start_time = base::Time::Now(); | 30 static base::Time main_start_time = base::Time::Now(); |
27 return &main_start_time; | 31 return &main_start_time; |
28 } | 32 } |
29 | 33 |
30 typedef base::hash_map<std::string,base::TimeDelta> SubsystemStartupTimeHash; | 34 typedef base::hash_map<std::string,base::TimeDelta> SubsystemStartupTimeHash; |
31 | 35 |
32 SubsystemStartupTimeHash* GetSubsystemStartupTimeHash() { | 36 SubsystemStartupTimeHash* GetSubsystemStartupTimeHash() { |
33 static SubsystemStartupTimeHash* slow_startup_time_hash = | 37 static SubsystemStartupTimeHash* slow_startup_time_hash = |
34 new SubsystemStartupTimeHash; | 38 new SubsystemStartupTimeHash; |
35 return slow_startup_time_hash; | 39 return slow_startup_time_hash; |
36 } | 40 } |
37 | 41 |
38 base::Lock* GetSubsystemStartupTimeHashLock() { | 42 base::Lock* GetSubsystemStartupTimeHashLock() { |
39 static base::Lock* slow_startup_time_hash_lock = new base::Lock; | 43 static base::Lock* slow_startup_time_hash_lock = new base::Lock; |
40 return slow_startup_time_hash_lock; | 44 return slow_startup_time_hash_lock; |
41 } | 45 } |
42 | 46 |
47 // The struct used to return system process information via the NT internal | |
48 // QuerySystemInformation call. This is partially documented at | |
49 // http://goo.gl/Ja9MrH and fully documented at http://goo.gl/QJ70rn | |
50 struct SYSTEM_PROCESS_INFORMATION_EX { | |
51 ULONG NextEntryOffset; | |
52 ULONG NumberOfThreads; | |
53 LARGE_INTEGER WorkingSetPrivateSize; | |
54 ULONG HardFaultCount; | |
55 BYTE Reserved1[36]; | |
56 PVOID Reserved2[3]; | |
57 ULONG UniqueProcessId; | |
58 PVOID Reserved3; | |
59 ULONG HandleCount; | |
60 BYTE Reserved4[4]; | |
61 PVOID Reserved5[11]; | |
62 SIZE_T PeakPagefileUsage; | |
63 SIZE_T PrivatePageCount; | |
64 LARGE_INTEGER Reserved6[6]; | |
65 // Array of SYSTEM_THREAD_INFORMATION structs follows. | |
66 }; | |
67 static_assert( | |
68 sizeof(SYSTEM_PROCESS_INFORMATION_EX) == 184, | |
Alexei Svitkine (slow)
2015/04/14 16:53:51
Is the size the same between 32 and 64 bit?
chrisha
2015/04/14 17:09:07
Good catch. Not the same size, but has the same la
| |
69 "The definition of SYSTEM_PROCESS_INFORMATION_EX does not match the " | |
70 "expected size."); | |
71 | |
72 // The signature of the NtQuerySystemInformation function. | |
73 typedef NTSTATUS (WINAPI *NtQuerySystemInformationPtr)( | |
74 SYSTEM_INFORMATION_CLASS, PVOID, ULONG, PULONG); | |
75 | |
76 // Gets the hard fault count of the current process, returning it via | |
77 // |hard_fault_count|. Returns true on success, false otherwise. Also returns | |
78 // whether or not the system call was even possible for the current OS version | |
79 // via |has_os_support|. | |
80 bool GetHardFaultCountForCurrentProcess(uint32* hard_fault_count, | |
81 bool* has_os_support) { | |
82 DCHECK(hard_fault_count); | |
83 DCHECK(has_os_support); | |
84 | |
85 *has_os_support = false; | |
86 OSVERSIONINFOEX version_info = {}; | |
87 version_info.dwOSVersionInfoSize = sizeof(OSVERSIONINFOEX); | |
88 if (!::GetVersionEx(reinterpret_cast<LPOSVERSIONINFOW>(&version_info))) | |
Alexei Svitkine (slow)
2015/04/14 16:53:51
Is this inside a file that's Windows-specific? If
| |
89 return false; | |
90 | |
91 // The hard fault counter is only available as of Windows 7 (version 6.1). | |
92 if (version_info.dwMajorVersion < 6) | |
93 return false; | |
94 if (version_info.dwMajorVersion == 6 && version_info.dwMinorVersion < 1) | |
95 return false; | |
96 | |
97 // At this point the OS supports the required system call. | |
98 *has_os_support = true; | |
99 | |
100 // Get the function pointer. | |
101 NtQuerySystemInformationPtr query_sys_info = | |
102 reinterpret_cast<NtQuerySystemInformationPtr>( | |
103 ::GetProcAddress(GetModuleHandle(L"ntdll.dll"), | |
104 "NtQuerySystemInformation")); | |
105 if (query_sys_info == nullptr) | |
106 return false; | |
107 | |
108 // The output of this system call depends on the number of threads and | |
109 // processes on the entire system, and this can change between calls. Retry | |
110 // a small handful of times growing the buffer along the way. | |
111 std::vector<uint8> buffer(1024); | |
112 for (size_t tries = 0; tries < 3; ++tries) { | |
113 ULONG return_length = 0; | |
114 NTSTATUS status = query_sys_info( | |
115 SystemProcessInformation, | |
116 buffer.data(), | |
117 buffer.size(), | |
118 &return_length); | |
119 // Insufficient space in the buffer. | |
120 if (return_length > buffer.size()) { | |
121 buffer.resize(return_length); | |
122 continue; | |
123 } | |
124 if (status == 0 && return_length <= buffer.size()) | |
125 break; | |
126 return false; | |
127 } | |
128 // The only way out to get here is if the system call was successful. | |
129 | |
130 // Look for the struct housing information for the current process. | |
131 DWORD proc_id = ::GetCurrentProcessId(); | |
132 size_t index = 0; | |
133 while (index < buffer.size()) { | |
134 SYSTEM_PROCESS_INFORMATION_EX* proc_info = | |
135 reinterpret_cast<SYSTEM_PROCESS_INFORMATION_EX*>(buffer.data() + index); | |
136 if (proc_info->UniqueProcessId == proc_id) { | |
137 *hard_fault_count = proc_info->HardFaultCount; | |
138 return true; | |
139 } | |
140 // The list ends with NextEntryOffset is zero. This also prevents busy | |
141 // looping if the data is in fact invalid. | |
142 if (proc_info->NextEntryOffset == 0) | |
143 return false; | |
144 index += proc_info->NextEntryOffset; | |
145 } | |
146 | |
147 return false; | |
148 } | |
149 | |
150 // On Windows, records the number of hard-faults that have occurred in the | |
151 // current chrome.exe process since it was started. | |
152 // crbug.com/476923 | |
153 // TODO(chrisha): If this proves useful, use it to split startup stats in two. | |
154 void RecordHardFaultHistogram(bool is_first_run) { | |
155 uint32 hard_fault_count = 0; | |
156 bool has_os_support = false; | |
157 bool success = GetHardFaultCountForCurrentProcess( | |
158 &hard_fault_count, &has_os_support); | |
159 | |
160 // Log whether or not the system call was successful, assuming the OS was | |
161 // detected to support it. | |
162 if (has_os_support) { | |
163 UMA_HISTOGRAM_BOOLEAN( | |
164 "Startup.BrowserMessageLoopStartHardFaultCount.Success", | |
165 success); | |
166 } | |
167 | |
168 // Don't log a histogram value if unable to get the hard fault count. | |
169 if (!success) | |
170 return; | |
171 | |
172 // Hard fault counts are expected to be in the thousands range, | |
173 // corresponding to faulting in ~10s of MBs of code ~10s of KBs at a time. | |
174 // (Observed to vary from 1000 to 10000 on various test machines and | |
175 // platforms.) | |
176 if (is_first_run) { | |
177 UMA_HISTOGRAM_CUSTOM_COUNTS( | |
178 "Startup.BrowserMessageLoopStartHardFaultCount.FirstRun", | |
179 hard_fault_count, | |
180 0, 20000, 50); | |
181 } else { | |
182 UMA_HISTOGRAM_CUSTOM_COUNTS( | |
183 "Startup.BrowserMessageLoopStartHardFaultCount", | |
184 hard_fault_count, | |
185 0, 20000, 50); | |
186 } | |
187 } | |
188 | |
43 // Record time of main entry so it can be read from Telemetry performance | 189 // Record time of main entry so it can be read from Telemetry performance |
44 // tests. | 190 // tests. |
45 // TODO(jeremy): Remove once crbug.com/317481 is fixed. | 191 // TODO(jeremy): Remove once crbug.com/317481 is fixed. |
46 void RecordMainEntryTimeHistogram() { | 192 void RecordMainEntryTimeHistogram() { |
47 const int kLowWordMask = 0xFFFFFFFF; | 193 const int kLowWordMask = 0xFFFFFFFF; |
48 const int kLower31BitsMask = 0x7FFFFFFF; | 194 const int kLower31BitsMask = 0x7FFFFFFF; |
49 base::TimeDelta browser_main_entry_time_absolute = | 195 base::TimeDelta browser_main_entry_time_absolute = |
50 *MainEntryPointTimeInternal() - base::Time::UnixEpoch(); | 196 *MainEntryPointTimeInternal() - base::Time::UnixEpoch(); |
51 | 197 |
52 uint64 browser_main_entry_time_raw_ms = | 198 uint64 browser_main_entry_time_raw_ms = |
(...skipping 55 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
108 } | 254 } |
109 #endif // OS_ANDROID | 255 #endif // OS_ANDROID |
110 | 256 |
111 // Return the time recorded by RecordMainEntryPointTime(). | 257 // Return the time recorded by RecordMainEntryPointTime(). |
112 const base::Time MainEntryStartTime() { | 258 const base::Time MainEntryStartTime() { |
113 DCHECK(g_main_entry_time_was_recorded); | 259 DCHECK(g_main_entry_time_was_recorded); |
114 return *MainEntryPointTimeInternal(); | 260 return *MainEntryPointTimeInternal(); |
115 } | 261 } |
116 | 262 |
117 void OnBrowserStartupComplete(bool is_first_run) { | 263 void OnBrowserStartupComplete(bool is_first_run) { |
264 RecordHardFaultHistogram(is_first_run); | |
118 RecordMainEntryTimeHistogram(); | 265 RecordMainEntryTimeHistogram(); |
119 | 266 |
120 // Bail if uptime < 7 minutes, to filter out cases where Chrome may have been | 267 // Bail if uptime < 7 minutes, to filter out cases where Chrome may have been |
121 // autostarted and the machine is under io pressure. | 268 // autostarted and the machine is under io pressure. |
122 const int64 kSevenMinutesInMilliseconds = | 269 const int64 kSevenMinutesInMilliseconds = |
123 base::TimeDelta::FromMinutes(7).InMilliseconds(); | 270 base::TimeDelta::FromMinutes(7).InMilliseconds(); |
124 if (base::SysInfo::Uptime() < kSevenMinutesInMilliseconds) { | 271 if (base::SysInfo::Uptime() < kSevenMinutesInMilliseconds) { |
125 g_startup_stats_collection_finished = true; | 272 g_startup_stats_collection_finished = true; |
126 return; | 273 return; |
127 } | 274 } |
(...skipping 114 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
242 SubsystemStartupTimeHash* hash = GetSubsystemStartupTimeHash(); | 389 SubsystemStartupTimeHash* hash = GetSubsystemStartupTimeHash(); |
243 // Only record the initial sample for a given histogram. | 390 // Only record the initial sample for a given histogram. |
244 if (hash->find(histogram_name_) != hash->end()) | 391 if (hash->find(histogram_name_) != hash->end()) |
245 return; | 392 return; |
246 | 393 |
247 (*hash)[histogram_name_] = | 394 (*hash)[histogram_name_] = |
248 base::TimeTicks::Now() - start_time_; | 395 base::TimeTicks::Now() - start_time_; |
249 } | 396 } |
250 | 397 |
251 } // namespace startup_metric_utils | 398 } // namespace startup_metric_utils |
OLD | NEW |