Add UMA stats for hard-fault counts for Windows 7 and greater.

components/startup_metric_utils/startup_metric_utils.cc

 // Copyright 2013 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "components/startup_metric_utils/startup_metric_utils.h"
 
 #include "base/containers/hash_tables.h"
 #include "base/environment.h"
 #include "base/logging.h"
 #include "base/metrics/histogram.h"
 #include "base/metrics/histogram_base.h"
 #include "base/metrics/statistics_recorder.h"
 #include "base/process/process_info.h"
 #include "base/strings/string_number_conversions.h"
 #include "base/synchronization/lock.h"
 #include "base/sys_info.h"
 #include "base/time/time.h"
 
+#if defined(OS_WIN)
+#include <winternl.h>
+#endif
+
 namespace {
 
 // Mark as volatile to defensively make sure usage is thread-safe.
 // Note that at the time of this writing, access is only on the UI thread.
 volatile bool g_non_browser_ui_displayed = false;
 
 base::Time* MainEntryPointTimeInternal() {
   static base::Time main_start_time = base::Time::Now();
   return &main_start_time;
 }
 
 typedef base::hash_map<std::string,base::TimeDelta> SubsystemStartupTimeHash;
 
 SubsystemStartupTimeHash* GetSubsystemStartupTimeHash() {
   static SubsystemStartupTimeHash* slow_startup_time_hash =
                                     new SubsystemStartupTimeHash;
   return slow_startup_time_hash;
 }
 
 base::Lock* GetSubsystemStartupTimeHashLock() {
   static base::Lock* slow_startup_time_hash_lock = new base::Lock;
   return slow_startup_time_hash_lock;
 }
 
+#if defined(OS_WIN)
+
+// The struct used to return system process information via the NT internal
+// QuerySystemInformation call. This is partially documented at
+// http://goo.gl/Ja9MrH and fully documented at http://goo.gl/QJ70rn
+// This structure is laid out in the same format on both 32-bit and 64-bit
+// systems, but has a different size due to the various pointer sized fields.
+struct SYSTEM_PROCESS_INFORMATION_EX {
+  ULONG NextEntryOffset;
+  ULONG NumberOfThreads;
+  LARGE_INTEGER WorkingSetPrivateSize;
+  ULONG HardFaultCount;
+  BYTE Reserved1[36];
+  PVOID Reserved2[3];
+  // This is labeled a handle so that it expands to the correct size for 32-bit
+  // and 64-bit operating systems. However, under the hood it's a 32-bit DWORD
+  // containing the process ID.
+  HANDLE UniqueProcessId;
+  PVOID Reserved3;
+  ULONG HandleCount;
+  BYTE Reserved4[4];
+  PVOID Reserved5[11];
+  SIZE_T PeakPagefileUsage;
+  SIZE_T PrivatePageCount;
+  LARGE_INTEGER Reserved6[6];
+  // Array of SYSTEM_THREAD_INFORMATION structs follows.
+};
+
+// The signature of the NtQuerySystemInformation function.
+typedef NTSTATUS (WINAPI *NtQuerySystemInformationPtr)(
+    SYSTEM_INFORMATION_CLASS, PVOID, ULONG, PULONG);
+
+// Gets the hard fault count of the current process, returning it via
+// |hard_fault_count|. Returns true on success, false otherwise. Also returns
+// whether or not the system call was even possible for the current OS version
+// via |has_os_support|.
+bool GetHardFaultCountForCurrentProcess(uint32* hard_fault_count,
+                                        bool* has_os_support) {
+  DCHECK(hard_fault_count);
+  DCHECK(has_os_support);
+
+  *has_os_support = false;
+  OSVERSIONINFOEX version_info = {};
+  version_info.dwOSVersionInfoSize = sizeof(OSVERSIONINFOEX);
+  if (!::GetVersionEx(reinterpret_cast<LPOSVERSIONINFOW>(&version_info)))
+    return false;
+
+  // The hard fault counter is only available as of Windows 7 (version 6.1).
+  if (version_info.dwMajorVersion < 6)
+    return false;
+  if (version_info.dwMajorVersion == 6 && version_info.dwMinorVersion < 1)
+    return false;
+
+  // At this point the OS supports the required system call.
+  *has_os_support = true;
+
+  // Get the function pointer.
+  NtQuerySystemInformationPtr query_sys_info =
+      reinterpret_cast<NtQuerySystemInformationPtr>(
+          ::GetProcAddress(GetModuleHandle(L"ntdll.dll"),
+                           "NtQuerySystemInformation"));
+  if (query_sys_info == nullptr)
+    return false;
+
+  // The output of this system call depends on the number of threads and
+  // processes on the entire system, and this can change between calls. Retry
+  // a small handful of times growing the buffer along the way.
+  std::vector<uint8> buffer(1024);
+  for (size_t tries = 0; tries < 3; ++tries) {
+    ULONG return_length = 0;
+    NTSTATUS status = query_sys_info(
+        SystemProcessInformation,
+        buffer.data(),
+        buffer.size(),
+        &return_length);
+    // Insufficient space in the buffer.
+    if (return_length > buffer.size()) {
+      buffer.resize(return_length);
+      continue;
+    }
+    if (status == 0 && return_length <= buffer.size())
+      break;
+    return false;
+  }
+  // The only way out to get here is if the system call was successful.
+
+  // Look for the struct housing information for the current process.
+  DWORD proc_id = ::GetCurrentProcessId();
+  size_t index = 0;
+  while (index < buffer.size()) {
+    SYSTEM_PROCESS_INFORMATION_EX* proc_info =
+        reinterpret_cast<SYSTEM_PROCESS_INFORMATION_EX*>(buffer.data() + index);
+    if (reinterpret_cast<DWORD>(proc_info->UniqueProcessId) == proc_id) {
+      *hard_fault_count = proc_info->HardFaultCount;
+      return true;
+    }
+    // The list ends with NextEntryOffset is zero. This also prevents busy
+    // looping if the data is in fact invalid.
+    if (proc_info->NextEntryOffset == 0)
+      return false;
+    index += proc_info->NextEntryOffset;
+  }
+
+  return false;
+}
+
+#endif  // defined(OS_WIN)
+
+// On Windows, records the number of hard-faults that have occurred in the
+// current chrome.exe process since it was started. This is a nop on other
+// platforms.
+// crbug.com/476923
+// TODO(chrisha): If this proves useful, use it to split startup stats in two.
+void RecordHardFaultHistogram(bool is_first_run) {
+#if defined(OS_WIN)
+  uint32 hard_fault_count = 0;
+  bool has_os_support = false;
+  bool success = GetHardFaultCountForCurrentProcess(
+      &hard_fault_count, &has_os_support);
+
+  // Log whether or not the system call was successful, assuming the OS was
+  // detected to support it.
+  if (has_os_support) {
+    UMA_HISTOGRAM_BOOLEAN(
+        "Startup.BrowserMessageLoopStartHardFaultCount.Success",
+        success);
+  }
+
+  // Don't log a histogram value if unable to get the hard fault count.
+  if (!success)
+    return;
+
+  // Hard fault counts are expected to be in the thousands range,
+  // corresponding to faulting in ~10s of MBs of code ~10s of KBs at a time.
+  // (Observed to vary from 1000 to 10000 on various test machines and

[erikchen, 2015/04/14 23:01:52]

 If you're observing 10000 on a test machine, it's going to go way higher in the
mild. Perhaps make the upper limit 200000, and the lower limit 100?

[chrisha, 2015/04/15 13:04:30]

I suppose it could go drastically higher, but it would be non-sensical. In an
absolute worst case scenario this value is realistically bounded above by about
17000. This is assuming that Chrome and every single one of its dependencies
(totaling about 70MB) is entirely faulted in using 4KB hard page faults. This is
quite unlikely. I could see maybe doubling this to ensure that we catch some of
the long tail... thoughts?

As to the lower bound, we can and will see actual values of 0 for a completely
warm start. I'd like to catch those explicitly.

[erikchen, 2015/04/15 17:26:59]

Sounds reasonable to me. We can always change the bounds afterwards.

+  // platforms.)
+  if (is_first_run) {
+    UMA_HISTOGRAM_CUSTOM_COUNTS(
+        "Startup.BrowserMessageLoopStartHardFaultCount.FirstRun",
+        hard_fault_count,
+        0, 20000, 50);
+  } else {
+    UMA_HISTOGRAM_CUSTOM_COUNTS(
+        "Startup.BrowserMessageLoopStartHardFaultCount",

[erikchen, 2015/04/14 23:01:52]

The description you give for this metric implies it's always recorded, but here
you only record it on non-first run. I think it makes more sense to always
record it, but either way the behavior and description should be consistent.

[chrisha, 2015/04/15 13:04:29]

I was just being consistent with how
Startup.BrowserMessageLoopStartTimeFromMainEntry and
Startup.BrowserMessageLoopStartTimeFromMainEntry.FirstRun work, elsewhere in
this file. I've modified the descriptions to be consistent.

+        hard_fault_count,
+        0, 20000, 50);
+  }
+#endif  // defined(OS_WIN)
+}
+
 // Record time of main entry so it can be read from Telemetry performance
 // tests.
 // TODO(jeremy): Remove once crbug.com/317481 is fixed.
 void RecordMainEntryTimeHistogram() {
   const int kLowWordMask = 0xFFFFFFFF;
   const int kLower31BitsMask = 0x7FFFFFFF;
   base::TimeDelta browser_main_entry_time_absolute =
       *MainEntryPointTimeInternal() - base::Time::UnixEpoch();
 
   uint64 browser_main_entry_time_raw_ms =
@@ skipping 55 matching lines @@
 }
 #endif // OS_ANDROID
 
 // Return the time recorded by RecordMainEntryPointTime().
 const base::Time MainEntryStartTime() {
   DCHECK(g_main_entry_time_was_recorded);
   return *MainEntryPointTimeInternal();
 }
 
 void OnBrowserStartupComplete(bool is_first_run) {
+  RecordHardFaultHistogram(is_first_run);

[erikchen, 2015/04/14 23:01:52]

As a quick sanity check, can you confirm that this method is fast via local
instrumentation? 

[chrisha, 2015/04/15 13:04:30]

This was benchmarked across various versions of the OS and across both
high-powered and low-powered machines. The results of the benchmarking are
linked to in the attached bug. This was seen to vary from tens of microseconds
to about 2 ms in the worst case.

   RecordMainEntryTimeHistogram();
 
   // Bail if uptime < 7 minutes, to filter out cases where Chrome may have been
   // autostarted and the machine is under io pressure.
   const int64 kSevenMinutesInMilliseconds =
       base::TimeDelta::FromMinutes(7).InMilliseconds();
   if (base::SysInfo::Uptime() < kSevenMinutesInMilliseconds) {
     g_startup_stats_collection_finished = true;
     return;
   }
@@ skipping 114 matching lines @@
   SubsystemStartupTimeHash* hash = GetSubsystemStartupTimeHash();
   // Only record the initial sample for a given histogram.
   if (hash->find(histogram_name_) !=  hash->end())
     return;
 
   (*hash)[histogram_name_] =
       base::TimeTicks::Now() - start_time_;
 }
 
 }  // namespace startup_metric_utils