bug 1357457 - Report non-overlapping Input Responses to Telemetry. r=bsmedberg,masayuki data-r=bsmedberg
authorChris H-C <chutten@mozilla.com>
Wed, 19 Apr 2017 15:53:30 -0400
changeset 355253 f175826d91892402ffb6ac1510eee1baef87344c
parent 355252 42efa142306770c841597e9079d66b0f69da476f
child 355254 c1339155e30164c191881948a06c8906d8c13f57
push id41627
push userchutten@mozilla.com
push dateThu, 27 Apr 2017 14:49:50 +0000
treeherderautoland@f175826d9189 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersbsmedberg, masayuki
bugs1357457
milestone55.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
bug 1357457 - Report non-overlapping Input Responses to Telemetry. r=bsmedberg,masayuki data-r=bsmedberg Say there's a single lag event, a GC or a busy loop, during which the user types several characters. Is this one (lag) event? Several (input) events? We have INPUT_EVENT_RESPONSE_MS which will accumulate several lagged events in this case. However, that is more of an indication of how users use Firefox than how good we've been at eliminating sources of lag. INPUT_EVENT_RESPONSE_COALESCED_MS records the coalesced time spend waiting for responses to input events. So in this case it will record one value for the entire duration of the lag. MozReview-Commit-ID: H5rYnhwF0q3
layout/base/PresShell.cpp
layout/base/PresShell.h
toolkit/components/telemetry/Histograms.json
--- a/layout/base/PresShell.cpp
+++ b/layout/base/PresShell.cpp
@@ -29,16 +29,17 @@
 #include "mozilla/IMEStateManager.h"
 #include "mozilla/MemoryReporting.h"
 #include "mozilla/dom/TabChild.h"
 #include "mozilla/Likely.h"
 #include "mozilla/Logging.h"
 #include "mozilla/MouseEvents.h"
 #include "mozilla/Sprintf.h"
 #include "mozilla/TextEvents.h"
+#include "mozilla/TimeStamp.h"
 #include "mozilla/TouchEvents.h"
 #include "mozilla/UniquePtr.h"
 #include "mozilla/Unused.h"
 #include "mozilla/StyleBackendType.h"
 #include <algorithm>
 
 #ifdef XP_WIN
 #include "winuser.h"
@@ -561,16 +562,19 @@ public:
 private:
   nsCOMPtr<nsIDocument> mDocument;
 };
 
 bool PresShell::sDisableNonTestMouseEvents = false;
 
 mozilla::LazyLogModule PresShell::gLog("PresShell");
 
+mozilla::TimeStamp PresShell::sLastInputCreated;
+mozilla::TimeStamp PresShell::sLastInputProcessed;
+
 #ifdef DEBUG
 static void
 VerifyStyleTree(nsPresContext* aPresContext, nsFrameManager* aFrameManager)
 {
   if (nsFrame::GetVerifyStyleTreeEnable()) {
     if (aPresContext->RestyleManager()->IsServo()) {
       NS_ERROR("stylo: cannot verify style tree with a ServoRestyleManager");
       return;
@@ -8201,21 +8205,34 @@ PresShell::HandleEventInternal(WidgetEve
       break;
     }
   }
 
   if (Telemetry::CanRecordBase() &&
       !aEvent->mTimeStamp.IsNull() &&
       aEvent->mTimeStamp > mLastOSWake &&
       aEvent->AsInputEvent()) {
-    double millis = (TimeStamp::Now() - aEvent->mTimeStamp).ToMilliseconds();
+    TimeStamp now = TimeStamp::Now();
+    double millis = (now - aEvent->mTimeStamp).ToMilliseconds();
     Telemetry::Accumulate(Telemetry::INPUT_EVENT_RESPONSE_MS, millis);
     if (mDocument && mDocument->GetReadyStateEnum() != nsIDocument::READYSTATE_COMPLETE) {
       Telemetry::Accumulate(Telemetry::LOAD_INPUT_EVENT_RESPONSE_MS, millis);
     }
+
+    if (!sLastInputProcessed || sLastInputProcessed < aEvent->mTimeStamp) {
+      if (sLastInputProcessed) {
+        // This input event was created after we handled the last one.
+        // Accumulate the previous events' coalesced duration.
+        double lastMillis = (sLastInputProcessed - sLastInputCreated).ToMilliseconds();
+        Telemetry::Accumulate(Telemetry::INPUT_EVENT_RESPONSE_COALESCED_MS,
+                              lastMillis);
+      }
+      sLastInputCreated = aEvent->mTimeStamp;
+    }
+    sLastInputProcessed = now;
   }
 
   return rv;
 }
 
 /* static */ void
 nsIPresShell::DispatchGotOrLostPointerCaptureEvent(
                 bool aIsGotCapture,
--- a/layout/base/PresShell.h
+++ b/layout/base/PresShell.h
@@ -902,13 +902,16 @@ protected:
   // Whether the widget has received a paint message yet.
   bool                      mHasReceivedPaintMessage : 1;
 
   bool                      mIsLastKeyDownCanceled : 1;
 
   static bool               sDisableNonTestMouseEvents;
 
   mozilla::TimeStamp        mLastOSWake;
+
+  static mozilla::TimeStamp sLastInputCreated;
+  static mozilla::TimeStamp sLastInputProcessed;
 };
 
 } // namespace mozilla
 
 #endif // mozilla_PresShell_h
--- a/toolkit/components/telemetry/Histograms.json
+++ b/toolkit/components/telemetry/Histograms.json
@@ -5584,16 +5584,25 @@
     "alert_emails": ["perf-telemetry-alerts@mozilla.com"],
     "bug_numbers": [1235908],
     "expires_in_version": "never",
     "kind": "exponential",
     "high": 10000,
     "n_buckets": 50,
     "description": "Time (ms) from the Input event being created to the end of it being handled"
   },
+  "INPUT_EVENT_RESPONSE_COALESCED_MS": {
+    "alert_emails": ["perf-telemetry-alerts@mozilla.com"],
+    "bug_numbers": [1357457],
+    "expires_in_version": "61",
+    "kind": "exponential",
+    "high": 10000,
+    "n_buckets": 50,
+    "description": "Time (ms) from the Input event being created to the end of it being handled, but with overlapping events coalesced."
+  },
   "LOAD_INPUT_EVENT_RESPONSE_MS": {
     "alert_emails": ["perf-telemetry-alerts@mozilla.com"],
     "bug_numbers": [1298101],
     "expires_in_version": "never",
     "kind": "exponential",
     "high": 10000,
     "n_buckets": 50,
     "description": "Time (ms) from the Input event being created to the end of it being handled for events handling during page load only"