Bug 1572337: Make GetRunningEventDelay handle threadpools r=froydnj

Threadpools run an event that then runs other events, so we need to tweak
things for GetRunningEventDelay()

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

--HG--
extra : moz-landing-system : lando

xpcom/threads/LazyIdleThread.cpp

@@ -405,6 +405,14 @@ LazyIdleThread::GetRunningEventDelay(TimeDuration* aDelay, TimeStamp* aStart) {
   return NS_OK;
 }
 
+NS_IMETHODIMP
+LazyIdleThread::SetRunningEventDelay(TimeDuration aDelay, TimeStamp aStart) {
+  if (mThread) {
+    return mThread->SetRunningEventDelay(aDelay, aStart);
+  }
+  return NS_OK;
+}
+
 NS_IMETHODIMP
 LazyIdleThread::IsOnCurrentThread(bool* aIsOnCurrentThread) {
   if (mThread) {

xpcom/threads/PrioritizedEventQueue.cpp

@@ -147,9 +147,14 @@ EventQueuePriority PrioritizedEventQueue::SelectQueue(
   return queue;
 }
 
+// The delay returned is the queuing delay a hypothetical Input event would
+// see due to the current running event if it had arrived while the current
+// event was queued.  This means that any event running at  priority below
+// Input doesn't cause queuing delay for Input events, and we return
+// TimeDuration() for those cases.
 already_AddRefed<nsIRunnable> PrioritizedEventQueue::GetEvent(
     EventQueuePriority* aPriority, const MutexAutoLock& aProofOfLock,
-    mozilla::TimeDuration* aLastEventDelay) {
+    mozilla::TimeDuration* aHypotheticalInputEventDelay) {
 #ifndef RELEASE_OR_BETA
   // Clear mNextIdleDeadline so that it is possible to determine that
   // we're running an idle runnable in ProcessNextEvent.
@@ -183,14 +188,16 @@ already_AddRefed<nsIRunnable> PrioritizedEventQueue::GetEvent(
       break;
 
     case EventQueuePriority::High:
-      event = mHighQueue->GetEvent(aPriority, aProofOfLock, aLastEventDelay);
+      event = mHighQueue->GetEvent(aPriority, aProofOfLock,
+                                   aHypotheticalInputEventDelay);
       MOZ_ASSERT(event);
       mInputHandlingStartTime = TimeStamp();
       mProcessHighPriorityQueue = false;
       break;
 
     case EventQueuePriority::Input:
-      event = mInputQueue->GetEvent(aPriority, aProofOfLock, aLastEventDelay);
+      event = mInputQueue->GetEvent(aPriority, aProofOfLock,
+                                    aHypotheticalInputEventDelay);
       MOZ_ASSERT(event);
       break;
 
@@ -200,17 +207,17 @@ already_AddRefed<nsIRunnable> PrioritizedEventQueue::GetEvent(
       // an event actually runs (if the event is below Input event's priority)
     case EventQueuePriority::MediumHigh:
       event = mMediumHighQueue->GetEvent(aPriority, aProofOfLock);
-      *aLastEventDelay = TimeDuration();
+      *aHypotheticalInputEventDelay = TimeDuration();
       break;
 
     case EventQueuePriority::Normal:
       event = mNormalQueue->GetEvent(aPriority, aProofOfLock);
-      *aLastEventDelay = TimeDuration();
+      *aHypotheticalInputEventDelay = TimeDuration();
       break;
 
     case EventQueuePriority::Idle:
     case EventQueuePriority::DeferredTimers:
-      *aLastEventDelay = TimeDuration();
+      *aHypotheticalInputEventDelay = TimeDuration();
       // If we get here, then all queues except deferredtimers and idle are
       // empty.
 
@@ -225,8 +232,7 @@ already_AddRefed<nsIRunnable> PrioritizedEventQueue::GetEvent(
         return nullptr;
       }
 
-      nsCOMPtr<nsIRunnable> event =
-          mDeferredTimersQueue->GetEvent(aPriority, aProofOfLock);
+      event = mDeferredTimersQueue->GetEvent(aPriority, aProofOfLock);
       if (!event) {
         event = mIdleQueue->GetEvent(aPriority, aProofOfLock);
       }
@@ -243,6 +249,10 @@ already_AddRefed<nsIRunnable> PrioritizedEventQueue::GetEvent(
 #endif
       }
       break;
+  }  // switch (queue)
+
+  if (!event) {
+    *aHypotheticalInputEventDelay = TimeDuration();
   }
 
   return event.forget();

xpcom/threads/nsIThread.idl

@@ -196,5 +196,18 @@ interface nsIThread : nsISerialEventTarget
    */
   [noscript] void getRunningEventDelay(out TimeDuration delay, out TimeStamp start);
 
+  /**
+   * Set information on the timing of the currently-running event.
+   * Overrides the values returned by getRunningEventDelay
+   *
+   * @param delay
+   *   Delay the running event spent in queues, or TimeDuration() if
+   *   there's no running event.
+   * @param start
+   *   The time the currently running event began to run, or TimeStamp() if no
+   *   event is running.
+   */
+  [noscript] void setRunningEventDelay(in TimeDuration delay, in TimeStamp start);
+
   [noscript] void setNameForWakeupTelemetry(in ACString name);
 };

xpcom/threads/nsThread.cpp

@@ -601,6 +601,7 @@ nsThread::nsThread(NotNull<SynchronizedEventQueue*> aQueue,
       mShutdownRequired(false),
       mPriority(PRIORITY_NORMAL),
       mIsMainThread(aMainThread == MAIN_THREAD),
+      mIsAPoolThreadFree(nullptr),
       mCanInvokeJS(false),
       mCurrentEvent(nullptr),
       mCurrentEventStart(TimeStamp::Now()),
@@ -733,8 +734,22 @@ nsThread::DelayedDispatch(already_AddRefed<nsIRunnable> aEvent,
 
 NS_IMETHODIMP
 nsThread::GetRunningEventDelay(TimeDuration* aDelay, TimeStamp* aStart) {
-  *aDelay = mLastEventDelay;
-  *aStart = mLastEventStart;
+  if (mIsAPoolThreadFree && *mIsAPoolThreadFree) {
+    // if there are unstarted threads in the pool, a new event to the
+    // pool would not be delayed at all (beyond thread start time)
+    *aDelay = TimeDuration();
+    *aStart = TimeStamp();
+  } else {
+    *aDelay = mLastEventDelay;
+    *aStart = mLastEventStart;
+  }
+  return NS_OK;
+}
+
+NS_IMETHODIMP
+nsThread::SetRunningEventDelay(TimeDuration aDelay, TimeStamp aStart) {
+  mLastEventDelay = aDelay;
+  mLastEventStart = aStart;
   return NS_OK;
 }
 

xpcom/threads/nsThread.h

@@ -14,6 +14,7 @@
 #include "nsThreadUtils.h"
 #include "nsString.h"
 #include "nsTObserverArray.h"
+#include "mozilla/Atomics.h"
 #include "mozilla/Attributes.h"
 #include "mozilla/LinkedList.h"
 #include "mozilla/MemoryReporting.h"
@@ -89,6 +90,12 @@ class nsThread : public nsIThreadInternal,
   // nsIThreadManager::NewThread.
   bool ShutdownRequired() { return mShutdownRequired; }
 
+  // Lets GetRunningEventDelay() determine if the pool this is part
+  // of has an unstarted thread
+  void SetPoolThreadFreePtr(mozilla::Atomic<bool, mozilla::Relaxed>* aPtr) {
+    mIsAPoolThreadFree = aPtr;
+  }
+
   void SetScriptObserver(mozilla::CycleCollectedJSContext* aScriptObserver);
 
   uint32_t RecursionDepth() const;
@@ -228,6 +235,7 @@ class nsThread : public nsIThreadInternal,
   int8_t mPriority;
 
   bool mIsMainThread;
+  mozilla::Atomic<bool, mozilla::Relaxed>* mIsAPoolThreadFree;
 
   // Set to true if this thread creates a JSRuntime.
   bool mCanInvokeJS;

xpcom/threads/nsThreadPool.cpp

@@ -56,7 +56,8 @@ nsThreadPool::nsThreadPool()
       mIdleCount(0),
       mStackSize(nsIThreadManager::DEFAULT_STACK_SIZE),
       mShutdown(false),
-      mRegressiveMaxIdleTime(false) {
+      mRegressiveMaxIdleTime(false),
+      mIsAPoolThreadFree(true) {
   static std::once_flag flag;
   std::call_once(flag, [] { gCurrentThreadPool.infallibleInit(); });
 
@@ -128,7 +129,11 @@ nsresult nsThreadPool::PutEvent(already_AddRefed<nsIRunnable> aEvent,
       killThread = true;
     } else if (mThreads.Count() < (int32_t)mThreadLimit) {
       mThreads.AppendObject(thread);
+      if (mThreads.Count() >= (int32_t)mThreadLimit) {
+        mIsAPoolThreadFree = false;
+      }
     } else {
+      // Someone else may have also been starting a thread
       killThread = true;  // okay, we don't need this thread anymore
     }
   }
@@ -162,6 +167,35 @@ void nsThreadPool::ShutdownThread(nsIThread* aThread) {
                                           &nsIThread::AsyncShutdown));
 }
 
+// This event 'runs' for the lifetime of the worker thread.  The actual
+// eventqueue is mEvents, and is shared by all the worker threads.  This
+// means that the set of threads together define the delay seen by a new
+// event sent to the pool.
+//
+// To model the delay experienced by the pool, we can have each thread in
+// the pool report 0 if it's idle OR if the pool is below the threadlimit;
+// or otherwise the current event's queuing delay plus current running
+// time.
+//
+// To reconstruct the delays for the pool, the profiler can look at all the
+// threads that are part of a pool (pools have defined naming patterns that
+// can be user to connect them).  If all threads have delays at time X,
+// that means that all threads saturated at that point and any event
+// dispatched to the pool would get a delay.
+//
+// The delay experienced by an event dispatched when all pool threads are
+// busy is based on the calculations shown in platform.cpp.  Run that
+// algorithm for each thread in the pool, and the delay at time X is the
+// longest value for time X of any of the threads, OR the time from X until
+// any one of the threads reports 0 (i.e. it's not busy), whichever is
+// shorter.
+
+// In order to record this when the profiler samples threads in the pool,
+// each thread must (effectively) override GetRunnningEventDelay, by
+// resetting the mLastEventDelay/Start values in the nsThread when we start
+// to run an event (or when we run out of events to run).  Note that handling
+// the shutdown of a thread may be a little tricky.
+
 NS_IMETHODIMP
 nsThreadPool::Run() {
   LOG(("THRD-P(%p) enter %s\n", this, mName.BeginReading()));
@@ -174,6 +208,10 @@ nsThreadPool::Run() {
   bool wasIdle = false;
   TimeStamp idleSince;
 
+  // This thread is an nsThread created below with NS_NewNamedThread()
+  static_cast<nsThread*>(current.get())
+      ->SetPoolThreadFreePtr(&mIsAPoolThreadFree);
+
   nsCOMPtr<nsIThreadPoolListener> listener;
   {
     MutexAutoLock lock(mMutex);
@@ -189,10 +227,11 @@ nsThreadPool::Run() {
 
   do {
     nsCOMPtr<nsIRunnable> event;
+    TimeDuration delay;
     {
       MutexAutoLock lock(mMutex);
 
-      event = mEvents.GetEvent(nullptr, lock);
+      event = mEvents.GetEvent(nullptr, lock, &delay);
       if (!event) {
         TimeStamp now = TimeStamp::Now();
         uint32_t idleTimeoutDivider =
@@ -228,7 +267,12 @@ nsThreadPool::Run() {
             --mIdleCount;
           }
           shutdownThreadOnExit = mThreads.RemoveObject(current);
+
+          // keep track if there are threads available to start
+          mIsAPoolThreadFree = (mThreads.Count() < (int32_t)mThreadLimit);
         } else {
+          current->SetRunningEventDelay(TimeDuration(), TimeStamp());
+
           AUTO_PROFILER_LABEL("nsThreadPool::Run::Wait", IDLE);
 
           TimeDuration delta = timeout - (now - idleSince);
@@ -253,6 +297,10 @@ nsThreadPool::Run() {
       // to run.
       DelayForChaosMode(ChaosFeature::TaskRunning, 1000);
 
+      // We'll handle the case of unstarted threads available
+      // when we sample.
+      current->SetRunningEventDelay(delay, TimeStamp::Now());
+
       event->Run();
     }
   } while (!exitThread);

xpcom/threads/nsThreadPool.h

@@ -13,6 +13,7 @@
 #include "nsCOMArray.h"
 #include "nsCOMPtr.h"
 #include "nsThreadUtils.h"
+#include "mozilla/Atomics.h"
 #include "mozilla/Attributes.h"
 #include "mozilla/AlreadyAddRefed.h"
 #include "mozilla/EventQueue.h"
@@ -47,6 +48,7 @@ class nsThreadPool final : public nsIThreadPool, public nsIRunnable {
   nsCOMPtr<nsIThreadPoolListener> mListener;
   bool mShutdown;
   bool mRegressiveMaxIdleTime;
+  mozilla::Atomic<bool, mozilla::Relaxed> mIsAPoolThreadFree;
   nsCString mName;
   nsThreadPoolNaming mThreadNaming;
 };