--- a/dom/base/DOMPrefsInternal.h
+++ b/dom/base/DOMPrefsInternal.h
@@ -8,26 +8,27 @@
// main-thread in DOM.
// The format is as follows:
//
// DOM_PREF(FooBar, "foo.bar")
//
// * First argument is the name of the getter function. This defines a
// DOMPrefs::FooBar()
// * The second argument is the name of the pref.
-//
+//
// DOM_WEBIDL_PREF(FooBar)
//
// * 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
@@ -40,16 +40,19 @@ 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.
+#ifndef RELEASE_OR_BETA
+ mPerformanceCounter = new mozilla::PerformanceCounter(aKey);
+#endif
}
DocGroup::~DocGroup()
{
MOZ_ASSERT(mDocuments.IsEmpty());
if (!NS_IsMainThread()) {
nsIEventTarget* target = EventTargetFor(TaskCategory::Other);
NS_ProxyRelease("DocGroup::mReactionsStack", target, mReactionsStack.forget());
@@ -57,16 +60,19 @@ DocGroup::~DocGroup()
mTabGroup->mDocGroups.RemoveEntry(mKey);
}
nsresult
DocGroup::Dispatch(TaskCategory aCategory,
already_AddRefed<nsIRunnable>&& aRunnable)
{
+#ifndef RELEASE_OR_BETA
+ mPerformanceCounter->IncrementDispatchCounter(DispatchCategory(aCategory));
+#endif
return mTabGroup->DispatchWithDocGroup(aCategory, Move(aRunnable), this);
}
nsISerialEventTarget*
DocGroup::EventTargetFor(TaskCategory aCategory) const
{
return mTabGroup->EventTargetFor(aCategory);
}
--- a/dom/base/DocGroup.h
+++ b/dom/base/DocGroup.h
@@ -11,16 +11,18 @@
#include "nsIPrincipal.h"
#include "nsTHashtable.h"
#include "nsString.h"
#include "mozilla/dom/TabGroup.h"
#include "mozilla/RefPtr.h"
#include "mozilla/dom/CustomElementRegistry.h"
#include "mozilla/dom/HTMLSlotElement.h"
+#include "mozilla/PerformanceCounter.h"
+
namespace mozilla {
class AbstractThread;
namespace dom {
// Two browsing contexts are considered "related" if they are reachable from one
// another through window.opener, window.parent, or window.frames. This is the
// spec concept of a "unit of related browsing contexts"
@@ -49,16 +51,22 @@ public:
// |aString| may still be set to an empty string.
static MOZ_MUST_USE nsresult
GetKey(nsIPrincipal* aPrincipal, nsACString& aString);
bool MatchesKey(const nsACString& aKey)
{
return aKey == mKey;
}
+#ifndef RELEASE_OR_BETA
+ PerformanceCounter* GetPerformanceCounter()
+ {
+ return mPerformanceCounter;
+ }
+#endif
TabGroup* GetTabGroup()
{
return mTabGroup;
}
mozilla::dom::CustomElementReactionsStack* CustomElementReactionsStack()
{
MOZ_ASSERT(NS_IsMainThread());
if (!mReactionsStack) {
@@ -121,14 +129,17 @@ private:
DocGroup(TabGroup* aTabGroup, const nsACString& aKey);
~DocGroup();
nsCString mKey;
RefPtr<TabGroup> mTabGroup;
nsTArray<nsIDocument*> mDocuments;
RefPtr<mozilla::dom::CustomElementReactionsStack> mReactionsStack;
nsTArray<RefPtr<HTMLSlotElement>> mSignalSlotList;
+#ifndef RELEASE_OR_BETA
+ RefPtr<mozilla::PerformanceCounter> mPerformanceCounter;
+#endif
};
} // namespace dom
} // namespace mozilla
#endif // defined(DocGroup_h)
--- a/dom/ipc/ContentPrefs.cpp
+++ b/dom/ipc/ContentPrefs.cpp
@@ -67,16 +67,17 @@ const char* mozilla::dom::ContentPrefs::
"dom.ipc.processPriorityManager.backgroundGracePeriodMS",
"dom.ipc.processPriorityManager.backgroundPerceivableGracePeriodMS",
"dom.ipc.useNativeEventProcessing.content",
"dom.max_chrome_script_run_time",
"dom.max_ext_content_script_run_time",
"dom.max_script_run_time",
"dom.mozBrowserFramesEnabled",
"dom.performance.enable_notify_performance_timing",
+ "dom.performance.enable_scheduler_timing",
"dom.performance.enable_user_timing_logging",
"dom.placeholder.show_on_focus",
"dom.requestIdleCallback.enabled",
"dom.script_loader.bytecode_cache.enabled",
"dom.script_loader.bytecode_cache.strategy",
"dom.storage.testing",
"dom.url.encode_decode_hash",
"dom.url.getters_decode_hash",
--- a/dom/workers/WorkerPrivate.cpp
+++ b/dom/workers/WorkerPrivate.cpp
@@ -83,16 +83,19 @@ WorkerLog()
}
mozilla::LogModule*
TimeoutsLog()
{
return sWorkerTimeoutsLog;
}
+#ifdef LOG
+#undef LOG
+#endif
#define LOG(log, _args) MOZ_LOG(log, LogLevel::Debug, _args);
namespace mozilla {
using namespace ipc;
namespace dom {
@@ -2613,16 +2616,19 @@ WorkerPrivate::WorkerPrivate(WorkerPriva
, mFetchHandlerWasAdded(false)
, mOnLine(false)
, mMainThreadObjectsForgotten(false)
, mIsChromeWorker(aIsChromeWorker)
, mParentFrozen(false)
, mIsSecureContext(false)
, mDebuggerRegistered(false)
, mIsInAutomation(false)
+#ifndef RELEASE_OR_BETA
+ , mPerformanceCounter(nullptr)
+#endif
{
MOZ_ASSERT_IF(!IsDedicatedWorker(), NS_IsMainThread());
mLoadInfo.StealFrom(aLoadInfo);
if (aParent) {
aParent->AssertIsOnWorkerThread();
// Note that this copies our parent's secure context state into mJSSettings.
@@ -5240,16 +5246,30 @@ WorkerPrivate::DumpCrashInformation(nsAC
nsTObserverArray<WorkerHolder*>::ForwardIterator iter(mHolders);
while (iter.HasMore()) {
WorkerHolder* holder = iter.GetNext();
aString.Append("|");
aString.Append(holder->Name());
}
}
+#ifndef RELEASE_OR_BETA
+PerformanceCounter*
+WorkerPrivate::GetPerformanceCounter()
+{
+ AssertIsOnWorkerThread();
+
+ if (!mPerformanceCounter) {
+ mPerformanceCounter = new PerformanceCounter(NS_ConvertUTF16toUTF8(mWorkerName));
+ }
+
+ return mPerformanceCounter;
+}
+#endif
+
PerformanceStorage*
WorkerPrivate::GetPerformanceStorage()
{
AssertIsOnMainThread();
if (!mPerformanceStorage) {
mPerformanceStorage = PerformanceStorageWorker::Create(this);
}
--- a/dom/workers/WorkerPrivate.h
+++ b/dom/workers/WorkerPrivate.h
@@ -14,16 +14,17 @@
#include "nsIEventTarget.h"
#include "nsTObserverArray.h"
#include "mozilla/dom/Worker.h"
#include "mozilla/dom/WorkerHolder.h"
#include "mozilla/dom/WorkerLoadInfo.h"
#include "mozilla/dom/workerinternals/JSSettings.h"
#include "mozilla/dom/workerinternals/Queue.h"
+#include "mozilla/PerformanceCounter.h"
class nsIConsoleReportCollector;
class nsIThreadInternal;
namespace mozilla {
namespace dom {
// If you change this, the corresponding list in nsIWorkerDebugger.idl needs
@@ -568,16 +569,21 @@ public:
Control(const ServiceWorkerDescriptor& aServiceWorker);
void
ExecutionReady();
PerformanceStorage*
GetPerformanceStorage();
+#ifndef RELEASE_OR_BETA
+ PerformanceCounter*
+ GetPerformanceCounter();
+#endif
+
bool
IsAcceptingEvents()
{
AssertIsOnParentThread();
MutexAutoLock lock(mMutex);
return mParentStatus < Terminating;
}
@@ -1484,16 +1490,20 @@ private:
// use our global object's secure state there.
bool mIsSecureContext;
bool mDebuggerRegistered;
// mIsInAutomation is true when we're running in test automation.
// We expose some extra testing functions in that case.
bool mIsInAutomation;
+
+#ifndef RELEASE_OR_BETA
+ RefPtr<mozilla::PerformanceCounter> mPerformanceCounter;
+#endif
};
class AutoSyncLoopHolder
{
WorkerPrivate* mWorkerPrivate;
nsCOMPtr<nsIEventTarget> mTarget;
uint32_t mIndex;
--- a/dom/workers/WorkerThread.cpp
+++ b/dom/workers/WorkerThread.cpp
@@ -5,16 +5,17 @@
* file, You can obtain one at http://mozilla.org/MPL/2.0/. */
#include "WorkerThread.h"
#include "mozilla/Assertions.h"
#include "mozilla/ipc/BackgroundChild.h"
#include "EventQueue.h"
#include "mozilla/ThreadEventQueue.h"
+#include "mozilla/PerformanceCounter.h"
#include "nsIThreadInternal.h"
#include "WorkerPrivate.h"
#include "WorkerRunnable.h"
#ifdef DEBUG
#include "nsThreadManager.h"
#endif
@@ -222,16 +223,25 @@ 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;
+#ifndef RELEASE_OR_BETA
+ if (GetSchedulerLoggingEnabled() && onWorkerThread && mWorkerPrivate) {
+ PerformanceCounter* performanceCounter = mWorkerPrivate->GetPerformanceCounter();
+ if (performanceCounter) {
+ performanceCounter->IncrementDispatchCounter(DispatchCategory::Worker);
+ }
+ }
+#endif
+
#ifdef DEBUG
if (runnable && !onWorkerThread) {
nsCOMPtr<nsICancelableRunnable> cancelable = do_QueryInterface(runnable);
{
MutexAutoLock lock(mLock);
// Only enforce cancelable runnables after we've started the worker loop.
@@ -309,16 +319,27 @@ WorkerThread::DelayedDispatch(already_Ad
uint32_t
WorkerThread::RecursionDepth(const WorkerThreadFriendKey& /* aKey */) const
{
MOZ_ASSERT(PR_GetCurrentThread() == mThread);
return mNestedEventLoopDepth;
}
+#ifndef RELEASE_OR_BETA
+PerformanceCounter*
+WorkerThread::GetPerformanceCounter(nsIRunnable* aEvent)
+{
+ if (mWorkerPrivate) {
+ return mWorkerPrivate->GetPerformanceCounter();
+ }
+ return nullptr;
+}
+#endif
+
NS_IMPL_ISUPPORTS(WorkerThread::Observer, nsIThreadObserver)
NS_IMETHODIMP
WorkerThread::Observer::OnDispatchedEvent()
{
MOZ_CRASH("OnDispatchedEvent() should never be called!");
}
--- a/dom/workers/WorkerThread.h
+++ b/dom/workers/WorkerThread.h
@@ -76,16 +76,21 @@ public:
nsresult
DispatchAnyThread(const WorkerThreadFriendKey& aKey,
already_AddRefed<WorkerRunnable> aWorkerRunnable);
uint32_t
RecursionDepth(const WorkerThreadFriendKey& aKey) const;
+#ifndef RELEASE_OR_BETA
+ PerformanceCounter*
+ GetPerformanceCounter(nsIRunnable* aEvent) override;
+#endif
+
NS_INLINE_DECL_REFCOUNTING_INHERITED(WorkerThread, nsThread)
private:
WorkerThread();
~WorkerThread();
// This should only be called by consumers that have an
// nsIEventTarget/nsIThread pointer.
--- a/modules/libpref/init/all.js
+++ b/modules/libpref/init/all.js
@@ -191,16 +191,19 @@ pref("dom.enable_resource_timing", true)
pref("dom.enable_performance_navigation_timing", true);
// Enable printing performance marks/measures to log
pref("dom.performance.enable_user_timing_logging", false);
// Enable notification of performance timing
pref("dom.performance.enable_notify_performance_timing", false);
+// Enable collecting of docgroup activity in the scheduler
+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 Performance Observer API
pref("dom.enable_performance_observer", true);
new file mode 100644
--- /dev/null
+++ b/xpcom/tests/gtest/TestThreadMetrics.cpp
@@ -0,0 +1,200 @@
+/* -*- 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 "gtest/gtest.h"
+#include "gmock/gmock.h"
+#include "mozilla/AbstractThread.h"
+#include "mozilla/Preferences.h"
+#include "mozilla/dom/DocGroup.h"
+#include "mozilla/dom/TabGroup.h"
+#include "mozilla/SchedulerGroup.h"
+#include "mozilla/TaskCategory.h"
+#include "mozilla/PerformanceCounter.h"
+#include "nsThreadUtils.h"
+#include "nsServiceManagerUtils.h"
+
+using namespace mozilla;
+using mozilla::Runnable;
+
+
+class MockSchedulerGroup: public SchedulerGroup
+{
+public:
+ explicit MockSchedulerGroup(mozilla::dom::DocGroup* aDocGroup)
+ : mDocGroup(aDocGroup) {}
+ NS_INLINE_DECL_REFCOUNTING(MockSchedulerGroup);
+
+ MOCK_METHOD1(SetValidatingAccess, void(ValidationType aType));
+ mozilla::dom::DocGroup* DocGroup() {
+ return mDocGroup;
+ }
+protected:
+ virtual ~MockSchedulerGroup() = default;
+private:
+
+ mozilla::dom::DocGroup* mDocGroup;
+};
+
+
+typedef testing::NiceMock<MockSchedulerGroup> MSchedulerGroup;
+
+/* 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)
+ : Runnable("TimedRunnable")
+ , mExecutionTime1(aExecutionTime1)
+ , mExecutionTime2(aExecutionTime2)
+ , mRecursive(aRecursive)
+ {
+ }
+ NS_IMETHODIMP Run()
+ {
+ PR_Sleep(PR_MillisecondsToInterval(mExecutionTime1 + 5));
+ if (mRecursive) {
+ // Dispatch another runnable so nsThread::ProcessNextEvent is called recursively
+ nsCOMPtr<nsIThread> thread = do_GetMainThread();
+ nsCOMPtr<nsIRunnable> runnable = new TimedRunnable(155, 0, false);
+ 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;
+};
+
+
+/* test class used for all metrics tests
+ *
+ * - sets up the enable_scheduler_timing pref
+ * - provides a function to dispatch runnables and spin the loop
+ */
+
+static const char prefKey[] = "dom.performance.enable_scheduler_timing";
+
+class ThreadMetrics: public ::testing::Test
+{
+public:
+ explicit ThreadMetrics() = default;
+
+protected:
+ virtual void SetUp() {
+ mOldPref = Preferences::GetBool(prefKey);
+ Preferences::SetBool(prefKey, true);
+ // building the TabGroup/DocGroup structure
+ nsCString key = NS_LITERAL_CSTRING("key");
+ nsCOMPtr<nsIDocument> doc;
+ RefPtr<mozilla::dom::TabGroup> tabGroup = new mozilla::dom::TabGroup(false);
+ 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() {
+ // 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);
+ // and remove the document from the doc group (actually, a nullptr)
+ mDocGroup->RemoveDocument(nullptr);
+ mDocGroup = nullptr;
+ Preferences::SetBool(prefKey, mOldPref);
+ }
+
+ nsresult Dispatch(uint32_t aExecutionTime1, uint32_t aExecutionTime2,
+ bool aRecursive) {
+ nsCOMPtr<nsIRunnable> runnable = new TimedRunnable(aExecutionTime1,
+ aExecutionTime2,
+ aRecursive);
+ runnable = new SchedulerGroup::Runnable(runnable.forget(),
+ mSchedulerGroup, mDocGroup);
+ return mDocGroup->Dispatch(TaskCategory::Other, runnable.forget());
+ }
+
+ void ProcessAllEvents() {
+ mThreadMgr->SpinEventLoopUntilEmpty();
+ }
+
+ uint32_t mOther;
+ bool mOldPref;
+ RefPtr<MSchedulerGroup> mSchedulerGroup;
+ RefPtr<mozilla::dom::DocGroup> mDocGroup;
+ RefPtr<mozilla::PerformanceCounter> mCounter;
+ nsCOMPtr<nsIThreadManager> mThreadMgr;
+ uint32_t mDispatchCount;
+};
+
+
+TEST_F(ThreadMetrics, CollectMetrics)
+{
+ nsresult rv;
+
+ // Dispatching a runnable that will last for +100ms
+ rv = Dispatch(100, 0, false);
+ ASSERT_TRUE(NS_SUCCEEDED(rv));
+
+ // Flush the queue
+ ProcessAllEvents();
+
+ // Let's look at the task category "other" counter
+ ASSERT_EQ(mCounter->GetDispatchCounter()[mOther], 1u);
+
+ // other counters should stay empty
+ 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);
+}
+
+
+TEST_F(ThreadMetrics, CollectRecursiveMetrics)
+{
+ nsresult rv;
+
+ // Dispatching a runnable that will last for +100ms
+ // and run another one recursively
+ rv = Dispatch(50, 50, true);
+ ASSERT_TRUE(NS_SUCCEEDED(rv));
+
+ // Flush the queue
+ ProcessAllEvents();
+
+ // let's look at the counters
+ ASSERT_EQ(mCounter->GetDispatchCounter()[mOther], 1u);
+
+ // other counters should stay empty
+ 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);
+
+ // let's make sure we don't count the time spent in recursive calls
+ ASSERT_LT(duration, 150000u);
+}
--- a/xpcom/tests/gtest/moz.build
+++ b/xpcom/tests/gtest/moz.build
@@ -46,16 +46,17 @@ UNIFIED_SOURCES += [
'TestStrings.cpp',
'TestStringStream.cpp',
'TestSynchronization.cpp',
'TestTArray.cpp',
'TestTArray2.cpp',
'TestTaskQueue.cpp',
'TestTextFormatter.cpp',
'TestThreadManager.cpp',
+ 'TestThreadMetrics.cpp',
'TestThreadPool.cpp',
'TestThreadPoolListener.cpp',
'TestThreads.cpp',
'TestThreadUtils.cpp',
'TestTimers.cpp',
'TestTimeStamp.cpp',
'TestTokenizer.cpp',
'TestUTF.cpp',
new file mode 100644
--- /dev/null
+++ b/xpcom/threads/PerformanceCounter.cpp
@@ -0,0 +1,75 @@
+/* -*- 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/Logging.h"
+#include "mozilla/PerformanceCounter.h"
+
+static mozilla::LazyLogModule sPerformanceCounter("PerformanceCounter");
+#ifdef LOG
+#undef LOG
+#endif
+#define LOG(args) MOZ_LOG(sPerformanceCounter, mozilla::LogLevel::Debug, args)
+
+// this instance is the extension for the worker
+const DispatchCategory DispatchCategory::Worker = DispatchCategory((uint32_t)TaskCategory::Count);
+
+PerformanceCounter::PerformanceCounter(const nsACString& aName)
+ : mExecutionDuration(0),
+ mTotalDispatchCount(0),
+ mDispatchCounter(),
+ mName(aName)
+{
+ ResetPerformanceCounters();
+}
+
+void
+PerformanceCounter::IncrementDispatchCounter(DispatchCategory aCategory)
+{
+ mDispatchCounter[aCategory.GetValue()] += 1;
+ mTotalDispatchCount += 1;
+ LOG(("[%s] Total dispatch %" PRIu64, mName.get(), uint64_t(mTotalDispatchCount)));
+}
+
+void
+PerformanceCounter::IncrementExecutionDuration(uint32_t aMicroseconds)
+{
+ mExecutionDuration += aMicroseconds;
+ LOG(("[%s] Total duration %" PRIu64, mName.get(), uint64_t(mExecutionDuration)));
+}
+
+const DispatchCounter&
+PerformanceCounter::GetDispatchCounter()
+{
+ return mDispatchCounter;
+}
+
+uint64_t
+PerformanceCounter::GetExecutionDuration()
+{
+ return mExecutionDuration;
+}
+
+uint64_t
+PerformanceCounter::GetTotalDispatchCount()
+{
+ return mTotalDispatchCount;
+}
+
+uint32_t
+PerformanceCounter::GetDispatchCount(DispatchCategory aCategory)
+{
+ return mDispatchCounter[aCategory.GetValue()];
+}
+
+void
+PerformanceCounter::ResetPerformanceCounters()
+{
+ for (auto& cnt : mDispatchCounter) {
+ cnt = 0;
+ }
+ mExecutionDuration = 0;
+ mTotalDispatchCount = 0;
+}
new file mode 100644
--- /dev/null
+++ b/xpcom/threads/PerformanceCounter.h
@@ -0,0 +1,128 @@
+/* -*- 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/. */
+
+#ifndef mozilla_PerformanceCounter_h
+#define mozilla_PerformanceCounter_h
+
+namespace mozilla {
+
+
+/*
+ * The DispatchCategory class is used to fake the inheritance
+ * of the TaskCategory enum so we can extend it to hold
+ * one more value corresponding to the category
+ * we use when a worker dispatches a call.
+ *
+ */
+class DispatchCategory final
+{
+public:
+ explicit DispatchCategory(uint32_t aValue)
+ : mValue(aValue)
+ {
+ // Since DispatchCategory is adding one single value to the
+ // TaskCategory enum, we can check here that the value is
+ // the next index e.g. TaskCategory::Count
+ MOZ_ASSERT(aValue == (uint32_t)TaskCategory::Count);
+ }
+
+ constexpr explicit DispatchCategory(TaskCategory aValue)
+ : mValue((uint32_t)aValue)
+ {}
+
+ uint32_t
+ GetValue() const
+ {
+ return mValue;
+ }
+
+ static const DispatchCategory Worker;
+private:
+ uint32_t mValue;
+};
+
+typedef Array<Atomic<uint32_t>, (uint32_t)TaskCategory::Count + 1> DispatchCounter;
+
+// PerformanceCounter is a class that can be used to keep track of
+// runnable execution times and dispatch counts.
+//
+// - runnable execution time: time spent in a runnable when called
+// in nsThread::ProcessNextEvent (not counting recursive calls)
+// - dispatch counts: number of times a tracked runnable is dispatched
+// in nsThread. Useful to measure the activity of a tab or worker.
+//
+// The PerformanceCounter class is currently instantiated in DocGroup
+// and WorkerPrivate in order to count how many scheduler dispatches
+// are done through them, and how long the execution lasts.
+//
+// The execution time is calculated by the nsThread class (and its
+// inherited WorkerThread class) in its ProcessNextEvent method.
+//
+// For each processed runnable, nsThread will reach out the
+// PerformanceCounter attached to the runnable via its DocGroup
+// or WorkerPrivate and call IncrementExecutionDuration()
+//
+// Notice that the execution duration counting takes into account
+// recursivity. If an event triggers a recursive call to
+// nsThread::ProcessNextEVent, the counter will discard the time
+// spent in sub events.
+class PerformanceCounter final
+{
+public:
+ NS_INLINE_DECL_THREADSAFE_REFCOUNTING(PerformanceCounter)
+
+ explicit PerformanceCounter(const nsACString& aName);
+
+ /**
+ * This is called everytime a runnable is dispatched.
+ *
+ * aCategory can be used to distinguish counts per TaskCategory
+ */
+ void IncrementDispatchCounter(DispatchCategory aCategory);
+
+ /**
+ * This is called via nsThread::ProcessNextEvent to measure runnable
+ * execution duration.
+ */
+ void IncrementExecutionDuration(uint32_t aMicroseconds);
+
+ /**
+ * Returns a category/counter array of all dispatches.
+ */
+ const DispatchCounter& GetDispatchCounter();
+
+ /**
+ * Returns the total execution duration.
+ */
+ uint64_t GetExecutionDuration();
+
+ /**
+ * Returns the number of dispatches per TaskCategory.
+ */
+ uint32_t GetDispatchCount(DispatchCategory aCategory);
+
+ /**
+ * Returns the total number of dispatches.
+ */
+ uint64_t GetTotalDispatchCount();
+
+ /**
+ * Reset all counters and execution duration.
+ */
+ void ResetPerformanceCounters();
+
+private:
+ ~PerformanceCounter() {}
+
+ Atomic<uint64_t> mExecutionDuration;
+ Atomic<uint64_t> mTotalDispatchCount;
+ DispatchCounter mDispatchCounter;
+ nsCString mName;
+};
+
+} // namespace mozilla
+
+#endif // mozilla_PerformanceCounter_h
--- a/xpcom/threads/moz.build
+++ b/xpcom/threads/moz.build
@@ -47,16 +47,17 @@ EXPORTS.mozilla += [
'HangAnnotations.h',
'HangMonitor.h',
'IdleTaskRunner.h',
'LazyIdleThread.h',
'MainThreadIdlePeriod.h',
'Monitor.h',
'MozPromise.h',
'Mutex.h',
+ 'PerformanceCounter.h',
'Queue.h',
'RecursiveMutex.h',
'ReentrantMonitor.h',
'RWLock.h',
'Scheduler.h',
'SchedulerGroup.h',
'SharedThreadPool.h',
'StateMirroring.h',
@@ -92,16 +93,17 @@ UNIFIED_SOURCES += [
'nsMemoryPressure.cpp',
'nsProcessCommon.cpp',
'nsProxyRelease.cpp',
'nsThread.cpp',
'nsThreadManager.cpp',
'nsThreadPool.cpp',
'nsThreadUtils.cpp',
'nsTimerImpl.cpp',
+ 'PerformanceCounter.cpp',
'PrioritizedEventQueue.cpp',
'RecursiveMutex.cpp',
'RWLock.cpp',
'Scheduler.cpp',
'SchedulerGroup.cpp',
'SharedThreadPool.cpp',
'SynchronizedEventQueue.cpp',
'SystemGroup.cpp',
--- a/xpcom/threads/nsThread.cpp
+++ b/xpcom/threads/nsThread.cpp
@@ -23,16 +23,17 @@
#include "pratom.h"
#include "mozilla/CycleCollectedJSContext.h"
#include "mozilla/Logging.h"
#include "nsIObserverService.h"
#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/SystemGroup.h"
#include "nsXPCOMPrivate.h"
#include "mozilla/ChaosMode.h"
#include "mozilla/Telemetry.h"
#include "mozilla/TimeStamp.h"
@@ -41,16 +42,17 @@
#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 || \
@@ -553,16 +555,22 @@ nsThread::nsThread(NotNull<SynchronizedE
, mThread(nullptr)
, mNestedEventLoopDepth(0)
, mStackSize(aStackSize)
, mShutdownContext(nullptr)
, mShutdownRequired(false)
, mIsMainThread(aMainThread)
, mLastUnlabeledRunnable(TimeStamp::Now())
, mCanInvokeJS(false)
+#ifndef RELEASE_OR_BETA
+ , mCurrentEvent(nullptr)
+ , mCurrentEventStart(TimeStamp::Now())
+ , mCurrentEventLoopDepth(-1)
+ , mCurrentPerformanceCounter(nullptr)
+#endif
{
}
nsThread::~nsThread()
{
NS_ASSERTION(mRequestedShutdownContexts.IsEmpty(),
"shouldn't be waiting on other threads to shutdown");
#ifdef DEBUG
@@ -573,16 +581,26 @@ 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
}
+#ifndef RELEASE_OR_BETA
+bool
+nsThread::GetSchedulerLoggingEnabled() {
+ if (!NS_IsMainThread() || !mozilla::Preferences::IsServiceAvailable()) {
+ return false;
+ }
+ return mozilla::dom::DOMPrefs::SchedulerLoggingEnabled();
+}
+#endif
+
nsresult
nsThread::Init(const nsACString& aName)
{
// spawn thread and wait until it is fully setup
RefPtr<nsThreadStartupEvent> startup = new nsThreadStartupEvent();
NS_ADDREF_THIS();
@@ -902,16 +920,30 @@ GetLabeledRunnableName(nsIRunnable* aEve
}
if (!labeled && aPriority > EventPriority::Input) {
aName.AppendLiteral("(unlabeled)");
}
return labeled;
}
+
+mozilla::PerformanceCounter*
+nsThread::GetPerformanceCounter(nsIRunnable* aEvent)
+{
+ RefPtr<SchedulerGroup::Runnable> docRunnable = do_QueryObject(aEvent);
+ if (docRunnable) {
+ mozilla::dom::DocGroup* docGroup = docRunnable->DocGroup();
+ if (docGroup) {
+ return docGroup->GetPerformanceCounter();
+ }
+ }
+ return nullptr;
+}
+
#endif
NS_IMETHODIMP
nsThread::ProcessNextEvent(bool aMayWait, bool* aResult)
{
LOG(("THRD(%p) ProcessNextEvent [%u %u]\n", this, aMayWait,
mNestedEventLoopDepth));
@@ -975,16 +1007,26 @@ nsThread::ProcessNextEvent(bool aMayWait
if (event) {
LOG(("THRD(%p) running [%p]\n", this, event.get()));
if (MAIN_THREAD == mIsMainThread) {
HangMonitor::NotifyActivity();
}
#ifndef RELEASE_OR_BETA
+ bool schedulerLoggingEnabled = GetSchedulerLoggingEnabled();
+ 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());
+ }
+
Maybe<Telemetry::AutoTimer<Telemetry::MAIN_THREAD_RUNNABLE_MS>> timer;
Maybe<Telemetry::AutoTimer<Telemetry::IDLE_RUNNABLE_BUDGET_OVERUSE_MS>> idleTimer;
nsAutoCString name;
if ((MAIN_THREAD == mIsMainThread) || mNextIdleDeadline) {
bool labeled = GetLabeledRunnableName(event, name, priority);
if (MAIN_THREAD == mIsMainThread) {
@@ -1032,17 +1074,52 @@ nsThread::ProcessNextEvent(bool aMayWait
memcpy(sMainThreadRunnableName.begin(), name.BeginReading(), length);
sMainThreadRunnableName[length] = '\0';
}
#endif
Maybe<AutoTimeDurationHelper> timeDurationHelper;
if (priority == EventPriority::Input) {
timeDurationHelper.emplace();
}
+
+#ifndef RELEASE_OR_BETA
+ // The event starts to run, storing the timestamp.
+ bool recursiveEvent = false;
+ RefPtr<mozilla::PerformanceCounter> currentPerformanceCounter;
+ if (schedulerLoggingEnabled) {
+ recursiveEvent = mNestedEventLoopDepth > mCurrentEventLoopDepth;
+ mCurrentEventStart = mozilla::TimeStamp::Now();
+ mCurrentEvent = event;
+ mCurrentEventLoopDepth = mNestedEventLoopDepth;
+ mCurrentPerformanceCounter = GetPerformanceCounter(event);
+ currentPerformanceCounter = mCurrentPerformanceCounter;
+ }
+#endif
event->Run();
+
+#ifndef RELEASE_OR_BETA
+ // End of execution, we can send the duration for the group
+ if (schedulerLoggingEnabled) {
+ if (recursiveEvent) {
+ // If we're in a recursive call, reset the timer,
+ // so the parent gets its remaining execution time right.
+ mCurrentEventStart = mozilla::TimeStamp::Now();
+ mCurrentPerformanceCounter = currentPerformanceCounter;
+ } else {
+ // We're done with this dispatch
+ if (currentPerformanceCounter) {
+ mozilla::TimeDuration duration = TimeStamp::Now() - mCurrentEventStart;
+ currentPerformanceCounter->IncrementExecutionDuration(duration.ToMicroseconds());
+ }
+ mCurrentEvent = nullptr;
+ mCurrentEventLoopDepth = -1;
+ mCurrentPerformanceCounter = nullptr;
+ }
+ }
+#endif
} else if (aMayWait) {
MOZ_ASSERT(ShuttingDown(),
"This should only happen when shutting down");
rv = NS_ERROR_UNEXPECTED;
}
}
NOTIFY_EVENT_OBSERVERS(EventQueue()->EventObservers(), AfterProcessNextEvent, (this, *aResult));
--- a/xpcom/threads/nsThread.h
+++ b/xpcom/threads/nsThread.h
@@ -17,16 +17,17 @@
#include "mozilla/Attributes.h"
#include "mozilla/SynchronizedEventQueue.h"
#include "mozilla/NotNull.h"
#include "mozilla/TimeStamp.h"
#include "nsAutoPtr.h"
#include "mozilla/AlreadyAddRefed.h"
#include "mozilla/UniquePtr.h"
#include "mozilla/Array.h"
+#include "mozilla/dom/DocGroup.h"
namespace mozilla {
class CycleCollectedJSContext;
class ThreadEventTarget;
}
using mozilla::NotNull;
@@ -124,16 +125,20 @@ public:
mozilla::SynchronizedEventQueue* EventQueue() { return mEvents.get(); }
bool ShuttingDown()
{
return mShutdownContext != nullptr;
}
+#ifndef RELEASE_OR_BETA
+ virtual mozilla::PerformanceCounter* GetPerformanceCounter(nsIRunnable* aEvent);
+#endif
+
private:
void DoMainThreadSpecificProcessing(bool aReallyWait);
protected:
friend class nsThreadShutdownEvent;
virtual ~nsThread();
@@ -173,17 +178,23 @@ protected:
// The time when we last ran an unlabeled runnable (one not associated with a
// SchedulerGroup).
mozilla::TimeStamp mLastUnlabeledRunnable;
// Set to true if this thread creates a JSRuntime.
bool mCanInvokeJS;
#ifndef RELEASE_OR_BETA
+ 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;
#endif
};
#if defined(XP_UNIX) && !defined(ANDROID) && !defined(DEBUG) && HAVE_UALARM \
&& defined(_GNU_SOURCE)
# define MOZ_CANARY
extern int sCanaryOutputFD;