[lldb] Make thread safety the responsibility of the log handlers

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

Author: JDevlieghere

lldb/include/lldb/Utility/Log.h

@@ -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 @@ class StreamLogHandler : public LogHandler {
   void Flush();
 
 private:
+  std::mutex m_mutex;
   llvm::raw_fd_ostream m_stream;
 };
 
@@ -91,6 +87,7 @@ class RotatingLogHandler : public LogHandler {
   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;

lldb/source/Commands/CommandObjectLog.cpp

@@ -94,9 +94,6 @@ class CommandObjectLogEnable : public CommandObjectParsed {
         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;

lldb/source/Commands/Options.td

@@ -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>,

lldb/source/Core/Debugger.cpp

@@ -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);

lldb/source/Utility/Log.cpp

@@ -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) {

lldb/test/API/commands/log/basic/TestLogging.py

@@ -31,7 +31,7 @@ def test_file_writing(self):
         # 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 @@ def test_log_truncate(self):
             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 @@ def test_log_append(self):
         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 @@ def test_all_log_options(self):
         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")
 

lldb/unittests/Utility/LogTest.cpp

@@ -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"));
 
   {