(logging-log4cxx) branch master updated: Restore LoggingEvent throughput performance (#746)

[swebb2066]

This is an automated email from the ASF dual-hosted git repository.

swebb2066 pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/logging-log4cxx.git


The following commit(s) were added to refs/heads/master by this push:
     new b5fca83f Restore LoggingEvent throughput performance (#746)
b5fca83f is described below

commit b5fca83fdb063d24cf2b32e750a59c2356a9f057
Author: Stephen Webb <stephen.w...@ieee.org>
AuthorDate: Sat Aug 29 11:10:58 2026 +1000

    Restore LoggingEvent throughput performance (#746)
---
 src/main/cpp/loggingevent.cpp            | 43 ++++++++++++++++++++++++++------
 src/test/cpp/asyncappenderracestress.cpp |  2 +-
 2 files changed, 37 insertions(+), 8 deletions(-)

diff --git a/src/main/cpp/loggingevent.cpp b/src/main/cpp/loggingevent.cpp
index 9bce733f..ed110564 100644
--- a/src/main/cpp/loggingevent.cpp
+++ b/src/main/cpp/loggingevent.cpp
@@ -33,6 +33,10 @@
 #include <log4cxx/helpers/messagebuffer.h>
 #include <log4cxx/helpers/date.h>
 #include <log4cxx/helpers/optional.h>
+#include <log4cxx/helpers/transcoder.h>
+#include <atomic>
+#include <memory>
+#include <thread>
 
 using namespace LOG4CXX_NS;
 using namespace LOG4CXX_NS::spi;
@@ -43,6 +47,7 @@ struct LoggingEvent::LoggingEventPrivate
        LoggingEventPrivate(const ThreadSpecificData::NamePairPtr p = 
ThreadSpecificData::getNames()) :
                timeStamp(0),
                pNames(p)
+               , renderState(RenderingRequired)
        {
        }
 
@@ -59,7 +64,8 @@ struct LoggingEvent::LoggingEventPrivate
                timeStamp(Date::currentTime()),
                locationInfo(locationInfo1),
                chronoTimeStamp(std::chrono::microseconds(timeStamp)),
-               pNames(p)
+               pNames(p),
+               renderState(RenderingCompleted)
        {
        }
 
@@ -77,6 +83,7 @@ struct LoggingEvent::LoggingEventPrivate
                , chronoTimeStamp(std::chrono::microseconds(timeStamp))
                , pNames(p)
                , messageAppender(std::move(messageAppenderArg))
+               , renderState(RenderingRequired)
        {
        }
 
@@ -91,7 +98,8 @@ struct LoggingEvent::LoggingEventPrivate
                timeStamp(Date::currentTime()),
                locationInfo(locationInfo1),
                chronoTimeStamp(std::chrono::microseconds(timeStamp)),
-               pNames(p)
+               pNames(p),
+               renderState(RenderingCompleted)
        {
        }
 
@@ -148,7 +156,7 @@ struct LoggingEvent::LoggingEventPrivate
         */
        helpers::AsyncBuffer messageAppender;
 
-       /** Ensures the deferred message is rendered exactly once.
+       /** Ensures an async message is rendered exactly once.
         *
         *  A LoggingEvent may be shared between threads, e.g. when it is
         *  queued to an AsyncAppender dispatcher while the logging thread
@@ -157,21 +165,42 @@ struct LoggingEvent::LoggingEventPrivate
         *  the closure vector while the other iterates it, and both
         *  move-assign \c message - a concurrent free/assign of the same
         *  heap buffer.
+        * Note: use of std::call_once was found to degrade throughput by up to 
120%
         */
-       std::once_flag renderOnce;
+       std::atomic<uint8_t> renderState;
+       static const uint8_t RenderingRequired = 0;
+       static const uint8_t RenderingActive = 1;
+       static const uint8_t RenderingCompleted = 2;
 
        void renderMessage()
        {
-               std::call_once(this->renderOnce, [this]()
+               if (renderState.load(std::memory_order_acquire) == 
RenderingCompleted)
+                       return;
+               uint8_t unrenderedState{ RenderingRequired };
+               if (renderState.compare_exchange_strong(unrenderedState, 
RenderingActive, std::memory_order_acquire))
                {
-                       if (!this->messageAppender.empty())
+                       if (this->messageAppender.empty())
+                               ;
+                       else try
                        {
                                helpers::LogCharMessageBuffer buf;
                                this->messageAppender.renderMessage(buf);
                                this->message = buf.extract_str(buf);
                                this->messageAppender.clear();
+
+                       }
+                       catch (const std::exception& e)
+                       {
+                               helpers::Transcoder::decode(e.what(), 
this->message);
+                       }
+                       catch (...)
+                       {
+                               this->message = LOG4CXX_STR("mesage rendering 
failed");
                        }
-               });
+                       renderState.store(RenderingCompleted, 
std::memory_order_release);
+               }
+               else while (renderState.load(std::memory_order_acquire) != 
RenderingCompleted)
+                       std::this_thread::yield();
        }
 };
 
diff --git a/src/test/cpp/asyncappenderracestress.cpp 
b/src/test/cpp/asyncappenderracestress.cpp
index f9e37716..aacf3a91 100644
--- a/src/test/cpp/asyncappenderracestress.cpp
+++ b/src/test/cpp/asyncappenderracestress.cpp
@@ -127,7 +127,7 @@ public:
        // Expected behavior:
        // - Without single-shot rendering, ThreadSanitizer reports data races 
in
        //   renderMessage (and the assertions below can observe torn messages).
-       // - With renderMessage guarded by std::call_once, ThreadSanitizer is 
clean
+       // - With renderMessage guarded by std::atomic, ThreadSanitizer is clean
        //   and both threads observe identical messages.
        void raceDeferredMessageRendering()
        {