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 <[email protected]> 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);
