Use atomic counters early in perf warning macros

Before this CL, snprintf was called repeatedly to format the warning
message which was then discarded after 4 logs. snprintf showed up in
profiling at ~2% and this CL appears to yield an ~8% power
improvement in one of the traces (egypt_1500).

A mutex was previously used to avoid the race condition on the static
sRepeatCount variable. This CL avoids the need for that by using static
atomics instead.

Also updated the Debug macro to use the VK macro vararg approach so that
formatting only happens when the message is actually logged.

Bug: b/302112423
Change-Id: Ia8a18361cfb5a9f2aa19ff939499754ba861efb7
Reviewed-on: https://chromium-review.googlesource.com/c/angle/angle/+/4886388
Reviewed-by: Shahbaz Youssefi <syoussefi@chromium.org>
Reviewed-by: Charlie Lao <cclao@google.com>
Commit-Queue: Roman Lavrov <romanl@google.com>

src/libANGLE/Debug.cpp

@@ -353,25 +353,10 @@ size_t Debug::getGroupStackDepth() const
     return mGroups.size();
 }
 
-void Debug::insertPerfWarning(GLenum severity, const char *message, uint32_t *repeatCount) const
+void Debug::insertPerfWarning(GLenum severity, bool isLastRepeat, const char *message) const
 {
-    bool repeatLast;
-
-    {
-        constexpr uint32_t kMaxRepeat = 4;
-        std::lock_guard<std::mutex> lock(GetDebugMutex());
-
-        if (*repeatCount >= kMaxRepeat)
-        {
-            return;
-        }
-
-        ++*repeatCount;
-        repeatLast = (*repeatCount == kMaxRepeat);
-    }
-
     std::string msg = message;
-    if (repeatLast)
+    if (isLastRepeat)
     {
         msg += " (this message will no longer repeat)";
     }

src/libANGLE/Debug.h

@@ -85,7 +85,7 @@ class Debug : angle::NonCopyable
     size_t getGroupStackDepth() const;
 
     // Helper for ANGLE_PERF_WARNING
-    void insertPerfWarning(GLenum severity, const char *message, uint32_t *repeatCount) const;
+    void insertPerfWarning(GLenum severity, bool isLastRepeat, const char *message) const;
 
   private:
     bool isMessageEnabled(GLenum source, GLenum type, GLuint id, GLenum severity) const;
@@ -170,12 +170,41 @@ class Debug : angle::NonCopyable
 };
 }  // namespace egl
 
+namespace
+{
+ANGLE_INLINE bool PerfCounterBelowMaxRepeat(std::atomic<uint32_t> *counter, bool *isLastRepeat)
+{
+    constexpr uint32_t kMaxPerfRepeat = 4;
+    // Stop incrementing the counter after max value to avoid unnecessary cache effects
+    if (counter->load(std::memory_order_relaxed) < kMaxPerfRepeat)
+    {
+        uint32_t count = counter->fetch_add(1, std::memory_order_relaxed);
+        // Check not strictly necessary as worst case is an additional log, but is good practice.
+        if (count < kMaxPerfRepeat)
+        {
+            if (count == kMaxPerfRepeat - 1)
+            {
+                *isLastRepeat = true;
+            }
+            return true;
+        }
+    }
+    return false;
+}
+}  // namespace
+
 // Generate a perf warning.  Only outputs the same message a few times to avoid spamming the logs.
-#define ANGLE_PERF_WARNING(debug, severity, message)                 \
+#define ANGLE_PERF_WARNING(debug, severity, ...)                              \
     do                                                                        \
     {                                                                         \
-        static uint32_t sRepeatCount = 0;                            \
-        (debug).insertPerfWarning(severity, message, &sRepeatCount); \
+        static std::atomic<uint32_t> sRepeatCount = 0;                        \
+        bool isLastRepeat                         = false;                    \
+        if (PerfCounterBelowMaxRepeat(&sRepeatCount, &isLastRepeat))          \
+        {                                                                     \
+            char ANGLE_MESSAGE[200];                                          \
+            snprintf(ANGLE_MESSAGE, sizeof(ANGLE_MESSAGE), __VA_ARGS__);      \
+            (debug).insertPerfWarning(severity, isLastRepeat, ANGLE_MESSAGE); \
+        }                                                                     \
     } while (0)
 
 #endif  // LIBANGLE_DEBUG_H_

src/libANGLE/Program.cpp

@@ -2110,11 +2110,9 @@ angle::Result Program::serialize(const Context *context, angle::MemoryBuffer *bi
     ASSERT(binaryOut);
     if (!binaryOut->resize(stream.length()))
     {
-        std::stringstream sstream;
-        sstream << "Failed to allocate enough memory to serialize a program. (" << stream.length()
-                << " bytes )";
         ANGLE_PERF_WARNING(context->getState().getDebug(), GL_DEBUG_SEVERITY_LOW,
-                           sstream.str().c_str());
+                           "Failed to allocate enough memory to serialize a program. (%zu bytes)",
+                           stream.length());
         return angle::Result::Incomplete;
     }
     memcpy(binaryOut->data(), stream.data(), stream.length());

src/libANGLE/Shader.cpp

@@ -680,11 +680,9 @@ angle::Result Shader::serialize(const Context *context, angle::MemoryBuffer *bin
     ASSERT(binaryOut);
     if (!binaryOut->resize(stream.length()))
     {
-        std::stringstream sstream;
-        sstream << "Failed to allocate enough memory to serialize a shader. (" << stream.length()
-                << " bytes )";
         ANGLE_PERF_WARNING(context->getState().getDebug(), GL_DEBUG_SEVERITY_LOW,
-                           sstream.str().c_str());
+                           "Failed to allocate enough memory to serialize a shader. (%zu bytes)",
+                           stream.length());
         return angle::Result::Incomplete;
     }
 

src/libANGLE/renderer/d3d/ProgramD3D.cpp

@@ -659,12 +659,11 @@ angle::Result ProgramD3D::link(const gl::Context *context, std::shared_ptr<LinkT
             {
                 for (const std::string &slowBlock : shader->slowCompilingUniformBlockSet)
                 {
-                    std::ostringstream stream;
-                    stream << "Uniform block '" << slowBlock << "' will be slow to compile. "
-                           << "See UniformBlockToStructuredBufferTranslation.md "
-                           << "(https://shorturl.at/drFY7) for details.";
                     ANGLE_PERF_WARNING(context->getState().getDebug(), GL_DEBUG_SEVERITY_MEDIUM,
-                                       stream.str().c_str());
+                                       "Uniform block '%s' will be slow to compile. "
+                                       "See UniformBlockToStructuredBufferTranslation.md "
+                                       "(https://shorturl.at/drFY7) for details.",
+                                       slowBlock.c_str());
                 }
             }
         }

src/libANGLE/renderer/vulkan/ContextVk.cpp

@@ -4513,7 +4513,7 @@ angle::Result ContextVk::insertEventMarker(GLsizei length, const char *marker)
 
 void ContextVk::insertEventMarkerImpl(GLenum source, const char *marker)
 {
-    if (!mRenderer->enableDebugUtils() && !mRenderer->angleDebuggerMode())
+    if (!isDebugEnabled())
     {
         return;
     }
@@ -4556,7 +4556,7 @@ angle::Result ContextVk::popDebugGroup(const gl::Context *context)
 
 angle::Result ContextVk::pushDebugGroupImpl(GLenum source, GLuint id, const char *message)
 {
-    if (!mRenderer->enableDebugUtils() && !mRenderer->angleDebuggerMode())
+    if (!isDebugEnabled())
     {
         return angle::Result::Continue;
     }
@@ -4578,7 +4578,7 @@ angle::Result ContextVk::pushDebugGroupImpl(GLenum source, GLuint id, const char
 
 angle::Result ContextVk::popDebugGroupImpl()
 {
-    if (!mRenderer->enableDebugUtils() && !mRenderer->angleDebuggerMode())
+    if (!isDebugEnabled())
     {
         return angle::Result::Continue;
     }

src/libANGLE/renderer/vulkan/ContextVk.h

@@ -235,6 +235,11 @@ class ContextVk : public ContextImpl, public vk::Context, public MultisampleText
     // Device loss
     gl::GraphicsResetStatus getResetStatus() override;
 
+    bool isDebugEnabled()
+    {
+        return mRenderer->enableDebugUtils() || mRenderer->angleDebuggerMode();
+    }
+
     // EXT_debug_marker
     angle::Result insertEventMarker(GLsizei length, const char *marker) override;
     angle::Result pushGroupMarker(GLsizei length, const char *marker) override;
@@ -1732,12 +1737,14 @@ uint32_t GetDriverUniformSize(vk::Context *context, PipelineType pipelineType);
 // Generate a perf warning, and insert an event marker in the command buffer.
 #define ANGLE_VK_PERF_WARNING(contextVk, severity, ...)                             \
     do                                                                              \
+    {                                                                               \
+        ANGLE_PERF_WARNING(contextVk->getDebug(), severity, __VA_ARGS__);           \
+        if (contextVk->isDebugEnabled())                                            \
         {                                                                           \
             char ANGLE_MESSAGE[200];                                                \
             snprintf(ANGLE_MESSAGE, sizeof(ANGLE_MESSAGE), __VA_ARGS__);            \
-        ANGLE_PERF_WARNING(contextVk->getDebug(), severity, ANGLE_MESSAGE);     \
-                                                                                \
             contextVk->insertEventMarkerImpl(GL_DEBUG_SOURCE_OTHER, ANGLE_MESSAGE); \
+        }                                                                           \
     } while (0)
 
 // Generate a trace event for graphics profiler, and insert an event marker in the command buffer.