Index: include/lldb/Utility/Log.h =================================================================== --- include/lldb/Utility/Log.h +++ include/lldb/Utility/Log.h @@ -66,7 +66,9 @@ default_flags(default_flags) {} // This function is safe to call at any time - // FIXME: Not true yet, mask access is not atomic + // If the channel is disabled after (or concurrently with) this function + // returning a non-null Log pointer, it is still safe to attempt to write to + // the Log object -- the output will be discarded. Log *GetLogIfAll(uint32_t mask) { Log *log = log_ptr.load(std::memory_order_acquire); if (log && log->GetMask().AllSet(mask)) @@ -75,7 +77,9 @@ } // This function is safe to call at any time - // FIXME: Not true yet, mask access is not atomic + // If the channel is disabled after (or concurrently with) this function + // returning a non-null Log pointer, it is still safe to attempt to write to + // the Log object -- the output will be discarded. Log *GetLogIfAny(uint32_t mask) { Log *log = log_ptr.load(std::memory_order_acquire); if (log && log->GetMask().AnySet(mask)) @@ -115,12 +119,13 @@ //------------------------------------------------------------------ // Member functions + // + // These functions are safe to call at any time you have a Log* obtained from + // the Channel class. If logging is disabled between you obtaining the Log + // object and writing to it, the output will be silently discarded. //------------------------------------------------------------------ - Log(); - - Log(const std::shared_ptr &stream_sp); - - ~Log(); + Log() = default; + ~Log() = default; void PutCString(const char *cstr); void PutString(llvm::StringRef str); @@ -136,9 +141,6 @@ void VAPrintf(const char *format, va_list args); - void LogIf(uint32_t mask, const char *fmt, ...) - __attribute__((format(printf, 3, 4))); - void Error(const char *fmt, ...) __attribute__((format(printf, 2, 3))); void VAError(const char *format, va_list args); @@ -147,15 +149,25 @@ void Warning(const char *fmt, ...) __attribute__((format(printf, 2, 3))); - Flags &GetOptions(); + const Flags GetOptions() const; - const Flags &GetOptions() const; + const Flags GetMask() const; - Flags &GetMask(); + bool GetVerbose() const; - const Flags &GetMask() const; +private: + llvm::sys::RWMutex m_stream_mutex; // Protects m_stream_sp + std::shared_ptr m_stream_sp; - bool GetVerbose() const; + std::atomic m_options{0}; + std::atomic m_mask{0}; + + void WriteHeader(llvm::raw_ostream &OS, llvm::StringRef file, + llvm::StringRef function); + void WriteMessage(const std::string &message); + + void Format(llvm::StringRef file, llvm::StringRef function, + const llvm::formatv_object_base &payload); void SetStream(const std::shared_ptr &stream_sp) { llvm::sys::ScopedWriter lock(m_stream_mutex); @@ -167,25 +179,7 @@ return m_stream_sp; } -protected: - //------------------------------------------------------------------ - // Member variables - //------------------------------------------------------------------ - llvm::sys::RWMutex m_stream_mutex; // Protects m_stream_sp - std::shared_ptr m_stream_sp; - - Flags m_options; - Flags m_mask_bits; - -private: DISALLOW_COPY_AND_ASSIGN(Log); - - void WriteHeader(llvm::raw_ostream &OS, llvm::StringRef file, - llvm::StringRef function); - void WriteMessage(const std::string &message); - - void Format(llvm::StringRef file, llvm::StringRef function, - const llvm::formatv_object_base &payload); }; } // namespace lldb_private Index: source/Utility/Log.cpp =================================================================== --- source/Utility/Log.cpp +++ source/Utility/Log.cpp @@ -87,9 +87,10 @@ void Log::Channel::Enable(Log &log, const std::shared_ptr &stream_sp, uint32_t options, uint32_t flags) { - log.GetMask().Set(flags); - if (log.GetMask().Get()) { - log.GetOptions().Reset(options); + uint32_t mask = log.m_mask.load(std::memory_order_acquire) | flags; + log.m_mask.store(mask, std::memory_order_release); + if (mask) { + log.m_options.store(options, std::memory_order_release); log.SetStream(stream_sp); log_ptr.store(&log, std::memory_order_release); } @@ -99,27 +100,21 @@ Log *log = log_ptr.load(std::memory_order_acquire); if (!log) return; - log->GetMask().Clear(flags); - if (!log->GetMask().Get()) { + uint32_t mask = log->m_mask.load(std::memory_order_acquire) & ~flags; + log->m_mask.store(mask, std::memory_order_release); + if (!mask) { log->SetStream(nullptr); log_ptr.store(nullptr, std::memory_order_release); } } -Log::Log() : m_stream_sp(), m_options(0), m_mask_bits(0) {} - -Log::Log(const std::shared_ptr &stream_sp) - : m_stream_sp(stream_sp), m_options(0), m_mask_bits(0) {} - -Log::~Log() = default; - -Flags &Log::GetOptions() { return m_options; } - -const Flags &Log::GetOptions() const { return m_options; } - -Flags &Log::GetMask() { return m_mask_bits; } +const Flags Log::GetOptions() const { + return m_options.load(std::memory_order_acquire); +} -const Flags &Log::GetMask() const { return m_mask_bits; } +const Flags Log::GetMask() const { + return m_mask.load(std::memory_order_acquire); +} void Log::PutCString(const char *cstr) { Printf("%s", cstr); } void Log::PutString(llvm::StringRef str) { PutCString(str.str().c_str()); } @@ -153,19 +148,6 @@ } //---------------------------------------------------------------------- -// Log only if all of the bits are set -//---------------------------------------------------------------------- -void Log::LogIf(uint32_t bits, const char *format, ...) { - if (!m_options.AllSet(bits)) - return; - - va_list args; - va_start(args, format); - VAPrintf(format, args); - va_end(args); -} - -//---------------------------------------------------------------------- // Printing of errors that are not fatal. //---------------------------------------------------------------------- void Log::Error(const char *format, ...) { @@ -187,7 +169,7 @@ // enabled. //---------------------------------------------------------------------- void Log::Verbose(const char *format, ...) { - if (!m_options.Test(LLDB_LOG_OPTION_VERBOSE)) + if (!GetVerbose()) return; va_list args; @@ -278,39 +260,42 @@ for (const auto &channel : *g_channel_map) ListCategories(*strm, channel); } -bool Log::GetVerbose() const { return m_options.Test(LLDB_LOG_OPTION_VERBOSE); } +bool Log::GetVerbose() const { + return m_options.load(std::memory_order_acquire) & LLDB_LOG_OPTION_VERBOSE; +} void Log::WriteHeader(llvm::raw_ostream &OS, llvm::StringRef file, llvm::StringRef function) { + Flags options = GetOptions(); static uint32_t g_sequence_id = 0; // Add a sequence ID if requested - if (m_options.Test(LLDB_LOG_OPTION_PREPEND_SEQUENCE)) + if (options.Test(LLDB_LOG_OPTION_PREPEND_SEQUENCE)) OS << ++g_sequence_id << " "; // Timestamp if requested - if (m_options.Test(LLDB_LOG_OPTION_PREPEND_TIMESTAMP)) { + if (options.Test(LLDB_LOG_OPTION_PREPEND_TIMESTAMP)) { auto now = std::chrono::duration( std::chrono::system_clock::now().time_since_epoch()); OS << llvm::formatv("{0:f9} ", now.count()); } // Add the process and thread if requested - if (m_options.Test(LLDB_LOG_OPTION_PREPEND_PROC_AND_THREAD)) + if (options.Test(LLDB_LOG_OPTION_PREPEND_PROC_AND_THREAD)) OS << llvm::formatv("[{0,0+4}/{1,0+4}] ", getpid(), llvm::get_threadid()); // Add the thread name if requested - if (m_options.Test(LLDB_LOG_OPTION_PREPEND_THREAD_NAME)) { + if (options.Test(LLDB_LOG_OPTION_PREPEND_THREAD_NAME)) { llvm::SmallString<32> thread_name; llvm::get_thread_name(thread_name); if (!thread_name.empty()) OS << thread_name; } - if (m_options.Test(LLDB_LOG_OPTION_BACKTRACE)) + if (options.Test(LLDB_LOG_OPTION_BACKTRACE)) llvm::sys::PrintStackTrace(OS); - if (m_options.Test(LLDB_LOG_OPTION_PREPEND_FILE_FUNCTION) && + if (options.Test(LLDB_LOG_OPTION_PREPEND_FILE_FUNCTION) && (!file.empty() || !function.empty())) { file = llvm::sys::path::filename(file).take_front(40); function = function.take_front(40); @@ -325,7 +310,8 @@ if (!stream_sp) return; - if (m_options.Test(LLDB_LOG_OPTION_THREADSAFE)) { + Flags options = GetOptions(); + if (options.Test(LLDB_LOG_OPTION_THREADSAFE)) { static std::recursive_mutex g_LogThreadedMutex; std::lock_guard guard(g_LogThreadedMutex); *stream_sp << message; Index: unittests/Utility/LogTest.cpp =================================================================== --- unittests/Utility/LogTest.cpp +++ unittests/Utility/LogTest.cpp @@ -13,6 +13,7 @@ #include "lldb/Utility/StreamString.h" #include "llvm/Support/ManagedStatic.h" #include "llvm/Support/Threading.h" +#include #include using namespace lldb; @@ -214,3 +215,51 @@ EXPECT_TRUE(stream_sp->str() == "" || stream_sp->str() == "Hello World\n") << "str(): " << stream_sp->str(); } + +TEST_F(LogChannelTest, LogVerboseThread) { + // Test that we are able to concurrently check the verbose flag of a log + // channel and enable it. + std::string message; + std::shared_ptr stream_sp( + new llvm::raw_string_ostream(message)); + StreamString err; + EXPECT_TRUE(Log::EnableLogChannel(stream_sp, 0, "chan", {}, err)); + + Log *log = test_channel.GetLogIfAll(FOO); + + // Start logging on one thread. Concurrently, try enabling the log channel + // (with different log options). + std::thread log_thread([log] { LLDB_LOGV(log, "Hello World"); }); + EXPECT_TRUE(Log::EnableLogChannel(stream_sp, LLDB_LOG_OPTION_VERBOSE, "chan", + {}, err)); + log_thread.join(); + EXPECT_TRUE(Log::DisableLogChannel("chan", {}, err)); + + // The log thread either managed to write to the log, or it didn't. In either + // case, we should not trip any undefined behavior (run the test under TSAN to + // verify this). + EXPECT_TRUE(stream_sp->str() == "" || stream_sp->str() == "Hello World\n") + << "str(): " << stream_sp->str(); +} + +TEST_F(LogChannelTest, LogGetLogThread) { + // Test that we are able to concurrently get mask of a Log object and disable + // it. + std::string message; + std::shared_ptr stream_sp( + new llvm::raw_string_ostream(message)); + StreamString err; + EXPECT_TRUE(Log::EnableLogChannel(stream_sp, 0, "chan", {}, err)); + Log *log = test_channel.GetLogIfAll(FOO); + + // Try fetching the log on one thread. Concurrently, try disabling the log + // channel. + uint32_t mask; + std::thread log_thread([log, &mask] { mask = log->GetMask().Get(); }); + EXPECT_TRUE(Log::DisableLogChannel("chan", {}, err)); + log_thread.join(); + + // The mask should be either zero of "FOO". In either case, we should not trip + // any undefined behavior (run the test under TSAN to verify this). + EXPECT_TRUE(mask == 0 || mask == FOO) << "mask: " << mask; +}