Bug 1373814 - Add new probe to measure start-up input latency. data-r=francois r?smaug draft
authorWei-Cheng Pan <wpan@mozilla.com>
Tue, 08 Aug 2017 17:54:13 +0800
changeset 656413 497b491b795dddea9a594aa9b42ed0c1acc3b0ce
parent 656346 04b6be50a2526c7a26a63715f441c47e1aa1f9be
child 729142 fbb251bbc91143f51fdf82f6c0c0d5e3abb4e51a
push id77214
push userbmo:wpan@mozilla.com
push dateThu, 31 Aug 2017 06:39:07 +0000
reviewerssmaug
bugs1373814
milestone57.0a1
Bug 1373814 - Add new probe to measure start-up input latency. data-r=francois r?smaug For parent process, users may expect the UI is interactable after they saw the first tab has restored/shown. So this patch added a new topic "sessionstore-one-or-no-tab-restored" which represents the parent process has finished a tab restoring. If there is nothing to restore, it is effectively equal to "sessionstore-windows-restored". For centent processes, users may expect web content is interactable when the top-level-content-document has finished loading, which is different from the parent case. MozReview-Commit-ID: AtEUW80Ea6n
browser/components/sessionstore/SessionStore.jsm
layout/base/PresShell.cpp
layout/base/PresShell.h
toolkit/components/telemetry/Histograms.json
--- a/browser/components/sessionstore/SessionStore.jsm
+++ b/browser/components/sessionstore/SessionStore.jsm
@@ -966,16 +966,18 @@ var SessionStoreInternal = {
         if (gDebuggingEnabled) {
           Services.obs.notifyObservers(browser, NOTIFY_TAB_RESTORED);
         }
 
         SessionStoreInternal._resetLocalTabRestoringState(tab);
         SessionStoreInternal.restoreNextTab();
 
         this._sendTabRestoredNotification(tab, data.isRemotenessUpdate);
+
+        Services.obs.notifyObservers(null, "sessionstore-one-or-no-tab-restored");
         break;
       case "SessionStore:crashedTabRevived":
         // The browser was revived by navigating to a different page
         // manually, so we remove it from the ignored browser set.
         this._crashedBrowsers.delete(browser.permanentKey);
         break;
       case "SessionStore:error":
         TabStateFlusher.resolveAll(browser, false, "Received error from the content process");
@@ -1144,16 +1146,17 @@ var SessionStoreInternal = {
         if (isPrivateWindow) {
           // We're starting with a single private window. Save the state we
           // actually wanted to restore so that we can do it later in case
           // the user opens another, non-private window.
           this._deferredInitialState = gSessionStartup.state;
 
           // Nothing to restore now, notify observers things are complete.
           Services.obs.notifyObservers(null, NOTIFY_WINDOWS_RESTORED);
+          Services.obs.notifyObservers(null, "sessionstore-one-or-no-tab-restored");
           this._deferredAllWindowsRestored.resolve();
         } else {
           TelemetryTimestamps.add("sessionRestoreRestoring");
           this._restoreCount = aInitialState.windows ? aInitialState.windows.length : 0;
 
           // global data must be restored before restoreWindow is called so that
           // it happens before observers are notified
           this._globalState.setFromState(aInitialState);
@@ -1163,16 +1166,17 @@ var SessionStoreInternal = {
 
           let overwrite = this._isCmdLineEmpty(aWindow, aInitialState);
           let options = {firstWindow: true, overwriteTabs: overwrite};
           this.restoreWindows(aWindow, aInitialState, options);
         }
       } else {
         // Nothing to restore, notify observers things are complete.
         Services.obs.notifyObservers(null, NOTIFY_WINDOWS_RESTORED);
+        Services.obs.notifyObservers(null, "sessionstore-one-or-no-tab-restored");
         this._deferredAllWindowsRestored.resolve();
       }
     // this window was opened by _openWindowWithState
     } else if (!this._isWindowLoaded(aWindow)) {
       let state = this._statesToRestore[aWindow.__SS_restoreID];
       let options = {overwriteTabs: true, isFollowUp: state.windows.length == 1};
       this.restoreWindow(aWindow, state.windows[0], options);
     // The user opened another, non-private window after starting up with
--- a/layout/base/PresShell.cpp
+++ b/layout/base/PresShell.cpp
@@ -555,16 +555,18 @@ private:
 
 bool PresShell::sDisableNonTestMouseEvents = false;
 
 mozilla::LazyLogModule PresShell::gLog("PresShell");
 
 mozilla::TimeStamp PresShell::sLastInputCreated;
 mozilla::TimeStamp PresShell::sLastInputProcessed;
 
+bool PresShell::sProcessInteractable = false;
+
 #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;
@@ -1012,16 +1014,19 @@ PresShell::Init(nsIDocument* aDocument,
   {
     nsCOMPtr<nsIObserverService> os = mozilla::services::GetObserverService();
     if (os) {
 #ifdef MOZ_XUL
       os->AddObserver(this, "chrome-flush-skin-caches", false);
 #endif
       os->AddObserver(this, "memory-pressure", false);
       os->AddObserver(this, NS_WIDGET_WAKE_OBSERVER_TOPIC, false);
+      if (XRE_IsParentProcess() && !sProcessInteractable) {
+        os->AddObserver(this, "sessionstore-one-or-no-tab-restored", false);
+      }
     }
   }
 
 #ifdef MOZ_REFLOW_PERF
     if (mReflowCountMgr) {
       bool paintFrameCounts =
         Preferences::GetBool("layout.reflow.showframecounts");
 
@@ -1240,16 +1245,19 @@ PresShell::Destroy()
   {
     nsCOMPtr<nsIObserverService> os = mozilla::services::GetObserverService();
     if (os) {
 #ifdef MOZ_XUL
       os->RemoveObserver(this, "chrome-flush-skin-caches");
 #endif
       os->RemoveObserver(this, "memory-pressure");
       os->RemoveObserver(this, NS_WIDGET_WAKE_OBSERVER_TOPIC);
+      if (XRE_IsParentProcess()) {
+        os->RemoveObserver(this, "sessionstore-one-or-no-tab-restored");
+      }
     }
   }
 
   // If our paint suppression timer is still active, kill it.
   if (mPaintSuppressionTimer) {
     mPaintSuppressionTimer->Cancel();
     mPaintSuppressionTimer = nullptr;
   }
@@ -8276,16 +8284,42 @@ PresShell::HandleEventInternal(WidgetEve
 
     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);
+
+        if (MOZ_UNLIKELY(!sProcessInteractable)) {
+          // For content process, we use the ready state of
+          // top-level-content-document to know if the process has finished the
+          // start-up.
+          // For parent process, see the topic
+          // 'sessionstore-one-or-no-tab-restored' in PresShell::Observe.
+          if (XRE_IsContentProcess() &&
+              mDocument && mDocument->IsTopLevelContentDocument()) {
+            switch (mDocument->GetReadyStateEnum()) {
+              case nsIDocument::READYSTATE_INTERACTIVE:
+              case nsIDocument::READYSTATE_COMPLETE:
+                sProcessInteractable = true;
+                break;
+              default:
+                break;
+            }
+          }
+        }
+        if (MOZ_LIKELY(sProcessInteractable)) {
+          Telemetry::Accumulate(Telemetry::INPUT_EVENT_RESPONSE_POST_STARTUP_MS,
+                                lastMillis);
+        } else {
+          Telemetry::Accumulate(Telemetry::INPUT_EVENT_RESPONSE_STARTUP_MS,
+                                lastMillis);
+        }
       }
       sLastInputCreated = aEvent->mTimeStamp;
     } else if (aEvent->mTimeStamp < sLastInputCreated) {
       // This event was created before the last input. May be processing out
       // of order, so coalesce backwards, too.
       sLastInputCreated = aEvent->mTimeStamp;
     }
     sLastInputProcessed = now;
@@ -9714,16 +9748,29 @@ PresShell::Observe(nsISupports* aSubject
     return NS_OK;
   }
 
   if (!nsCRT::strcmp(aTopic, NS_WIDGET_WAKE_OBSERVER_TOPIC)) {
     mLastOSWake = TimeStamp::Now();
     return NS_OK;
   }
 
+  // For parent process, user may expect the UI is interactable after a
+  // tab (previously opened page or home page) has restored.
+  if (!nsCRT::strcmp(aTopic, "sessionstore-one-or-no-tab-restored")) {
+    MOZ_ASSERT(XRE_IsParentProcess());
+    sProcessInteractable = true;
+
+    nsCOMPtr<nsIObserverService> os = mozilla::services::GetObserverService();
+    if (os) {
+      os->RemoveObserver(this, "sessionstore-one-or-no-tab-restored");
+    }
+    return NS_OK;
+  }
+
   NS_WARNING("unrecognized topic in PresShell::Observe");
   return NS_ERROR_FAILURE;
 }
 
 bool
 nsIPresShell::AddRefreshObserverInternal(nsARefreshObserver* aObserver,
                                          FlushType aFlushType)
 {
--- a/layout/base/PresShell.h
+++ b/layout/base/PresShell.h
@@ -897,13 +897,15 @@ protected:
   bool                      mIsLastKeyDownCanceled : 1;
 
   static bool               sDisableNonTestMouseEvents;
 
   mozilla::TimeStamp        mLastOSWake;
 
   static mozilla::TimeStamp sLastInputCreated;
   static mozilla::TimeStamp sLastInputProcessed;
+
+  static bool               sProcessInteractable;
 };
 
 } // namespace mozilla
 
 #endif // mozilla_PresShell_h
--- a/toolkit/components/telemetry/Histograms.json
+++ b/toolkit/components/telemetry/Histograms.json
@@ -6515,16 +6515,38 @@
     "bug_numbers": [1357457],
     "expires_in_version": "61",
     "kind": "exponential",
     "high": 10000,
     "n_buckets": 50,
     "releaseChannelCollection": "opt-out",
     "description": "Time (ms) from the Input event being created to the end of it being handled, but with overlapping events coalesced."
   },
+  "INPUT_EVENT_RESPONSE_STARTUP_MS": {
+    "record_in_processes": ["main", "content"],
+    "alert_emails": ["wpan@mozilla.com"],
+    "bug_numbers": [1373814],
+    "expires_in_version": "61",
+    "kind": "exponential",
+    "high": 10000,
+    "n_buckets": 50,
+    "releaseChannelCollection": "opt-out",
+    "description": "Time (ms) from the Input event being created to the end of it being handled, but with overlapping events coalesced, which happens before the process is ready for interaction."
+  },
+  "INPUT_EVENT_RESPONSE_POST_STARTUP_MS": {
+    "record_in_processes": ["main", "content"],
+    "alert_emails": ["wpan@mozilla.com"],
+    "bug_numbers": [1373814],
+    "expires_in_version": "61",
+    "kind": "exponential",
+    "high": 10000,
+    "n_buckets": 50,
+    "releaseChannelCollection": "opt-out",
+    "description": "Time (ms) from the Input event being created to the end of it being handled, but with overlapping events coalesced, which happens after the process is ready for interaction."
+  },
   "LOAD_INPUT_EVENT_RESPONSE_MS": {
     "record_in_processes": ["main", "content"],
     "alert_emails": ["perf-telemetry-alerts@mozilla.com"],
     "bug_numbers": [1298101],
     "expires_in_version": "never",
     "kind": "exponential",
     "high": 10000,
     "n_buckets": 50,