Histogram times surrounding render crashes

chrome/browser/metrics/metrics_service.cc

 // Copyright (c) 2012 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.
 
 //------------------------------------------------------------------------------
 // Description of the life cycle of a instance of MetricsService.
 //
 //  OVERVIEW
 //
 // A MetricsService instance is typically created at application startup.  It
@@ skipping 541 matching lines @@
       LogLoadStarted();
       break;
 
     case content::NOTIFICATION_RENDERER_PROCESS_CLOSED: {
         content::RenderProcessHost::RendererClosedDetails* process_details =
             content::Details<
                 content::RenderProcessHost::RendererClosedDetails>(
                     details).ptr();
         content::RenderProcessHost* host =
             content::Source<content::RenderProcessHost>(source).ptr();
-        LogRendererCrash(
-            host, process_details->status, process_details->was_alive);
+        LogRendererCrash(host, process_details->status,
+                         process_details->was_alive, process_details->handle);
       }
       break;
 
     case content::NOTIFICATION_RENDERER_PROCESS_HANG:
       LogRendererHang();
       break;
 
     case content::NOTIFICATION_CHILD_PROCESS_HOST_CONNECTED:
     case content::NOTIFICATION_CHILD_PROCESS_CRASHED:
     case content::NOTIFICATION_CHILD_INSTANCE_CREATED:
@@ skipping 787 matching lines @@
 }
 
 void MetricsService::LogLoadStarted() {
   HISTOGRAM_ENUMERATION("Chrome.UmaPageloadCounter", 1, 2);
   IncrementPrefValue(prefs::kStabilityPageLoadCount);
   IncrementLongPrefsValue(prefs::kUninstallMetricsPageLoadCount);
   // We need to save the prefs, as page load count is a critical stat, and it
   // might be lost due to a crash :-(.
 }
 
+#if defined(OS_WIN)
+static base::TimeDelta FromWinFileTime(FILETIME filetime) {

[rvargas (doing something else), 2012/03/21 22:54:41]

use Time::FromFileTime() instead

+  ULARGE_INTEGER large_integer;
+  large_integer.LowPart = filetime.dwLowDateTime;
+  large_integer.HighPart = filetime.dwHighDateTime;
+  // Time is supplied in 100 nano-second counts.
+  return base::TimeDelta::FromMicroseconds(large_integer.QuadPart / 10);
+}
+#endif   // OS_WIN
+
 void MetricsService::LogRendererCrash(content::RenderProcessHost* host,
                                       base::TerminationStatus status,
-                                      bool was_alive) {
+                                      bool was_alive,
+                                      base::ProcessHandle handle) {
   Profile* profile = Profile::FromBrowserContext(host->GetBrowserContext());
   ExtensionService* service = profile->GetExtensionService();
   bool was_extension_process =
       service && service->process_map()->Contains(host->GetID());
+
+#if defined(OS_WIN)
+  FILETIME win_creation_time;
+  FILETIME win_exit_time;
+  FILETIME win_kernel_time;
+  FILETIME win_user_time;
+  base::TimeDelta creation_time;
+  base::TimeDelta exit_time;
+  base::TimeDelta kernel_duration;
+  base::TimeDelta user_duration;
+  base::TimeDelta run_duration;
+  bool have_process_times = (0 != GetProcessTimes(handle, &win_creation_time,
+      &win_exit_time, &win_kernel_time, &win_user_time));
+  if (have_process_times) {
+    creation_time = FromWinFileTime(win_creation_time);
+    exit_time = FromWinFileTime(win_exit_time);
+    kernel_duration = FromWinFileTime(win_kernel_time);
+    user_duration = FromWinFileTime(win_user_time);
+    run_duration = exit_time - creation_time;
+  } else {
+    DWORD an_error = GetLastError();
+    DLOG(ERROR) << "Error getting process data" << an_error;
+  }
+#endif  // OS_WIN
+
   if (status == base::TERMINATION_STATUS_PROCESS_CRASHED ||
       status == base::TERMINATION_STATUS_ABNORMAL_TERMINATION) {
-    if (was_extension_process)
+    if (was_extension_process) {
       IncrementPrefValue(prefs::kStabilityExtensionRendererCrashCount);
-    else
+    } else {
       IncrementPrefValue(prefs::kStabilityRendererCrashCount);
 
+#if defined(OS_WIN)
+      if (have_process_times) {
+        if (status == base::TERMINATION_STATUS_PROCESS_CRASHED) {
+          UMA_HISTOGRAM_TIMES("BrowserRenderProcessHost.CrashedDuration",
+                              run_duration);
+          UMA_HISTOGRAM_TIMES("BrowserRenderProcessHost.CrashedKernelTime",
+                              kernel_duration);
+          UMA_HISTOGRAM_TIMES("BrowserRenderProcessHost.CrashedUserTime",
+                              user_duration);
+        } else {
+          DCHECK(status == base::TERMINATION_STATUS_ABNORMAL_TERMINATION);
+          UMA_HISTOGRAM_TIMES("BrowserRenderProcessHost.AbnormalTermDuration",
+                              run_duration);
+          UMA_HISTOGRAM_TIMES("BrowserRenderProcessHost.AbnormalTermKernelTime",
+                              kernel_duration);
+          UMA_HISTOGRAM_TIMES("BrowserRenderProcessHost.AbnormalTermUserTime",
+                              user_duration);
+        }
+      }
+#endif  // OS_WIN
+
+    }
+
+    // TODO(jar): These histograms should be small enumerated histograms.
     UMA_HISTOGRAM_PERCENTAGE("BrowserRenderProcessHost.ChildCrashes",
                              was_extension_process ? 2 : 1);
     if (was_alive) {
       UMA_HISTOGRAM_PERCENTAGE("BrowserRenderProcessHost.ChildCrashesWasAlive",
                                was_extension_process ? 2 : 1);
     }
   } else if (status == base::TERMINATION_STATUS_PROCESS_WAS_KILLED) {
     UMA_HISTOGRAM_PERCENTAGE("BrowserRenderProcessHost.ChildKills",
                              was_extension_process ? 2 : 1);
     if (was_alive) {
       UMA_HISTOGRAM_PERCENTAGE("BrowserRenderProcessHost.ChildKillsWasAlive",
                                was_extension_process ? 2 : 1);
     }
   }
+
+#if defined(OS_WIN)
+  if (have_process_times && !was_extension_process &&
+      status != base::TERMINATION_STATUS_PROCESS_CRASHED &&
+      status != base::TERMINATION_STATUS_ABNORMAL_TERMINATION) {
+    UMA_HISTOGRAM_TIMES("BrowserRenderProcessHost.NormalTermDuration",
+                        run_duration);
+    UMA_HISTOGRAM_TIMES("BrowserRenderProcessHost.NormalTermKernelTime",
+                        kernel_duration);
+    UMA_HISTOGRAM_TIMES("BrowserRenderProcessHost.NormalTermUserTime",
+                        user_duration);
+  }
+#endif  // OS_WIN
+
 }
 
 void MetricsService::LogRendererHang() {
   IncrementPrefValue(prefs::kStabilityRendererHangCount);
 }
 
 void MetricsService::LogNeedForCleanShutdown() {
   PrefService* pref = g_browser_process->local_state();
   pref->SetBoolean(prefs::kStabilityExitedCleanly, false);
   // Redundant setting to be sure we call for a clean shutdown.
@@ skipping 255 matching lines @@
   if (local_state) {
     const PrefService::Preference* uma_pref =
         local_state->FindPreference(prefs::kMetricsReportingEnabled);
     if (uma_pref) {
       bool success = uma_pref->GetValue()->GetAsBoolean(&result);
       DCHECK(success);
     }
   }
   return result;
 }