Bug 1688300 - Add 'Runnable' profiler markers showing when runnables are executed and a 'Task' label frame showing which tasks are started by TaskController, r=bas,gerald.

Differential Revision: https://phabricator.services.mozilla.com/D102803

dom/base/nsContentUtils.cpp

@@ -5578,7 +5578,10 @@ void nsContentUtils::RemoveScriptBlocker() {
     ++firstBlocker;
 
     // Calling the runnable can reenter us
-    runnable->Run();
+    {
+      AUTO_PROFILE_FOLLOWING_RUNNABLE(runnable);
+      runnable->Run();
+    }
     // So can dropping the reference to the runnable
     runnable = nullptr;
 
@@ -5639,6 +5642,7 @@ void nsContentUtils::AddScriptRunner(already_AddRefed<nsIRunnable> aRunnable) {
     return;
   }
 
+  AUTO_PROFILE_FOLLOWING_RUNNABLE(runnable);
   runnable->Run();
 }
 
@@ -8900,9 +8904,9 @@ static inline bool ShouldEscape(nsIContent* aParent) {
   }
 
   static const nsAtom* nonEscapingElements[] = {
-      nsGkAtoms::style, nsGkAtoms::script, nsGkAtoms::xmp, nsGkAtoms::iframe,
-      nsGkAtoms::noembed, nsGkAtoms::noframes, nsGkAtoms::plaintext,
-      nsGkAtoms::noscript};
+      nsGkAtoms::style,     nsGkAtoms::script,  nsGkAtoms::xmp,
+      nsGkAtoms::iframe,    nsGkAtoms::noembed, nsGkAtoms::noframes,
+      nsGkAtoms::plaintext, nsGkAtoms::noscript};
   static mozilla::BloomFilter<12, nsAtom> sFilter;
   static bool sInitialized = false;
   if (!sInitialized) {

gfx/layers/apz/util/APZThreadUtils.cpp

@@ -6,6 +6,7 @@
 
 #include "APZThreadUtils.h"
 
+#include "GeckoProfiler.h"
 #include "mozilla/ClearOnShutdown.h"
 #include "mozilla/StaticMutex.h"
 
@@ -72,6 +73,7 @@ void APZThreadUtils::RunOnControllerThread(RefPtr<Runnable>&& aTask) {
   }
 
   if (thread->IsOnCurrentThread()) {
+    AUTO_PROFILE_FOLLOWING_RUNNABLE(task);
     task->Run();
   } else {
     thread->Dispatch(task.forget());

ipc/chromium/src/base/message_loop.cc

@@ -13,6 +13,7 @@
 #include "base/message_pump_default.h"
 #include "base/string_util.h"
 #include "base/thread_local.h"
+#include "GeckoProfiler.h"
 #include "mozilla/Atomics.h"
 #include "mozilla/Mutex.h"
 #include "nsThreadUtils.h"
@@ -461,9 +462,12 @@ void MessageLoop::RunTask(already_AddRefed<nsIRunnable> aTask) {
 
   nsCOMPtr<nsIRunnable> task = aTask;
 
-  mozilla::LogRunnable::Run log(task.get());
-  task->Run();
-  task = nullptr;
+  {
+    mozilla::LogRunnable::Run log(task.get());
+    AUTO_PROFILE_FOLLOWING_RUNNABLE(task);
+    task->Run();
+    task = nullptr;
+  }
 
   nestable_tasks_allowed_ = true;
 }

tools/profiler/public/GeckoProfiler.h

@@ -62,6 +62,8 @@
 #  define AUTO_PROFILER_LABEL_DYNAMIC_FAST(label, dynamicString, categoryPair, \
                                            ctx, flags)
 
+#  define AUTO_PROFILE_FOLLOWING_RUNNABLE(runnable)
+
 // Function stubs for when MOZ_GECKO_PROFILER is not defined.
 
 // This won't be used, it's just there to allow the empty definition of
@@ -100,7 +102,9 @@ profiler_capture_backtrace() {
 #  include "mozilla/TimeStamp.h"
 #  include "mozilla/UniquePtr.h"
 #  include "nscore.h"
+#  include "nsINamed.h"
 #  include "nsString.h"
+#  include "nsThreadUtils.h"
 
 #  include <functional>
 #  include <stdint.h>
@@ -1165,6 +1169,51 @@ class MOZ_RAII AutoProfilerLabel {
 void GetProfilerEnvVarsForChildProcess(
     std::function<void(const char* key, const char* value)>&& aSetEnv);
 
+#  ifndef MOZ_COLLECTING_RUNNABLE_TELEMETRY
+#    define AUTO_PROFILE_FOLLOWING_RUNNABLE(runnable)
+#  else
+#    define AUTO_PROFILE_FOLLOWING_RUNNABLE(runnable) \
+      mozilla::AutoProfileRunnable PROFILER_RAII(runnable)
+
+class MOZ_RAII AutoProfileRunnable {
+ public:
+  explicit AutoProfileRunnable(Runnable* aRunnable)
+      : mStartTime(TimeStamp::Now()) {
+    if (!profiler_thread_is_being_profiled()) {
+      return;
+    }
+
+    aRunnable->GetName(mName);
+  }
+  explicit AutoProfileRunnable(nsIRunnable* aRunnable)
+      : mStartTime(TimeStamp::Now()) {
+    if (!profiler_thread_is_being_profiled()) {
+      return;
+    }
+
+    nsCOMPtr<nsINamed> named = do_QueryInterface(aRunnable);
+    if (named) {
+      named->GetName(mName);
+    }
+  }
+
+  ~AutoProfileRunnable() {
+    if (!profiler_thread_is_being_profiled()) {
+      return;
+    }
+
+    AUTO_PROFILER_STATS(AUTO_PROFILE_RUNNABLE);
+    profiler_add_marker("Runnable", ::mozilla::baseprofiler::category::OTHER,
+                        MarkerTiming::IntervalUntilNowFrom(mStartTime),
+                        geckoprofiler::markers::TextMarker{}, mName);
+  }
+
+ protected:
+  TimeStamp mStartTime;
+  nsAutoCString mName;
+};
+#  endif
+
 }  // namespace mozilla
 
 #endif  // !MOZ_GECKO_PROFILER

xpcom/threads/TaskController.cpp

@@ -54,6 +54,16 @@ static int32_t GetPoolThreadCount() {
   return std::min<int32_t>(kMaximumPoolThreadCount, numCores - 1);
 }
 
+#if defined(MOZ_GECKO_PROFILER) && defined(MOZ_COLLECTING_RUNNABLE_TELEMETRY)
+#  define AUTO_PROFILE_FOLLOWING_TASK(task)                                  \
+    nsAutoCString name;                                                      \
+    (task)->GetName(name);                                                   \
+    AUTO_PROFILER_LABEL_DYNAMIC_NSCSTRING_NONSENSITIVE("Task", OTHER, name); \
+    AUTO_PROFILER_MARKER_TEXT("Runnable", OTHER, {}, name);
+#else
+#  define AUTO_PROFILE_FOLLOWING_TASK(task)
+#endif
+
 bool TaskManager::
     UpdateCachesForCurrentIterationAndReportPriorityModifierChanged(
         const MutexAutoLock& aProofOfLock, IterationType aIterationType) {
@@ -245,6 +255,7 @@ void TaskController::RunPoolThread() {
         {
           MutexAutoUnlock unlock(mGraphMutex);
           lastTask = nullptr;
+          AUTO_PROFILE_FOLLOWING_TASK(task);
           taskCompleted = task->Run();
           ranTask = true;
         }
@@ -738,6 +749,7 @@ bool TaskController::DoExecuteNextTaskOnlyMainThreadInternal(
 
         {
           LogTask::Run log(task);
+          AUTO_PROFILE_FOLLOWING_TASK(task);
           result = task->Run();
         }
 

xpcom/threads/nsThread.cpp

@@ -1160,7 +1160,16 @@ nsThread::ProcessNextEvent(bool aMayWait, bool* aResult) {
 
       mLastEventStart = now;
 
-      event->Run();
+      if (!usingTaskController) {
+        AUTO_PROFILE_FOLLOWING_RUNNABLE(event);
+        event->Run();
+      } else {
+        // Avoid generating "Runnable" profiler markers for the
+        // "TaskController::ExecutePendingMTTasks" runnables created
+        // by TaskController, which already adds "Runnable" markers
+        // when executing tasks.
+        event->Run();
+      }
 
       if (usingTaskController) {
         *aResult = TaskController::Get()->MTTaskRunnableProcessedTask();

xpcom/threads/nsThreadPool.cpp

@@ -298,6 +298,7 @@ nsThreadPool::Run() {
       current->SetRunningEventDelay(delay, TimeStamp::Now());
 
       LogRunnable::Run log(event);
+      AUTO_PROFILE_FOLLOWING_RUNNABLE(event);
       event->Run();
       // To cover the event's destructor code in the LogRunnable span
       event = nullptr;