Bug 1307242 - Add a non-blank paint telemetry probe for foreground root content documents. r=bkelly, f=bsmedberg
authorMarkus Stange <mstange@themasta.com>
Thu, 10 Nov 2016 14:26:54 -0500
changeset 322275 aa04cab9513bb57d300076b2ded9f217b2039778
parent 322274 10dd4c02d4b635ed79599ed5b9b2756bb272c3b8
child 322276 cee95271302ba9777c77449092e0cba396e6eeb7
push id30945
push usercbook@mozilla.com
push dateMon, 14 Nov 2016 09:22:29 +0000
treeherdermozilla-central@1196bf3032e1 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersbkelly
bugs1307242
milestone52.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 1307242 - Add a non-blank paint telemetry probe for foreground root content documents. r=bkelly, f=bsmedberg This adds a probe called TIME_TO_NON_BLANK_PAINT_MS which reports time to non-blank paint for root content documents whose docshell was active for the entire time between navigation start and first non-blank paint. MozReview-Commit-ID: 7JQdk5vHr1O
docshell/base/nsDocShell.cpp
dom/base/nsDOMNavigationTiming.cpp
dom/base/nsDOMNavigationTiming.h
image/SVGDocumentWrapper.cpp
layout/base/nsPresContext.cpp
toolkit/components/telemetry/Histograms.json
--- a/docshell/base/nsDocShell.cpp
+++ b/docshell/base/nsDocShell.cpp
@@ -1723,17 +1723,19 @@ nsDocShell::MaybeInitTiming()
       mBlankTiming = false;
     }
   }
 
   if (!mTiming) {
     mTiming = new nsDOMNavigationTiming();
   }
 
-  mTiming->NotifyNavigationStart();
+  mTiming->NotifyNavigationStart(
+    mIsActive ? nsDOMNavigationTiming::DocShellState::eActive
+              : nsDOMNavigationTiming::DocShellState::eInactive);
 }
 
 //
 // Bug 13871: Prevent frameset spoofing
 //
 // This routine answers: 'Is origin's document from same domain as
 // target's document?'
 //
@@ -6214,16 +6216,30 @@ nsDocShell::SetIsActive(bool aIsActive)
           ScreenOrientation::UpdateActiveOrientationLock(orientation);
         }
       }
 
       doc->PostVisibilityUpdateEvent();
     }
   }
 
+  // Tell the nsDOMNavigationTiming about it
+  RefPtr<nsDOMNavigationTiming> timing = mTiming;
+  if (!timing && mContentViewer) {
+    nsIDocument* doc = mContentViewer->GetDocument();
+    if (doc) {
+      timing = doc->GetNavigationTiming();
+    }
+  }
+  if (timing) {
+    timing->NotifyDocShellStateChanged(
+      aIsActive ? nsDOMNavigationTiming::DocShellState::eActive
+                : nsDOMNavigationTiming::DocShellState::eInactive);
+  }
+
   // Recursively tell all of our children, but don't tell <iframe mozbrowser>
   // children; they handle their state separately.
   nsTObserverArray<nsDocLoader*>::ForwardIterator iter(mChildList);
   while (iter.HasMore()) {
     nsCOMPtr<nsIDocShell> docshell = do_QueryObject(iter.GetNext());
     if (!docshell) {
       continue;
     }
--- a/dom/base/nsDOMNavigationTiming.cpp
+++ b/dom/base/nsDOMNavigationTiming.cpp
@@ -43,16 +43,17 @@ nsDOMNavigationTiming::Clear()
 
   mLoadEventStartSet = false;
   mLoadEventEndSet = false;
   mDOMLoadingSet = false;
   mDOMInteractiveSet = false;
   mDOMContentLoadedEventStartSet = false;
   mDOMContentLoadedEventEndSet = false;
   mDOMCompleteSet = false;
+  mDocShellHasBeenActiveSinceNavigationStart = false;
 }
 
 DOMTimeMilliSec
 nsDOMNavigationTiming::TimeStampToDOM(mozilla::TimeStamp aStamp) const
 {
   if (aStamp.IsNull()) {
     return 0;
   }
@@ -61,20 +62,21 @@ nsDOMNavigationTiming::TimeStampToDOM(mo
 }
 
 DOMTimeMilliSec nsDOMNavigationTiming::DurationFromStart()
 {
   return TimeStampToDOM(mozilla::TimeStamp::Now());
 }
 
 void
-nsDOMNavigationTiming::NotifyNavigationStart()
+nsDOMNavigationTiming::NotifyNavigationStart(DocShellState aDocShellState)
 {
   mNavigationStartHighRes = (double)PR_Now() / PR_USEC_PER_MSEC;
   mNavigationStartTimeStamp = mozilla::TimeStamp::Now();
+  mDocShellHasBeenActiveSinceNavigationStart = (aDocShellState == DocShellState::eActive);
 }
 
 void
 nsDOMNavigationTiming::NotifyFetchStart(nsIURI* aURI, Type aNavigationType)
 {
   mNavigationType = aNavigationType;
   // At the unload event time we don't really know the loading uri.
   // Need it for later check for unload timing access.
@@ -180,37 +182,51 @@ nsDOMNavigationTiming::NotifyDOMContentL
   if (!mDOMContentLoadedEventEndSet) {
     mLoadedURI = aURI;
     mDOMContentLoadedEventEnd = DurationFromStart();
     mDOMContentLoadedEventEndSet = true;
   }
 }
 
 void
-nsDOMNavigationTiming::NotifyNonBlankPaint()
+nsDOMNavigationTiming::NotifyNonBlankPaintForRootContentDocument()
 {
   MOZ_ASSERT(NS_IsMainThread());
   MOZ_ASSERT(!mNavigationStartTimeStamp.IsNull());
 
   if (!mNonBlankPaintTimeStamp.IsNull()) {
     return;
   }
 
   mNonBlankPaintTimeStamp = TimeStamp::Now();
   TimeDuration elapsed = mNonBlankPaintTimeStamp - mNavigationStartTimeStamp;
 
   if (profiler_is_active()) {
     nsAutoCString spec;
     if (mLoadedURI) {
       mLoadedURI->GetSpec(spec);
     }
-    nsPrintfCString marker("Non-blank paint after %dms for URL %s",
-                           int(elapsed.ToMilliseconds()), spec.get());
+    nsPrintfCString marker("Non-blank paint 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 first non-blank paint");
     PROFILER_MARKER(marker.get());
   }
+
+  if (mDocShellHasBeenActiveSinceNavigationStart) {
+    Telemetry::AccumulateTimeDelta(Telemetry::TIME_TO_NON_BLANK_PAINT_MS,
+                                   mNavigationStartTimeStamp,
+                                   mNonBlankPaintTimeStamp);
+  }
+}
+
+void
+nsDOMNavigationTiming::NotifyDocShellStateChanged(DocShellState aDocShellState)
+{
+  mDocShellHasBeenActiveSinceNavigationStart &=
+    (aDocShellState == DocShellState::eActive);
 }
 
 DOMTimeMilliSec
 nsDOMNavigationTiming::GetUnloadEventStart()
 {
   nsIScriptSecurityManager* ssm = nsContentUtils::GetSecurityManager();
   nsresult rv = ssm->CheckSameOriginURI(mLoadedURI, mUnloadedURI, false);
   if (NS_SUCCEEDED(rv)) {
--- a/dom/base/nsDOMNavigationTiming.h
+++ b/dom/base/nsDOMNavigationTiming.h
@@ -76,34 +76,40 @@ public:
   {
     return mLoadEventStart;
   }
   DOMTimeMilliSec GetLoadEventEnd() const
   {
     return mLoadEventEnd;
   }
 
-  void NotifyNavigationStart();
+  enum class DocShellState : uint8_t {
+    eActive,
+    eInactive
+  };
+
+  void NotifyNavigationStart(DocShellState aDocShellState);
   void NotifyFetchStart(nsIURI* aURI, Type aNavigationType);
   void NotifyBeforeUnload();
   void NotifyUnloadAccepted(nsIURI* aOldURI);
   void NotifyUnloadEventStart();
   void NotifyUnloadEventEnd();
   void NotifyLoadEventStart();
   void NotifyLoadEventEnd();
 
   // Document changes state to 'loading' before connecting to timing
   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 NotifyNonBlankPaint();
+  void NotifyNonBlankPaintForRootContentDocument();
+  void NotifyDocShellStateChanged(DocShellState aDocShellState);
 
   DOMTimeMilliSec TimeStampToDOM(mozilla::TimeStamp aStamp) const;
 
   inline DOMHighResTimeStamp TimeStampToDOMHighRes(mozilla::TimeStamp aStamp)
   {
     mozilla::TimeDuration duration = aStamp - mNavigationStartTimeStamp;
     return duration.ToMilliseconds();
   }
@@ -140,11 +146,12 @@ private:
   // once.
   bool mLoadEventStartSet : 1;
   bool mLoadEventEndSet : 1;
   bool mDOMLoadingSet : 1;
   bool mDOMInteractiveSet : 1;
   bool mDOMContentLoadedEventStartSet : 1;
   bool mDOMContentLoadedEventEndSet : 1;
   bool mDOMCompleteSet : 1;
+  bool mDocShellHasBeenActiveSinceNavigationStart : 1;
 };
 
 #endif /* nsDOMNavigationTiming_h___ */
--- a/image/SVGDocumentWrapper.cpp
+++ b/image/SVGDocumentWrapper.cpp
@@ -357,17 +357,17 @@ SVGDocumentWrapper::SetupViewer(nsIReque
   // document needs this navigation timing object for time computation, such
   // as to calculate current time stamp based on the start time of navigation
   // time object.
   //
   // For a root document, DocShell would do these sort of things
   // automatically. Since there is no DocShell for this wrapped SVG document,
   // we must set it up manually.
   RefPtr<nsDOMNavigationTiming> timing = new nsDOMNavigationTiming();
-  timing->NotifyNavigationStart();
+  timing->NotifyNavigationStart(nsDOMNavigationTiming::DocShellState::eInactive);
   viewer->SetNavigationTiming(timing);
 
   nsCOMPtr<nsIParser> parser = do_QueryInterface(listener);
   NS_ENSURE_TRUE(parser, NS_ERROR_UNEXPECTED);
 
   // XML-only, because this is for SVG content
   nsCOMPtr<nsIContentSink> sink = parser->GetContentSink();
   NS_ENSURE_TRUE(sink, NS_ERROR_UNEXPECTED);
--- a/layout/base/nsPresContext.cpp
+++ b/layout/base/nsPresContext.cpp
@@ -2752,19 +2752,21 @@ nsPresContext::IsRootContentDocument() c
   return (f && f->PresContext()->IsChrome());
 }
 
 void
 nsPresContext::NotifyNonBlankPaint()
 {
   MOZ_ASSERT(!mHadNonBlankPaint);
   mHadNonBlankPaint = true;
-  RefPtr<nsDOMNavigationTiming> timing = mDocument->GetNavigationTiming();
-  if (timing) {
-    timing->NotifyNonBlankPaint();
+  if (IsRootContentDocument()) {
+    RefPtr<nsDOMNavigationTiming> timing = mDocument->GetNavigationTiming();
+    if (timing) {
+      timing->NotifyNonBlankPaintForRootContentDocument();
+    }
   }
 }
 
 bool nsPresContext::GetPaintFlashing() const
 {
   if (!mPaintFlashingInitialized) {
     bool pref = Preferences::GetBool("nglayout.debug.paint_flashing");
     if (!pref && IsChrome()) {
--- a/toolkit/components/telemetry/Histograms.json
+++ b/toolkit/components/telemetry/Histograms.json
@@ -10773,10 +10773,19 @@
     "alert_emails": ["mconley@mozilla.com"],
     "bug_numbers": [1313686],
     "expires_in_version": "56",
     "kind": "exponential",
     "high": 1000,
     "n_buckets": 50,
     "description": "Time spent painting the contents of a remote browser (ms).",
     "releaseChannelCollection": "opt-out"
+  },
+  "TIME_TO_NON_BLANK_PAINT_MS": {
+    "alert_emails": ["hkirschner@mozilla.com"],
+    "expires_in_version": "55",
+    "kind": "exponential",
+    "high": 100000,
+    "n_buckets": 100,
+    "bug_numbers": [1307242],
+    "description": "The time between navigation start and the first non-blank paint of a foreground root content document, in milliseconds. This only records documents that were in an active docshell throughout the whole time between navigation start and non-blank paint. The non-blank paint timestamp is taken during display list building and does not include rasterization or compositing of that paint."
   }
 }