Bug 1339897 - Rename PROFILER_LABEL_PRINTF to PROFILER_LABEL_DYNAMIC and make it really cheap. r=Ehsan,njn

Instead of copying and concatenating strings into an mDest buffer in
SamplerStackFramePrintfRAII, require callers to keep the string buffer alive
for the duration of the current scope, and store the pointer to the annotation
string in the ProfileEntry. During stackwalking, concatenate the label and the
annotation (separated by a space) and store the resulting string in the
profile buffer.

MozReview-Commit-ID: GEjcLrhhdvb

--HG--
extra : rebase_source : 683749421ee2122805a249cf413e882ee5f33331

dom/base/nsJSEnvironment.cpp

@@ -1183,9 +1183,9 @@ nsJSContext::GarbageCollectNow(JS::gcreason::Reason aReason,
                                IsShrinking aShrinking,
                                int64_t aSliceMillis)
 {
-  PROFILER_LABEL_PRINTF("nsJSContext", "GarbageCollectNow",
-                        js::ProfileEntry::Category::GC,
-                        "%s", JS::gcreason::ExplainReason(aReason));
+  PROFILER_LABEL_DYNAMIC("nsJSContext", "GarbageCollectNow",
+                         js::ProfileEntry::Category::GC,
+                         JS::gcreason::ExplainReason(aReason));
 
   MOZ_ASSERT_IF(aSliceMillis, aIncremental == IncrementalGC);
 

dom/events/EventListenerManager.cpp

@@ -1275,10 +1275,9 @@ EventListenerManager::HandleEventInternal(nsPresContext* aPresContext,
               // do this extra work when we're not profiling.
               nsAutoString typeStr;
               (*aDOMEvent)->GetType(typeStr);
-              PROFILER_LABEL_PRINTF("EventListenerManager", "HandleEventInternal",
-                                    js::ProfileEntry::Category::EVENTS,
-                                    "%s",
-                                    NS_LossyConvertUTF16toASCII(typeStr).get());
+              PROFILER_LABEL_DYNAMIC("EventListenerManager", "HandleEventInternal",
+                                     js::ProfileEntry::Category::EVENTS,
+                                     NS_LossyConvertUTF16toASCII(typeStr));
               TimeStamp startTime = TimeStamp::Now();
 
               rv = HandleEventSubType(listener, *aDOMEvent, aCurrentTarget);

image/RasterImage.cpp

@@ -1132,19 +1132,19 @@ LaunchDecodingTask(IDecodingTask* aTask,
                    bool aHaveSourceData)
 {
   if (aHaveSourceData) {
+    nsCString uri(aImage->GetURIString());
+
     // If we have all the data, we can sync decode if requested.
     if (aFlags & imgIContainer::FLAG_SYNC_DECODE) {
-      PROFILER_LABEL_PRINTF("DecodePool", "SyncRunIfPossible",
-        js::ProfileEntry::Category::GRAPHICS,
-        "%s", aImage->GetURIString().get());
+      PROFILER_LABEL_DYNAMIC("DecodePool", "SyncRunIfPossible",
+        js::ProfileEntry::Category::GRAPHICS, uri.get());
       DecodePool::Singleton()->SyncRunIfPossible(aTask);
       return true;
     }
 
     if (aFlags & imgIContainer::FLAG_SYNC_DECODE_IF_FAST) {
-      PROFILER_LABEL_PRINTF("DecodePool", "SyncRunIfPreferred",
-        js::ProfileEntry::Category::GRAPHICS,
-        "%s", aImage->GetURIString().get());
+      PROFILER_LABEL_DYNAMIC("DecodePool", "SyncRunIfPreferred",
+        js::ProfileEntry::Category::GRAPHICS, uri.get());
       return DecodePool::Singleton()->SyncRunIfPreferred(aTask);
     }
   }

js/public/ProfilingStack.h

@@ -36,9 +36,14 @@ class ProfileEntry
     //
     // A ProfileEntry represents both a C++ profile entry and a JS one.
 
-    // Descriptive string of this entry.
+    // Descriptive string of this entry. Can be a static string or a dynamic
+    // string. If it's a dynamic string (which will need to be copied during
+    // sampling), then isCopyLabel() needs to return true.
     const char * volatile string;
 
+    // An additional descriptive string of this entry. Can be null.
+    const char * volatile dynamicString;
+
     // Stack pointer for non-JS entries, the script pointer otherwise.
     void * volatile spOrScript;
 
@@ -57,8 +62,8 @@ class ProfileEntry
         // a JS or CPP frame with `initJsFrame` or `initCppFrame` respectively.
         IS_CPP_ENTRY = 0x01,
 
-        // Indicate that copying the frame label is not necessary when taking a
-        // sample of the pseudostack.
+        // Indicates that the label string is not a static string and needs to
+        // be copied during sampling.
         FRAME_LABEL_COPY = 0x02,
 
         // This ProfileEntry is a dummy entry indicating the start of a run
@@ -108,6 +113,9 @@ class ProfileEntry
     void setLabel(const char* aString) volatile { string = aString; }
     const char* label() const volatile { return string; }
 
+    void setDynamicString(const char* aDynamicString) volatile { dynamicString = aDynamicString; }
+    const char* getDynamicString() const volatile { return dynamicString; }
+
     void initJsFrame(JSScript* aScript, jsbytecode* aPc) volatile {
         flags_ = 0;
         spOrScript = aScript;

js/src/vm/GeckoProfiler.cpp

@@ -289,6 +289,7 @@ GeckoProfiler::push(const char* string, void* sp, JSScript* script, jsbytecode*
         }
 
         entry.setLabel(string);
+        entry.setDynamicString(nullptr);
         entry.setCategory(category);
 
         // Track if mLabel needs a copy.

layout/base/GeckoRestyleManager.cpp

@@ -3038,16 +3038,14 @@ ElementRestyler::ComputeStyleChangeFor(nsIFrame*          aFrame,
                                          aSwappedStructOwners)
 {
   nsIContent* content = aFrame->GetContent();
-  nsAutoCString localDescriptor;
+  std::string elemDesc;
   if (profiler_is_active() && content) {
-    std::string elemDesc = ToString(*content);
-    localDescriptor.Assign(elemDesc.c_str());
+    elemDesc = ToString(*content);
   }
 
-  PROFILER_LABEL_PRINTF("ElementRestyler", "ComputeStyleChangeFor",
-                        js::ProfileEntry::Category::CSS,
-                        content ? "Element: %s" : "%s",
-                        content ? localDescriptor.get() : "");
+  PROFILER_LABEL_DYNAMIC("ElementRestyler", "ComputeStyleChangeFor",
+                         js::ProfileEntry::Category::CSS,
+                         content ? elemDesc.c_str() : "<unknown>");
   if (aMinChange) {
     aChangeList->AppendChange(aFrame, content, aMinChange);
   }

layout/base/PresShell.cpp

@@ -4088,8 +4088,8 @@ PresShell::DoFlushPendingNotifications(mozilla::ChangesToFlush aFlush)
     "Display"
   };
 
-  PROFILER_LABEL_PRINTF("PresShell", "Flush",
-    js::ProfileEntry::Category::GRAPHICS, "(FlushType::%s)",
+  PROFILER_LABEL_DYNAMIC("PresShell", "Flush",
+    js::ProfileEntry::Category::GRAPHICS,
     flushTypeNames[flushType]);
 #endif
 
@@ -6357,9 +6357,9 @@ PresShell::Paint(nsView*        aViewToPaint,
   if (contentRoot) {
     uri = contentRoot->GetDocumentURI();
   }
-  PROFILER_LABEL_PRINTF("PresShell", "Paint",
-    js::ProfileEntry::Category::GRAPHICS, "(%s)",
-    uri ? uri->GetSpecOrDefault().get() : "N/A");
+  nsCString uriString = uri ? uri->GetSpecOrDefault() : NS_LITERAL_CSTRING("N/A");
+  PROFILER_LABEL_DYNAMIC("PresShell", "Paint",
+    js::ProfileEntry::Category::GRAPHICS, Move(uriString));
 #endif
 
   Maybe<js::AutoAssertNoContentJS> nojs;
@@ -9176,9 +9176,9 @@ PresShell::DoReflow(nsIFrame* target, bool aInterruptible)
 
 #ifdef MOZ_GECKO_PROFILER
   nsIURI* uri = mDocument->GetDocumentURI();
-  PROFILER_LABEL_PRINTF("PresShell", "DoReflow",
-    js::ProfileEntry::Category::GRAPHICS, "(%s)",
-    uri ? uri->GetSpecOrDefault().get() : "N/A");
+  nsCString uriString = uri ? uri->GetSpecOrDefault() : NS_LITERAL_CSTRING("N/A");
+  PROFILER_LABEL_DYNAMIC("PresShell", "DoReflow",
+    js::ProfileEntry::Category::GRAPHICS, Move(uriString));
 #endif
 
   nsDocShell* docShell = static_cast<nsDocShell*>(GetPresContext()->GetDocShell());

layout/base/RestyleTracker.cpp

@@ -114,8 +114,8 @@ RestyleTracker::DoProcessRestyles()
       docURL = uri->GetSpecOrDefault();
     }
   }
-  PROFILER_LABEL_PRINTF("RestyleTracker", "ProcessRestyles",
-                        js::ProfileEntry::Category::CSS, "(%s)", docURL.get());
+  PROFILER_LABEL_DYNAMIC("RestyleTracker", "ProcessRestyles",
+                         js::ProfileEntry::Category::CSS, docURL.get());
 
   nsDocShell* docShell = static_cast<nsDocShell*>(mRestyleManager->PresContext()->GetDocShell());
   RefPtr<TimelineConsumers> timelines = TimelineConsumers::Get();

layout/painting/FrameLayerBuilder.cpp

@@ -6007,8 +6007,8 @@ FrameLayerBuilder::PaintItems(nsTArray<ClippedDisplayItem>& aItems,
       continue;
 
 #ifdef MOZ_DUMP_PAINTING
-    PROFILER_LABEL_PRINTF("DisplayList", "Draw",
-      js::ProfileEntry::Category::GRAPHICS, "%s", cdi->mItem->Name());
+    PROFILER_LABEL_DYNAMIC("DisplayList", "Draw",
+      js::ProfileEntry::Category::GRAPHICS, cdi->mItem->Name());
 #else
     PROFILER_LABEL("DisplayList", "Draw",
       js::ProfileEntry::Category::GRAPHICS);

tools/profiler/core/platform.cpp

@@ -411,6 +411,8 @@ AddDynamicCodeLocationTag(ProfileBuffer* aBuffer, const char* aStr)
   }
 }
 
+static const int SAMPLER_MAX_STRING_LENGTH = 128;
+
 static void
 AddPseudoEntry(ProfileBuffer* aBuffer, volatile js::ProfileEntry& entry,
                PseudoStack* stack, void* lastpc)
@@ -426,8 +428,17 @@ AddPseudoEntry(ProfileBuffer* aBuffer, volatile js::ProfileEntry& entry,
   // First entry has kind CodeLocation. Check for magic pointer bit 1 to
   // indicate copy.
   const char* sampleLabel = entry.label();
+  const char* dynamicString = entry.getDynamicString();
+  char combinedStringBuffer[SAMPLER_MAX_STRING_LENGTH];
 
-  if (entry.isCopyLabel()) {
+  if (entry.isCopyLabel() || dynamicString) {
+    if (dynamicString) {
+      int bytesWritten =
+        SprintfLiteral(combinedStringBuffer, "%s %s", sampleLabel, dynamicString);
+      if (bytesWritten > 0) {
+        sampleLabel = combinedStringBuffer;
+      }
+    }
     // Store the string using 1 or more EmbeddedString tags.
     // That will happen to the preceding tag.
     AddDynamicCodeLocationTag(aBuffer, sampleLabel);
@@ -2867,11 +2878,28 @@ profiler_get_backtrace_noalloc(char *output, size_t outputSize)
   uint32_t pseudoCount = pseudoStack->stackSize();
 
   for (uint32_t i = 0; i < pseudoCount; i++) {
-    size_t len = strlen(pseudoFrames[i].label());
-    if (output + len >= bound)
-      break;
-    strcpy(output, pseudoFrames[i].label());
-    output += len;
+    const char* label = pseudoFrames[i].label();
+    const char* dynamicString = pseudoFrames[i].getDynamicString();
+    size_t labelLength = strlen(label);
+    if (dynamicString) {
+      // Put the label, a space, and the dynamic string into output.
+      size_t dynamicStringLength = strlen(dynamicString);
+      if (output + labelLength + 1 + dynamicStringLength >= bound) {
+        break;
+      }
+      strcpy(output, label);
+      output += labelLength;
+      *output++ = ' ';
+      strcpy(output, dynamicString);
+      output += dynamicStringLength;
+    } else {
+      // Only put the label into output.
+      if (output + labelLength >= bound) {
+        break;
+      }
+      strcpy(output, label);
+      output += labelLength;
+    }
     *output++ = '\0';
     *output = '\0';
   }

tools/profiler/public/GeckoProfiler.h

@@ -27,6 +27,7 @@
 #include "mozilla/GuardObjects.h"
 #include "mozilla/UniquePtr.h"
 #include "mozilla/Vector.h"
+#include "nsString.h"
 
 namespace mozilla {
 class TimeStamp;
@@ -66,20 +67,34 @@ using UniqueProfilerBacktrace =
 #define PROFILER_FUNC(decl, rv)  static inline decl { return rv; }
 #define PROFILER_FUNC_VOID(decl) static inline void decl {}
 
-// Insert a RAII in this scope to active a pseudo label. Any samples collected
-// in this scope will contain this annotation. For dynamic strings use
-// PROFILER_LABEL_PRINTF. Arguments must be string literals.
+// Insert an RAII object in this scope to enter a pseudo stack frame. Any
+// samples collected in this scope will contain this label in their pseudo
+// stack. The name_space and info arguments must be string literals.
+// Use PROFILER_LABEL_DYNAMIC if you want to add additional / dynamic
+// information to the pseudo stack frame.
 #define PROFILER_LABEL(name_space, info, category) do {} while (0)
 
 // Similar to PROFILER_LABEL, PROFILER_LABEL_FUNC will push/pop the enclosing
 // functon name as the pseudostack label.
 #define PROFILER_LABEL_FUNC(category) do {} while (0)
 
-// Format a dynamic string as a pseudo label. These labels will a considerable
-// storage size in the circular buffer compared to regular labels. This function
-// can be used to annotate custom information such as URL for the resource being
-// decoded or the size of the paint.
-#define PROFILER_LABEL_PRINTF(name_space, info, category, format, ...) do {} while (0)
+// Enter a pseudo stack frame in this scope and associate it with an
+// additional string.
+// This macro generates an RAII object. This RAII object stores the str
+// pointer in a field; it does not copy the string. This means that the string
+// you pass to this macro needs to live at least until the end of the current
+// scope.
+// If the profiler samples the current thread and walks the pseudo stack while
+// this RAII object is on the stack, it will copy the supplied string into the
+// profile buffer. So there's one string copy operation, and it happens at
+// sample time.
+// Compare this to the plain PROFILER_LABEL macro, which only accepts literal
+// strings: When the pseudo stack frames generated by PROFILER_LABEL are
+// sampled, no string copy needs to be made because the profile buffer can
+// just store the raw pointers to the literal strings. Consequently,
+// PROFILER_LABEL frames take up considerably less space in the profile buffer
+// than PROFILER_LABEL_DYNAMIC frames.
+#define PROFILER_LABEL_DYNAMIC(name_space, info, category, str) do {} while (0)
 
 // Insert a marker in the profile timeline. This is useful to delimit something
 // important happening such as the first paint. Unlike profiler_label that are
@@ -100,7 +115,7 @@ using UniqueProfilerBacktrace =
 
 #define PROFILER_LABEL_FUNC(category) MOZ_PLATFORM_TRACING(SAMPLE_FUNCTION_NAME) mozilla::SamplerStackFrameRAII SAMPLER_APPEND_LINE_NUMBER(sampler_raii)(SAMPLE_FUNCTION_NAME, category, __LINE__)
 
-#define PROFILER_LABEL_PRINTF(name_space, info, category, ...) MOZ_PLATFORM_TRACING(name_space "::" info) mozilla::SamplerStackFramePrintfRAII SAMPLER_APPEND_LINE_NUMBER(sampler_raii)(name_space "::" info, category, __LINE__, __VA_ARGS__)
+#define PROFILER_LABEL_DYNAMIC(name_space, info, category, str) MOZ_PLATFORM_TRACING(name_space "::" info) mozilla::SamplerStackFrameDynamicRAII SAMPLER_APPEND_LINE_NUMBER(sampler_raii)(name_space "::" info, category, __LINE__, str)
 
 #define PROFILER_MARKER(info) profiler_add_marker(info)
 #define PROFILER_MARKER_PAYLOAD(info, payload) profiler_add_marker(info, payload)
@@ -343,7 +358,8 @@ extern ProfilerState* gPS;
 static inline void*
 profiler_call_enter(const char* aInfo,
                     js::ProfileEntry::Category aCategory,
-                    void *aFrameAddress, bool aCopy, uint32_t line)
+                    void *aFrameAddress, bool aCopy, uint32_t line,
+                    const char* aAnnotationString = nullptr)
 {
   // This function runs both on and off the main thread.
 
@@ -353,7 +369,7 @@ profiler_call_enter(const char* aInfo,
   if (!stack) {
     return stack;
   }
-  stack->push(aInfo, aCategory, aFrameAddress, aCopy, line);
+  stack->push(aInfo, aCategory, aFrameAddress, aCopy, line, aAnnotationString);
 
   // The handle is meant to support future changes but for now it is simply
   // used to avoid having to call tlsPseudoStack.get() in profiler_call_exit().
@@ -477,35 +493,41 @@ private:
   void* mHandle;
 };
 
-static const int SAMPLER_MAX_STRING = 128;
-class MOZ_RAII SamplerStackFramePrintfRAII {
+class MOZ_RAII SamplerStackFrameDynamicRAII {
 public:
-  // We only copy the strings at save time, so to take multiple parameters we'd
-  // need to copy them then.
-  SamplerStackFramePrintfRAII(const char *aInfo,
-    js::ProfileEntry::Category aCategory, uint32_t line, const char *aFormat, ...)
-    : mHandle(nullptr)
+  SamplerStackFrameDynamicRAII(const char* aInfo,
+    js::ProfileEntry::Category aCategory, uint32_t aLine,
+    const char* aDynamicString)
   {
-    if (profiler_is_active_and_not_in_privacy_mode()) {
-      va_list args;
-      va_start(args, aFormat);
-      char buff[SAMPLER_MAX_STRING];
-
-      // We have to use separate printfs because we're using the vargs.
-      VsprintfLiteral(buff, aFormat, args);
-      SprintfLiteral(mDest, "%s %s", aInfo, buff);
-
-      mHandle = profiler_call_enter(mDest, aCategory, this, true, line);
-      va_end(args);
-    } else {
-      mHandle = profiler_call_enter(aInfo, aCategory, this, false, line);
-    }
+    mHandle = Enter(aInfo, aCategory, aLine, aDynamicString);
   }
-  ~SamplerStackFramePrintfRAII() {
+
+  // An alternative constructor that accepts an rvalue string and moves it
+  // into this object (without copying!).
+  SamplerStackFrameDynamicRAII(const char* aInfo,
+    js::ProfileEntry::Category aCategory, uint32_t aLine,
+    nsCString&& aDynamicString)
+    : mDynamicStorage(aDynamicString)
+  {
+    mHandle = Enter(aInfo, aCategory, aLine, mDynamicStorage.get());
+  }
+
+  ~SamplerStackFrameDynamicRAII() {
     profiler_call_exit(mHandle);
   }
+
 private:
-  char mDest[SAMPLER_MAX_STRING];
+  void* Enter(const char* aInfo, js::ProfileEntry::Category aCategory,
+              uint32_t aLine, const char* aDynamicString)
+  {
+    if (profiler_is_active_and_not_in_privacy_mode()) {
+      return profiler_call_enter(aInfo, aCategory, this, true, aLine, aDynamicString);
+    } else {
+      return profiler_call_enter(aInfo, aCategory, this, false, aLine);
+    }
+  }
+
+  nsCString mDynamicStorage;
   void* mHandle;
 };
 

tools/profiler/public/PseudoStack.h

@@ -249,11 +249,12 @@ public:
   void push(const char* aName, js::ProfileEntry::Category aCategory,
             uint32_t line)
   {
-    push(aName, aCategory, nullptr, false, line);
+    push(aName, aCategory, nullptr, false, line, nullptr);
   }
 
   void push(const char* aName, js::ProfileEntry::Category aCategory,
-            void* aStackAddress, bool aCopy, uint32_t line)
+            void* aStackAddress, bool aCopy, uint32_t line,
+            const char* aDynamicString)
   {
     if (size_t(mStackPointer) >= mozilla::ArrayLength(mStack)) {
       mStackPointer++;
@@ -266,6 +267,7 @@ public:
     // that mStack is always consistent.
     entry.initCppFrame(aStackAddress, line);
     entry.setLabel(aName);
+    entry.setDynamicString(aDynamicString);
     MOZ_ASSERT(entry.flags() == js::ProfileEntry::IS_CPP_ENTRY);
     entry.setCategory(aCategory);