[lldb] Make thread safety the responsibility of the log handlers
authorJonas Devlieghere <jonas@devlieghere.com>
Thu, 23 Jun 2022 15:08:36 +0000 (08:08 -0700)
committerJonas Devlieghere <jonas@devlieghere.com>
Thu, 23 Jun 2022 16:12:05 +0000 (09:12 -0700)
Drop the thread-safe flag and make the locking strategy the
responsibility of the individual log handler.

Previously we got away with a non-thread safe mode because we were using
unbuffered streams that rely on the underlying syscalls/OS for
synchronization. With the introduction of log handlers, we can have
arbitrary logic involved in writing out the logs. With this patch the
log handlers can pick the most appropriate locking strategy for their
particular implementation.

Differential revision: https://reviews.llvm.org/D127922

lldb/include/lldb/Utility/Log.h
lldb/source/Commands/CommandObjectLog.cpp
lldb/source/Commands/Options.td
lldb/source/Core/Debugger.cpp
lldb/source/Utility/Log.cpp
lldb/test/API/commands/log/basic/TestLogging.py
lldb/unittests/Utility/LogTest.cpp

index 3fd474d..4772291 100644 (file)
@@ -33,7 +33,6 @@ namespace llvm {
 class raw_ostream;
 }
 // Logging Options
-#define LLDB_LOG_OPTION_THREADSAFE (1u << 0)
 #define LLDB_LOG_OPTION_VERBOSE (1u << 1)
 #define LLDB_LOG_OPTION_PREPEND_SEQUENCE (1u << 3)
 #define LLDB_LOG_OPTION_PREPEND_TIMESTAMP (1u << 4)
@@ -50,10 +49,6 @@ class LogHandler {
 public:
   virtual ~LogHandler() = default;
   virtual void Emit(llvm::StringRef message) = 0;
-  void EmitThreadSafe(llvm::StringRef message);
-
-private:
-  std::mutex m_mutex;
 };
 
 class StreamLogHandler : public LogHandler {
@@ -65,6 +60,7 @@ public:
   void Flush();
 
 private:
+  std::mutex m_mutex;
   llvm::raw_fd_ostream m_stream;
 };
 
@@ -91,6 +87,7 @@ private:
   size_t GetNumMessages() const;
   size_t GetFirstMessageIndex() const;
 
+  mutable std::mutex m_mutex;
   std::unique_ptr<std::string[]> m_messages;
   const size_t m_size = 0;
   size_t m_next_index = 0;
index 190b262..91277e3 100644 (file)
@@ -94,9 +94,6 @@ public:
         error =
             buffer_size.SetValueFromString(option_arg, eVarSetOperationAssign);
         break;
-      case 't':
-        log_options |= LLDB_LOG_OPTION_THREADSAFE;
-        break;
       case 'v':
         log_options |= LLDB_LOG_OPTION_VERBOSE;
         break;
index f3c041e..b95fc6b 100644 (file)
@@ -433,8 +433,6 @@ let Command = "log enable" in {
     Desc<"Set the destination file to log to.">;
   def log_buffer_size : Option<"buffer", "b">, Group<1>, Arg<"UnsignedInteger">,
     Desc<"Set the log to be buffered, using the specified buffer size.">;
-  def log_threadsafe : Option<"threadsafe", "t">, Group<1>,
-    Desc<"Enable thread safe logging to avoid interweaved log lines.">;
   def log_verbose : Option<"verbose", "v">, Group<1>,
     Desc<"Enable verbose logging.">;
   def log_sequence : Option<"sequence", "s">, Group<1>,
index 0be7748..fd9679c 100644 (file)
@@ -1448,8 +1448,7 @@ bool Debugger::EnableLog(llvm::StringRef channel,
   assert(log_handler_sp);
 
   if (log_options == 0)
-    log_options =
-        LLDB_LOG_OPTION_PREPEND_THREAD_NAME | LLDB_LOG_OPTION_THREADSAFE;
+    log_options = LLDB_LOG_OPTION_PREPEND_THREAD_NAME;
 
   return Log::EnableLogChannel(log_handler_sp, log_options, channel, categories,
                                error_stream);
index 37704b7..4c3e05a 100644 (file)
@@ -317,12 +317,7 @@ void Log::WriteMessage(const std::string &message) {
   auto handler_sp = GetHandler();
   if (!handler_sp)
     return;
-
-  Flags options = GetOptions();
-  if (options.Test(LLDB_LOG_OPTION_THREADSAFE))
-    handler_sp->EmitThreadSafe(message);
-  else
-    handler_sp->Emit(message);
+  handler_sp->Emit(message);
 }
 
 void Log::Format(llvm::StringRef file, llvm::StringRef function,
@@ -334,11 +329,6 @@ void Log::Format(llvm::StringRef file, llvm::StringRef function,
   WriteMessage(message.str());
 }
 
-void LogHandler::EmitThreadSafe(llvm::StringRef message) {
-  std::lock_guard<std::mutex> guard(m_mutex);
-  Emit(message);
-}
-
 StreamLogHandler::StreamLogHandler(int fd, bool should_close,
                                    size_t buffer_size)
     : m_stream(fd, should_close, buffer_size == 0) {
@@ -348,9 +338,19 @@ StreamLogHandler::StreamLogHandler(int fd, bool should_close,
 
 StreamLogHandler::~StreamLogHandler() { Flush(); }
 
-void StreamLogHandler::Flush() { m_stream.flush(); }
+void StreamLogHandler::Flush() {
+  std::lock_guard<std::mutex> guard(m_mutex);
+  m_stream.flush();
+}
 
-void StreamLogHandler::Emit(llvm::StringRef message) { m_stream << message; }
+void StreamLogHandler::Emit(llvm::StringRef message) {
+  if (m_stream.GetBufferSize() > 0) {
+    std::lock_guard<std::mutex> guard(m_mutex);
+    m_stream << message;
+  } else {
+    m_stream << message;
+  }
+}
 
 CallbackLogHandler::CallbackLogHandler(lldb::LogOutputCallback callback,
                                        void *baton)
@@ -364,6 +364,7 @@ RotatingLogHandler::RotatingLogHandler(size_t size)
     : m_messages(std::make_unique<std::string[]>(size)), m_size(size) {}
 
 void RotatingLogHandler::Emit(llvm::StringRef message) {
+  std::lock_guard<std::mutex> guard(m_mutex);
   ++m_total_count;
   const size_t index = m_next_index;
   m_next_index = NormalizeIndex(index + 1);
@@ -381,6 +382,7 @@ size_t RotatingLogHandler::GetFirstMessageIndex() const {
 }
 
 void RotatingLogHandler::Dump(llvm::raw_ostream &stream) const {
+  std::lock_guard<std::mutex> guard(m_mutex);
   const size_t start_idx = GetFirstMessageIndex();
   const size_t stop_idx = start_idx + GetNumMessages();
   for (size_t i = start_idx; i < stop_idx; ++i) {
index b062da5..da2227e 100644 (file)
@@ -31,7 +31,7 @@ class LogTestCase(TestBase):
         # By default, Debugger::EnableLog() will set log options to
         # PREPEND_THREAD_NAME + OPTION_THREADSAFE. We don't want the
         # threadnames here, so we enable just threadsafe (-t).
-        self.runCmd("log enable -t -f '%s' lldb commands" % (self.log_file))
+        self.runCmd("log enable -f '%s' lldb commands" % (self.log_file))
 
         self.runCmd("command alias bp breakpoint")
 
@@ -59,7 +59,7 @@ class LogTestCase(TestBase):
             for i in range(1, 1000):
                 f.write("bacon\n")
 
-        self.runCmd("log enable -t -f '%s' lldb commands" % self.log_file)
+        self.runCmd("log enable -f '%s' lldb commands" % self.log_file)
         self.runCmd("help log")
         self.runCmd("log disable lldb")
 
@@ -76,7 +76,7 @@ class LogTestCase(TestBase):
         with open(self.log_file, "w") as f:
             f.write("bacon\n")
 
-        self.runCmd( "log enable -t -a -f '%s' lldb commands" % self.log_file)
+        self.runCmd( "log enable -a -f '%s' lldb commands" % self.log_file)
         self.runCmd("help log")
         self.runCmd("log disable lldb")
 
@@ -93,7 +93,7 @@ class LogTestCase(TestBase):
         if (os.path.exists(self.log_file)):
             os.remove(self.log_file)
 
-        self.runCmd("log enable -v -t -s -T -p -n -S -F -f '%s' lldb commands" % self.log_file)
+        self.runCmd("log enable -v -s -T -p -n -S -F -f '%s' lldb commands" % self.log_file)
         self.runCmd("help log")
         self.runCmd("log disable lldb")
 
index d89f6df..87928a6 100644 (file)
@@ -270,8 +270,7 @@ TEST_F(LogChannelTest, List) {
 TEST_F(LogChannelEnabledTest, log_options) {
   std::string Err;
   EXPECT_EQ("Hello World\n", logAndTakeOutput("Hello World"));
-  EXPECT_TRUE(EnableChannel(getLogHandler(), LLDB_LOG_OPTION_THREADSAFE, "chan",
-                            {}, Err));
+  EXPECT_TRUE(EnableChannel(getLogHandler(), 0, "chan", {}, Err));
   EXPECT_EQ("Hello World\n", logAndTakeOutput("Hello World"));
 
   {