Bug 1492121 - Gecko Profiler integrates BaseProfiler startup profiled threads - r=njn
authorGerald Squelart <gsquelart@mozilla.com>
Thu, 06 Jun 2019 06:20:14 +0000
changeset 477571 ebe23063def2d09ce67a8c5096009f1cab6da0e5
parent 477570 a679e252817a39f5de0502994f6c91c47dd64019
child 477572 0cbffc5bb53560b91640ae23dba1daa13f172c65
push id36119
push userncsoregi@mozilla.com
push dateThu, 06 Jun 2019 21:52:09 +0000
treeherdermozilla-central@6a81efd823db [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersnjn
bugs1492121
milestone69.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 1492121 - Gecko Profiler integrates BaseProfiler startup profiled threads - r=njn If MOZ_BASE_PROFILER_STARTUP and MOZ_PROFILER_STARTUP are set, this will integrate a pre-XPCOM startup profile into the main profile. It is stored as separate threads (in a single JSON string that is moved around), which will appear as a new track under the main process. Only adding threads from BaseProfiler means a better integration with Gecko Profiler profiles, and is more efficient: Less code, and a smaller memory footprint. Differential Revision: https://phabricator.services.mozilla.com/D31932
mozglue/baseprofiler/core/platform.cpp
mozglue/baseprofiler/public/BaseProfiler.h
tools/profiler/core/platform.cpp
--- a/mozglue/baseprofiler/core/platform.cpp
+++ b/mozglue/baseprofiler/core/platform.cpp
@@ -1575,90 +1575,99 @@ static void StreamPages(PSLockRef aLock,
   ActivePS::DiscardExpiredPages(aLock);
   for (const auto& page : ActivePS::ProfiledPages(aLock)) {
     page->StreamJSON(aWriter);
   }
 }
 
 static void locked_profiler_stream_json_for_this_process(
     PSLockRef aLock, SpliceableJSONWriter& aWriter, double aSinceTime,
-    bool aIsShuttingDown) {
+    bool aIsShuttingDown, bool aOnlyThreads = false) {
   LOG("locked_profiler_stream_json_for_this_process");
 
   MOZ_RELEASE_ASSERT(CorePS::Exists() && ActivePS::Exists(aLock));
 
   double collectionStart = profiler_time();
 
   ProfileBuffer& buffer = ActivePS::Buffer(aLock);
 
-  // Put shared library info
-  aWriter.StartArrayProperty("libs");
-  AppendSharedLibraries(aWriter);
-  aWriter.EndArray();
-
-  // Put meta data
-  aWriter.StartObjectProperty("meta");
-  { StreamMetaJSCustomObject(aLock, aWriter, aIsShuttingDown); }
-  aWriter.EndObject();
-
-  // Put page data
-  aWriter.StartArrayProperty("pages");
-  { StreamPages(aLock, aWriter); }
-  aWriter.EndArray();
-
-  buffer.StreamProfilerOverheadToJSON(aWriter, CorePS::ProcessStartTime(),
-                                      aSinceTime);
-  buffer.StreamCountersToJSON(aWriter, CorePS::ProcessStartTime(), aSinceTime);
-  buffer.StreamMemoryToJSON(aWriter, CorePS::ProcessStartTime(), aSinceTime);
-
-  // Lists the samples for each thread profile
-  aWriter.StartArrayProperty("threads");
+  if (!aOnlyThreads) {
+    // Put shared library info
+    aWriter.StartArrayProperty("libs");
+    AppendSharedLibraries(aWriter);
+    aWriter.EndArray();
+
+    // Put meta data
+    aWriter.StartObjectProperty("meta");
+    { StreamMetaJSCustomObject(aLock, aWriter, aIsShuttingDown); }
+    aWriter.EndObject();
+
+    // Put page data
+    aWriter.StartArrayProperty("pages");
+    { StreamPages(aLock, aWriter); }
+    aWriter.EndArray();
+
+    buffer.StreamProfilerOverheadToJSON(aWriter, CorePS::ProcessStartTime(),
+                                        aSinceTime);
+    buffer.StreamCountersToJSON(aWriter, CorePS::ProcessStartTime(),
+                                aSinceTime);
+    buffer.StreamMemoryToJSON(aWriter, CorePS::ProcessStartTime(), aSinceTime);
+
+    // Lists the samples for each thread profile
+    aWriter.StartArrayProperty("threads");
+  }
+
+  // if aOnlyThreads is true, the only output will be the threads array items.
   {
     ActivePS::DiscardExpiredDeadProfiledThreads(aLock);
     Vector<Pair<RegisteredThread*, ProfiledThreadData*>> threads =
         ActivePS::ProfiledThreads(aLock);
     for (auto& thread : threads) {
       ProfiledThreadData* profiledThreadData = thread.second();
       profiledThreadData->StreamJSON(buffer, aWriter,
                                      CorePS::ProcessName(aLock),
                                      CorePS::ProcessStartTime(), aSinceTime);
     }
   }
-  aWriter.EndArray();
-
-  aWriter.StartArrayProperty("pausedRanges");
-  { buffer.StreamPausedRangesToJSON(aWriter, aSinceTime); }
-  aWriter.EndArray();
+
+  if (!aOnlyThreads) {
+    aWriter.EndArray();
+
+    aWriter.StartArrayProperty("pausedRanges");
+    { buffer.StreamPausedRangesToJSON(aWriter, aSinceTime); }
+    aWriter.EndArray();
+  }
 
   double collectionEnd = profiler_time();
 
   // Record timestamps for the collection into the buffer, so that consumers
   // know why we didn't collect any samples for its duration.
   // We put these entries into the buffer after we've collected the profile,
   // so they'll be visible for the *next* profile collection (if they haven't
   // been overwritten due to buffer wraparound by then).
   buffer.AddEntry(ProfileBufferEntry::CollectionStart(collectionStart));
   buffer.AddEntry(ProfileBufferEntry::CollectionEnd(collectionEnd));
 }
 
 bool profiler_stream_json_for_this_process(SpliceableJSONWriter& aWriter,
                                            double aSinceTime,
-                                           bool aIsShuttingDown) {
+                                           bool aIsShuttingDown,
+                                           bool aOnlyThreads) {
   LOG("profiler_stream_json_for_this_process");
 
   MOZ_RELEASE_ASSERT(CorePS::Exists());
 
   PSAutoLock lock;
 
   if (!ActivePS::Exists(lock)) {
     return false;
   }
 
   locked_profiler_stream_json_for_this_process(lock, aWriter, aSinceTime,
-                                               aIsShuttingDown);
+                                               aIsShuttingDown, aOnlyThreads);
   return true;
 }
 
 // END saving/streaming code
 ////////////////////////////////////////////////////////////////////////
 
 static char FeatureCategory(uint32_t aFeature) {
   if (aFeature & DefaultFeatures()) {
@@ -2370,49 +2379,59 @@ void profiler_shutdown() {
   // We do these operations with gPSMutex unlocked. The comments in
   // profiler_stop() explain why.
   if (samplerThread) {
     delete samplerThread;
   }
 }
 
 static bool WriteProfileToJSONWriter(SpliceableChunkedJSONWriter& aWriter,
-                                     double aSinceTime, bool aIsShuttingDown) {
+                                     double aSinceTime, bool aIsShuttingDown,
+                                     bool aOnlyThreads = false) {
   LOG("WriteProfileToJSONWriter");
 
   MOZ_RELEASE_ASSERT(CorePS::Exists());
 
-  aWriter.Start();
-  {
+  if (!aOnlyThreads) {
+    aWriter.Start();
+    {
+      if (!profiler_stream_json_for_this_process(
+              aWriter, aSinceTime, aIsShuttingDown, aOnlyThreads)) {
+        return false;
+      }
+
+      // Don't include profiles from other processes because this is a
+      // synchronous function.
+      aWriter.StartArrayProperty("processes");
+      aWriter.EndArray();
+    }
+    aWriter.End();
+  } else {
+    aWriter.StartBareList();
     if (!profiler_stream_json_for_this_process(aWriter, aSinceTime,
-                                               aIsShuttingDown)) {
+                                               aIsShuttingDown, aOnlyThreads)) {
       return false;
     }
-
-    // Don't include profiles from other processes because this is a
-    // synchronous function.
-    aWriter.StartArrayProperty("processes");
-    aWriter.EndArray();
+    aWriter.EndBareList();
   }
-  aWriter.End();
   return true;
 }
 
 void profiler_set_process_name(const std::string& aProcessName) {
   LOG("profiler_set_process_name(\"%s\")", aProcessName.c_str());
   PSAutoLock lock;
   CorePS::SetProcessName(lock, aProcessName);
 }
 
-UniquePtr<char[]> profiler_get_profile(double aSinceTime,
-                                       bool aIsShuttingDown) {
+UniquePtr<char[]> profiler_get_profile(double aSinceTime, bool aIsShuttingDown,
+                                       bool aOnlyThreads) {
   LOG("profiler_get_profile");
 
   SpliceableChunkedJSONWriter b;
-  if (!WriteProfileToJSONWriter(b, aSinceTime, aIsShuttingDown)) {
+  if (!WriteProfileToJSONWriter(b, aSinceTime, aIsShuttingDown, aOnlyThreads)) {
     return nullptr;
   }
   return b.WriteFunc()->CopyData();
 }
 
 void profiler_get_profile_json_into_lazily_allocated_buffer(
     const std::function<char*(size_t)>& aAllocator, double aSinceTime,
     bool aIsShuttingDown) {
--- a/mozglue/baseprofiler/public/BaseProfiler.h
+++ b/mozglue/baseprofiler/public/BaseProfiler.h
@@ -759,23 +759,24 @@ class MOZ_RAII AutoProfilerTextMarker {
 // Set a user-friendly process name, used in JSON stream.
 MFBT_API void profiler_set_process_name(const std::string& aProcessName);
 
 // Get the profile encoded as a JSON string. A no-op (returning nullptr) if the
 // profiler is inactive.
 // If aIsShuttingDown is true, the current time is included as the process
 // shutdown time in the JSON's "meta" object.
 MFBT_API UniquePtr<char[]> profiler_get_profile(double aSinceTime = 0,
-                                                bool aIsShuttingDown = false);
+                                                bool aIsShuttingDown = false,
+                                                bool aOnlyThreads = false);
 
 // Write the profile for this process (excluding subprocesses) into aWriter.
 // Returns false if the profiler is inactive.
 MFBT_API bool profiler_stream_json_for_this_process(
     SpliceableJSONWriter& aWriter, double aSinceTime = 0,
-    bool aIsShuttingDown = false);
+    bool aIsShuttingDown = false, bool aOnlyThreads = false);
 
 // Get the profile and write it into a file. A no-op if the profile is
 // inactive.
 MFBT_API void profiler_save_profile_to_file(const char* aFilename);
 
 //---------------------------------------------------------------------------
 // RAII classes
 //---------------------------------------------------------------------------
--- a/tools/profiler/core/platform.cpp
+++ b/tools/profiler/core/platform.cpp
@@ -850,22 +850,40 @@ class ActivePS {
     IOInterposer::Register(IOInterposeObserver::OpAll,
                            sInstance->mInterposeObserver);
   }
 #endif
 
   static void ClearExpiredExitProfiles(PSLockRef) {
     uint64_t bufferRangeStart = sInstance->mBuffer->mRangeStart;
     // Discard exit profiles that were gathered before our buffer RangeStart.
+#ifdef MOZ_BASE_PROFILER
+    if (bufferRangeStart != 0 && sInstance->mBaseProfileThreads) {
+      sInstance->mBaseProfileThreads.reset();
+    }
+#endif
     sInstance->mExitProfiles.eraseIf(
         [bufferRangeStart](const ExitProfile& aExitProfile) {
           return aExitProfile.mBufferPositionAtGatherTime < bufferRangeStart;
         });
   }
 
+#ifdef MOZ_BASE_PROFILER
+  static void AddBaseProfileThreads(PSLockRef aLock,
+                                    UniquePtr<char[]> aBaseProfileThreads) {
+    sInstance->mBaseProfileThreads = std::move(aBaseProfileThreads);
+  }
+
+  static UniquePtr<char[]> MoveBaseProfileThreads(PSLockRef aLock) {
+    ClearExpiredExitProfiles(aLock);
+
+    return std::move(sInstance->mBaseProfileThreads);
+  }
+#endif
+
   static void AddExitProfile(PSLockRef aLock, const nsCString& aExitProfile) {
     ClearExpiredExitProfiles(aLock);
 
     MOZ_RELEASE_ASSERT(sInstance->mExitProfiles.append(
         ExitProfile{aExitProfile, sInstance->mBuffer->mRangeEnd}));
   }
 
   static Vector<nsCString> MoveExitProfiles(PSLockRef aLock) {
@@ -950,16 +968,21 @@ class ActivePS {
   bool mIsPaused;
 
 #if defined(GP_OS_linux)
   // Used to record whether the profiler was paused just before forking. False
   // at all times except just before/after forking.
   bool mWasPaused;
 #endif
 
+#ifdef MOZ_BASE_PROFILER
+  // Optional startup profile thread array from BaseProfiler.
+  UniquePtr<char[]> mBaseProfileThreads;
+#endif
+
   struct ExitProfile {
     nsCString mJSON;
     uint64_t mBufferPositionAtGatherTime;
   };
   Vector<ExitProfile> mExitProfiles;
 };
 
 ActivePS* ActivePS::sInstance = nullptr;
@@ -2113,16 +2136,24 @@ static void locked_profiler_stream_json_
       profiledThreadData.StreamJSON(*javaBuffer.get(), nullptr, aWriter,
                                     CorePS::ProcessName(aLock),
                                     CorePS::ProcessStartTime(), aSinceTime,
                                     ActivePS::FeatureJSTracer(aLock));
 
       java::GeckoJavaSampler::Unpause();
     }
 #endif
+
+#ifdef MOZ_BASE_PROFILER
+    UniquePtr<char[]> baseProfileThreads =
+        ActivePS::MoveBaseProfileThreads(aLock);
+    if (baseProfileThreads) {
+      aWriter.Splice(baseProfileThreads.get());
+    }
+#endif
   }
   aWriter.EndArray();
 
   if (ActivePS::FeatureJSTracer(aLock)) {
     aWriter.StartArrayProperty("jsTracerDictionary");
     {
       JS::AutoTraceLoggerLockGuard lockGuard;
       // Collect Event Dictionary
@@ -3324,16 +3355,46 @@ static void locked_profiler_start(PSLock
   if (aDuration && *aDuration <= 0) {
     duration = Nothing();
   }
   double interval = aInterval > 0 ? aInterval : PROFILER_DEFAULT_INTERVAL;
 
   ActivePS::Create(aLock, capacity, interval, aFeatures, aFilters, aFilterCount,
                    duration);
 
+  // ActivePS::Create can only succeed or crash.
+  MOZ_ASSERT(ActivePS::Exists(aLock));
+
+#ifdef MOZ_BASE_PROFILER
+  if (baseprofiler::profiler_is_active()) {
+    // Note that we still hold the lock, so the sampler cannot run yet and
+    // interact negatively with the still-active BaseProfiler sampler.
+    // Assume that BaseProfiler is active because of MOZ_BASE_PROFILER_STARTUP.
+    // Capture the BaseProfiler startup profile threads (if any).
+    UniquePtr<char[]> baseprofile = baseprofiler::profiler_get_profile(
+        /* aSinceTime */ 0, /* aIsShuttingDown */ false,
+        /* aOnlyThreads */ true);
+
+    // Now stop BaseProfiler, as further recording will be ignored anyway, and
+    // so that it won't clash with Gecko Profiler sampling starting after the
+    // lock is dropped.
+    // TODO: Allow non-sampling profiling to continue.
+    // TODO: Re-start BaseProfiler after Gecko Profiler shutdown, to capture
+    // post-XPCOM shutdown.
+    baseprofiler::profiler_stop();
+
+    if (baseprofile && baseprofile.get()[0] != '\0') {
+      // The BaseProfiler startup profile will be stored as a separate process
+      // in the Gecko Profiler profile, and shown as a new track under the
+      // corresponding Gecko Profiler thread.
+      ActivePS::AddBaseProfileThreads(aLock, std::move(baseprofile));
+    }
+  }
+#endif
+
   // Set up profiling for each registered thread, if appropriate.
   int tid = profiler_current_thread_id();
   const Vector<UniquePtr<RegisteredThread>>& registeredThreads =
       CorePS::RegisteredThreads(aLock);
   for (auto& registeredThread : registeredThreads) {
     RefPtr<ThreadInfo> info = registeredThread->Info();
 
     if (ActivePS::ShouldProfileThread(aLock, info)) {