[lldb] Add a BufferedLogHandler

[JDevlieghere]

Summary

Add a BufferedLogHandler as requested by Greg in D127986.

[JDevlieghere]

Flush on destruction

[labath]

I feel I should note that the llvm streams already have a buffered mode, and given the way things are implemented now (our log class writes the entire log message in one call, and the raw_ostream flushing the entire buffer whenever a message does not fit), I don't think this class has any advantages over using stream buffering (that's a very long-winded way of saying you're not going to get partial messages in either of the solutions). The only two differences I see are:

• one of them specifies the size, the other specifies the number of messages
• different behavior in case of races (in non-thread-safe mode). I'll write more on that elsewhere.

[JDevlieghere]

In D128026#3595457, @labath wrote:

I feel I should note that the llvm streams already have a buffered mode, and given the way things are implemented now (our log class writes the entire log message in one call, and the raw_ostream flushing the entire buffer whenever a message does not fit), I don't think this class has any advantages over using stream buffering (that's a very long-winded way of saying you're not going to get partial messages in either of the solutions). The only two differences I see are:

• one of them specifies the size, the other specifies the number of messages
• different behavior in case of races (in non-thread-safe mode). I'll write more on that elsewhere.

As I said in the other patch, I (personally) don't really care all that much about buffering except for the circular buffer. I've implemented an alterantive, stream based buffering approach in https://reviews.llvm.org/D127986. I'll put up a separate patch for the circular buffer.

[clayborg]

This is an interesting take that makes more sense than specifying a size in bytes and a "m_circular" since that kind of thing could cut the first message. Saving entire messages as they are logged might make more sense for our circular log messages as we would ensure we have full message lines, though it does come with a "copy each message" cost

lldb/source/Utility/Log.cpp

361

maybe assert size > 0 here to make sure we don't crash in Emit() or set m_size to 1 if size is zero?

366

If we are going to buffer, I worry about the performance with saving an array or strings that must be copied each time. Though I do like that we are saving messages as entire buffers.

If we go the circular buffer route we can either have one fixed size buffer that we copy into and then try the keep the current insert index, or copy the strings like you are already doing.

[JDevlieghere]

With D127986 I don't think we need this anymore.

lldb/include/lldb/Utility/Log.h

public:
 
   void Emit(llvm::StringRef message) override;
 
 private:
   lldb::LogOutputCallback m_callback;
   void *m_baton;
 };
 
+class BufferedLogHandler : public LogHandler {
+public:
+  BufferedLogHandler(size_t size, std::shared_ptr<LogHandler> delegate);
+  ~BufferedLogHandler();
+
+  void Emit(llvm::StringRef message) override;
+  void Flush();
+
+private:
+  std::shared_ptr<LogHandler> m_delegate;
+  std::unique_ptr<std::string[]> m_messages;
+  const size_t m_size = 0;
+  size_t m_next_index = 0;
+};
+
 class RotatingLogHandler : public LogHandler {
 public:
   RotatingLogHandler(size_t size);
 
   void Emit(llvm::StringRef message) override;
   void Dump(llvm::raw_ostream &stream) const;
 
 private:

lldb/source/Utility/Log.cpp

 CallbackLogHandler::CallbackLogHandler(lldb::LogOutputCallback callback,
                                        void *baton)
     : m_callback(callback), m_baton(baton) {}
 
 void CallbackLogHandler::Emit(llvm::StringRef message) {
   m_callback(message.data(), m_baton);
 }
 
+BufferedLogHandler::BufferedLogHandler(size_t size,
+                                       std::shared_ptr<LogHandler> delegate)
+    : m_delegate(delegate), m_messages(std::make_unique<std::string[]>(size)),
+      m_size(size) {}
+
+BufferedLogHandler::~BufferedLogHandler() { Flush(); }
+
+void BufferedLogHandler::Emit(llvm::StringRef message) {
+  m_messages[m_next_index++] = message.str();
+  if (m_next_index == m_size)
+    Flush();
+}
+
+void BufferedLogHandler::Flush() {
+  for (size_t i = 0; i < m_next_index; ++i) {
+    m_delegate->Emit(m_messages[i]);
+    m_messages[i].clear();
+  }
+  m_next_index = 0;
+}
+
 RotatingLogHandler::RotatingLogHandler(size_t size)
     : m_messages(std::make_unique<std::string[]>(size)), m_size(size) {}
 
 void RotatingLogHandler::Emit(llvm::StringRef message) {
   ++m_total_count;
   const size_t index = m_next_index;
   m_next_index = NormalizeIndex(index + 1);
   m_messages[index] = message.str();

lldb/unittests/Utility/LogTest.cpp

TEST(LogHandlerTest, RotatingLogHandler) {
   handler.Emit("baz");
   handler.Emit("qux");
   EXPECT_EQ(GetDumpAsString(handler), "barbazqux");
 
   handler.Emit("quux");
   EXPECT_EQ(GetDumpAsString(handler), "bazquxquux");
 }
 
+TEST(LogHandlerTest, BufferedLogHandler) {
+  auto delegate_sp = std::make_shared<TestLogHandler>();
+
+  {
+    BufferedLogHandler handler(3, delegate_sp);
+
+    handler.Emit("1");
+    handler.Emit("2");
+    EXPECT_EQ(delegate_sp->m_stream.str(), "");
+
+    handler.Emit("3");
+    EXPECT_EQ(delegate_sp->m_stream.str(), "123");
+
+    handler.Emit("4");
+    handler.Emit("5");
+    EXPECT_EQ(delegate_sp->m_stream.str(), "123");
+
+    handler.Emit("6");
+    EXPECT_EQ(delegate_sp->m_stream.str(), "123456");
+
+    handler.Emit("7");
+    EXPECT_EQ(delegate_sp->m_stream.str(), "123456");
+  }
+
+  // Make sure we flush on destruction.
+  EXPECT_EQ(delegate_sp->m_stream.str(), "1234567");
+}
+
 TEST_F(LogChannelTest, Enable) {
   EXPECT_EQ(nullptr, GetLog(TestChannel::FOO));
   std::string message;
   auto log_handler_sp = std::make_shared<TestLogHandler>();
   std::string error;
   ASSERT_FALSE(EnableChannel(log_handler_sp, 0, "chanchan", {}, error));
   EXPECT_EQ("Invalid log channel 'chanchan'.\n", error);