diff --git a/cpp/src/arrow/util/logging.cc b/cpp/src/arrow/util/logging.cc index 993c5306ca4a..9a61d261ed34 100644 --- a/cpp/src/arrow/util/logging.cc +++ b/cpp/src/arrow/util/logging.cc @@ -24,6 +24,8 @@ #endif #include #include +#include +#include #ifdef ARROW_USE_GLOG @@ -67,7 +69,9 @@ class CerrLog { virtual ~CerrLog() { if (has_logged_) { - std::cerr << std::endl; + static std::mutex cerr_mutex; + std::lock_guard lock(cerr_mutex); + std::cerr << std::move(buffer_).str() << std::endl; } if (severity_ == ArrowLogLevel::ARROW_FATAL) { PrintBackTrace(); @@ -77,14 +81,14 @@ class CerrLog { std::ostream& Stream() { has_logged_ = true; - return std::cerr; + return buffer_; } template CerrLog& operator<<(const T& t) { if (severity_ != ArrowLogLevel::ARROW_DEBUG) { has_logged_ = true; - std::cerr << t; + buffer_ << t; } return *this; } @@ -92,6 +96,7 @@ class CerrLog { protected: const ArrowLogLevel severity_; bool has_logged_; + std::ostringstream buffer_; void PrintBackTrace() { #ifdef ARROW_WITH_BACKTRACE diff --git a/cpp/src/arrow/util/logging_test.cc b/cpp/src/arrow/util/logging_test.cc index 280edd6111c3..2b846afdd6ab 100644 --- a/cpp/src/arrow/util/logging_test.cc +++ b/cpp/src/arrow/util/logging_test.cc @@ -18,6 +18,8 @@ #include #include #include +#include +#include #include @@ -40,17 +42,11 @@ int64_t current_time_ms() { // This file just print some information using the logging macro. void PrintLog() { - ARROW_LOG(DEBUG) << "This is the" - << " DEBUG" - << " message"; - ARROW_LOG(INFO) << "This is the" - << " INFO message"; - ARROW_LOG(WARNING) << "This is the" - << " WARNING message"; - ARROW_LOG(ERROR) << "This is the" - << " ERROR message"; - ARROW_CHECK(true) << "This is a ARROW_CHECK" - << " message but it won't show up"; + ARROW_LOG(DEBUG) << "This is the" << " DEBUG" << " message"; + ARROW_LOG(INFO) << "This is the" << " INFO message"; + ARROW_LOG(WARNING) << "This is the" << " WARNING message"; + ARROW_LOG(ERROR) << "This is the" << " ERROR message"; + ARROW_CHECK(true) << "This is a ARROW_CHECK" << " message but it won't show up"; // The following 2 lines should not run since it will cause program failure. // ARROW_LOG(FATAL) << "This is the FATAL message"; // ARROW_CHECK(false) << "This is a ARROW_CHECK message but it won't show up"; @@ -95,6 +91,29 @@ TEST(ArrowCheck, PayloadEvaluatedOnFailure) { ASSERT_TRUE(tracer.was_printed); } +TEST(ArrowLog, MultiThreadedLogging) { + // This is mostly a visual test that logging from multiple threads produces + // a clean output without interleaving messages (GH-49433). + constexpr int kNumThreads = 10; + constexpr int kNumMessges = 10; + std::vector threads; + + threads.reserve(kNumThreads); + + for (int i = 0; i < kNumThreads; ++i) { + threads.emplace_back([i]() { + for (int j = 0; j < kNumMessges; ++j) { + ARROW_LOG(INFO) << "Thread " << i << " message " << j + << " - testing thread safety."; + } + }); + } + + for (auto& thread : threads) { + thread.join(); + } +} + } // namespace util TEST(DcheckMacros, DoNotEvaluateReleaseMode) {