Bug 1457325 - Expose time to DOMContentFlushed on the timeline. r=bholley,r=mstange
authorBobby Holley <bobbyholley@gmail.com>
Thu, 26 Apr 2018 15:36:52 -0700
changeset 472229 560f881dffb8c2c35384ca89dc7a25df1ee15a7b
parent 472228 9ebd471b8e07825cae5aca75a69eb97dd5d079a1
child 472230 e03927d418ba7b3535eff25063a31704c417510e
push id1728
push userjlund@mozilla.com
push dateMon, 18 Jun 2018 21:12:27 +0000
treeherdermozilla-release@c296fde26f5f [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersbholley, mstange
bugs1457325
milestone61.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 1457325 - Expose time to DOMContentFlushed on the timeline. r=bholley,r=mstange MozReview-Commit-ID: E6QPjgfUKdo
dom/base/nsDOMNavigationTiming.cpp
dom/base/nsDOMNavigationTiming.h
dom/base/nsDocument.cpp
dom/performance/PerformanceTiming.h
dom/webidl/PerformanceTiming.webidl
layout/base/nsPresContext.cpp
layout/base/nsPresContext.h
layout/base/nsRefreshDriver.cpp
layout/base/nsRefreshDriver.h
modules/libpref/init/all.js
--- a/dom/base/nsDOMNavigationTiming.cpp
+++ b/dom/base/nsDOMNavigationTiming.cpp
@@ -292,16 +292,43 @@ nsDOMNavigationTiming::NotifyNonBlankPai
 
     Telemetry::AccumulateTimeDelta(Telemetry::TIME_TO_NON_BLANK_PAINT_MS,
                                    mNavigationStart,
                                    mNonBlankPaint);
   }
 }
 
 void
+nsDOMNavigationTiming::NotifyDOMContentFlushedForRootContentDocument()
+{
+  MOZ_ASSERT(NS_IsMainThread());
+  MOZ_ASSERT(!mNavigationStart.IsNull());
+
+  if (!mDOMContentFlushed.IsNull()) {
+    return;
+  }
+
+  mDOMContentFlushed = TimeStamp::Now();
+
+#ifdef MOZ_GECKO_PROFILER
+  if (profiler_is_active()) {
+    TimeDuration elapsed = mDOMContentFlushed - mNavigationStart;
+    nsAutoCString spec;
+    if (mLoadedURI) {
+      mLoadedURI->GetSpec(spec);
+    }
+    nsPrintfCString marker("DOMContentFlushed after %dms for URL %s, %s",
+                           int(elapsed.ToMilliseconds()), spec.get(),
+                           mDocShellHasBeenActiveSinceNavigationStart ? "foreground tab" : "this tab was inactive some of the time between navigation start and DOMContentFlushed");
+    profiler_add_marker(marker.get());
+  }
+#endif
+}
+
+void
 nsDOMNavigationTiming::NotifyDocShellStateChanged(DocShellState aDocShellState)
 {
   mDocShellHasBeenActiveSinceNavigationStart &=
     (aDocShellState == DocShellState::eActive);
 }
 
 mozilla::TimeStamp
 nsDOMNavigationTiming::GetUnloadEventStartTimeStamp() const
--- a/dom/base/nsDOMNavigationTiming.h
+++ b/dom/base/nsDOMNavigationTiming.h
@@ -91,16 +91,20 @@ public:
   DOMTimeMilliSec GetLoadEventEnd() const
   {
     return TimeStampToDOM(mLoadEventEnd);
   }
   DOMTimeMilliSec GetTimeToNonBlankPaint() const
   {
     return TimeStampToDOM(mNonBlankPaint);
   }
+  DOMTimeMilliSec GetTimeToDOMContentFlushed() const
+  {
+    return TimeStampToDOM(mDOMContentFlushed);
+  }
 
   DOMHighResTimeStamp GetUnloadEventStartHighRes()
   {
     mozilla::TimeStamp stamp = GetUnloadEventStartTimeStamp();
     if (stamp.IsNull()) {
       return 0;
     }
     return TimeStampToDOMHighRes(stamp);
@@ -156,16 +160,17 @@ public:
   void SetDOMLoadingTimeStamp(nsIURI* aURI, mozilla::TimeStamp aValue);
   void NotifyDOMLoading(nsIURI* aURI);
   void NotifyDOMInteractive(nsIURI* aURI);
   void NotifyDOMComplete(nsIURI* aURI);
   void NotifyDOMContentLoadedStart(nsIURI* aURI);
   void NotifyDOMContentLoadedEnd(nsIURI* aURI);
 
   void NotifyNonBlankPaintForRootContentDocument();
+  void NotifyDOMContentFlushedForRootContentDocument();
   void NotifyDocShellStateChanged(DocShellState aDocShellState);
 
   DOMTimeMilliSec TimeStampToDOM(mozilla::TimeStamp aStamp) const;
 
   inline DOMHighResTimeStamp TimeStampToDOMHighRes(mozilla::TimeStamp aStamp) const
   {
     if (aStamp.IsNull()) {
       return 0;
@@ -189,16 +194,17 @@ private:
 
   nsCOMPtr<nsIURI> mUnloadedURI;
   nsCOMPtr<nsIURI> mLoadedURI;
 
   Type mNavigationType;
   DOMHighResTimeStamp mNavigationStartHighRes;
   mozilla::TimeStamp mNavigationStart;
   mozilla::TimeStamp mNonBlankPaint;
+  mozilla::TimeStamp mDOMContentFlushed;
 
   mozilla::TimeStamp mBeforeUnloadStart;
   mozilla::TimeStamp mUnloadStart;
   mozilla::TimeStamp mUnloadEnd;
   mozilla::TimeStamp mLoadEventStart;
   mozilla::TimeStamp mLoadEventEnd;
 
   mozilla::TimeStamp mDOMLoading;
--- a/dom/base/nsDocument.cpp
+++ b/dom/base/nsDocument.cpp
@@ -5459,16 +5459,20 @@ nsIDocument::UnblockDOMContentLoaded()
   MOZ_ASSERT(mBlockDOMContentLoaded);
   if (--mBlockDOMContentLoaded != 0 || mDidFireDOMContentLoaded) {
     return;
   }
 
   MOZ_LOG(gDocumentLeakPRLog, LogLevel::Debug, ("DOCUMENT %p UnblockDOMContentLoaded", this));
 
   mDidFireDOMContentLoaded = true;
+  if (nsIPresShell* shell = GetShell()) {
+    shell->GetRefreshDriver()->NotifyDOMContentLoaded();
+  }
+
 
   MOZ_ASSERT(mReadyState == READYSTATE_INTERACTIVE);
   if (!mSynchronousDOMContentLoaded) {
     MOZ_RELEASE_ASSERT(NS_IsMainThread());
     nsCOMPtr<nsIRunnable> ev =
       NewRunnableMethod("nsIDocument::DispatchContentLoadedEvents",
                         this,
                         &nsIDocument::DispatchContentLoadedEvents);
--- a/dom/performance/PerformanceTiming.h
+++ b/dom/performance/PerformanceTiming.h
@@ -435,16 +435,30 @@ public:
     if (mPerformance->IsSystemPrincipal()) {
       return GetDOMTiming()->GetTimeToNonBlankPaint();
     }
     return nsRFPService::ReduceTimePrecisionAsMSecs(
       GetDOMTiming()->GetTimeToNonBlankPaint(),
       mPerformance->GetRandomTimelineSeed());
   }
 
+  DOMTimeMilliSec TimeToDOMContentFlushed() const
+  {
+    if (!nsContentUtils::IsPerformanceTimingEnabled() ||
+        nsContentUtils::ShouldResistFingerprinting()) {
+      return 0;
+    }
+    if (mPerformance->IsSystemPrincipal()) {
+      return GetDOMTiming()->GetTimeToDOMContentFlushed();
+    }
+    return nsRFPService::ReduceTimePrecisionAsMSecs(
+      GetDOMTiming()->GetTimeToDOMContentFlushed(),
+      mPerformance->GetRandomTimelineSeed());
+  }
+
   PerformanceTimingData* Data() const
   {
     return mTimingData.get();
   }
 
 private:
   ~PerformanceTiming();
 
--- a/dom/webidl/PerformanceTiming.webidl
+++ b/dom/webidl/PerformanceTiming.webidl
@@ -34,10 +34,16 @@ interface PerformanceTiming {
   readonly attribute unsigned long long loadEventEnd;
 
   // This is a Chrome proprietary extension and not part of the
   // performance/navigation timing specification.
   // Returns 0 if a non-blank paint has not happened.
   [Pref="dom.performance.time_to_non_blank_paint.enabled"]
   readonly attribute unsigned long long timeToNonBlankPaint;
 
+  // This is a Mozilla proprietary extension and not part of the
+  // performance/navigation timing specification. It marks the
+  // completion of the first presentation flush after DOMContentLoaded.
+  [Pref="dom.performance.time_to_dom_content_flushed.enabled"]
+  readonly attribute unsigned long long timeToDOMContentFlushed;
+
   jsonifier;
 };
--- a/layout/base/nsPresContext.cpp
+++ b/layout/base/nsPresContext.cpp
@@ -2909,16 +2909,28 @@ nsPresContext::NotifyNonBlankPaint()
     if (timing) {
       timing->NotifyNonBlankPaintForRootContentDocument();
     }
 
     mFirstNonBlankPaintTime = TimeStamp::Now();
   }
 }
 
+void
+nsPresContext::NotifyDOMContentFlushed()
+{
+  NS_ENSURE_TRUE_VOID(mShell);
+  if (IsRootContentDocument()) {
+    RefPtr<nsDOMNavigationTiming> timing = mDocument->GetNavigationTiming();
+    if (timing) {
+      timing->NotifyDOMContentFlushedForRootContentDocument();
+    }
+  }
+}
+
 bool nsPresContext::GetPaintFlashing() const
 {
   if (!mPaintFlashingInitialized) {
     bool pref = Preferences::GetBool("nglayout.debug.paint_flashing");
     if (!pref && IsChrome()) {
       pref = Preferences::GetBool("nglayout.debug.paint_flashing_chrome");
     }
     mPaintFlashing = pref;
--- a/layout/base/nsPresContext.h
+++ b/layout/base/nsPresContext.h
@@ -1138,16 +1138,17 @@ public:
 
   bool IsRootContentDocument() const;
 
   bool HadNonBlankPaint() const {
     return mHadNonBlankPaint;
   }
 
   void NotifyNonBlankPaint();
+  void NotifyDOMContentFlushed();
 
   bool UsesRootEMUnits() const {
     return mUsesRootEMUnits;
   }
 
   void SetUsesRootEMUnits(bool aValue) {
     mUsesRootEMUnits = aValue;
   }
--- a/layout/base/nsRefreshDriver.cpp
+++ b/layout/base/nsRefreshDriver.cpp
@@ -1158,16 +1158,17 @@ nsRefreshDriver::nsRefreshDriver(nsPresC
     mNeedToRecomputeVisibility(false),
     mTestControllingRefreshes(false),
     mViewManagerFlushIsPending(false),
     mHasScheduleFlush(false),
     mInRefresh(false),
     mWaitingForTransaction(false),
     mSkippedPaints(false),
     mResizeSuppressed(false),
+    mNotifyDOMContentFlushed(false),
     mWarningThreshold(REFRESH_WAIT_WARNING)
 {
   MOZ_ASSERT(NS_IsMainThread());
   MOZ_ASSERT(mPresContext,
              "Need a pres context to tell us to call Disconnect() later "
              "and decrement sRefreshDriverCount.");
   mMostRecentRefreshEpochTime = JS_Now();
   mMostRecentRefresh = TimeStamp::Now();
@@ -1330,16 +1331,29 @@ nsRefreshDriver::RemoveImageRequest(imgI
     ImageStartData* start = mStartTable.Get(delay);
     if (start) {
       start->mEntries.RemoveEntry(aRequest);
     }
   }
 }
 
 void
+nsRefreshDriver::NotifyDOMContentLoaded()
+{
+  // If the refresh driver is going to tick, we mark the timestamp after
+  // everything is flushed in the next tick. If it isn't, mark ourselves as
+  // flushed now.
+  if (!HasObservers()) {
+      GetPresContext()->NotifyDOMContentFlushed();
+  } else {
+    mNotifyDOMContentFlushed = true;
+  }
+}
+
+void
 nsRefreshDriver::EnsureTimerStarted(EnsureTimerStartedFlags aFlags)
 {
   // FIXME: Bug 1346065: We should also assert the case where we have
   // STYLO_THREADS=1.
   MOZ_ASSERT(!ServoStyleSet::IsInServoTraversal() || NS_IsMainThread(),
              "EnsureTimerStarted should be called only when we are not "
              "in servo traversal or on the main-thread");
 
@@ -2068,16 +2082,21 @@ nsRefreshDriver::Tick(int64_t aNowEpoch,
     dispatchRunnablesAfterTick = true;
     mHasScheduleFlush = false;
   }
 
 #ifndef ANDROID  /* bug 1142079 */
   mozilla::Telemetry::AccumulateTimeDelta(mozilla::Telemetry::REFRESH_DRIVER_TICK, mTickStart);
 #endif
 
+  if (mNotifyDOMContentFlushed) {
+    mNotifyDOMContentFlushed = false;
+    mPresContext->NotifyDOMContentFlushed();
+  }
+
   nsTObserverArray<nsAPostRefreshObserver*>::ForwardIterator iter(mPostRefreshObservers);
   while (iter.HasMore()) {
     nsAPostRefreshObserver* observer = iter.GetNext();
     observer->DidRefresh();
   }
 
   NS_ASSERTION(mInRefresh, "Still in refresh");
 
--- a/layout/base/nsRefreshDriver.h
+++ b/layout/base/nsRefreshDriver.h
@@ -393,16 +393,18 @@ public:
                                             uint32_t aDelay);
   static void CancelIdleRunnable(nsIRunnable* aRunnable);
 
   bool SkippedPaints() const
   {
     return mSkippedPaints;
   }
 
+  void NotifyDOMContentLoaded();
+
 private:
   typedef nsTObserverArray<nsARefreshObserver*> ObserverArray;
   typedef nsTArray<RefPtr<mozilla::Runnable>> ScrollEventArray;
   typedef nsTHashtable<nsISupportsHashKey> RequestTable;
   struct ImageStartData {
     ImageStartData()
     {
     }
@@ -490,16 +492,19 @@ private:
   // of waiting until the next interval.
   bool mSkippedPaints;
 
   // True if view managers should delay any resize request until the
   // next tick by the refresh driver. This flag will be reset at the
   // start of every tick.
   bool mResizeSuppressed;
 
+  // True if the next tick should notify DOMContentFlushed.
+  bool mNotifyDOMContentFlushed;
+
   int64_t mMostRecentRefreshEpochTime;
   // Number of seconds that the refresh driver is blocked waiting for a compositor
   // transaction to be completed before we append a note to the gfx critical log.
   // The number is doubled every time the threshold is hit.
   uint64_t mWarningThreshold;
   mozilla::TimeStamp mMostRecentRefresh;
   mozilla::TimeStamp mMostRecentTick;
   mozilla::TimeStamp mTickStart;
--- a/modules/libpref/init/all.js
+++ b/modules/libpref/init/all.js
@@ -195,16 +195,19 @@ pref("dom.performance.enable_notify_perf
 pref("dom.performance.enable_scheduler_timing", false);
 
 // Enable Permission API's .revoke() method
 pref("dom.permissions.revoke.enable", false);
 
 // Enable exposing timeToNonBlankPaint
 pref("dom.performance.time_to_non_blank_paint.enabled", false);
 
+// Enable exposing timeToDOMContentFlushed
+pref("dom.performance.time_to_dom_content_flushed.enabled", false);
+
 // Enable Performance Observer API
 pref("dom.enable_performance_observer", true);
 
 // Enable requestIdleCallback API
 pref("dom.requestIdleCallback.enabled", true);
 
 // Whether the Gamepad API is enabled
 pref("dom.gamepad.enabled", true);