Bug 1705019 - Always record LogMessage profiler markers for enabled log messages when the profiler is enabled and add a new 'profilerstacks' keyword to enable capturing stacks in these markers, r=mstange.

Differential Revision: https://phabricator.services.mozilla.com/D156969

toolkit/content/aboutNetworking.js

@@ -379,8 +379,8 @@ function updateLogModules() {
       }
     } catch (e) {}
     try {
-      if (Services.prefs.getBoolPref("logging.config.profilermarkers")) {
-        activeLogModules.push("profilermarkers");
+      if (Services.prefs.getBoolPref("logging.config.profilerstacks")) {
+        activeLogModules.push("profilerstacks");
       }
     } catch (e) {}
 
@@ -449,8 +449,8 @@ function setLogModules() {
       // XXX: append is not yet supported.
     } else if (module == "sync") {
       Services.prefs.setBoolPref("logging.config.sync", true);
-    } else if (module == "profilermarkers") {
-      Services.prefs.setBoolPref("logging.config.profilermarkers", true);
+    } else if (module == "profilerstacks") {
+      Services.prefs.setBoolPref("logging.config.profilerstacks", true);
     } else {
       let lastColon = module.lastIndexOf(":");
       let key = module.slice(0, lastColon);

xpcom/base/LogModulePrefWatcher.cpp

@@ -23,7 +23,7 @@ static const char kLoggingPrefClearOnStartup[] =
 static const char kLoggingPrefLogFile[] = "logging.config.LOG_FILE";
 static const char kLoggingPrefAddTimestamp[] = "logging.config.add_timestamp";
 static const char kLoggingPrefSync[] = "logging.config.sync";
-static const char kLoggingPrefMarkers[] = "logging.config.profilermarkers";
+static const char kLoggingPrefStacks[] = "logging.config.profilerstacks";
 
 namespace mozilla {
 
@@ -83,9 +83,9 @@ static void LoadPrefValue(const char* aName) {
     } else if (prefName.EqualsLiteral(kLoggingPrefSync)) {
       bool sync = Preferences::GetBool(aName, false);
       LogModule::SetIsSync(sync);
-    } else if (prefName.EqualsLiteral(kLoggingPrefMarkers)) {
-      bool enableMarkers = Preferences::GetBool(aName, false);
-      LogModule::SetRecordMarkers(enableMarkers);
+    } else if (prefName.EqualsLiteral(kLoggingPrefStacks)) {
+      bool captureStacks = Preferences::GetBool(aName, false);
+      LogModule::SetCaptureStacks(captureStacks);
     }
     return;
   }

xpcom/base/Logging.cpp

@@ -315,7 +315,7 @@ class LogModuleManager {
         mMainThread(PR_GetCurrentThread()),
         mSetFromEnv(false),
         mAddTimestamp(false),
-        mAddProfilerMarker(false),
+        mCaptureProfilerStack(false),
         mIsRaw(false),
         mIsSync(false),
         mRotate(0),
@@ -358,7 +358,7 @@ class LogModuleManager {
     bool addTimestamp = false;
     bool isSync = false;
     bool isRaw = false;
-    bool isMarkers = false;
+    bool captureStacks = false;
     int32_t rotate = 0;
     int32_t maxSize = 0;
     bool prependHeader = false;
@@ -385,8 +385,8 @@ class LogModuleManager {
     NSPRLogModulesParser(
         modules,
         [this, &shouldAppend, &addTimestamp, &isSync, &isRaw, &rotate, &maxSize,
-         &prependHeader, &isMarkers](const char* aName, LogLevel aLevel,
-                                     int32_t aValue) mutable {
+         &prependHeader, &captureStacks](const char* aName, LogLevel aLevel,
+                                         int32_t aValue) mutable {
           if (strcmp(aName, "append") == 0) {
             shouldAppend = true;
           } else if (strcmp(aName, "timestamp") == 0) {
@@ -401,8 +401,8 @@ class LogModuleManager {
             maxSize = aValue << 20;
           } else if (strcmp(aName, "prependheader") == 0) {
             prependHeader = true;
-          } else if (strcmp(aName, "profilermarkers") == 0) {
-            isMarkers = true;
+          } else if (strcmp(aName, "profilerstacks") == 0) {
+            captureStacks = true;
           } else {
             this->CreateOrGetModule(aName)->SetLevel(aLevel);
           }
@@ -413,7 +413,7 @@ class LogModuleManager {
     mIsSync = isSync;
     mIsRaw = isRaw;
     mRotate = rotate;
-    mAddProfilerMarker = isMarkers;
+    mCaptureProfilerStack = captureStacks;
 
     if (rotate > 0 && shouldAppend) {
       NS_WARNING("MOZ_LOG: when you rotate the log, you cannot use append!");
@@ -520,8 +520,8 @@ class LogModuleManager {
 
   void SetIsSync(bool aIsSync) { mIsSync = aIsSync; }
 
-  void SetRecordMarkers(bool aRecordMarkers) {
-    mAddProfilerMarker = aRecordMarkers;
+  void SetCaptureStacks(bool aCaptureStacks) {
+    mCaptureProfilerStack = aCaptureStacks;
   }
 
   void SetAddTimestamp(bool aAddTimestamp) { mAddTimestamp = aAddTimestamp; }
@@ -603,7 +603,7 @@ class LogModuleManager {
       charsWritten = strlen(buffToWrite);
     }
 
-    if (mAddProfilerMarker && profiler_thread_is_being_profiled_for_markers()) {
+    if (profiler_thread_is_being_profiled_for_markers()) {
       struct LogMarker {
         static constexpr Span<const char> MarkerTypeName() {
           return MakeStringSpan("Log");
@@ -627,8 +627,9 @@ class LogModuleManager {
 
       profiler_add_marker(
           "LogMessages", geckoprofiler::category::OTHER,
-          aStart ? MarkerTiming::IntervalUntilNowFrom(*aStart)
-                 : MarkerTiming::InstantNow(),
+          {aStart ? MarkerTiming::IntervalUntilNowFrom(*aStart)
+                  : MarkerTiming::InstantNow(),
+           MarkerStack::MaybeCapture(mCaptureProfilerStack)},
           LogMarker{}, ProfilerString8View::WrapNullTerminatedString(aName),
           ProfilerString8View::WrapNullTerminatedString(buffToWrite));
     }
@@ -782,7 +783,7 @@ class LogModuleManager {
   PRThread* mMainThread;
   bool mSetFromEnv;
   Atomic<bool, Relaxed> mAddTimestamp;
-  Atomic<bool, Relaxed> mAddProfilerMarker;
+  Atomic<bool, Relaxed> mCaptureProfilerStack;
   Atomic<bool, Relaxed> mIsRaw;
   Atomic<bool, Relaxed> mIsSync;
   int32_t mRotate;
@@ -816,8 +817,8 @@ void LogModule::SetIsSync(bool aIsSync) {
   sLogModuleManager->SetIsSync(aIsSync);
 }
 
-void LogModule::SetRecordMarkers(bool aRecordMarkers) {
-  sLogModuleManager->SetRecordMarkers(aRecordMarkers);
+void LogModule::SetCaptureStacks(bool aCaptureStacks) {
+  sLogModuleManager->SetCaptureStacks(aCaptureStacks);
 }
 
 // This function is defined in gecko_logger/src/lib.rs

xpcom/base/Logging.h

@@ -120,10 +120,10 @@ class LogModule {
   static void SetIsSync(bool aIsSync);
 
   /**
-   * @param aRecordMarkers If we should add Firefox Profiler markers for each
-   * log entry.
+   * @param aCaptureStacks If we should capture stacks for the Firefox
+   * Profiler markers that are recorded for for each log entry.
    */
-  static void SetRecordMarkers(bool aRecordMarkers);
+  static void SetCaptureStacks(bool aCaptureStacks);
 
   /**
    * Indicates whether or not the given log level is enabled.
@@ -278,9 +278,9 @@ void log_print(const LogModule* aModule, LogLevel aLevel, TimeStamp* aStart,
 // code will never be executed.)  Hence, the following code.
 //
 // MOZ_LOG_DURATION takes a start time, and will generate a time range
-// in the logs.  Also, if 'profilermarkers' is used in the env var
-// MOZ_LOG, MOZ_LOG_DURATION will generate a marker with a time
-// duration instead of a single point in time.
+// in the logs.  Also, if the Firefox Profiler is running,
+// MOZ_LOG_DURATION will generate a marker with a time duration
+// instead of a single point in time.
 #if MOZ_LOGGING_ENABLED
 #  define MOZ_LOG(_module, _level, _args)                      \
     do {                                                       \