Bug 1523333: add setTimeout/Interval profiler markers for all uses r=mstange a=lizzard
authorRandell Jesup <rjesup@jesup.org>
Mon, 28 Jan 2019 23:52:35 -0500
changeset 515644 9df1f456d924ec6a3dc096d2c5e0e6da193d5a45
parent 515643 72201a8d9d95ed3d4a8d88b2cfe446e1ccc149e9
child 515645 0419384222dc56ac89a19062ad62d20749f9d337
push id1953
push userffxbld-merge
push dateMon, 11 Mar 2019 12:10:20 +0000
treeherdermozilla-release@9c35dcbaa899 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersmstange, lizzard
bugs1523333
milestone66.0
Bug 1523333: add setTimeout/Interval profiler markers for all uses r=mstange a=lizzard
dom/base/TimeoutManager.cpp
--- a/dom/base/TimeoutManager.cpp
+++ b/dom/base/TimeoutManager.cpp
@@ -141,17 +141,19 @@ void TimeoutManager::SetLoading(bool val
   // move to loading.  When they would have fired, we'll see we're loading
   // and move them then.
   mIsLoading = value;
 }
 
 void TimeoutManager::MoveIdleToActive() {
   uint32_t num = 0;
   TimeStamp when;
+#if MOZ_GECKO_PROFILER
   TimeStamp now;
+#endif
   // Ensure we maintain the ordering of timeouts, so timeouts
   // never fire before a timeout set for an earlier time, or
   // before a timeout for the same time already submitted.
   // See https://html.spec.whatwg.org/#dom-settimeout #16 and #17
   while (RefPtr<Timeout> timeout = mIdleTimeouts.GetLast()) {
     if (num == 0) {
       when = timeout->When();
     }
@@ -167,17 +169,17 @@ void TimeoutManager::MoveIdleToActive() 
       TimeDuration delta = now - timeout->When();
       nsPrintfCString marker(
           "Releasing deferred setTimeout() for %dms (original target time was "
           "%dms (%dms delta))",
           int(elapsed.ToMilliseconds()), int(target.ToMilliseconds()),
           int(delta.ToMilliseconds()));
       // don't have end before start...
       profiler_add_marker(
-          "setTimeout release", js::ProfilingStackFrame::Category::DOM,
+          "setTimeout deferred release", js::ProfilingStackFrame::Category::DOM,
           MakeUnique<TextMarkerPayload>(
               marker, delta.ToMilliseconds() >= 0 ? timeout->When() : now,
               now));
     }
 #endif
     num++;
   }
   if (num > 0) {
@@ -907,37 +909,38 @@ void TimeoutManager::RunTimeout(const Ti
           // No context means this window was closed or never properly
           // initialized for this language.  This timer will never fire
           // so just remove it.
           timeout->remove();
           continue;
         }
 
         // This timeout is good to run
+        bool timeout_was_cleared = mWindow.RunTimeoutHandler(timeout, scx);
 #if MOZ_GECKO_PROFILER
         if (profiler_is_active()) {
-          if (aProcessIdle) {
-            TimeDuration elapsed = now - timeout->SubmitTime();
-            TimeDuration target = timeout->When() - timeout->SubmitTime();
-            TimeDuration delta = now - timeout->When();
-            nsPrintfCString marker(
-                "%ssetTimeout() for %dms (original target time was %dms (%dms "
-                "delta))",
-                aProcessIdle ? "Deferred " : "", int(elapsed.ToMilliseconds()),
-                int(target.ToMilliseconds()), int(delta.ToMilliseconds()));
-            // don't have end before start...
-            profiler_add_marker(
-                "setTimeout", js::ProfilingStackFrame::Category::DOM,
-                MakeUnique<TextMarkerPayload>(
-                    marker, delta.ToMilliseconds() >= 0 ? timeout->When() : now,
-                    now));
-          }
+          TimeDuration elapsed = now - timeout->SubmitTime();
+          TimeDuration target = timeout->When() - timeout->SubmitTime();
+          TimeDuration delta = now - timeout->When();
+          TimeDuration runtime = TimeStamp::Now() - now;
+          nsPrintfCString marker(
+              "%sset%s() for %dms (original target time was %dms (%dms "
+              "delta)); runtime = %dms",
+              aProcessIdle ? "Deferred " : "",
+              timeout->mIsInterval ? "Interval" : "Timeout",
+              int(elapsed.ToMilliseconds()), int(target.ToMilliseconds()),
+              int(delta.ToMilliseconds()),  int(runtime.ToMilliseconds()));
+          // don't have end before start...
+          profiler_add_marker(
+              "setTimeout", js::ProfilingStackFrame::Category::DOM,
+              MakeUnique<TextMarkerPayload>(
+                  marker, delta.ToMilliseconds() >= 0 ? timeout->When() : now,
+                  now));
         }
 #endif
-        bool timeout_was_cleared = mWindow.RunTimeoutHandler(timeout, scx);
 
         MOZ_LOG(gTimeoutLog, LogLevel::Debug,
                 ("Run%s(TimeoutManager=%p, timeout=%p) returned %d\n",
                  timeout->mIsInterval ? "Interval" : "Timeout", this,
                  timeout.get(), !!timeout_was_cleared));
 
         if (timeout_was_cleared) {
           // Make sure we're not holding any Timeout objects alive.