Bug 710935 - Measure lag in handling user input. r=bsmedberg

toolkit/components/telemetry/TelemetryHistograms.h

@@ -345,6 +345,12 @@ HISTOGRAM(FX_THUMBNAILS_CAPTURE_TIME_MS, 1, 500, 15, EXPONENTIAL, "THUMBNAILS: T
 HISTOGRAM(FX_THUMBNAILS_STORE_TIME_MS, 1, 500, 15, EXPONENTIAL, "THUMBNAILS: Time (ms) it takes to store a thumbnail in the cache")
 HISTOGRAM(FX_THUMBNAILS_HIT_OR_MISS, 0, 1, 2, BOOLEAN, "THUMBNAILS: Thumbnail found")
 
+
+/*
+ * Widget telemetry.
+ */
+HISTOGRAM(EVENTLOOP_UI_LAG, 50, 30000, 200, LINEAR, "Widget: Time (ms) it takes for the message before a UI message")
+
 /**
  * Session restore telemetry
  */

widget/windows/nsAppShell.cpp

@@ -303,15 +303,21 @@ nsAppShell::ProcessNextNativeEvent(bool mayWait)
 
   do {
     MSG msg;
+    bool uiMessage = PeekUIMessage(&msg);
+
     // Give priority to keyboard and mouse messages.
-    if (PeekUIMessage(&msg) ||
-        ::PeekMessageW(&msg, NULL, 0, 0, PM_REMOVE)) {
+    if (uiMessage ||
+        PeekMessageW(&msg, NULL, 0, 0, PM_REMOVE)) {
       gotMessage = true;
       if (msg.message == WM_QUIT) {
         ::PostQuitMessage(msg.wParam);
         Exit();
       } else {
-        mozilla::HangMonitor::NotifyActivity();
+        // If we had UI activity we would be processing it now so we know we
+        // have either kUIActivity or kActivityNoUIAVail.
+        mozilla::HangMonitor::NotifyActivity(
+          uiMessage ? mozilla::HangMonitor::kUIActivity :
+                      mozilla::HangMonitor::kActivityNoUIAVail);
         ::TranslateMessage(&msg);
         ::DispatchMessageW(&msg);
       }

xpcom/threads/HangMonitor.cpp

@@ -50,7 +50,7 @@ bool gShutdown;
 
 // The timestamp of the last event notification, or PR_INTERVAL_NO_WAIT if
 // we're currently not processing events.
-volatile PRIntervalTime gTimestamp;
+volatile PRIntervalTime gTimestamp = PR_INTERVAL_NO_WAIT;
 
 #ifdef REPORT_CHROME_HANGS
 // Main thread ID used in reporting chrome hangs under Windows
@@ -307,15 +307,70 @@ Shutdown()
   gMonitor = NULL;
 }
 
-void
-NotifyActivity()
+static bool
+IsUIMessageWaiting()
 {
-  NS_ASSERTION(NS_IsMainThread(), "HangMonitor::Notify called from off the main thread.");
+#ifndef XP_WIN
+  return false;
+#else
+  #define NS_WM_IMEFIRST WM_IME_SETCONTEXT
+  #define NS_WM_IMELAST  WM_IME_KEYUP
+  BOOL haveUIMessageWaiting = FALSE;
+  MSG msg;
+  haveUIMessageWaiting |= ::PeekMessageW(&msg, NULL, WM_KEYFIRST, 
+                                         WM_IME_KEYLAST, PM_NOREMOVE);
+  haveUIMessageWaiting |= ::PeekMessageW(&msg, NULL, NS_WM_IMEFIRST,
+                                         NS_WM_IMELAST, PM_NOREMOVE);
+  haveUIMessageWaiting |= ::PeekMessageW(&msg, NULL, WM_MOUSEFIRST,
+                                         WM_MOUSELAST, PM_NOREMOVE);
+  return haveUIMessageWaiting;
+#endif
+}
+
+void
+NotifyActivity(ActivityType activityType)
+{
+  NS_ASSERTION(NS_IsMainThread(),
+    "HangMonitor::Notify called from off the main thread.");
+
+  // Determine the activity type more specifically
+  if (activityType == kGeneralActivity) {
+    activityType = IsUIMessageWaiting() ? kActivityUIAVail : 
+                                          kActivityNoUIAVail;
+  }
+
+  // Calculate the cumulative amount of lag time since the last UI message
+  static PRUint32 cumulativeUILagMS = 0;
+  switch(activityType) {
+  case kActivityNoUIAVail:
+    cumulativeUILagMS = 0;
+    break;
+  case kActivityUIAVail:
+  case kUIActivity:
+    if (gTimestamp != PR_INTERVAL_NO_WAIT) {
+      cumulativeUILagMS += PR_IntervalToMilliseconds(PR_IntervalNow() -
+                                                     gTimestamp);
+    }
+    break;
+  }
 
   // This is not a locked activity because PRTimeStamp is a 32-bit quantity
   // which can be read/written atomically, and we don't want to pay locking
   // penalties here.
   gTimestamp = PR_IntervalNow();
+
+  // If we have UI activity we should reset the timer and report it if it is
+  // significant enough.
+  if (activityType == kUIActivity) {
+    // The minimum amount of lag time that we should report for telemetry data.
+    // Mozilla's UI responsiveness goal is 50ms
+    static const PRUint32 kUIResponsivenessThresholdMS = 50;
+    if (cumulativeUILagMS > kUIResponsivenessThresholdMS) {
+      mozilla::Telemetry::Accumulate(mozilla::Telemetry::EVENTLOOP_UI_LAG,
+                                     cumulativeUILagMS);
+    }
+    cumulativeUILagMS = 0;
+  }
 }
 
 void

xpcom/threads/HangMonitor.h

@@ -8,6 +8,23 @@
 
 namespace mozilla { namespace HangMonitor {
 
+/**
+ * Signifies the type of activity in question
+*/
+enum ActivityType {
+  /* There is activity and it is known to be UI related activity. */
+  kUIActivity,
+
+  /* There is non UI activity and no UI activity is pending */
+  kActivityNoUIAVail,
+
+  /* There is non UI activity and UI activity is known to be pending */
+  kActivityUIAVail,
+
+  /* There is non UI activity and UI activity pending is unknown */
+  kGeneralActivity
+};
+
 /**
  * Start monitoring hangs. Should be called by the XPCOM startup process only.
  */
@@ -19,12 +36,14 @@ void Startup();
 void Shutdown();
 
 /**
- * Notify the hang monitor of new activity which should reset its internal
- * timer.
+ * Notify the hang monitor of activity which will reset its internal timer.
+ * 
+ * @param activityType The type of activity being reported.
+ * @see ActivityType
  */
-void NotifyActivity();
+void NotifyActivity(ActivityType activityType = kGeneralActivity);
 
-/**
+/*
  * Notify the hang monitor that the browser is now idle and no detection should
  * be done.
  */