(logging-log4cxx) 01/01: Prevent a possible fault when multiple appenders concurrently format an async logging request

[sw...@apache.org]

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

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

commit 7a757b8c6f923e19b8c3b785de87fa53e24bfb3b
Author: Stephen Webb <sw...@gmail.com>
AuthorDate: Wed Aug 19 14:54:42 2026 +1000

    Prevent a possible fault when multiple appenders concurrently format an async logging request
---
 src/main/cpp/loggingevent.cpp            | 28 +++++++++++----
 src/test/cpp/CMakeLists.txt              |  1 +
 src/test/cpp/asyncappenderracestress.cpp | 58 ++++++++++++++++++++++++++++++++
 3 files changed, 81 insertions(+), 6 deletions(-)

diff --git a/src/main/cpp/loggingevent.cpp b/src/main/cpp/loggingevent.cpp
index ceae144c..9bce733f 100644
--- a/src/main/cpp/loggingevent.cpp
+++ b/src/main/cpp/loggingevent.cpp
@@ -16,6 +16,7 @@
  */
 
 #include <chrono>
+#include <mutex>
 #include <log4cxx/spi/loggingevent.h>
 #include <log4cxx/ndc.h>
 
@@ -147,15 +148,30 @@ struct LoggingEvent::LoggingEventPrivate
 	 */
 	helpers::AsyncBuffer messageAppender;
 
+	/** Ensures the deferred 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
+	 *  formats the same event for a synchronous appender.  Without this,
+	 *  two threads could pass the empty() check concurrently: one clears
+	 *  the closure vector while the other iterates it, and both
+	 *  move-assign \c message - a concurrent free/assign of the same
+	 *  heap buffer.
+	 */
+	std::once_flag renderOnce;
+
 	void renderMessage()
 	{
-		if (!this->messageAppender.empty())
+		std::call_once(this->renderOnce, [this]()
 		{
-			helpers::LogCharMessageBuffer buf;
-			this->messageAppender.renderMessage(buf);
-			this->message = buf.extract_str(buf);
-			this->messageAppender.clear();
-		}
+			if (!this->messageAppender.empty())
+			{
+				helpers::LogCharMessageBuffer buf;
+				this->messageAppender.renderMessage(buf);
+				this->message = buf.extract_str(buf);
+				this->messageAppender.clear();
+			}
+		});
 	}
 };
 
diff --git a/src/test/cpp/CMakeLists.txt b/src/test/cpp/CMakeLists.txt
index a23347b8..913a5512 100644
--- a/src/test/cpp/CMakeLists.txt
+++ b/src/test/cpp/CMakeLists.txt
@@ -127,6 +127,7 @@ if(LOG4CXX_TEST_ONLY_BUILD)
   list(APPEND TEST_COMPILE_DEFINITIONS
       "ENABLE_FAILING_APPENDER_SIMULATION_TESTING=1"
       "ENABLE_2GB_STRING_TESTING=1"
+      "ENABLE_4000_THREAD_SANITIZER_TESTING=1"
       "LOGLOG_THRESHOLD=1"
   )
 endif()
diff --git a/src/test/cpp/asyncappenderracestress.cpp b/src/test/cpp/asyncappenderracestress.cpp
index ef0e9eba..f9e37716 100644
--- a/src/test/cpp/asyncappenderracestress.cpp
+++ b/src/test/cpp/asyncappenderracestress.cpp
@@ -18,6 +18,9 @@
 #include "logunit.h"
 
 #include <log4cxx/asyncappender.h>
+#include <log4cxx/level.h>
+#include <log4cxx/helpers/asyncbuffer.h>
+#include <log4cxx/spi/loggingevent.h>
 
 #include <atomic>
 #include <memory>
@@ -30,6 +33,9 @@ LOGUNIT_CLASS(AsyncAppenderRaceStressTestCase)
 	LOGUNIT_TEST_SUITE(AsyncAppenderRaceStressTestCase);
 	LOGUNIT_TEST(raceGetSetBufferSize);
 	LOGUNIT_TEST(raceGetSetBlocking);
+#if ENABLE_4000_THREAD_SANITIZER_TESTING
+	LOGUNIT_TEST(raceDeferredMessageRendering);
+#endif
 	LOGUNIT_TEST_SUITE_END();
 
 public:
@@ -111,6 +117,58 @@ public:
 		writer.join();
 		reader.join();
 	}
+
+	// A LoggingEvent created via the deferred-render (AsyncBuffer) API may be
+	// rendered concurrently, e.g. by an AsyncAppender dispatcher thread and by
+	// the logging thread when the event is also routed to a synchronous
+	// appender.  The message must be rendered exactly once: both threads must
+	// observe the same, complete message.
+	//
+	// 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
+	//   and both threads observe identical messages.
+	void raceDeferredMessageRendering()
+	{
+		for (int i = 0; i < 2000; ++i)
+		{
+			helpers::AsyncBuffer buf;
+			buf << "test message " << i;
+			auto event = std::make_shared<spi::LoggingEvent>
+				( LOG4CXX_STR("test.logger")
+				, Level::getInfo()
+				, LOG4CXX_LOCATION
+				, std::move(buf)
+				);
+
+			std::atomic<int> ready{ 0 };
+			std::atomic<bool> start{ false };
+			LogString first, second;
+
+			std::thread t1([&]()
+			{
+				ready.fetch_add(1, std::memory_order_release);
+				while (!start.load(std::memory_order_acquire)) {}
+				first = event->getRenderedMessage();
+			});
+			std::thread t2([&]()
+			{
+				ready.fetch_add(1, std::memory_order_release);
+				while (!start.load(std::memory_order_acquire)) {}
+				second = event->getRenderedMessage();
+			});
+
+			while (ready.load(std::memory_order_acquire) != 2) {}
+			start.store(true, std::memory_order_release);
+
+			t1.join();
+			t2.join();
+
+			LOGUNIT_ASSERT(!first.empty());
+			LOGUNIT_ASSERT_EQUAL(first, second);
+		}
+	}
 };
 
 LOGUNIT_TEST_SUITE_REGISTRATION(AsyncAppenderRaceStressTestCase);