Bug 1384693 - Let callers of profiler_stream_json_for_this_process obtain the time of the first sample in the buffer. r=njn
authorMarkus Stange <mstange@themasta.com>
Thu, 27 Jul 2017 15:04:59 -0400
changeset 420216 4d932d0c9a761a09461383776590670207a2dcfb
parent 420215 21996e01ca43e5505f0d7c2c8a3b0f742da429c6
child 420217 926fa981b826656af4cbbd28865b4f9025aefc86
push id7566
push usermtabara@mozilla.com
push dateWed, 02 Aug 2017 08:25:16 +0000
treeherdermozilla-beta@86913f512c3c [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersnjn
bugs1384693
milestone56.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 1384693 - Let callers of profiler_stream_json_for_this_process obtain the time of the first sample in the buffer. r=njn MozReview-Commit-ID: IRFq1F3dWIk
tools/profiler/core/ProfileBuffer.h
tools/profiler/core/ProfileBufferEntry.cpp
tools/profiler/core/ProfilerBacktrace.cpp
tools/profiler/core/ThreadInfo.cpp
tools/profiler/core/ThreadInfo.h
tools/profiler/core/platform.cpp
tools/profiler/public/GeckoProfiler.h
--- a/tools/profiler/core/ProfileBuffer.h
+++ b/tools/profiler/core/ProfileBuffer.h
@@ -52,17 +52,18 @@ public:
   virtual void CollectCodeLocation(
     const char* aLabel, const char* aStr, int aLineNumber,
     const mozilla::Maybe<js::ProfileEntry::Category>& aCategory) override;
 
   // Maximum size of a frameKey string that we'll handle.
   static const size_t kMaxFrameKeyLength = 512;
 
   void StreamSamplesToJSON(SpliceableJSONWriter& aWriter, int aThreadId,
-                           double aSinceTime, JSContext* cx,
+                           double aSinceTime, double* aOutFirstSampleTime,
+                           JSContext* cx,
                            UniqueStacks& aUniqueStacks) const;
   void StreamMarkersToJSON(SpliceableJSONWriter& aWriter, int aThreadId,
                            const mozilla::TimeStamp& aProcessStartTime,
                            double aSinceTime,
                            UniqueStacks& aUniqueStacks) const;
 
   // Find (via |aLS|) the most recent sample for the thread denoted by
   // |aThreadId| and clone it, patching in |aProcessStartTime| as appropriate.
--- a/tools/profiler/core/ProfileBufferEntry.cpp
+++ b/tools/profiler/core/ProfileBufferEntry.cpp
@@ -690,32 +690,35 @@ private:
 //     DynamicStringFragment("ac0da204")
 //     DynamicStringFragment("aaa44d75")
 //     DynamicStringFragment("a800.bun")
 //     DynamicStringFragment("dle.js:2")
 //     DynamicStringFragment("5)")
 //
 void
 ProfileBuffer::StreamSamplesToJSON(SpliceableJSONWriter& aWriter, int aThreadId,
-                                   double aSinceTime, JSContext* aContext,
+                                   double aSinceTime,
+                                   double* aOutFirstSampleTime,
+                                   JSContext* aContext,
                                    UniqueStacks& aUniqueStacks) const
 {
   UniquePtr<char[]> strbuf = MakeUnique<char[]>(kMaxFrameKeyLength);
 
   // Because this is a format entirely internal to the Profiler, any parsing
   // error indicates a bug in the ProfileBuffer writing or the parser itself,
   // or possibly flaky hardware.
   #define ERROR_AND_SKIP_TO_NEXT_SAMPLE(msg) \
     do { \
       fprintf(stderr, "ProfileBuffer parse error: %s", msg); \
       MOZ_ASSERT(false, msg); \
       goto skip_to_next_sample; \
     } while (0)
 
   EntryGetter e(*this);
+  bool seenFirstSample = false;
 
   // This block skips entries until we find the start of the next sample. This
   // is useful in two situations.
   //
   // - The circular buffer overwrites old entries, so when we start parsing we
   //   might be in the middle of a sample, and we must skip forward to the
   //   start of the next sample.
   //
@@ -750,16 +753,23 @@ skip_to_next_sample:
     if (e.Has() && e.Get().IsTime()) {
       sample.mTime = e.Get().u.mDouble;
       e.Next();
 
       // Ignore samples that are too old.
       if (sample.mTime < aSinceTime) {
         goto skip_to_next_sample;
       }
+
+      if (!seenFirstSample) {
+        if (aOutFirstSampleTime) {
+          *aOutFirstSampleTime = sample.mTime;
+        }
+        seenFirstSample = true;
+      }
     } else {
       ERROR_AND_SKIP_TO_NEXT_SAMPLE("expected a Time entry");
     }
 
     UniqueStacks::Stack stack =
       aUniqueStacks.BeginStack(UniqueStacks::OnStackFrameKey("(root)"));
 
     int numFrames = 0;
--- a/tools/profiler/core/ProfilerBacktrace.cpp
+++ b/tools/profiler/core/ProfilerBacktrace.cpp
@@ -27,15 +27,18 @@ void
 ProfilerBacktrace::StreamJSON(SpliceableJSONWriter& aWriter,
                               const TimeStamp& aProcessStartTime,
                               UniqueStacks& aUniqueStacks)
 {
   // This call to StreamSamplesAndMarkers() can safely pass in a non-null
   // JSContext. That's because StreamSamplesAndMarkers() only accesses the
   // JSContext when streaming JitReturnAddress entries, and such entries
   // never appear in synchronous samples.
+  double firstSampleTimeIgnored;
   StreamSamplesAndMarkers(mName.get(), mThreadId,
                           *mBuffer.get(), aWriter, aProcessStartTime,
-                          /* aSinceTime */ 0, /* aContext */ nullptr,
+                          /* aSinceTime */ 0, &firstSampleTimeIgnored,
+                          /* aContext */ nullptr,
                           /* aSavedStreamedSamples */ nullptr,
+                          /* aFirstSavedStreamedSampleTime */ 0.0,
                           /* aSavedStreamedMarkers */ nullptr,
                           aUniqueStacks);
 }
--- a/tools/profiler/core/ThreadInfo.cpp
+++ b/tools/profiler/core/ThreadInfo.cpp
@@ -64,33 +64,39 @@ ThreadInfo::StartProfiling()
 
 void
 ThreadInfo::StopProfiling()
 {
   mResponsiveness.reset();
   mIsBeingProfiled = false;
 }
 
-void
+double
 ThreadInfo::StreamJSON(const ProfileBuffer& aBuffer,
                        SpliceableJSONWriter& aWriter,
                        const TimeStamp& aProcessStartTime, double aSinceTime)
 {
   // mUniqueStacks may already be emplaced from FlushSamplesAndMarkers.
   if (!mUniqueStacks.isSome()) {
     mUniqueStacks.emplace(mContext);
   }
 
+  double firstSampleTime = 0.0;
+
   aWriter.Start(SpliceableJSONWriter::SingleLineStyle);
   {
     StreamSamplesAndMarkers(Name(), ThreadId(), aBuffer, aWriter,
-                            aProcessStartTime, aSinceTime, mContext,
+                            aProcessStartTime, aSinceTime, &firstSampleTime,
+                            mContext,
                             mSavedStreamedSamples.get(),
-                            mSavedStreamedMarkers.get(), *mUniqueStacks);
+                            mFirstSavedStreamedSampleTime,
+                            mSavedStreamedMarkers.get(),
+                            *mUniqueStacks);
     mSavedStreamedSamples.reset();
+    mFirstSavedStreamedSampleTime = 0.0;
     mSavedStreamedMarkers.reset();
 
     aWriter.StartObjectProperty("stackTable");
     {
       {
         JSONSchemaWriter schema(aWriter);
         schema.WriteField("prefix");
         schema.WriteField("frame");
@@ -127,27 +133,31 @@ ThreadInfo::StreamJSON(const ProfileBuff
     {
       mUniqueStacks->mUniqueStrings.SpliceStringTableElements(aWriter);
     }
     aWriter.EndArray();
   }
   aWriter.End();
 
   mUniqueStacks.reset();
+
+  return firstSampleTime;
 }
 
 void
 StreamSamplesAndMarkers(const char* aName,
                         int aThreadId,
                         const ProfileBuffer& aBuffer,
                         SpliceableJSONWriter& aWriter,
                         const TimeStamp& aProcessStartTime,
                         double aSinceTime,
+                        double* aOutFirstSampleTime,
                         JSContext* aContext,
                         char* aSavedStreamedSamples,
+                        double aFirstSavedStreamedSampleTime,
                         char* aSavedStreamedMarkers,
                         UniqueStacks& aUniqueStacks)
 {
   aWriter.StringProperty("processType",
                          XRE_ChildProcessTypeToString(XRE_GetProcessType()));
 
   aWriter.StringProperty("name", aName);
   aWriter.IntProperty("tid", static_cast<int64_t>(aThreadId));
@@ -168,18 +178,22 @@ StreamSamplesAndMarkers(const char* aNam
     {
       if (aSavedStreamedSamples) {
         // We would only have saved streamed samples during shutdown
         // streaming, which cares about dumping the entire buffer, and thus
         // should have passed in 0 for aSinceTime.
         MOZ_ASSERT(aSinceTime == 0);
         aWriter.Splice(aSavedStreamedSamples);
       }
-      aBuffer.StreamSamplesToJSON(aWriter, aThreadId, aSinceTime, aContext,
+      aBuffer.StreamSamplesToJSON(aWriter, aThreadId, aSinceTime,
+                                  aOutFirstSampleTime, aContext,
                                   aUniqueStacks);
+      if (aSavedStreamedSamples) {
+        *aOutFirstSampleTime = aFirstSavedStreamedSampleTime;
+      }
     }
     aWriter.EndArray();
   }
   aWriter.EndObject();
 
   aWriter.StartObjectProperty("markers");
   {
     {
@@ -220,16 +234,17 @@ ThreadInfo::FlushSamplesAndMarkers(const
   // mapping is stable across JS shutdown.
   mUniqueStacks.emplace(mContext);
 
   {
     SpliceableChunkedJSONWriter b;
     b.StartBareList();
     {
       aBuffer.StreamSamplesToJSON(b, mThreadId, /* aSinceTime = */ 0,
+                                  &mFirstSavedStreamedSampleTime,
                                   mContext, *mUniqueStacks);
     }
     b.EndBareList();
     mSavedStreamedSamples = b.WriteFunc()->CopyData();
   }
 
   {
     SpliceableChunkedJSONWriter b;
--- a/tools/profiler/core/ThreadInfo.h
+++ b/tools/profiler/core/ThreadInfo.h
@@ -204,19 +204,20 @@ private:
   void* mStackTop;
 
   //
   // The following code is only used for threads that are being profiled, i.e.
   // for which IsBeingProfiled() returns true.
   //
 
 public:
-  void StreamJSON(const ProfileBuffer& aBuffer, SpliceableJSONWriter& aWriter,
-                  const mozilla::TimeStamp& aProcessStartTime,
-                  double aSinceTime);
+  // Returns the time of the first sample.
+  double StreamJSON(const ProfileBuffer& aBuffer, SpliceableJSONWriter& aWriter,
+                    const mozilla::TimeStamp& aProcessStartTime,
+                    double aSinceTime);
 
   // Call this method when the JS entries inside the buffer are about to
   // become invalid, i.e., just before JS shutdown.
   void FlushSamplesAndMarkers(const mozilla::TimeStamp& aProcessStartTime,
                               ProfileBuffer& aBuffer);
 
   // Returns nullptr if this is not the main thread or if this thread is not
   // being profiled.
@@ -299,16 +300,17 @@ public:
 private:
   bool mIsBeingProfiled;
 
   // JS frames in the buffer may require a live JSRuntime to stream (e.g.,
   // stringifying JIT frames). In the case of JSRuntime destruction,
   // FlushSamplesAndMarkers should be called to save them. These are spliced
   // into the final stream.
   mozilla::UniquePtr<char[]> mSavedStreamedSamples;
+  double mFirstSavedStreamedSampleTime;
   mozilla::UniquePtr<char[]> mSavedStreamedMarkers;
   mozilla::Maybe<UniqueStacks> mUniqueStacks;
 
   // This is only used for the main thread.
   mozilla::Maybe<ThreadResponsiveness> mResponsiveness;
 
 public:
   // If this is a JS thread, this is its JSContext, which is required for any
@@ -369,14 +371,16 @@ private:
 };
 
 void
 StreamSamplesAndMarkers(const char* aName, int aThreadId,
                         const ProfileBuffer& aBuffer,
                         SpliceableJSONWriter& aWriter,
                         const mozilla::TimeStamp& aProcessStartTime,
                         double aSinceTime,
+                        double* aOutFirstSampleTime,
                         JSContext* aContext,
                         char* aSavedStreamedSamples,
+                        double aFirstSavedStreamedSampleTime,
                         char* aSavedStreamedMarkers,
                         UniqueStacks& aUniqueStacks);
 
 #endif  // ThreadInfo_h
--- a/tools/profiler/core/platform.cpp
+++ b/tools/profiler/core/platform.cpp
@@ -1578,17 +1578,17 @@ BuildJavaThreadJSObject(SpliceableJSONWr
         break;
       }
     }
   }
   aWriter.EndArray();
 }
 #endif
 
-static void
+static TimeStamp
 locked_profiler_stream_json_for_this_process(PSLockRef aLock,
                                              SpliceableJSONWriter& aWriter,
                                              double aSinceTime)
 {
   LOG("locked_profiler_stream_json_for_this_process");
 
   MOZ_RELEASE_ASSERT(CorePS::Exists() && ActivePS::Exists(aLock));
 
@@ -1606,35 +1606,41 @@ locked_profiler_stream_json_for_this_pro
 
   // Data of TaskTracer doesn't belong in the circular buffer.
   if (ActivePS::FeatureTaskTracer(aLock)) {
     aWriter.StartObjectProperty("tasktracer");
     StreamTaskTracer(aLock, aWriter);
     aWriter.EndObject();
   }
 
+  double firstSampleTime = INFINITY;
+
   // Lists the samples for each thread profile
   aWriter.StartArrayProperty("threads");
   {
     const CorePS::ThreadVector& liveThreads = CorePS::LiveThreads(aLock);
     for (size_t i = 0; i < liveThreads.size(); i++) {
       ThreadInfo* info = liveThreads.at(i);
       if (!info->IsBeingProfiled()) {
         continue;
       }
-      info->StreamJSON(ActivePS::Buffer(aLock), aWriter,
-                       CorePS::ProcessStartTime(), aSinceTime);
+      double thisThreadFirstSampleTime =
+        info->StreamJSON(ActivePS::Buffer(aLock), aWriter,
+                         CorePS::ProcessStartTime(), aSinceTime);
+      firstSampleTime = std::min(thisThreadFirstSampleTime, firstSampleTime);
     }
 
     const CorePS::ThreadVector& deadThreads = CorePS::DeadThreads(aLock);
     for (size_t i = 0; i < deadThreads.size(); i++) {
       ThreadInfo* info = deadThreads.at(i);
       MOZ_ASSERT(info->IsBeingProfiled());
-      info->StreamJSON(ActivePS::Buffer(aLock), aWriter,
-                       CorePS::ProcessStartTime(), aSinceTime);
+      double thisThreadFirstSampleTime =
+        info->StreamJSON(ActivePS::Buffer(aLock), aWriter,
+                        CorePS::ProcessStartTime(), aSinceTime);
+      firstSampleTime = std::min(thisThreadFirstSampleTime, firstSampleTime);
     }
 
 #if defined(GP_OS_android)
     if (ActivePS::FeatureJava(aLock)) {
       java::GeckoJavaSampler::Pause();
 
       aWriter.Start();
       {
@@ -1642,32 +1648,47 @@ locked_profiler_stream_json_for_this_pro
       }
       aWriter.End();
 
       java::GeckoJavaSampler::Unpause();
     }
 #endif
   }
   aWriter.EndArray();
+
+  if (firstSampleTime != INFINITY) {
+    return CorePS::ProcessStartTime() +
+           TimeDuration::FromMilliseconds(firstSampleTime);
+  }
+
+  return TimeStamp();
 }
 
 bool
-profiler_stream_json_for_this_process(SpliceableJSONWriter& aWriter, double aSinceTime)
+profiler_stream_json_for_this_process(SpliceableJSONWriter& aWriter,
+                                      double aSinceTime,
+                                      TimeStamp* aOutFirstSampleTime)
 {
   LOG("profiler_stream_json_for_this_process");
 
   MOZ_RELEASE_ASSERT(CorePS::Exists());
 
   PSAutoLock lock(gPSMutex);
 
   if (!ActivePS::Exists(lock)) {
     return false;
   }
 
-  locked_profiler_stream_json_for_this_process(lock, aWriter, aSinceTime);
+  TimeStamp firstSampleTime =
+    locked_profiler_stream_json_for_this_process(lock, aWriter, aSinceTime);
+
+  if (aOutFirstSampleTime) {
+    *aOutFirstSampleTime = firstSampleTime;
+  }
+
   return true;
 }
 
 // END saving/streaming code
 ////////////////////////////////////////////////////////////////////////
 
 static void
 PrintUsageThenExit(int aExitCode)
--- a/tools/profiler/public/GeckoProfiler.h
+++ b/tools/profiler/public/GeckoProfiler.h
@@ -41,16 +41,17 @@
 
 class ProfilerBacktrace;
 class ProfilerMarkerPayload;
 class SpliceableJSONWriter;
 
 namespace mozilla {
 class MallocAllocPolicy;
 template <class T, size_t MinInlineCapacity, class AllocPolicy> class Vector;
+class TimeStamp;
 } // namespace mozilla
 
 // When the profiler is disabled functions declared with these macros are
 // static inline functions (with a trivial return value if they are non-void)
 // that will be optimized away during compilation.
 #ifdef MOZ_GECKO_PROFILER
 # define PROFILER_FUNC(decl, rv)  decl;
 # define PROFILER_FUNC_VOID(decl) void decl;
@@ -455,17 +456,18 @@ PROFILER_FUNC_VOID(profiler_tracing(cons
 PROFILER_FUNC(
   mozilla::UniquePtr<char[]> profiler_get_profile(double aSinceTime = 0),
   nullptr)
 
 // Write the profile for this process (excluding subprocesses) into aWriter.
 // Returns false if the profiler is inactive.
 PROFILER_FUNC(
   bool profiler_stream_json_for_this_process(SpliceableJSONWriter& aWriter,
-                                             double aSinceTime = 0),
+                                             double aSinceTime = 0,
+                                             mozilla::TimeStamp* aOutFirstSampleTime = nullptr),
   false)
 
 // Get the profile and write it into a file. A no-op if the profile is
 // inactive.
 //
 // This function is 'extern "C"' so that it is easily callable from a debugger
 // in a build without debugging information (a workaround for
 // http://llvm.org/bugs/show_bug.cgi?id=22211).