Bug 1423890 - Add markers for background hangs r=mstange draft
authorAlexandre Poirot <poirot.alex@gmail.com>
Thu, 07 Dec 2017 02:35:36 -0800
changeset 718601 48663a793fa31f0d4f0aef1f593477d0d3e0b042
parent 717183 ca379fcca95b1f4a3744242ea8647004b99b3507
child 745554 70af3b899871dc9e521ec2c897b8d92165cd61ef
push id95000
push userbmo:poirot.alex@gmail.com
push dateWed, 10 Jan 2018 17:22:03 +0000
reviewersmstange
bugs1423890
milestone59.0a1
Bug 1423890 - Add markers for background hangs r=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