Author: labath Date: Tue Feb 21 03:58:23 2017 New Revision: 295712 URL: http://llvm.org/viewvc/llvm-project?rev=295712&view=rev Log: Log: Fix race in accessing the stream variable
Summary: The code was attempting to copy the shared pointer member in order to guarantee atomicity, but this is not enough. Instead, protect the pointer with a proper read-write mutex. This bug was present here for a long time, but my recent refactors must have altered the timings slightly, such that now this fails fairly often when running the tests: the test runner runs the "log disable" command just as the thread monitoring the lldb-server child is about to report that the server has exited. I add a test case for this. It's not possible to reproduce the race deterministically in normal circumstances, but I have verified that before the fix, the test failed when run under tsan, and was running fine afterwards. Reviewers: clayborg, zturner Subscribers: lldb-commits Differential Revision: https://reviews.llvm.org/D30168 Modified: lldb/trunk/include/lldb/Core/Log.h lldb/trunk/source/Core/Log.cpp lldb/trunk/unittests/Core/LogTest.cpp Modified: lldb/trunk/include/lldb/Core/Log.h URL: http://llvm.org/viewvc/llvm-project/lldb/trunk/include/lldb/Core/Log.h?rev=295712&r1=295711&r2=295712&view=diff ============================================================================== --- lldb/trunk/include/lldb/Core/Log.h (original) +++ lldb/trunk/include/lldb/Core/Log.h Tue Feb 21 03:58:23 2017 @@ -18,6 +18,7 @@ // Other libraries and framework includes #include "llvm/Support/FormatVariadic.h" +#include "llvm/Support/RWMutex.h" // C++ Includes #include <atomic> #include <cstdarg> @@ -184,14 +185,22 @@ public: bool GetVerbose() const; void SetStream(const std::shared_ptr<llvm::raw_ostream> &stream_sp) { + llvm::sys::ScopedWriter lock(m_stream_mutex); m_stream_sp = stream_sp; } + std::shared_ptr<llvm::raw_ostream> GetStream() { + llvm::sys::ScopedReader lock(m_stream_mutex); + return m_stream_sp; + } + protected: //------------------------------------------------------------------ // Member variables //------------------------------------------------------------------ + llvm::sys::RWMutex m_stream_mutex; // Protects m_stream_sp std::shared_ptr<llvm::raw_ostream> m_stream_sp; + Flags m_options; Flags m_mask_bits; Modified: lldb/trunk/source/Core/Log.cpp URL: http://llvm.org/viewvc/llvm-project/lldb/trunk/source/Core/Log.cpp?rev=295712&r1=295711&r2=295712&view=diff ============================================================================== --- lldb/trunk/source/Core/Log.cpp (original) +++ lldb/trunk/source/Core/Log.cpp Tue Feb 21 03:58:23 2017 @@ -400,7 +400,7 @@ void Log::WriteHeader(llvm::raw_ostream void Log::WriteMessage(const std::string &message) { // Make a copy of our stream shared pointer in case someone disables our // log while we are logging and releases the stream - auto stream_sp = m_stream_sp; + auto stream_sp = GetStream(); if (!stream_sp) return; Modified: lldb/trunk/unittests/Core/LogTest.cpp URL: http://llvm.org/viewvc/llvm-project/lldb/trunk/unittests/Core/LogTest.cpp?rev=295712&r1=295711&r2=295712&view=diff ============================================================================== --- lldb/trunk/unittests/Core/LogTest.cpp (original) +++ lldb/trunk/unittests/Core/LogTest.cpp Tue Feb 21 03:58:23 2017 @@ -13,6 +13,7 @@ #include "lldb/Host/Host.h" #include "lldb/Utility/StreamString.h" #include "llvm/Support/ManagedStatic.h" +#include <thread> using namespace lldb; using namespace lldb_private; @@ -26,6 +27,8 @@ static constexpr uint32_t default_flags static Log::Channel test_channel(test_categories, default_flags); struct LogChannelTest : public ::testing::Test { + void TearDown() override { Log::DisableAllLogChannels(nullptr); } + static void SetUpTestCase() { Log::Register("chan", test_channel); } @@ -170,3 +173,26 @@ TEST_F(LogChannelTest, List) { EXPECT_FALSE(Log::ListChannelCategories("chanchan", str)); EXPECT_EQ("Invalid log channel 'chanchan'.\n", str.GetString().str()); } + +TEST_F(LogChannelTest, LogThread) { + // Test that we are able to concurrently write to a log channel and disable + // it. + std::string message; + std::shared_ptr<llvm::raw_string_ostream> stream_sp( + new llvm::raw_string_ostream(message)); + StreamString err; + EXPECT_TRUE(Log::EnableLogChannel(stream_sp, 0, "chan", nullptr, err)); + + Log *log = test_channel.GetLogIfAll(FOO); + + // Start logging on one thread. Concurrently, try disabling the log channel. + std::thread log_thread([log] { LLDB_LOG(log, "Hello World"); }); + EXPECT_TRUE(Log::DisableLogChannel("chan", nullptr, err)); + log_thread.join(); + + // The log thread either managed to write to the log in time, 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(); +} _______________________________________________ lldb-commits mailing list lldb-commits@lists.llvm.org http://lists.llvm.org/cgi-bin/mailman/listinfo/lldb-commits
