Bug 1464571 - fixes DOM Worker performance counters - r?baku,froydnj draft
authorTarek Ziadé <tarek@mozilla.com>
Tue, 19 Jun 2018 16:14:06 +0200
changeset 808429 e1e4cb7aac9cb88dc2aac4bfed99d172af5a4dc7
parent 808264 1e2c9151a09e43613a79daa8d4a94dc3e314020c
push id113379
push usertziade@mozilla.com
push dateTue, 19 Jun 2018 14:16:07 +0000
reviewersbaku, froydnj
bugs1464571
milestone62.0a1
Bug 1464571 - fixes DOM Worker performance counters - r?baku,froydnj Now uses StaticPrefs instead of DOMPrefs, and how we count dispatches for Workers. MozReview-Commit-ID: DTumwcI5bG
dom/base/DOMPrefsInternal.h
dom/base/DocGroup.cpp
dom/ipc/ContentChild.cpp
dom/ipc/ContentParent.cpp
dom/tests/browser/browser_test_performance_metrics.js
dom/tests/browser/ping_worker.html
dom/workers/WorkerPrivate.cpp
dom/workers/WorkerThread.cpp
dom/workers/WorkerThread.h
modules/libpref/init/StaticPrefList.h
xpcom/tests/gtest/TestThreadMetrics.cpp
xpcom/threads/nsThread.cpp
xpcom/threads/nsThread.h
--- a/dom/base/DOMPrefsInternal.h
+++ b/dom/base/DOMPrefsInternal.h
@@ -18,17 +18,16 @@
 //
 //   * This defines DOMPrefs::FooBar(JSContext* aCx, JSObject* aObj);
 //     This is allows the use of DOMPrefs in WebIDL files.
 
 DOM_PREF(ImageBitmapExtensionsEnabled, "canvas.imagebitmap_extensions.enabled")
 DOM_PREF(DOMCachesEnabled, "dom.caches.enabled")
 DOM_PREF(DOMCachesTestingEnabled, "dom.caches.testing.enabled")
 DOM_PREF(PerformanceLoggingEnabled, "dom.performance.enable_user_timing_logging")
-DOM_PREF(SchedulerLoggingEnabled, "dom.performance.enable_scheduler_timing")
 DOM_PREF(NotificationEnabled, "dom.webnotifications.enabled")
 DOM_PREF(NotificationEnabledInServiceWorkers, "dom.webnotifications.serviceworker.enabled")
 DOM_PREF(NotificationRIEnabled, "dom.webnotifications.requireinteraction.enabled")
 DOM_PREF(ServiceWorkersEnabled, "dom.serviceWorkers.enabled")
 DOM_PREF(ServiceWorkersTestingEnabled, "dom.serviceWorkers.testing.enabled")
 DOM_PREF(StorageManagerEnabled, "dom.storageManager.enabled")
 DOM_PREF(PromiseRejectionEventsEnabled, "dom.promise_rejection_events.enabled")
 DOM_PREF(PushEnabled, "dom.push.enabled")
--- a/dom/base/DocGroup.cpp
+++ b/dom/base/DocGroup.cpp
@@ -1,18 +1,18 @@
 /* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 2 -*- */
 /* vim: set ts=8 sts=2 et sw=2 tw=80: */
 /* This Source Code Form is subject to the terms of the Mozilla Public
  * License, v. 2.0. If a copy of the MPL was not distributed with this file,
  * You can obtain one at http://mozilla.org/MPL/2.0/. */
 
 #include "mozilla/dom/DocGroup.h"
-#include "mozilla/dom/DOMPrefs.h"
 #include "mozilla/dom/DOMTypes.h"
 #include "mozilla/dom/TabGroup.h"
+#include "mozilla/StaticPrefs.h"
 #include "mozilla/Telemetry.h"
 #include "nsIDocShell.h"
 #include "nsDOMMutationObserver.h"
 #if defined(XP_WIN)
 #include <processthreadsapi.h>  // for GetCurrentProcessId()
 #else
 #include <unistd.h> // for getpid()
 #endif // defined(XP_WIN)
@@ -47,18 +47,18 @@ DocGroup::RemoveDocument(nsIDocument* aD
   MOZ_ASSERT(mDocuments.Contains(aDocument));
   mDocuments.RemoveElement(aDocument);
 }
 
 DocGroup::DocGroup(TabGroup* aTabGroup, const nsACString& aKey)
   : mKey(aKey), mTabGroup(aTabGroup)
 {
   // This method does not add itself to mTabGroup->mDocGroups as the caller does it for us.
-  if (mozilla::dom::DOMPrefs::SchedulerLoggingEnabled()) {
-    mPerformanceCounter = new mozilla::PerformanceCounter(aKey);
+  if (mozilla::StaticPrefs::dom_performance_enable_scheduler_timing()) {
+    mPerformanceCounter = new mozilla::PerformanceCounter(NS_LITERAL_CSTRING("DocGroup:") + aKey);
   }
 }
 
 DocGroup::~DocGroup()
 {
   MOZ_ASSERT(mDocuments.IsEmpty());
   if (!NS_IsMainThread()) {
     nsIEventTarget* target = EventTargetFor(TaskCategory::Other);
--- a/dom/ipc/ContentChild.cpp
+++ b/dom/ipc/ContentChild.cpp
@@ -14,16 +14,17 @@
 #include "TabChild.h"
 #include "HandlerServiceChild.h"
 
 #include "mozilla/Attributes.h"
 #include "mozilla/LookAndFeel.h"
 #include "mozilla/Preferences.h"
 #include "mozilla/ProcessHangMonitorIPC.h"
 #include "mozilla/Unused.h"
+#include "mozilla/StaticPrefs.h"
 #include "mozilla/TelemetryIPC.h"
 #include "mozilla/devtools/HeapSnapshotTempFileHelperChild.h"
 #include "mozilla/docshell/OfflineCacheUpdateChild.h"
 #include "mozilla/dom/ClientManager.h"
 #include "mozilla/dom/ClientOpenWindowOpActors.h"
 #include "mozilla/dom/ChildProcessMessageManager.h"
 #include "mozilla/dom/ContentBridgeChild.h"
 #include "mozilla/dom/ContentBridgeParent.h"
@@ -1381,17 +1382,17 @@ ContentChild::GetResultForRenderingInitF
   // the next ContentChild::RecvReinitRendering call.
   gfxCriticalNote << "Could not initialize rendering with GPU process";
   return IPC_OK();
 }
 
 mozilla::ipc::IPCResult
 ContentChild::RecvRequestPerformanceMetrics()
 {
-  MOZ_ASSERT(mozilla::dom::DOMPrefs::SchedulerLoggingEnabled());
+  MOZ_ASSERT(mozilla::StaticPrefs::dom_performance_enable_scheduler_timing());
   nsTArray<PerformanceInfo> info;
   CollectPerformanceInfo(info);
   SendAddPerformanceMetrics(info);
   return IPC_OK();
 }
 
 mozilla::ipc::IPCResult
 ContentChild::RecvInitRendering(Endpoint<PCompositorManagerChild>&& aCompositor,
--- a/dom/ipc/ContentParent.cpp
+++ b/dom/ipc/ContentParent.cpp
@@ -91,16 +91,17 @@
 #include "mozilla/Preferences.h"
 #include "mozilla/ProcessHangMonitor.h"
 #include "mozilla/ProcessHangMonitorIPC.h"
 #include "mozilla/Scheduler.h"
 #include "mozilla/ScopeExit.h"
 #include "mozilla/ScriptPreloader.h"
 #include "mozilla/Services.h"
 #include "mozilla/StaticPtr.h"
+#include "mozilla/StaticPrefs.h"
 #include "mozilla/Telemetry.h"
 #include "mozilla/TelemetryIPC.h"
 #include "mozilla/WebBrowserPersistDocumentParent.h"
 #include "mozilla/widget/ScreenManager.h"
 #include "mozilla/Unused.h"
 #include "mozilla/HangDetails.h"
 #include "nsAnonymousTemporaryFile.h"
 #include "nsAppRunner.h"
@@ -3305,17 +3306,17 @@ ContentParent::RecvFinishMemoryReport(co
     mMemoryReportRequest = nullptr;
   }
   return IPC_OK();
 }
 
 mozilla::ipc::IPCResult
 ContentParent::RecvAddPerformanceMetrics(nsTArray<PerformanceInfo>&& aMetrics)
 {
-  if (!mozilla::dom::DOMPrefs::SchedulerLoggingEnabled()) {
+  if (!mozilla::StaticPrefs::dom_performance_enable_scheduler_timing()) {
     // The pref is off, we should not get a performance metrics from the content
     // child
     return IPC_OK();
   }
   Unused << NS_WARN_IF(NS_FAILED(mozilla::NotifyPerformanceInfo(aMetrics)));
   return IPC_OK();
 }
 
--- a/dom/tests/browser/browser_test_performance_metrics.js
+++ b/dom/tests/browser/browser_test_performance_metrics.js
@@ -58,59 +58,64 @@ add_task(async function test() {
 
   let parent_process_event = false;
   let worker_event = false;
 
   // load a 4th tab with a worker
   await BrowserTestUtils.withNewTab({ gBrowser, url: WORKER_URL },
     async function(browser) {
     // grab events..
-    var events = [];
+    let worker_duration = 0;
+    let worker_total = 0;
+    let duration = 0;
+    let total = 0;
+
     function getInfoFromService(subject, topic, value) {
       subject = subject.QueryInterface(Ci.nsIMutableArray);
       let enumerator = subject.enumerate();
       while (enumerator.hasMoreElements()) {
-        let item = enumerator.getNext();
-        item = item.QueryInterface(Ci.nsIPerformanceMetricsData);
-        if (item.pid == Services.appinfo.processID) {
+        let entry = enumerator.getNext();
+        entry = entry.QueryInterface(Ci.nsIPerformanceMetricsData);
+        if (entry.pid == Services.appinfo.processID) {
           parent_process_event = true;
         }
-        if (item.worker) {
+        if (entry.worker) {
           worker_event = true;
+          worker_duration += entry.duration;
+        } else {
+          duration += entry.duration;
         }
-        events.push(item);
+        // let's look at the XPCOM data we got back
+        let items = entry.items.QueryInterface(Ci.nsIMutableArray);
+        let enumerator2 = items.enumerate();
+        while (enumerator2.hasMoreElements()) {
+          let item = enumerator2.getNext();
+          item = item.QueryInterface(Ci.nsIPerformanceMetricsDispatchCategory);
+          if (entry.worker) {
+            worker_total += item.count;
+          } else {
+            total += item.count;
+          }
+        }
       }
     }
 
     Services.obs.addObserver(getInfoFromService, "performance-metrics");
 
     // wait until we get some events back by triggering requestPerformanceMetrics
     await BrowserTestUtils.waitForCondition(() => {
       ChromeUtils.requestPerformanceMetrics();
-      return events.length > 10;
-    }, "wait for events to come in", 500, 10);
+      return worker_duration > 0 && duration > 0 && parent_process_event;
+    }, "wait for events to come in", 250, 20);
 
     BrowserTestUtils.removeTab(page1);
     BrowserTestUtils.removeTab(page2);
     BrowserTestUtils.removeTab(page3);
 
-    // let's check the events
-    let duration = 0;
-    let total = 0;
-    for (let i=0; i < events.length; i++) {
-      duration += events[i].duration;
-      // let's look at the XPCOM data we got back
-      let items = events[i].items.QueryInterface(Ci.nsIMutableArray);
-      let enumerator = items.enumerate();
-      while (enumerator.hasMoreElements()) {
-        let item = enumerator.getNext();
-        item = item.QueryInterface(Ci.nsIPerformanceMetricsDispatchCategory);
-        total += item.count;
-      }
-    }
-
+    Assert.ok(worker_duration > 0, "Worker duration should be positive");
+    Assert.ok(worker_total > 0, "Worker count should be positive");
     Assert.ok(duration > 0, "Duration should be positive");
     Assert.ok(total > 0, "Should get a positive count");
     Assert.ok(parent_process_event, "parent process sent back some events");
   });
 
   SpecialPowers.clearUserPref('dom.performance.enable_scheduler_timing');
 });
--- a/dom/tests/browser/ping_worker.html
+++ b/dom/tests/browser/ping_worker.html
@@ -1,17 +1,18 @@
 <!DOCTYPE html>
 <html lang="en" dir="ltr">
 <head>
+  <meta charset="utf-8">
   <script type="text/javascript">
 
   var myWorker;
   function init() {
    myWorker = new Worker('ping_worker.js');
-   myWorker.postMessage("ping");
+   for (let i = 0; i++; i < 10) myWorker.postMessage("ping");
   }
 
   </script>
 </head>
 <body onload="init()">
   <h1>A page with a worker</h1>
 </body>
 </html>
--- a/dom/workers/WorkerPrivate.cpp
+++ b/dom/workers/WorkerPrivate.cpp
@@ -4,21 +4,21 @@
  * License, v. 2.0. If a copy of the MPL was not distributed with this
  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
 
 #include "WorkerPrivate.h"
 
 #include "js/MemoryMetrics.h"
 #include "MessageEventRunnable.h"
 #include "mozilla/ScopeExit.h"
+#include "mozilla/StaticPrefs.h"
 #include "mozilla/dom/ClientManager.h"
 #include "mozilla/dom/ClientSource.h"
 #include "mozilla/dom/ClientState.h"
 #include "mozilla/dom/Console.h"
-#include "mozilla/dom/DOMPrefs.h"
 #include "mozilla/dom/DOMTypes.h"
 #include "mozilla/dom/ErrorEvent.h"
 #include "mozilla/dom/ErrorEventBinding.h"
 #include "mozilla/dom/Event.h"
 #include "mozilla/dom/FunctionBinding.h"
 #include "mozilla/dom/IndexedDatabaseManager.h"
 #include "mozilla/dom/MessageEvent.h"
 #include "mozilla/dom/MessageEventBinding.h"
@@ -425,17 +425,18 @@ private:
       return false;
     }
 
     // PerformanceStorage & PerformanceCounter both need to be initialized
     // on the worker thread before being used on main-thread.
     // Let's be sure that it is created before any
     // content loading.
     aWorkerPrivate->EnsurePerformanceStorage();
-    if (mozilla::dom::DOMPrefs::SchedulerLoggingEnabled()) {
+
+    if (mozilla::StaticPrefs::dom_performance_enable_scheduler_timing()) {
       aWorkerPrivate->EnsurePerformanceCounter();
     }
 
     ErrorResult rv;
     workerinternals::LoadMainScript(aWorkerPrivate, mScriptURL, WorkerScript, rv);
     rv.WouldReportJSException();
     // Explicitly ignore NS_BINDING_ABORTED on rv.  Or more precisely, still
     // return false and don't SetWorkerScriptExecutedSuccessfully() in that
@@ -5384,26 +5385,26 @@ WorkerPrivate::DumpCrashInformation(nsAC
     aString.Append(holder->Name());
   }
 }
 
 void
 WorkerPrivate::EnsurePerformanceCounter()
 {
   AssertIsOnWorkerThread();
-  MOZ_ASSERT(mozilla::dom::DOMPrefs::SchedulerLoggingEnabled());
+  MOZ_ASSERT(mozilla::StaticPrefs::dom_performance_enable_scheduler_timing());
   if (!mPerformanceCounter) {
-    mPerformanceCounter = new PerformanceCounter(NS_ConvertUTF16toUTF8(mWorkerName));
+    nsPrintfCString workerName("Worker:%s", NS_ConvertUTF16toUTF8(mWorkerName).get());
+    mPerformanceCounter = new PerformanceCounter(workerName);
   }
 }
 
 PerformanceCounter*
 WorkerPrivate::GetPerformanceCounter()
 {
-  MOZ_ASSERT(mPerformanceCounter);
   return mPerformanceCounter;
 }
 
 PerformanceStorage*
 WorkerPrivate::GetPerformanceStorage()
 {
   AssertIsOnMainThread();
   MOZ_ASSERT(mPerformanceStorage);
--- a/dom/workers/WorkerThread.cpp
+++ b/dom/workers/WorkerThread.cpp
@@ -6,16 +6,17 @@
 
 #include "WorkerThread.h"
 
 #include "mozilla/Assertions.h"
 #include "mozilla/ipc/BackgroundChild.h"
 #include "EventQueue.h"
 #include "mozilla/ThreadEventQueue.h"
 #include "mozilla/PerformanceCounter.h"
+#include "mozilla/StaticPrefs.h"
 #include "nsIThreadInternal.h"
 #include "WorkerPrivate.h"
 #include "WorkerRunnable.h"
 
 #ifdef DEBUG
 #include "nsThreadManager.h"
 #endif
 
@@ -143,16 +144,31 @@ WorkerThread::SetWorker(const WorkerThre
 #ifdef DEBUG
       mAcceptingNonWorkerRunnables = true;
 #endif
       mWorkerPrivate = nullptr;
     }
   }
 }
 
+void
+WorkerThread::IncrementDispatchCounter()
+{
+  if (!mozilla::StaticPrefs::dom_performance_enable_scheduler_timing()) {
+    return;
+  }
+  MutexAutoLock lock(mLock);
+  if (mWorkerPrivate) {
+    PerformanceCounter* performanceCounter = mWorkerPrivate->GetPerformanceCounter();
+    if (performanceCounter) {
+      performanceCounter->IncrementDispatchCounter(DispatchCategory::Worker);
+    }
+  }
+}
+
 nsresult
 WorkerThread::DispatchPrimaryRunnable(const WorkerThreadFriendKey& /* aKey */,
                                       already_AddRefed<nsIRunnable> aRunnable)
 {
   nsCOMPtr<nsIRunnable> runnable(aRunnable);
 
 #ifdef DEBUG
   MOZ_ASSERT(PR_GetCurrentThread() != mThread);
@@ -189,16 +205,20 @@ WorkerThread::DispatchAnyThread(const Wo
       MOZ_ASSERT(!mAcceptingNonWorkerRunnables);
 
       if (onWorkerThread) {
         mWorkerPrivate->AssertIsOnWorkerThread();
       }
     }
   }
 #endif
+
+  // Increment the PerformanceCounter dispatch count
+  // to keep track of how many runnables are executed.
+  IncrementDispatchCounter();
   nsCOMPtr<nsIRunnable> runnable(aWorkerRunnable);
 
   nsresult rv = nsThread::Dispatch(runnable.forget(), NS_DISPATCH_NORMAL);
   if (NS_WARN_IF(NS_FAILED(rv))) {
     return rv;
   }
 
   // We don't need to notify the worker's condition variable here because we're
@@ -223,22 +243,16 @@ WorkerThread::Dispatch(already_AddRefed<
 
   // Workers only support asynchronous dispatch.
   if (NS_WARN_IF(aFlags != NS_DISPATCH_NORMAL)) {
     return NS_ERROR_UNEXPECTED;
   }
 
   const bool onWorkerThread = PR_GetCurrentThread() == mThread;
 
-  if (GetSchedulerLoggingEnabled() && onWorkerThread && mWorkerPrivate) {
-    PerformanceCounter* performanceCounter = mWorkerPrivate->GetPerformanceCounter();
-    if (performanceCounter) {
-      performanceCounter->IncrementDispatchCounter(DispatchCategory::Worker);
-    }
-  }
 
 #ifdef DEBUG
   if (runnable && !onWorkerThread) {
     nsCOMPtr<nsICancelableRunnable> cancelable = do_QueryInterface(runnable);
 
     {
       MutexAutoLock lock(mLock);
 
@@ -267,16 +281,19 @@ WorkerThread::Dispatch(already_AddRefed<
       workerPrivate = mWorkerPrivate;
 
       // Incrementing this counter will make the worker thread sleep if it
       // somehow tries to unset mWorkerPrivate while we're using it.
       mOtherThreadsDispatchingViaEventTarget++;
     }
   }
 
+  // Increment the PerformanceCounter dispatch count
+  // to keep track of how many runnables are executed.
+  IncrementDispatchCounter();
   nsresult rv;
   if (runnable && onWorkerThread) {
     RefPtr<WorkerRunnable> workerRunnable = workerPrivate->MaybeWrapAsWorkerRunnable(runnable.forget());
     rv = nsThread::Dispatch(workerRunnable.forget(), NS_DISPATCH_NORMAL);
   } else {
     rv = nsThread::Dispatch(runnable.forget(), NS_DISPATCH_NORMAL);
   }
 
--- a/dom/workers/WorkerThread.h
+++ b/dom/workers/WorkerThread.h
@@ -95,14 +95,17 @@ private:
   NS_IMETHOD
   Dispatch(already_AddRefed<nsIRunnable> aRunnable, uint32_t aFlags) override;
 
   NS_IMETHOD
   DispatchFromScript(nsIRunnable* aRunnable, uint32_t aFlags) override;
 
   NS_IMETHOD
   DelayedDispatch(already_AddRefed<nsIRunnable>, uint32_t) override;
+
+  void
+  IncrementDispatchCounter();
 };
 
 } // namespace dom
 } // namespace mozilla
 
 #endif // mozilla_dom_workers_WorkerThread_h__
--- a/modules/libpref/init/StaticPrefList.h
+++ b/modules/libpref/init/StaticPrefList.h
@@ -100,16 +100,22 @@ VARCACHE_PREF(
 // Whether we disable triggering mutation events for changes to style
 // attribute via CSSOM.
 VARCACHE_PREF(
   "dom.mutation-events.cssom.disabled",
    dom_mutation_events_cssom_disabled,
   bool, true
 )
 
+VARCACHE_PREF(
+  "dom.performance.enable_scheduler_timing",
+  dom_performance_enable_scheduler_timing,
+  RelaxedAtomicBool, false
+)
+
 //---------------------------------------------------------------------------
 // Full-screen prefs
 //---------------------------------------------------------------------------
 
 #ifdef RELEASE_OR_BETA
 # define PREF_VALUE false
 #else
 # define PREF_VALUE true
--- a/xpcom/tests/gtest/TestThreadMetrics.cpp
+++ b/xpcom/tests/gtest/TestThreadMetrics.cpp
@@ -4,22 +4,24 @@
  * License, v. 2.0. If a copy of the MPL was not distributed with this
  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
 
 #include "gtest/gtest.h"
 #include "gmock/gmock.h"
 #include "mozilla/AbstractThread.h"
 #include "mozilla/Preferences.h"
 #include "mozilla/dom/DocGroup.h"
+#include "mozilla/dom/DOMPrefs.h"
 #include "mozilla/dom/TabGroup.h"
 #include "mozilla/SchedulerGroup.h"
 #include "mozilla/TaskCategory.h"
 #include "mozilla/PerformanceCounter.h"
 #include "nsThreadUtils.h"
 #include "nsServiceManagerUtils.h"
+#include "nsThread.h"
 
 using namespace mozilla;
 using mozilla::Runnable;
 
 
 class MockSchedulerGroup: public SchedulerGroup
 {
 public:
@@ -43,40 +45,40 @@ typedef testing::NiceMock<MockSchedulerG
 
 /* Timed runnable which simulates some execution time
  * and can run a nested runnable.
  */
 class TimedRunnable final : public Runnable
 {
 public:
   explicit TimedRunnable(uint32_t aExecutionTime1, uint32_t aExecutionTime2,
-                         bool aRecursive)
+                         uint32_t aSubExecutionTime)
     : Runnable("TimedRunnable")
     , mExecutionTime1(aExecutionTime1)
     , mExecutionTime2(aExecutionTime2)
-    , mRecursive(aRecursive)
+    , mSubExecutionTime(aSubExecutionTime)
   {
   }
   NS_IMETHODIMP Run()
   {
     PR_Sleep(PR_MillisecondsToInterval(mExecutionTime1 + 5));
-    if (mRecursive) {
+    if (mSubExecutionTime > 0) {
       // Dispatch another runnable so nsThread::ProcessNextEvent is called recursively
       nsCOMPtr<nsIThread> thread = do_GetMainThread();
-      nsCOMPtr<nsIRunnable> runnable = new TimedRunnable(155, 0, false);
+      nsCOMPtr<nsIRunnable> runnable = new TimedRunnable(mSubExecutionTime, 0, 0);
       thread->Dispatch(runnable, NS_DISPATCH_NORMAL);
       (void)NS_ProcessNextEvent(thread, false);
     }
     PR_Sleep(PR_MillisecondsToInterval(mExecutionTime2 + 5));
     return NS_OK;
   }
 private:
-  uint32_t                    mExecutionTime1;
-  uint32_t                    mExecutionTime2;
-  bool                        mRecursive;
+  uint32_t mExecutionTime1;
+  uint32_t mExecutionTime2;
+  uint32_t mSubExecutionTime;
 };
 
 
 /* test class used for all metrics tests
  *
  * - sets up the enable_scheduler_timing pref
  * - provides a function to dispatch runnables and spin the loop
  */
@@ -99,34 +101,47 @@ protected:
     mDocGroup = tabGroup->AddDocument(key, doc);
     mSchedulerGroup = new MSchedulerGroup(mDocGroup);
     mCounter = mDocGroup->GetPerformanceCounter();
     mThreadMgr = do_GetService("@mozilla.org/thread-manager;1");
     mOther = DispatchCategory(TaskCategory::Other).GetValue();
     mDispatchCount = (uint32_t)TaskCategory::Other + 1;
   }
 
-  virtual void TearDown() {
+  void resetCounters() {
     // let's reset the counters
     mCounter->ResetPerformanceCounters();
     for (uint32_t i = 0; i < mDispatchCount; i++) {
       ASSERT_EQ(mCounter->GetDispatchCounter()[i], 0u);
     }
     ASSERT_EQ(mCounter->GetExecutionDuration(), 0u);
+  }
+
+  virtual void TearDown() {
+    // let's reset the counters
+    resetCounters();
+
     // and remove the document from the doc group (actually, a nullptr)
     mDocGroup->RemoveDocument(nullptr);
     mDocGroup = nullptr;
     Preferences::SetBool(prefKey, mOldPref);
+    ProcessAllEvents();
+  }
+
+  // this is used to get rid of transient events
+  void initScheduler() {
+    ProcessAllEvents();
   }
 
   nsresult Dispatch(uint32_t aExecutionTime1, uint32_t aExecutionTime2,
-                    bool aRecursive) {
+                    uint32_t aSubExecutionTime) {
+    ProcessAllEvents();
     nsCOMPtr<nsIRunnable> runnable = new TimedRunnable(aExecutionTime1,
                                                        aExecutionTime2,
-                                                       aRecursive);
+                                                       aSubExecutionTime);
     runnable = new SchedulerGroup::Runnable(runnable.forget(),
                                             mSchedulerGroup, mDocGroup);
     return mDocGroup->Dispatch(TaskCategory::Other, runnable.forget());
   }
 
   void ProcessAllEvents() {
     mThreadMgr->SpinEventLoopUntilEmpty();
   }
@@ -139,19 +154,20 @@ protected:
   nsCOMPtr<nsIThreadManager> mThreadMgr;
   uint32_t mDispatchCount;
 };
 
 
 TEST_F(ThreadMetrics, CollectMetrics)
 {
   nsresult rv;
+  initScheduler();
 
-  // Dispatching a runnable that will last for +100ms
-  rv = Dispatch(100, 0, false);
+  // Dispatching a runnable that will last for +50ms
+  rv = Dispatch(25, 25, 0);
   ASSERT_TRUE(NS_SUCCEEDED(rv));
 
   // Flush the queue
   ProcessAllEvents();
 
   // Let's look at the task category "other" counter
   ASSERT_EQ(mCounter->GetDispatchCounter()[mOther], 1u);
 
@@ -159,28 +175,30 @@ TEST_F(ThreadMetrics, CollectMetrics)
   for (uint32_t i = 0; i < mDispatchCount; i++) {
     if (i != mOther) {
         ASSERT_EQ(mCounter->GetDispatchCounter()[i], 0u);
     }
   }
 
   // Did we get incremented in the docgroup ?
   uint64_t duration = mCounter->GetExecutionDuration();
-  ASSERT_GE(duration, 100000u);
-  ASSERT_LT(duration, 150000u);
+  ASSERT_GE(duration, 50000u);
+  ASSERT_LT(duration, 200000u);
 }
 
 
 TEST_F(ThreadMetrics, CollectRecursiveMetrics)
 {
   nsresult rv;
 
-  // Dispatching a runnable that will last for +100ms
-  // and run another one recursively
-  rv = Dispatch(50, 50, true);
+  initScheduler();
+
+  // Dispatching a runnable that will last for +50ms
+  // and run another one recursively that lasts for 200ms
+  rv = Dispatch(25, 25, 200);
   ASSERT_TRUE(NS_SUCCEEDED(rv));
 
   // Flush the queue
   ProcessAllEvents();
 
   // let's look at the counters
   ASSERT_EQ(mCounter->GetDispatchCounter()[mOther], 1u);
 
@@ -188,13 +206,13 @@ TEST_F(ThreadMetrics, CollectRecursiveMe
   for (uint32_t i = 0; i < mDispatchCount; i++) {
     if (i != mOther) {
         ASSERT_EQ(mCounter->GetDispatchCounter()[i], 0u);
     }
   }
 
   // did we get incremented in the docgroup ?
   uint64_t duration = mCounter->GetExecutionDuration();
-  ASSERT_GE(duration, 100000u);
+  ASSERT_GE(duration, 50000u);
 
   // let's make sure we don't count the time spent in recursive calls
-  ASSERT_LT(duration, 150000u);
+  ASSERT_LT(duration, 200000u);
 }
--- a/xpcom/threads/nsThread.cpp
+++ b/xpcom/threads/nsThread.cpp
@@ -27,32 +27,32 @@
 #include "mozilla/HangMonitor.h"
 #include "mozilla/IOInterposer.h"
 #include "mozilla/ipc/MessageChannel.h"
 #include "mozilla/ipc/BackgroundChild.h"
 #include "mozilla/Preferences.h"
 #include "mozilla/Scheduler.h"
 #include "mozilla/SchedulerGroup.h"
 #include "mozilla/Services.h"
+#include "mozilla/StaticPrefs.h"
 #include "mozilla/SystemGroup.h"
 #include "nsXPCOMPrivate.h"
 #include "mozilla/ChaosMode.h"
 #include "mozilla/Telemetry.h"
 #include "mozilla/TimeStamp.h"
 #include "mozilla/Unused.h"
 #include "mozilla/dom/ScriptSettings.h"
 #include "nsICrashReporter.h"
 #include "nsThreadSyncDispatch.h"
 #include "nsServiceManagerUtils.h"
 #include "GeckoProfiler.h"
 #include "InputEventStatistics.h"
 #include "ThreadEventTarget.h"
 
 #include "mozilla/dom/ContentChild.h"
-#include "mozilla/dom/DOMPrefs.h"
 
 #ifdef XP_LINUX
 #include <sys/time.h>
 #include <sys/resource.h>
 #include <sched.h>
 #endif
 
 #define HAVE_UALARM _BSD_SOURCE || (_XOPEN_SOURCE >= 500 ||                 \
@@ -576,24 +576,16 @@ nsThread::~nsThread()
   // requesting shutdown on another, which can be helpful for diagnosing
   // the leak.
   for (size_t i = 0; i < mRequestedShutdownContexts.Length(); ++i) {
     Unused << mRequestedShutdownContexts[i].forget();
   }
 #endif
 }
 
-bool
-nsThread::GetSchedulerLoggingEnabled() {
-  if (!NS_IsMainThread() || !mozilla::Preferences::IsServiceAvailable()) {
-    return false;
-  }
-  return mozilla::dom::DOMPrefs::SchedulerLoggingEnabled();
-}
-
 nsresult
 nsThread::Init(const nsACString& aName)
 {
   // spawn thread and wait until it is fully setup
   RefPtr<nsThreadStartupEvent> startup = new nsThreadStartupEvent();
 
   NS_ADDREF_THIS();
 
@@ -998,17 +990,17 @@ nsThread::ProcessNextEvent(bool aMayWait
 
     if (event) {
       LOG(("THRD(%p) running [%p]\n", this, event.get()));
 
       if (MAIN_THREAD == mIsMainThread) {
         HangMonitor::NotifyActivity();
       }
 
-      bool schedulerLoggingEnabled = GetSchedulerLoggingEnabled();
+      bool schedulerLoggingEnabled = mozilla::StaticPrefs::dom_performance_enable_scheduler_timing();
       if (schedulerLoggingEnabled
           && mNestedEventLoopDepth > mCurrentEventLoopDepth
           && mCurrentPerformanceCounter) {
           // This is a recursive call, we're saving the time
           // spent in the parent event if the runnable is linked to a DocGroup.
           mozilla::TimeDuration duration = TimeStamp::Now() - mCurrentEventStart;
           mCurrentPerformanceCounter->IncrementExecutionDuration(duration.ToMicroseconds());
       }
--- a/xpcom/threads/nsThread.h
+++ b/xpcom/threads/nsThread.h
@@ -171,17 +171,16 @@ protected:
   nsTArray<nsAutoPtr<struct nsThreadShutdownContext>> mRequestedShutdownContexts;
 
   mozilla::Atomic<bool> mShutdownRequired;
   MainThreadFlag mIsMainThread;
 
   // Set to true if this thread creates a JSRuntime.
   bool mCanInvokeJS;
 
-  bool GetSchedulerLoggingEnabled();
   mozilla::TimeStamp mNextIdleDeadline;
   // Used to track which event is being executed by ProcessNextEvent
   nsCOMPtr<nsIRunnable> mCurrentEvent;
   mozilla::TimeStamp mCurrentEventStart;
   uint32_t mCurrentEventLoopDepth;
   RefPtr<mozilla::PerformanceCounter> mCurrentPerformanceCounter;
 };