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