Bug 1203427 (part 5) - Add logging of timer firings. r=froydnj.
authorNicholas Nethercote <nnethercote@mozilla.com>
Thu, 10 Sep 2015 00:50:51 -0700
changeset 295572 21235635ebdec9bdfa6d65b71285f0fdb7b1bce8
parent 295571 afa92bf6913ed5a49e2de35ad9539da144a6f626
child 295573 004e30faaea89ac7f4118f71fda916eebb0fa136
push id5245
push userraliiev@mozilla.com
push dateThu, 29 Oct 2015 11:30:51 +0000
treeherdermozilla-beta@dac831dc1bd0 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersfroydnj
bugs1203427
milestone43.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
Bug 1203427 (part 5) - Add logging of timer firings. r=froydnj.
dom/base/nsGlobalWindow.cpp
dom/base/nsGlobalWindow.h
dom/base/nsJSEnvironment.cpp
dom/html/HTMLMediaElement.cpp
dom/media/MediaTimer.cpp
dom/workers/WorkerPrivate.cpp
layout/base/nsPresShell.cpp
layout/generic/ScrollbarActivity.cpp
parser/html/nsHtml5TreeOpExecutor.cpp
toolkit/components/statusfilter/nsBrowserStatusFilter.cpp
xpcom/ds/nsExpirationTracker.h
xpcom/threads/nsITimer.idl
xpcom/threads/nsTimerImpl.cpp
xpcom/threads/nsTimerImpl.h
--- a/dom/base/nsGlobalWindow.cpp
+++ b/dom/base/nsGlobalWindow.cpp
@@ -48,16 +48,17 @@
 #include "jsapi.h"              // for JSAutoRequest
 #include "jswrapper.h"
 #include "nsReadableUtils.h"
 #include "nsDOMClassInfo.h"
 #include "nsJSEnvironment.h"
 #include "ScriptSettings.h"
 #include "mozilla/Preferences.h"
 #include "mozilla/Likely.h"
+#include "mozilla/Snprintf.h"
 #include "mozilla/unused.h"
 
 // Other Classes
 #include "mozilla/dom/BarProps.h"
 #include "nsContentCID.h"
 #include "nsLayoutStatics.h"
 #include "nsCCUncollectableMarker.h"
 #include "mozilla/dom/workers/Workers.h"
@@ -540,18 +541,19 @@ NS_IMPL_CYCLE_COLLECTION_TRAVERSE_BEGIN(
   NS_IMPL_CYCLE_COLLECTION_TRAVERSE(mScriptHandler)
 NS_IMPL_CYCLE_COLLECTION_TRAVERSE_END
 NS_IMPL_CYCLE_COLLECTION_ROOT_NATIVE(nsTimeout, AddRef)
 NS_IMPL_CYCLE_COLLECTION_UNROOT_NATIVE(nsTimeout, Release)
 
 nsresult
 nsTimeout::InitTimer(uint32_t aDelay)
 {
-  return mTimer->InitWithFuncCallback(nsGlobalWindow::TimerCallback, this,
-                                      aDelay, nsITimer::TYPE_ONE_SHOT);
+  return mTimer->InitWithNameableFuncCallback(
+    nsGlobalWindow::TimerCallback, this, aDelay,
+    nsITimer::TYPE_ONE_SHOT, nsGlobalWindow::TimerNameCallback);
 }
 
 // Return true if this timeout has a refcount of 1. This is used to check
 // that dummy_timeout doesn't leak from nsGlobalWindow::RunTimeout.
 bool
 nsTimeout::HasRefCntOne()
 {
   return mRefCnt.get() == 1;
@@ -13156,16 +13158,29 @@ nsGlobalWindow::InsertTimeoutIntoList(ns
 void
 nsGlobalWindow::TimerCallback(nsITimer *aTimer, void *aClosure)
 {
   nsRefPtr<nsTimeout> timeout = (nsTimeout *)aClosure;
 
   timeout->mWindow->RunTimeout(timeout);
 }
 
+// static
+void
+nsGlobalWindow::TimerNameCallback(nsITimer* aTimer, void* aClosure, char* aBuf,
+                                  size_t aLen)
+{
+  nsRefPtr<nsTimeout> timeout = (nsTimeout*)aClosure;
+
+  const char* filename;
+  uint32_t lineNum, column;
+  timeout->mScriptHandler->GetLocation(&filename, &lineNum, &column);
+  snprintf(aBuf, aLen, "[content] %s:%u:%u", filename, lineNum, column);
+}
+
 //*****************************************************************************
 // nsGlobalWindow: Helper Functions
 //*****************************************************************************
 
 already_AddRefed<nsIDocShellTreeOwner>
 nsGlobalWindow::GetTreeOwner()
 {
   FORWARD_TO_OUTER(GetTreeOwner, (), nullptr);
--- a/dom/base/nsGlobalWindow.h
+++ b/dom/base/nsGlobalWindow.h
@@ -1419,16 +1419,18 @@ public:
   bool RescheduleTimeout(nsTimeout* aTimeout, const TimeStamp& now,
                          bool aRunningPendingTimeouts);
 
   void ClearAllTimeouts();
   // Insert aTimeout into the list, before all timeouts that would
   // fire after it, but no earlier than mTimeoutInsertionPoint, if any.
   void InsertTimeoutIntoList(nsTimeout *aTimeout);
   static void TimerCallback(nsITimer *aTimer, void *aClosure);
+  static void TimerNameCallback(nsITimer* aTimer, void* aClosure, char* aBuf,
+                                size_t aLen);
 
   // Helper Functions
   already_AddRefed<nsIDocShellTreeOwner> GetTreeOwner();
   already_AddRefed<nsIBaseWindow> GetTreeOwnerWindow();
   already_AddRefed<nsIWebBrowserChrome> GetWebBrowserChrome();
   nsresult SecurityCheckURL(const char *aURL);
   bool IsPrivateBrowsing();
 
--- a/dom/base/nsJSEnvironment.cpp
+++ b/dom/base/nsJSEnvironment.cpp
@@ -1631,20 +1631,20 @@ nsJSContext::BeginCycleCollectionCallbac
   gCCStats.RunForgetSkippable();
 
   MOZ_ASSERT(!sICCTimer, "Tried to create a new ICC timer when one already existed.");
 
   // Create an ICC timer even if ICC is globally disabled, because we could be manually triggering
   // an incremental collection, and we want to be sure to finish it.
   CallCreateInstance("@mozilla.org/timer;1", &sICCTimer);
   if (sICCTimer) {
-    sICCTimer->InitWithFuncCallback(ICCTimerFired,
-                                    nullptr,
-                                    kICCIntersliceDelay,
-                                    nsITimer::TYPE_REPEATING_SLACK);
+    sICCTimer->InitWithNamedFuncCallback(ICCTimerFired, nullptr,
+                                         kICCIntersliceDelay,
+                                         nsITimer::TYPE_REPEATING_SLACK,
+                                         "ICCTimerFired");
   }
 }
 
 static_assert(NS_GC_DELAY > kMaxICCDuration, "A max duration ICC shouldn't reduce GC delay to 0");
 
 //static
 void
 nsJSContext::EndCycleCollectionCallback(CycleCollectorResults &aResults)
@@ -2031,24 +2031,25 @@ nsJSContext::PokeGC(JS::gcreason::Reason
 
   if (!sGCTimer) {
     // Failed to create timer (probably because we're in XPCOM shutdown)
     return;
   }
 
   static bool first = true;
 
-  sGCTimer->InitWithFuncCallback(GCTimerFired, reinterpret_cast<void *>(aReason),
-                                 aDelay
-                                 ? aDelay
-                                 : (first
-                                    ? NS_FIRST_GC_DELAY
-                                    : NS_GC_DELAY),
-                                 nsITimer::TYPE_ONE_SHOT);
-
+  sGCTimer->InitWithNamedFuncCallback(GCTimerFired,
+                                      reinterpret_cast<void *>(aReason),
+                                      aDelay
+                                      ? aDelay
+                                      : (first
+                                         ? NS_FIRST_GC_DELAY
+                                         : NS_GC_DELAY),
+                                      nsITimer::TYPE_ONE_SHOT,
+                                      "GCTimerFired");
   first = false;
 }
 
 // static
 void
 nsJSContext::PokeShrinkGCBuffers()
 {
   if (sShrinkGCBuffersTimer || sShuttingDown) {
@@ -2057,19 +2058,21 @@ nsJSContext::PokeShrinkGCBuffers()
 
   CallCreateInstance("@mozilla.org/timer;1", &sShrinkGCBuffersTimer);
 
   if (!sShrinkGCBuffersTimer) {
     // Failed to create timer (probably because we're in XPCOM shutdown)
     return;
   }
 
-  sShrinkGCBuffersTimer->InitWithFuncCallback(ShrinkGCBuffersTimerFired, nullptr,
-                                              NS_SHRINK_GC_BUFFERS_DELAY,
-                                              nsITimer::TYPE_ONE_SHOT);
+  sShrinkGCBuffersTimer->InitWithNamedFuncCallback(ShrinkGCBuffersTimerFired,
+                                                   nullptr,
+                                                   NS_SHRINK_GC_BUFFERS_DELAY,
+                                                   nsITimer::TYPE_ONE_SHOT,
+                                                   "ShrinkGCBuffersTimerFired");
 }
 
 // static
 void
 nsJSContext::PokeShrinkingGC()
 {
   if (sShrinkingGCTimer || sShuttingDown) {
     return;
@@ -2077,19 +2080,20 @@ nsJSContext::PokeShrinkingGC()
 
   CallCreateInstance("@mozilla.org/timer;1", &sShrinkingGCTimer);
 
   if (!sShrinkingGCTimer) {
     // Failed to create timer (probably because we're in XPCOM shutdown)
     return;
   }
 
-  sShrinkingGCTimer->InitWithFuncCallback(ShrinkingGCTimerFired, nullptr,
-                                          sCompactOnUserInactiveDelay,
-                                          nsITimer::TYPE_ONE_SHOT);
+  sShrinkingGCTimer->InitWithNamedFuncCallback(ShrinkingGCTimerFired, nullptr,
+                                               sCompactOnUserInactiveDelay,
+                                               nsITimer::TYPE_ONE_SHOT,
+                                               "ShrinkingGCTimerFired");
 }
 
 // static
 void
 nsJSContext::MaybePokeCC()
 {
   if (sCCTimer || sICCTimer || sShuttingDown || !sHasRunGC) {
     return;
@@ -2099,19 +2103,20 @@ nsJSContext::MaybePokeCC()
     sCCTimerFireCount = 0;
     CallCreateInstance("@mozilla.org/timer;1", &sCCTimer);
     if (!sCCTimer) {
       return;
     }
     // We can kill some objects before running forgetSkippable.
     nsCycleCollector_dispatchDeferredDeletion();
 
-    sCCTimer->InitWithFuncCallback(CCTimerFired, nullptr,
-                                   NS_CC_SKIPPABLE_DELAY,
-                                   nsITimer::TYPE_REPEATING_SLACK);
+    sCCTimer->InitWithNamedFuncCallback(CCTimerFired, nullptr,
+                                        NS_CC_SKIPPABLE_DELAY,
+                                        nsITimer::TYPE_REPEATING_SLACK,
+                                        "CCTimerFired");
   }
 }
 
 //static
 void
 nsJSContext::KillGCTimer()
 {
   if (sGCTimer) {
@@ -2258,20 +2263,21 @@ DOMGCSliceCallback(JSRuntime *aRt, JS::G
       sCleanupsSinceLastGC = 0;
       sNeedsFullCC = true;
       sHasRunGC = true;
       nsJSContext::MaybePokeCC();
 
       if (aDesc.isCompartment_) {
         if (!sFullGCTimer && !sShuttingDown) {
           CallCreateInstance("@mozilla.org/timer;1", &sFullGCTimer);
-          sFullGCTimer->InitWithFuncCallback(FullGCTimerFired,
-                                             nullptr,
-                                             NS_FULL_GC_DELAY,
-                                             nsITimer::TYPE_ONE_SHOT);
+          sFullGCTimer->InitWithNamedFuncCallback(FullGCTimerFired,
+                                                  nullptr,
+                                                  NS_FULL_GC_DELAY,
+                                                  nsITimer::TYPE_ONE_SHOT,
+                                                  "FullGCTimerFired");
         }
       } else {
         nsJSContext::KillFullGCTimer();
 
         // Avoid shrinking during heavy activity, which is suggested by
         // compartment GC. We don't need to shrink after a shrinking GC as this
         // happens automatically in this case.
         if (aDesc.invocationKind_ == GC_NORMAL) {
@@ -2290,20 +2296,21 @@ DOMGCSliceCallback(JSRuntime *aRt, JS::G
       break;
 
     case JS::GC_SLICE_END:
 
       // The GC has more work to do, so schedule another GC slice.
       nsJSContext::KillInterSliceGCTimer();
       if (!sShuttingDown) {
         CallCreateInstance("@mozilla.org/timer;1", &sInterSliceGCTimer);
-        sInterSliceGCTimer->InitWithFuncCallback(InterSliceGCTimerFired,
-                                                 nullptr,
-                                                 NS_INTERSLICE_GC_DELAY,
-                                                 nsITimer::TYPE_ONE_SHOT);
+        sInterSliceGCTimer->InitWithNamedFuncCallback(InterSliceGCTimerFired,
+                                                      nullptr,
+                                                      NS_INTERSLICE_GC_DELAY,
+                                                      nsITimer::TYPE_ONE_SHOT,
+                                                      "InterSliceGCTimerFired");
       }
 
       if (ShouldTriggerCC(nsCycleCollector_suspectedCount())) {
         nsCycleCollector_dispatchDeferredDeletion();
       }
 
       if (sPostGCEventsToConsole) {
         nsString gcstats;
--- a/dom/html/HTMLMediaElement.cpp
+++ b/dom/html/HTMLMediaElement.cpp
@@ -3517,20 +3517,19 @@ void HTMLMediaElement::ProgressTimerCall
 
 void HTMLMediaElement::StartProgressTimer()
 {
   MOZ_ASSERT(NS_IsMainThread());
   MOZ_ASSERT(mNetworkState == nsIDOMHTMLMediaElement::NETWORK_LOADING);
   NS_ASSERTION(!mProgressTimer, "Already started progress timer.");
 
   mProgressTimer = do_CreateInstance("@mozilla.org/timer;1");
-  mProgressTimer->InitWithFuncCallback(ProgressTimerCallback,
-                                       this,
-                                       PROGRESS_MS,
-                                       nsITimer::TYPE_REPEATING_SLACK);
+  mProgressTimer->InitWithNamedFuncCallback(
+    ProgressTimerCallback, this, PROGRESS_MS, nsITimer::TYPE_REPEATING_SLACK,
+    "HTMLMediaElement::ProgressTimerCallback");
 }
 
 void HTMLMediaElement::StartProgress()
 {
   // Record the time now for detecting stalled.
   mDataTime = TimeStamp::NowLoRes();
   // Reset mProgressTime so that mDataTime is not indicating bytes received
   // after the last progress event.
--- a/dom/media/MediaTimer.cpp
+++ b/dom/media/MediaTimer.cpp
@@ -169,14 +169,16 @@ MediaTimer::ArmTimer(const TimeStamp& aT
   MOZ_DIAGNOSTIC_ASSERT(!TimerIsArmed());
   MOZ_DIAGNOSTIC_ASSERT(aTarget > aNow);
 
   // XPCOM timer resolution is in milliseconds. It's important to never resolve
   // a timer when mTarget might compare < now (even if very close), so round up.
   unsigned long delay = std::ceil((aTarget - aNow).ToMilliseconds());
   TIMER_LOG("MediaTimer::ArmTimer delay=%lu", delay);
   mCurrentTimerTarget = aTarget;
-  nsresult rv = mTimer->InitWithFuncCallback(&TimerCallback, this, delay, nsITimer::TYPE_ONE_SHOT);
+  nsresult rv = mTimer->InitWithNamedFuncCallback(&TimerCallback, this, delay,
+                                                  nsITimer::TYPE_ONE_SHOT,
+                                                  "MediaTimer::TimerCallback");
   MOZ_DIAGNOSTIC_ASSERT(NS_SUCCEEDED(rv));
   (void) rv;
 }
 
 } // namespace mozilla
--- a/dom/workers/WorkerPrivate.cpp
+++ b/dom/workers/WorkerPrivate.cpp
@@ -1183,18 +1183,19 @@ public:
     nsRefPtr<TimerThreadEventTarget> target =
       new TimerThreadEventTarget(mWorkerPrivate, runnable);
 
     if (NS_FAILED(timer->SetTarget(target))) {
       JS_ReportError(aCx, "Failed to set timer's target!");
       return false;
     }
 
-    if (NS_FAILED(timer->InitWithFuncCallback(DummyCallback, nullptr, aDelayMS,
-                                              nsITimer::TYPE_ONE_SHOT))) {
+    if (NS_FAILED(timer->InitWithNamedFuncCallback(
+          DummyCallback, nullptr, aDelayMS, nsITimer::TYPE_ONE_SHOT,
+          "dom::workers::DummyCallback(1)"))) {
       JS_ReportError(aCx, "Failed to start timer!");
       return false;
     }
 
     mTimer.swap(timer);
     return true;
   }
 
@@ -4531,19 +4532,19 @@ WorkerPrivate::SetGCTimerMode(GCTimerMod
   }
   else {
     target = mIdleGCTimerTarget;
     delay = IDLE_GC_TIMER_DELAY_SEC * 1000;
     type = nsITimer::TYPE_ONE_SHOT;
   }
 
   MOZ_ALWAYS_TRUE(NS_SUCCEEDED(mGCTimer->SetTarget(target)));
-  MOZ_ALWAYS_TRUE(NS_SUCCEEDED(mGCTimer->InitWithFuncCallback(DummyCallback,
-                                                              nullptr, delay,
-                                                              type)));
+  MOZ_ALWAYS_TRUE(NS_SUCCEEDED(
+    mGCTimer->InitWithNamedFuncCallback(DummyCallback, nullptr, delay, type,
+                                        "dom::workers::DummyCallback(2)")));
 
   if (aMode == PeriodicTimer) {
     LOG(("Worker %p scheduled periodic GC timer\n", this));
     mPeriodicGCTimerRunning = true;
   }
   else {
     LOG(("Worker %p scheduled idle GC timer\n", this));
     mIdleGCTimerRunning = true;
@@ -5940,18 +5941,19 @@ WorkerPrivate::RescheduleTimeoutTimer(JS
   AssertIsOnWorkerThread();
   NS_ASSERTION(!mTimeouts.IsEmpty(), "Should have some timeouts!");
   NS_ASSERTION(mTimer, "Should have a timer!");
 
   double delta =
     (mTimeouts[0]->mTargetTime - TimeStamp::Now()).ToMilliseconds();
   uint32_t delay = delta > 0 ? std::min(delta, double(UINT32_MAX)) : 0;
 
-  nsresult rv = mTimer->InitWithFuncCallback(DummyCallback, nullptr, delay,
-                                             nsITimer::TYPE_ONE_SHOT);
+  nsresult rv = mTimer->InitWithNamedFuncCallback(
+    DummyCallback, nullptr, delay, nsITimer::TYPE_ONE_SHOT,
+    "dom::workers::DummyCallback(3)");
   if (NS_FAILED(rv)) {
     JS_ReportError(aCx, "Failed to start timer!");
     return false;
   }
 
   return true;
 }
 
--- a/layout/base/nsPresShell.cpp
+++ b/layout/base/nsPresShell.cpp
@@ -1743,19 +1743,19 @@ PresShell::Initialize(nscoord aWidth, ns
     } else {
       // Initialize the timer.
 
       // Default to PAINTLOCK_EVENT_DELAY if we can't get the pref value.
       int32_t delay =
         Preferences::GetInt("nglayout.initialpaint.delay",
                             PAINTLOCK_EVENT_DELAY);
 
-      mPaintSuppressionTimer->InitWithFuncCallback(sPaintSuppressionCallback,
-                                                   this, delay,
-                                                   nsITimer::TYPE_ONE_SHOT);
+      mPaintSuppressionTimer->InitWithNamedFuncCallback(
+        sPaintSuppressionCallback, this, delay, nsITimer::TYPE_ONE_SHOT,
+        "PresShell::sPaintSuppressionCallback");
     }
   }
 
   // If we get here and painting is not suppressed, then we can paint anytime
   // and we should fire the before-first-paint notification
   if (!mPaintingSuppressed) {
     ScheduleBeforeFirstPaint();
   }
--- a/layout/generic/ScrollbarActivity.cpp
+++ b/layout/generic/ScrollbarActivity.cpp
@@ -421,19 +421,19 @@ void
 ScrollbarActivity::StartFadeBeginTimer()
 {
   if (GetForceAlwaysVisiblePref()) {
     return;
   }
   if (!mFadeBeginTimer) {
     mFadeBeginTimer = do_CreateInstance("@mozilla.org/timer;1");
   }
-  mFadeBeginTimer->InitWithFuncCallback(FadeBeginTimerFired, this,
-                                        mScrollbarFadeBeginDelay,
-                                        nsITimer::TYPE_ONE_SHOT);
+  mFadeBeginTimer->InitWithNamedFuncCallback(
+    FadeBeginTimerFired, this, mScrollbarFadeBeginDelay,
+    nsITimer::TYPE_ONE_SHOT, "ScrollbarActivity::FadeBeginTimerFired");
 }
 
 void
 ScrollbarActivity::CancelFadeBeginTimer()
 {
   if (mFadeBeginTimer) {
     mFadeBeginTimer->Cancel();
   }
--- a/parser/html/nsHtml5TreeOpExecutor.cpp
+++ b/parser/html/nsHtml5TreeOpExecutor.cpp
@@ -270,18 +270,19 @@ nsHtml5TreeOpExecutor::ContinueInterrupt
       gBackgroundFlushList->insertBack(this);
     }
     if (!gFlushTimer) {
       nsCOMPtr<nsITimer> t = do_CreateInstance("@mozilla.org/timer;1");
       t.swap(gFlushTimer);
       // The timer value 50 should not hopefully slow down background pages too
       // much, yet lets event loop to process enough between ticks.
       // See bug 734015.
-      gFlushTimer->InitWithFuncCallback(FlushTimerCallback, nullptr,
-                                        50, nsITimer::TYPE_REPEATING_SLACK);
+      gFlushTimer->InitWithNamedFuncCallback(FlushTimerCallback, nullptr,
+                                             50, nsITimer::TYPE_REPEATING_SLACK,
+                                             "FlushTimerCallback");
     }
   }
 }
 
 void
 nsHtml5TreeOpExecutor::FlushSpeculativeLoads()
 {
   nsTArray<nsHtml5SpeculativeLoad> speculativeLoadQueue;
--- a/toolkit/components/statusfilter/nsBrowserStatusFilter.cpp
+++ b/toolkit/components/statusfilter/nsBrowserStatusFilter.cpp
@@ -350,18 +350,19 @@ nsresult
 nsBrowserStatusFilter::StartDelayTimer()
 {
     NS_ASSERTION(!DelayInEffect(), "delay should not be in effect");
 
     mTimer = do_CreateInstance("@mozilla.org/timer;1");
     if (!mTimer)
         return NS_ERROR_FAILURE;
 
-    return mTimer->InitWithFuncCallback(TimeoutHandler, this, 160, 
-                                        nsITimer::TYPE_ONE_SHOT);
+    return mTimer->InitWithNamedFuncCallback(
+        TimeoutHandler, this, 160, nsITimer::TYPE_ONE_SHOT,
+        "nsBrowserStatusFilter::TimeoutHandler");
 }
 
 void
 nsBrowserStatusFilter::ProcessTimeout()
 {
     mTimer = nullptr;
 
     if (!mListener)
--- a/xpcom/ds/nsExpirationTracker.h
+++ b/xpcom/ds/nsExpirationTracker.h
@@ -355,18 +355,18 @@ private:
   {
     if (mTimer || !mTimerPeriod) {
       return NS_OK;
     }
     mTimer = do_CreateInstance("@mozilla.org/timer;1");
     if (!mTimer) {
       return NS_ERROR_OUT_OF_MEMORY;
     }
-    mTimer->InitWithFuncCallback(TimerCallback, this, mTimerPeriod,
-                                 nsITimer::TYPE_REPEATING_SLACK);
+    mTimer->InitWithNamedFuncCallback(TimerCallback, this, mTimerPeriod,
+                                      nsITimer::TYPE_REPEATING_SLACK, mName);
     return NS_OK;
   }
 };
 
 template<class T, uint32_t K>
 NS_IMETHODIMP
 nsExpirationTracker<T, K>::ExpirationTrackerObserver::Observe(
     nsISupports* aSubject, const char* aTopic, const char16_t* aData)
--- a/xpcom/threads/nsITimer.idl
+++ b/xpcom/threads/nsITimer.idl
@@ -16,19 +16,34 @@ interface nsIEventTarget;
  * This is the function that will get called when the timer expires if the
  * timer is initialized via initWithFuncCallback.
  *
  * @param aTimer the timer which has expired
  * @param aClosure opaque parameter passed to initWithFuncCallback
  */
 class nsITimer;
 typedef void (*nsTimerCallbackFunc) (nsITimer *aTimer, void *aClosure);
+
+/**
+ * The signature of the timer name callback function passed to
+ * initWithNameableFuncCallback.
+ * This is the function that will get called when timer profiling is enabled
+ * via the "TimerFirings" log module.
+ *
+ * @param aTimer the timer which has expired
+ * @param aClosure opaque parameter passed to initWithFuncCallback
+ * @param aBuf a buffer in which to put the name
+ * @param aLen the length of the buffer
+ */
+typedef void (*nsTimerNameCallbackFunc) (nsITimer *aTimer, void *aClosure,
+                                         char *aBuf, size_t aLen);
 %}
 
 native nsTimerCallbackFunc(nsTimerCallbackFunc);
+native nsTimerNameCallbackFunc(nsTimerNameCallbackFunc);
 
 /**
  * The callback interface for timers.
  */
 interface nsITimer;
 
 [function, scriptable, uuid(a796816d-7d47-4348-9ab8-c7aeb3216a7d)]
 interface nsITimerCallback : nsISupports
@@ -52,17 +67,17 @@ interface nsITimerCallback : nsISupports
  *
  * By default a timer will fire on the thread that created it.  Set the .target
  * attribute to fire on a different thread.  Once you have set a timer's .target
  * and called one of its init functions, any further interactions with the timer
  * (calling cancel(), changing member fields, etc) should only be done by the
  * target thread, or races may occur with bad results like timers firing after
  * they've been canceled, and/or not firing after re-initiatization.
  */
-[scriptable, uuid(c569e813-333f-4b78-8691-13ca5839e10a)]
+[scriptable, uuid(3de4b105-363c-482c-a409-baac83a01bfc)]
 interface nsITimer : nsISupports
 {
   /* Timer types */
 
   /**
    * Type of a timer that fires once only.
    */
   const short TYPE_ONE_SHOT = 0;
@@ -147,16 +162,50 @@ interface nsITimer : nsISupports
    * Cancel the timer.  This method works on all types, not just on repeating
    * timers -- you might want to cancel a TYPE_ONE_SHOT timer, and even reuse
    * it by re-initializing it (to avoid object destruction and creation costs
    * by conserving one timer instance).
    */
   void cancel();
 
   /**
+   * Like initWithFuncCallback, but also takes a name for the timer; the name
+   * will be used when timer profiling is enabled via the "TimerFirings" log
+   * module.
+   *
+   * @param aFunc      The function to invoke
+   * @param aClosure   An opaque pointer to pass to that function
+   * @param aDelay     The millisecond interval
+   * @param aType      Timer type per TYPE* consts defined above
+   * @param aName      The timer's name
+   */
+  [noscript] void initWithNamedFuncCallback(in nsTimerCallbackFunc aCallback,
+                                            in voidPtr aClosure,
+                                            in unsigned long aDelay,
+                                            in unsigned long aType,
+                                            in string aName);
+
+  /**
+   * Like initWithNamedFuncCallback, but instead of a timer name it takes a
+   * callback that will provide a name when the timer fires.
+   *
+   * @param aFunc      The function to invoke
+   * @param aClosure   An opaque pointer to pass to that function
+   * @param aDelay     The millisecond interval
+   * @param aType      Timer type per TYPE* consts defined above
+   * @param aNameCallback  The callback function
+   */
+  [noscript] void initWithNameableFuncCallback(
+                    in nsTimerCallbackFunc aCallback,
+                    in voidPtr aClosure,
+                    in unsigned long aDelay,
+                    in unsigned long aType,
+                    in nsTimerNameCallbackFunc aNameCallback);
+
+  /**
    * The millisecond delay of the timeout.
    *
    * NOTE: Re-setting the delay on a one-shot timer that has already fired
    * doesn't restart the timer. Call one of the init() methods to restart
    * a one-shot timer.
    */
   attribute unsigned long delay;
 
--- a/xpcom/threads/nsTimerImpl.cpp
+++ b/xpcom/threads/nsTimerImpl.cpp
@@ -16,34 +16,82 @@
 #ifdef MOZ_NUWA_PROCESS
 #include "ipc/Nuwa.h"
 #endif
 #ifdef MOZ_TASK_TRACER
 #include "GeckoTaskTracerImpl.h"
 using namespace mozilla::tasktracer;
 #endif
 
+#ifdef XP_WIN
+#include <process.h>
+#ifndef getpid
+#define getpid _getpid
+#endif
+#else
+#include <unistd.h>
+#endif
+
 using mozilla::Atomic;
 using mozilla::LogLevel;
 using mozilla::TimeDuration;
 using mozilla::TimeStamp;
 
 static Atomic<int32_t>  gGenerator;
 static TimerThread*     gThread = nullptr;
 
+// This module prints info about the precision of timers.
 PRLogModuleInfo*
 GetTimerLog()
 {
   static PRLogModuleInfo* sLog;
   if (!sLog) {
     sLog = PR_NewLogModule("nsTimerImpl");
   }
   return sLog;
 }
 
+// This module prints info about which timers are firing, which is useful for
+// wakeups for the purposes of power profiling. Set the following environment
+// variable before starting the browser.
+//
+//   NSPR_LOG_MODULES=TimerFirings:4
+//
+// Then a line will be printed for every timer that fires. The name used for a
+// |CallbackType::Function| timer depends on the circumstances.
+//
+// - If it was explicitly named (e.g. it was initialized with
+//   InitWithNamedFuncCallback()) then that explicit name will be shown.
+//
+// - Otherwise, if we are on a platform that supports function name lookup
+//   (currently only Mac) then the looked-up name will be shown with a
+//   "[from dladdr]" annotation.
+//
+// - Otherwise, no name will be printed. If many timers hit this case then
+//   you'll need to re-run the workload on a Mac to find out which timers they
+//   are, and then give them explicit names.
+//
+// If you redirect this output to a file called "out", you can then
+// post-process it with a command something like the following.
+//
+//   cat out | grep timer | sort | uniq -c | sort -r -n
+//
+// This will show how often each unique line appears, with the most common ones
+// first.
+//
+PRLogModuleInfo*
+GetTimerFiringsLog()
+{
+  static PRLogModuleInfo* sLog;
+  if (!sLog) {
+    sLog = PR_NewLogModule("TimerFirings");
+  }
+  return sLog;
+}
+
 #include <math.h>
 
 double nsTimerImpl::sDeltaSumSquared = 0;
 double nsTimerImpl::sDeltaSum = 0;
 double nsTimerImpl::sDeltaNum = 0;
 
 static void
 myNS_MeanAndStdDev(double n, double sumOfValues, double sumOfSquaredValues,
@@ -123,16 +171,17 @@ nsTimerImpl::Release(void)
     }
   }
 
   return count;
 }
 
 nsTimerImpl::nsTimerImpl() :
   mClosure(nullptr),
+  mName(nsTimerImpl::Nothing),
   mCallbackType(CallbackType::Unknown),
   mFiring(false),
   mArmed(false),
   mCanceled(false),
   mGeneration(0),
   mDelay(0)
 {
   // XXXbsmedberg: shouldn't this be in Init()?
@@ -211,35 +260,69 @@ nsTimerImpl::InitCommon(uint32_t aDelay,
   mGeneration = gGenerator++;
 
   mType = (uint8_t)aType;
   SetDelayInternal(aDelay);
 
   return gThread->AddTimer(this);
 }
 
-NS_IMETHODIMP
-nsTimerImpl::InitWithFuncCallback(nsTimerCallbackFunc aFunc,
-                                  void* aClosure,
-                                  uint32_t aDelay,
-                                  uint32_t aType)
+nsresult
+nsTimerImpl::InitWithFuncCallbackCommon(nsTimerCallbackFunc aFunc,
+                                        void* aClosure,
+                                        uint32_t aDelay,
+                                        uint32_t aType,
+                                        Name aName)
 {
   if (NS_WARN_IF(!aFunc)) {
     return NS_ERROR_INVALID_ARG;
   }
 
   ReleaseCallback();
   mCallbackType = CallbackType::Function;
   mCallback.c = aFunc;
   mClosure = aClosure;
+  mName = aName;
 
   return InitCommon(aDelay, aType);
 }
 
 NS_IMETHODIMP
+nsTimerImpl::InitWithFuncCallback(nsTimerCallbackFunc aFunc,
+                                  void* aClosure,
+                                  uint32_t aDelay,
+                                  uint32_t aType)
+{
+  Name name(nsTimerImpl::Nothing);
+  return InitWithFuncCallbackCommon(aFunc, aClosure, aDelay, aType, name);
+}
+
+NS_IMETHODIMP
+nsTimerImpl::InitWithNamedFuncCallback(nsTimerCallbackFunc aFunc,
+                                       void* aClosure,
+                                       uint32_t aDelay,
+                                       uint32_t aType,
+                                       const char* aNameString)
+{
+  Name name(aNameString);
+  return InitWithFuncCallbackCommon(aFunc, aClosure, aDelay, aType, name);
+}
+
+NS_IMETHODIMP
+nsTimerImpl::InitWithNameableFuncCallback(nsTimerCallbackFunc aFunc,
+                                          void* aClosure,
+                                          uint32_t aDelay,
+                                          uint32_t aType,
+                                          nsTimerNameCallbackFunc aNameFunc)
+{
+  Name name(aNameFunc);
+  return InitWithFuncCallbackCommon(aFunc, aClosure, aDelay, aType, name);
+}
+
+NS_IMETHODIMP
 nsTimerImpl::InitWithCallback(nsITimerCallback* aCallback,
                               uint32_t aDelay,
                               uint32_t aType)
 {
   if (NS_WARN_IF(!aCallback)) {
     return NS_ERROR_INVALID_ARG;
   }
 
@@ -427,16 +510,20 @@ nsTimerImpl::Fire()
   CallbackType callbackType = mCallbackType;
   if (callbackType == CallbackType::Interface) {
     NS_ADDREF(callback.i);
   } else if (callbackType == CallbackType::Observer) {
     NS_ADDREF(callback.o);
   }
   ReleaseCallback();
 
+  if (MOZ_LOG_TEST(GetTimerFiringsLog(), LogLevel::Debug)) {
+    LogFiring(callbackType, callback);
+  }
+
   switch (callbackType) {
     case CallbackType::Function:
       callback.c(this, mClosure);
       break;
     case CallbackType::Interface:
       callback.i->Notify(this);
       break;
     case CallbackType::Observer:
@@ -479,16 +566,118 @@ nsTimerImpl::Fire()
     // REPEATING_PRECISE_CAN_SKIP timers this has
     // already happened.
     if (gThread) {
       gThread->AddTimer(this);
     }
   }
 }
 
+#if defined(XP_MACOSX)
+#include <cxxabi.h>
+#include <dlfcn.h>
+#endif
+
+// See the big comment above GetTimerFiringsLog() to understand this code.
+void
+nsTimerImpl::LogFiring(CallbackType aCallbackType, CallbackUnion aCallback)
+{
+  const char* typeStr;
+  switch (mType) {
+    case TYPE_ONE_SHOT:                   typeStr = "ONE_SHOT"; break;
+    case TYPE_REPEATING_SLACK:            typeStr = "SLACK   "; break;
+    case TYPE_REPEATING_PRECISE:          /* fall through */
+    case TYPE_REPEATING_PRECISE_CAN_SKIP: typeStr = "PRECISE "; break;
+    default:                              MOZ_CRASH("bad type");
+  }
+
+  switch (aCallbackType) {
+    case CallbackType::Function: {
+      bool needToFreeName = false;
+      const char* annotation = "";
+      const char* name;
+      static const size_t buflen = 1024;
+      char buf[buflen];
+
+      if (mName.is<NameString>()) {
+        name = mName.as<NameString>();
+
+      } else if (mName.is<NameFunc>()) {
+        mName.as<NameFunc>()(this, mClosure, buf, buflen);
+        name = buf;
+
+      } else {
+        MOZ_ASSERT(mName.is<NameNothing>());
+#if defined(XP_MACOSX)
+        annotation = "[from dladdr] ";
+
+        Dl_info info;
+        if (dladdr(reinterpret_cast<void*>(aCallback.c), &info) == 0) {
+          name = "???[dladdr: failed]";
+        } else if (!info.dli_sname) {
+          name = "???[dladdr: no matching symbol]";
+
+        } else {
+          int status;
+          name = abi::__cxa_demangle(info.dli_sname, nullptr, nullptr, &status);
+          if (status == 0) {
+            // Success. Because we didn't pass in a buffer to __cxa_demangle it
+            // allocates its own one with malloc() which we must free() later.
+            MOZ_ASSERT(name);
+            needToFreeName = true;
+          } else if (status == -1) {
+            name = "???[__cxa_demangle: OOM]";
+          } else if (status == -2) {
+            name = "???[__cxa_demangle: invalid mangled name]";
+          } else if (status == -3) {
+            name = "???[__cxa_demangle: invalid argument]";
+          } else {
+            name = "???[__cxa_demangle: unexpected status value]";
+          }
+        }
+#else
+        name = "???[dladdr: unavailable/doesn't work on this platform]";
+#endif
+      }
+
+      MOZ_LOG(GetTimerFiringsLog(), LogLevel::Debug,
+              ("[%d]    fn timer (%s %5d ms): %s%s\n",
+               getpid(), typeStr, mDelay, annotation, name));
+
+      if (needToFreeName) {
+        free(const_cast<char*>(name));
+      }
+
+      break;
+    }
+
+    case CallbackType::Interface: {
+      MOZ_LOG(GetTimerFiringsLog(), LogLevel::Debug,
+              ("[%d] iface timer (%s %5d ms): %p\n",
+               getpid(), typeStr, mDelay, aCallback.i));
+      break;
+    }
+
+    case CallbackType::Observer: {
+      MOZ_LOG(GetTimerFiringsLog(), LogLevel::Debug,
+              ("[%d]   obs timer (%s %5d ms): %p\n",
+               getpid(), typeStr, mDelay, aCallback.o));
+      break;
+    }
+
+    case CallbackType::Unknown:
+    default: {
+      MOZ_LOG(GetTimerFiringsLog(), LogLevel::Debug,
+              ("[%d]   ??? timer (%s, %5d ms)\n",
+               getpid(), typeStr, mDelay));
+      break;
+    }
+  }
+}
+
 void
 nsTimerImpl::SetDelayInternal(uint32_t aDelay)
 {
   TimeDuration delayInterval = TimeDuration::FromMilliseconds(aDelay);
 
   mDelay = aDelay;
 
   TimeStamp now = TimeStamp::Now();
@@ -506,16 +695,18 @@ nsTimerImpl::SetDelayInternal(uint32_t a
 }
 
 size_t
 nsTimerImpl::SizeOfIncludingThis(mozilla::MallocSizeOf aMallocSizeOf) const
 {
   return aMallocSizeOf(this);
 }
 
+/* static */ const nsTimerImpl::NameNothing nsTimerImpl::Nothing = 0;
+
 #ifdef MOZ_TASK_TRACER
 void
 nsTimerImpl::GetTLSTraceInfo()
 {
   mTracedTask.GetTLSTraceInfo();
 }
 
 TracedTaskCommon
--- a/xpcom/threads/nsTimerImpl.h
+++ b/xpcom/threads/nsTimerImpl.h
@@ -8,19 +8,20 @@
 #define nsTimerImpl_h___
 
 #include "nsITimer.h"
 #include "nsIEventTarget.h"
 #include "nsIObserver.h"
 
 #include "nsCOMPtr.h"
 
+#include "mozilla/Attributes.h"
 #include "mozilla/Logging.h"
 #include "mozilla/TimeStamp.h"
-#include "mozilla/Attributes.h"
+#include "mozilla/Variant.h"
 
 #ifdef MOZ_TASK_TRACER
 #include "TracedTaskCommon.h"
 #endif
 
 extern PRLogModuleInfo* GetTimerLog();
 
 #define NS_TIMER_CID \
@@ -117,16 +118,38 @@ private:
   union CallbackUnion
   {
     nsTimerCallbackFunc c;
     // These refcounted references are managed manually, as they are in a union
     nsITimerCallback* MOZ_OWNING_REF i;
     nsIObserver* MOZ_OWNING_REF o;
   } mCallback;
 
+  void LogFiring(CallbackType aCallbackType, CallbackUnion aCallbackUnion);
+
+  // |Name| is a tagged union type representing one of (a) nothing, (b) a
+  // string, or (c) a function. mozilla::Variant doesn't naturally handle the
+  // "nothing" case, so we define a dummy type and value (which is unused and
+  // so the exact value doesn't matter) for it.
+  typedef const int NameNothing;
+  typedef const char* NameString;
+  typedef nsTimerNameCallbackFunc NameFunc;
+  typedef mozilla::Variant<NameNothing, NameString, NameFunc> Name;
+  static const NameNothing Nothing;
+
+  nsresult InitWithFuncCallbackCommon(nsTimerCallbackFunc aFunc,
+                                      void* aClosure,
+                                      uint32_t aDelay,
+                                      uint32_t aType,
+                                      Name aName);
+
+  // This is set by Init. It records the name (if there is one) for the timer,
+  // for use when logging timer firings.
+  Name mName;
+
   // Some callers expect to be able to access the callback while the
   // timer is firing.
   nsCOMPtr<nsITimerCallback> mTimerCallbackWhileFiring;
 
   // These members are set by Init and never reset.
   CallbackType          mCallbackType;
 
   // These members are set by the initiating thread, when the timer's type is