Bug 1423890 - Add markers for background hangs r=dthayer,mstange
authorAlexandre Poirot <poirot.alex@gmail.com>
Thu, 07 Dec 2017 02:35:36 -0800
changeset 452897 88e1c3fbec11c4cfe1ffb5b11cb4882da18e3a54
parent 452896 f46f4e29d4a083d5e4ed9b0e1fe6669d6e275a9a
child 452898 a559e2141dec6d93ac55ba88ada188ccd01d0af1
push id1648
push usermtabara@mozilla.com
push dateThu, 01 Mar 2018 12:45:47 +0000
treeherdermozilla-release@cbb9688c2eeb [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersdthayer, mstange
bugs1423890
milestone59.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 1423890 - Add markers for background hangs r=dthayer,mstange MozReview-Commit-ID: 484UZEbbd12
toolkit/components/backgroundhangmonitor/BackgroundHangMonitor.cpp
toolkit/components/backgroundhangmonitor/HangDetails.cpp
toolkit/components/backgroundhangmonitor/HangDetails.h
tools/profiler/core/ProfilerMarkerPayload.cpp
tools/profiler/public/ProfilerMarkerPayload.h
--- a/toolkit/components/backgroundhangmonitor/BackgroundHangMonitor.cpp
+++ b/toolkit/components/backgroundhangmonitor/BackgroundHangMonitor.cpp
@@ -21,16 +21,20 @@
 #include "prthread.h"
 #include "ThreadStackHelper.h"
 #include "nsIObserverService.h"
 #include "nsIObserver.h"
 #include "mozilla/Services.h"
 #include "nsThreadUtils.h"
 #include "nsXULAppAPI.h"
 #include "GeckoProfiler.h"
+#ifdef MOZ_GECKO_PROFILER
+#include "mozilla/TimeStamp.h"
+#include "ProfilerMarkerPayload.h"
+#endif
 #include "nsNetCID.h"
 #include "HangDetails.h"
 
 #include <algorithm>
 
 // Activate BHR only for one every BHR_BETA_MOD users.
 // We're doing experimentation with collecting a lot more data from BHR, and
 // don't want to enable it for beta users at the moment. We can scale this up in
@@ -209,17 +213,17 @@ public:
 
   BackgroundHangThread(const char* aName,
                        uint32_t aTimeoutMs,
                        uint32_t aMaxTimeoutMs,
                        BackgroundHangMonitor::ThreadType aThreadType = BackgroundHangMonitor::THREAD_SHARED);
 
   // Report a hang; aManager->mLock IS locked. The hang will be processed
   // off-main-thread, and will then be submitted back.
-  void ReportHang(PRIntervalTime aHangTime);
+  void ReportHang(PRIntervalTime aHangTime, TimeStamp aHangEndTime);
   // Report a permanent hang; aManager->mLock IS locked
   void ReportPermaHang();
   // Called by BackgroundHangMonitor::NotifyActivity
   void NotifyActivity()
   {
     MonitorAutoLock autoLock(mManager->mLock);
     Update();
   }
@@ -381,17 +385,17 @@ BackgroundHangManager::RunMonitorThread(
           currentThread->mHangStart = interval;
           currentThread->mHanging = true;
           currentThread->mAnnotations =
             currentThread->mAnnotators.GatherAnnotations();
         }
       } else {
         if (MOZ_LIKELY(interval != currentThread->mHangStart)) {
           // A hang ended
-          currentThread->ReportHang(intervalNow - currentThread->mHangStart);
+          currentThread->ReportHang(intervalNow - currentThread->mHangStart, TimeStamp::Now());
           currentThread->mHanging = false;
         }
       }
 
       /* If we are hanging, the next time we check for hang status is when
          the hang turns into a permahang. If we're not hanging, the next
          recheck timeout is when we may be entering a hang. */
       PRIntervalTime nextRecheck;
@@ -459,22 +463,23 @@ BackgroundHangThread::~BackgroundHangThr
 
   // We no longer have a thread
   if (sTlsKeyInitialized && IsShared()) {
     sTlsKey.set(nullptr);
   }
 }
 
 void
-BackgroundHangThread::ReportHang(PRIntervalTime aHangTime)
+BackgroundHangThread::ReportHang(PRIntervalTime aHangTime, TimeStamp aHangEndTime)
 {
   // Recovered from a hang; called on the monitor thread
   // mManager->mLock IS locked
 
   HangDetails hangDetails(aHangTime,
+                          aHangEndTime,
                           XRE_GetProcessType(),
                           mThreadName,
                           mRunnableName,
                           Move(mHangStack),
                           Move(mAnnotations));
   // If we have the stream transport service avaliable, we can process the
   // native stack on it. Otherwise, we are unable to report a native stack, so
   // we just report without one.
@@ -496,17 +501,17 @@ BackgroundHangThread::ReportPermaHang()
   // mManager->mLock IS locked
 
   // NOTE: We used to capture a native stack in this situation if one had not
   // already been captured, but with the new ReportHang design that is less
   // practical.
   //
   // We currently don't look at hang reports outside of nightly, and already
   // collect native stacks eagerly on nightly, so this should be OK.
-  ReportHang(mMaxTimeout);
+  ReportHang(mMaxTimeout, TimeStamp::Now());
 }
 
 MOZ_ALWAYS_INLINE void
 BackgroundHangThread::Update()
 {
   PRIntervalTime intervalNow = mManager->mIntervalNow;
   if (mWaiting) {
     mInterval = intervalNow;
--- a/toolkit/components/backgroundhangmonitor/HangDetails.cpp
+++ b/toolkit/components/backgroundhangmonitor/HangDetails.cpp
@@ -1,15 +1,18 @@
 #include "HangDetails.h"
 #include "nsIHangDetails.h"
 #include "nsPrintfCString.h"
 #include "mozilla/gfx/GPUParent.h"
 #include "mozilla/dom/ContentChild.h"
 #include "mozilla/Unused.h"
 #include "mozilla/GfxMessageUtils.h" // For ParamTraits<GeckoProcessType>
+#ifdef MOZ_GECKO_PROFILER
+#include "ProfilerMarkerPayload.h"
+#endif
 
 namespace mozilla {
 
 NS_IMETHODIMP
 nsHangDetails::GetDuration(uint32_t* aDuration)
 {
   *aDuration = mDetails.mDuration;
   return NS_OK;
@@ -264,16 +267,26 @@ nsHangDetails::Submit()
       break;
     }
     default:
       // XXX: Consider handling GeckoProcessType_GMPlugin and
       // GeckoProcessType_Plugin?
       NS_WARNING("Unsupported BHR process type - discarding hang.");
       break;
     }
+#ifdef MOZ_GECKO_PROFILER
+    if (profiler_is_active()) {
+      TimeStamp endTime = hangDetails->mDetails.mEndTime;
+      TimeStamp startTime = endTime -
+                            TimeDuration::FromMilliseconds(hangDetails->mDetails.mDuration);
+      profiler_add_marker(
+        "BHR-detected hang",
+        MakeUnique<HangMarkerPayload>(startTime, endTime));
+    }
+#endif
   });
 
   nsresult rv = SystemGroup::Dispatch(TaskCategory::Other,
                                       notifyObservers.forget());
   MOZ_RELEASE_ASSERT(NS_SUCCEEDED(rv));
 }
 
 NS_IMPL_ISUPPORTS(nsHangDetails, nsIHangDetails)
--- a/toolkit/components/backgroundhangmonitor/HangDetails.h
+++ b/toolkit/components/backgroundhangmonitor/HangDetails.h
@@ -10,54 +10,59 @@
 #include "ipc/IPCMessageUtils.h"
 #include "mozilla/ProcessedStack.h"
 #include "mozilla/RefPtr.h"
 #include "mozilla/Move.h"
 #include "mozilla/HangStack.h"
 #include "mozilla/HangAnnotations.h"
 #include "nsTArray.h"
 #include "nsIHangDetails.h"
+#include "mozilla/TimeStamp.h"
 
 namespace mozilla {
 
 /**
  * HangDetails is a POD struct which contains the information collected from the
  * hang. It can be wrapped in a nsHangDetails to provide an XPCOM interface for
  * extracting information from it easily.
  *
  * This type is separate, as it can be sent over IPC while nsHangDetails is an
  * XPCOM interface which is harder to serialize over IPC.
  */
 class HangDetails
 {
 public:
   HangDetails()
     : mDuration(0)
+    , mEndTime(TimeStamp::Now())
     , mProcess(GeckoProcessType_Invalid)
     , mRemoteType(VoidString())
   {}
 
   HangDetails(const HangDetails& aOther) = default;
   HangDetails(HangDetails&& aOther) = default;
   HangDetails(uint32_t aDuration,
+              TimeStamp aEndTime,
               GeckoProcessType aProcess,
               const nsACString& aThreadName,
               const nsACString& aRunnableName,
               HangStack&& aStack,
               HangMonitor::HangAnnotations&& aAnnotations)
     : mDuration(aDuration)
+    , mEndTime(aEndTime)
     , mProcess(aProcess)
     , mRemoteType(VoidString())
     , mThreadName(aThreadName)
     , mRunnableName(aRunnableName)
     , mStack(Move(aStack))
     , mAnnotations(Move(aAnnotations))
   {}
 
   uint32_t mDuration;
+  TimeStamp mEndTime;
   GeckoProcessType mProcess;
   // NOTE: mRemoteType is set in nsHangDetails::Submit before the HangDetails
   // object is sent to the parent process.
   nsString mRemoteType;
   nsCString mThreadName;
   nsCString mRunnableName;
   HangStack mStack;
   HangMonitor::HangAnnotations mAnnotations;
--- a/tools/profiler/core/ProfilerMarkerPayload.cpp
+++ b/tools/profiler/core/ProfilerMarkerPayload.cpp
@@ -152,8 +152,16 @@ GCMinorMarkerPayload::StreamPayload(Spli
   MOZ_ASSERT(mTimingData);
   StreamCommonProps("GCMinor", aWriter, aProcessStartTime, aUniqueStacks);
   if (mTimingData) {
     aWriter.SplicedJSONProperty("nursery", mTimingData.get());
   } else {
     aWriter.NullProperty("nursery");
   }
 }
+
+void
+HangMarkerPayload::StreamPayload(SpliceableJSONWriter& aWriter,
+                                 const TimeStamp& aProcessStartTime,
+                                 UniqueStacks& aUniqueStacks)
+{
+  StreamCommonProps("BHR-detected hang", aWriter, aProcessStartTime, aUniqueStacks);
+}
--- a/tools/profiler/public/ProfilerMarkerPayload.h
+++ b/tools/profiler/public/ProfilerMarkerPayload.h
@@ -245,9 +245,21 @@ public:
   {}
 
   DECL_STREAM_PAYLOAD
 
 private:
   JS::UniqueChars mTimingData;
 };
 
+class HangMarkerPayload : public ProfilerMarkerPayload
+{
+public:
+  HangMarkerPayload(const mozilla::TimeStamp& aStartTime,
+                    const mozilla::TimeStamp& aEndTime)
+   : ProfilerMarkerPayload(aStartTime, aEndTime)
+  {}
+
+  DECL_STREAM_PAYLOAD
+private:
+};
+
 #endif // ProfilerMarkerPayload_h