teemperor updated this revision to Diff 365944.
teemperor added a comment.

- Fix double printing and formatting of the old plain text format.


CHANGES SINCE LAST ACTION
  https://reviews.llvm.org/D107079/new/

https://reviews.llvm.org/D107079

Files:
  lldb/docs/design/logging.rst
  lldb/docs/index.rst
  lldb/include/lldb/Interpreter/CommandCompletions.h
  lldb/include/lldb/Utility/Log.h
  lldb/include/lldb/lldb-enumerations.h
  lldb/source/Commands/CommandCompletions.cpp
  lldb/source/Commands/CommandObjectLog.cpp
  lldb/source/Commands/Options.td
  lldb/source/Interpreter/CommandObject.cpp
  lldb/source/Utility/Log.cpp
  lldb/test/API/commands/log/invalid-args/TestInvalidArgsLog.py
  lldb/test/API/functionalities/completion/TestCompletion.py
  lldb/test/API/functionalities/logging/Makefile
  lldb/test/API/functionalities/logging/TestLogging.py
  lldb/test/API/functionalities/logging/main.cpp
  lldb/unittests/Utility/LogTest.cpp

Index: lldb/unittests/Utility/LogTest.cpp
===================================================================
--- lldb/unittests/Utility/LogTest.cpp
+++ lldb/unittests/Utility/LogTest.cpp
@@ -11,6 +11,7 @@
 
 #include "lldb/Utility/Log.h"
 #include "lldb/Utility/StreamString.h"
+#include "llvm/Support/JSON.h"
 #include "llvm/Support/ManagedStatic.h"
 #include "llvm/Support/Threading.h"
 #include <thread>
@@ -82,6 +83,16 @@
   llvm::StringRef takeOutput();
   llvm::StringRef logAndTakeOutput(llvm::StringRef Message);
 
+  llvm::json::Object logAndTakeLogObject(llvm::StringRef Message) {
+    llvm::StringRef Out = logAndTakeOutput(Message).trim();
+    EXPECT_TRUE(Out.consume_back(","));
+    llvm::Expected<llvm::json::Value> parsed = llvm::json::parse(Out);
+    EXPECT_TRUE(static_cast<bool>(parsed));
+    llvm::json::Object *parsed_obj = parsed->getAsObject();
+    EXPECT_NE(parsed_obj, nullptr);
+    return *parsed_obj;
+  }
+
 public:
   void SetUp() override;
 };
@@ -92,6 +103,11 @@
 
   std::string error;
   ASSERT_TRUE(EnableChannel(m_stream_sp, 0, "chan", {}, error));
+  llvm::raw_string_ostream error_stream(error);
+  // Use JSON logging by default so the log messages can be parsed.
+  ASSERT_TRUE(
+      Log::SetLogChannelFormat("chan", Log::OutputFormat::JSON, error_stream));
+  EXPECT_EQ(error, "");
 
   m_log = test_channel.GetLogIfAll(FOO);
   ASSERT_NE(nullptr, m_log);
@@ -211,37 +227,71 @@
 
 TEST_F(LogChannelEnabledTest, log_options) {
   std::string Err;
-  EXPECT_EQ("Hello World\n", logAndTakeOutput("Hello World"));
+  EXPECT_EQ("{\"message\":\"Hello World\"},\n",
+            logAndTakeOutput("Hello World"));
   EXPECT_TRUE(EnableChannel(getStream(), LLDB_LOG_OPTION_THREADSAFE, "chan", {},
                             Err));
-  EXPECT_EQ("Hello World\n", logAndTakeOutput("Hello World"));
+  EXPECT_EQ("{\"message\":\"Hello World\"},\n",
+            logAndTakeOutput("Hello World"));
 
   {
     EXPECT_TRUE(EnableChannel(getStream(), LLDB_LOG_OPTION_PREPEND_SEQUENCE,
                               "chan", {}, Err));
-    llvm::StringRef Msg = logAndTakeOutput("Hello World");
-    int seq_no;
-    EXPECT_EQ(1, sscanf(Msg.str().c_str(), "%d Hello World", &seq_no));
+    llvm::json::Object parsed_obj = logAndTakeLogObject("Hello World");
+    // Check that any sequence-id was added.
+    EXPECT_TRUE(parsed_obj.getInteger("sequence-id"));
   }
 
   {
     EXPECT_TRUE(EnableChannel(getStream(), LLDB_LOG_OPTION_PREPEND_FILE_FUNCTION,
                               "chan", {}, Err));
-    llvm::StringRef Msg = logAndTakeOutput("Hello World");
-    char File[12];
-    char Function[17];
-      
-    sscanf(Msg.str().c_str(), "%[^:]:%s                                 Hello World", File, Function);
-    EXPECT_STRCASEEQ("LogTest.cpp", File);
-    EXPECT_STREQ("logAndTakeOutput", Function);
+    llvm::json::Object parsed_obj = logAndTakeLogObject("Hello World");
+    // Check that function/file parameters were added.
+    llvm::Optional<llvm::StringRef> function = parsed_obj.getString("function");
+    llvm::Optional<llvm::StringRef> file = parsed_obj.getString("file");
+    EXPECT_TRUE(function.hasValue());
+    EXPECT_TRUE(file.hasValue());
+
+    EXPECT_EQ(*function, "logAndTakeOutput");
+    EXPECT_EQ(*file, "LogTest.cpp");
   }
 
-  EXPECT_TRUE(EnableChannel(
-      getStream(), LLDB_LOG_OPTION_PREPEND_PROC_AND_THREAD, "chan", {}, Err));
-  EXPECT_EQ(llvm::formatv("[{0,0+4}/{1,0+4}] Hello World\n", ::getpid(),
-                          llvm::get_threadid())
-                .str(),
-            logAndTakeOutput("Hello World"));
+  {
+    EXPECT_TRUE(EnableChannel(
+        getStream(), LLDB_LOG_OPTION_PREPEND_PROC_AND_THREAD, "chan", {}, Err));
+    llvm::json::Object parsed_obj = logAndTakeLogObject("Hello World");
+
+    // Check that function/file parameters were added.
+    llvm::Optional<int64_t> pid = parsed_obj.getInteger("pid");
+    llvm::Optional<int64_t> tid = parsed_obj.getInteger("tid");
+    EXPECT_TRUE(pid.hasValue());
+    EXPECT_TRUE(tid.hasValue());
+
+    EXPECT_EQ(*pid, static_cast<int64_t>(::getpid()));
+    EXPECT_EQ(*tid, static_cast<int64_t>(llvm::get_threadid()));
+  }
+}
+
+TEST_F(LogChannelEnabledTest, PlainTextFormat) {
+  std::string error;
+  llvm::raw_string_ostream error_stream(error);
+  EXPECT_TRUE(
+      Log::SetLogChannelFormat("chan", Log::OutputFormat::Plain, error_stream));
+  EXPECT_EQ(error, "");
+
+  std::string Err;
+  EXPECT_EQ("Hello World\n", logAndTakeOutput("Hello World"));
+
+  // Test plain text formatting with pid/tid option set.
+  {
+    EXPECT_TRUE(EnableChannel(
+        getStream(), LLDB_LOG_OPTION_PREPEND_PROC_AND_THREAD, "chan", {}, Err));
+    const std::string expected_msg =
+        llvm::formatv("{0,0+4} {1,0+4} Hello World\n", getpid(),
+                      llvm::get_threadid())
+            .str();
+    EXPECT_EQ(expected_msg, logAndTakeOutput("Hello World"));
+  }
 }
 
 TEST_F(LogChannelEnabledTest, LLDB_LOG_ERROR) {
@@ -252,7 +302,7 @@
                  llvm::make_error<llvm::StringError>(
                      "My Error", llvm::inconvertibleErrorCode()),
                  "Foo failed: {0}");
-  ASSERT_EQ("Foo failed: My Error\n", takeOutput());
+  ASSERT_EQ("{\"message\":\"Foo failed: My Error\"},\n", takeOutput());
 
   // Doesn't log, but doesn't assert either
   LLDB_LOG_ERROR(nullptr,
@@ -274,7 +324,8 @@
   // 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_THAT(takeOutput(), testing::AnyOf("", "Hello World\n"));
+  EXPECT_THAT(takeOutput(),
+              testing::AnyOf("", "{\"message\":\"Hello World\"},\n"));
 }
 
 TEST_F(LogChannelEnabledTest, LogVerboseThread) {
@@ -292,7 +343,8 @@
   // 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_THAT(takeOutput(), testing::AnyOf("", "Hello World\n"));
+  EXPECT_THAT(takeOutput(),
+              testing::AnyOf("", "{\"message\":\"Hello World\"},\n"));
 }
 
 TEST_F(LogChannelEnabledTest, LogGetLogThread) {
Index: lldb/test/API/functionalities/logging/main.cpp
===================================================================
--- /dev/null
+++ lldb/test/API/functionalities/logging/main.cpp
@@ -0,0 +1,3 @@
+int main() {
+  return 0; // break here
+}
Index: lldb/test/API/functionalities/logging/TestLogging.py
===================================================================
--- /dev/null
+++ lldb/test/API/functionalities/logging/TestLogging.py
@@ -0,0 +1,74 @@
+import lldb
+from lldbsuite.test.decorators import *
+from lldbsuite.test.lldbtest import *
+from lldbsuite.test import lldbutil
+
+import json
+
+class TestCase(TestBase):
+
+    mydir = TestBase.compute_mydir(__file__)
+
+    @no_debug_info_test
+    def test_mixed_log_formats(self):
+        """
+        Tests having two log channels that target the same output file but with
+        different output formats (JSON and plain text).
+        """
+        self.build()
+        logfile = self.getBuildArtifact("mixed.log")
+
+        # Enable two logging channels. One uses JSON, the other plain text
+        # but they log to the same file. Timestamps are enabled so that
+        # the start of the plain text messages are just numbers and not by
+        # accident something that looks like a JSON object ("{...}").
+        self.expect("log enable -T -O json lldb target comm -f {}".format(logfile))
+        self.expect("log enable -T -O plain gdb-remote all -f {}".format(logfile))
+
+        lldbutil.run_to_source_breakpoint(self, "// break here", lldb.SBFileSpec("main.cpp"))
+
+        if configuration.is_reproducer_replay():
+            logfile = self.getReproducerRemappedPath(logfile)
+
+        self.assertTrue(os.path.isfile(logfile))
+        with open(logfile, 'r') as f:
+            log_lines = f.readlines()
+        log_content = "\n".join(log_lines)
+
+        # Go over the log and try to parse all the JSON messages. Even with
+        # the also enabled plain text logging every separate JSON message should
+        # be valid.
+        found_json = False
+        for line in log_lines:
+            line = line.strip()
+            if line.startswith("{"):
+                found_json = True
+                json_payload = line
+                # Strip the trailing comma that is behind every object in the
+                # big JSON array that the logger is printing. JSON can't have
+                # trailing commas behind the top-level object, so we have to
+                # to make the JSON parser happy by removing the comma.
+                self.assertTrue(json_payload.endswith(","), "payload: " + json_payload)
+                json_payload = json_payload[:-1]
+                parsed_payload = json.loads(json_payload)
+                # Check that message and timestamps were added to the log
+                # message.
+                self.assertIn("timestamp", parsed_payload)
+                self.assertIn("message", parsed_payload)
+
+        # Sanity check that we got at least one JSON log message.
+        self.assertTrue(found_json, "log: " + log_content)
+
+        # Go over the log and try to verify the plain text messages.
+        found_plain = False
+        for line in log_lines:
+            line = line.strip()
+            # The only thing that can be checked for plain text is that there
+            # is at least one line that starts with something that looks like
+            # a timestamp (i.e., a digit).
+            if not line.startswith("{") and len(line) != 0 and line[0].isdigit():
+                found_plain = True
+                break
+
+        # Sanity check that we got a tleast one plain text message.
+        self.assertTrue(found_plain, "log: " + log_content)
Index: lldb/test/API/functionalities/logging/Makefile
===================================================================
--- /dev/null
+++ lldb/test/API/functionalities/logging/Makefile
@@ -0,0 +1,3 @@
+CXX_SOURCES := main.cpp
+
+include Makefile.rules
Index: lldb/test/API/functionalities/completion/TestCompletion.py
===================================================================
--- lldb/test/API/functionalities/completion/TestCompletion.py
+++ lldb/test/API/functionalities/completion/TestCompletion.py
@@ -244,6 +244,14 @@
         self.complete_from_to('log enable lldb expr -f ' + src_dir,
                               [src_dir + os.sep], turn_off_re_match=True)
 
+    def test_log_enable_output_format(self):
+        self.complete_from_to('log enable -O js', ['json'])
+        self.complete_from_to('log enable -O pl', ['plain'])
+        self.complete_from_to('log enable -O ', ['json', 'plain'])
+        # No possible completion.
+        self.complete_from_to('log enable -O b',
+                              'log enable -O b')
+
     # <rdar://problem/11052829>
     def test_infinite_loop_while_completing(self):
         """Test that 'process print hello\' completes to itself and does not infinite loop."""
Index: lldb/test/API/commands/log/invalid-args/TestInvalidArgsLog.py
===================================================================
--- lldb/test/API/commands/log/invalid-args/TestInvalidArgsLog.py
+++ lldb/test/API/commands/log/invalid-args/TestInvalidArgsLog.py
@@ -21,3 +21,8 @@
         invalid_path = os.path.join("this", "is", "not", "a", "valid", "path")
         self.expect("log enable lldb all -f " + invalid_path, error=True,
                     substrs=["Unable to open log file '" + invalid_path + "': ", "\n"])
+
+    @no_debug_info_test
+    def test_disable_empty(self):
+        self.expect("log enable -O invalid_format lldb all", error=True,
+                    substrs=["error: Unknown log format: invalid_format"])
Index: lldb/source/Utility/Log.cpp
===================================================================
--- lldb/source/Utility/Log.cpp
+++ lldb/source/Utility/Log.cpp
@@ -132,14 +132,11 @@
 void Log::VAPrintf(const char *format, va_list args) {
   llvm::SmallString<64> FinalMessage;
   llvm::raw_svector_ostream Stream(FinalMessage);
-  WriteHeader(Stream, "", "");
 
   llvm::SmallString<64> Content;
   lldb_private::VASprintf(Content, format, args);
 
-  Stream << Content << "\n";
-
-  WriteMessage(std::string(FinalMessage.str()));
+  Format(/*file=*/"", /*function=*/"", llvm::formatv("{0}", Content));
 }
 
 // Printing of errors that are not fatal.
@@ -230,6 +227,17 @@
   return true;
 }
 
+bool Log::SetLogChannelFormat(llvm::StringRef channel, Log::OutputFormat format,
+                              llvm::raw_ostream &error_stream) {
+  auto iter = g_channel_map->find(channel);
+  if (iter == g_channel_map->end()) {
+    error_stream << llvm::formatv("Invalid log channel '{0}'.\n", channel);
+    return false;
+  }
+  iter->second.m_output_format = format;
+  return true;
+}
+
 bool Log::ListChannelCategories(llvm::StringRef channel,
                                 llvm::raw_ostream &stream) {
   auto ch = g_channel_map->find(channel);
@@ -277,25 +285,90 @@
   return m_options.load(std::memory_order_relaxed) & LLDB_LOG_OPTION_VERBOSE;
 }
 
-void Log::WriteHeader(llvm::raw_ostream &OS, llvm::StringRef file,
-                      llvm::StringRef function) {
+void Log::WriteMessage(llvm::StringRef json) {
+  // 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 = GetStream();
+  if (!stream_sp)
+    return;
+
   Flags options = GetOptions();
+  if (options.Test(LLDB_LOG_OPTION_THREADSAFE)) {
+    static std::recursive_mutex g_LogThreadedMutex;
+    std::lock_guard<std::recursive_mutex> guard(g_LogThreadedMutex);
+    *stream_sp << json;
+    stream_sp->flush();
+  } else {
+    *stream_sp << json;
+    stream_sp->flush();
+  }
+}
+
+namespace {
+struct PlainTextWriter {
+  llvm::raw_ostream &m_output;
+  /// True if any output has been written by this class to this point.
+  bool m_anything_written = false;
+  explicit PlainTextWriter(llvm::raw_ostream &output) : m_output(output) {}
+  ~PlainTextWriter() { m_output << "\n"; }
+  void PrintSeparatorIfNeeded() {
+    // The first output at the start of the line doesn't need a separating
+    // space.
+    if (!m_anything_written)
+      return;
+    m_output << " ";
+  }
+  template <class T> void Write(llvm::StringRef key, const T &value) {
+    PrintSeparatorIfNeeded();
+    m_anything_written = true;
+    m_output << value;
+  }
+  template <> void Write<double>(llvm::StringRef key, const double &value) {
+    PrintSeparatorIfNeeded();
+    m_anything_written = true;
+    // Limit the precision of printed doubles.
+    m_output << llvm::formatv("{0:f9}", value);
+  }
+};
+struct JSONWriter {
+  llvm::raw_ostream &m_output;
+  llvm::json::OStream m_json;
+  explicit JSONWriter(llvm::raw_ostream &output)
+      : m_output(output), m_json(output) {
+    m_json.objectBegin();
+  }
+  ~JSONWriter() {
+    m_json.objectEnd();
+    m_json.flush();
+    m_output << ",\n";
+  }
+  template <class T> void Write(llvm::StringRef key, const T &value) {
+    m_json.attribute(key, value);
+  }
+};
+} // namespace
+
+template <class Writer>
+static void BuildMessage(Writer &output, const Flags options,
+                         llvm::StringRef file, llvm::StringRef function,
+                         llvm::StringRef message) {
   static uint32_t g_sequence_id = 0;
   // Add a sequence ID if requested
   if (options.Test(LLDB_LOG_OPTION_PREPEND_SEQUENCE))
-    OS << ++g_sequence_id << " ";
+    output.Write("sequence-id", ++g_sequence_id);
 
   // Timestamp if requested
   if (options.Test(LLDB_LOG_OPTION_PREPEND_TIMESTAMP)) {
     auto now = std::chrono::duration<double>(
         std::chrono::system_clock::now().time_since_epoch());
-    OS << llvm::formatv("{0:f9} ", now.count());
+    output.Write("timestamp", now.count());
   }
 
   // Add the process and thread if requested
-  if (options.Test(LLDB_LOG_OPTION_PREPEND_PROC_AND_THREAD))
-    OS << llvm::formatv("[{0,0+4}/{1,0+4}] ", getpid(),
-                        llvm::get_threadid());
+  if (options.Test(LLDB_LOG_OPTION_PREPEND_PROC_AND_THREAD)) {
+    output.Write("pid", static_cast<int64_t>(getpid()));
+    output.Write("tid", static_cast<int64_t>(llvm::get_threadid()));
+  }
 
   // Add the thread name if requested
   if (options.Test(LLDB_LOG_OPTION_PREPEND_THREAD_NAME)) {
@@ -305,45 +378,44 @@
     llvm::SmallString<12> format_str;
     llvm::raw_svector_ostream format_os(format_str);
     format_os << "{0,-" << llvm::alignTo<16>(thread_name.size()) << "} ";
-    OS << llvm::formatv(format_str.c_str(), thread_name);
+    output.Write("thread-name", thread_name);
   }
 
-  if (options.Test(LLDB_LOG_OPTION_BACKTRACE))
-    llvm::sys::PrintStackTrace(OS);
+  if (options.Test(LLDB_LOG_OPTION_BACKTRACE)) {
+    std::string stacktrace;
+    llvm::raw_string_ostream stacktrace_stream(stacktrace);
+    llvm::sys::PrintStackTrace(stacktrace_stream);
+    stacktrace_stream.flush();
+    output.Write("stacktrace", stacktrace);
+  }
 
   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);
-    OS << llvm::formatv("{0,-60:60} ", (file + ":" + function).str());
+    output.Write("file", llvm::sys::path::filename(file));
+    output.Write("function", function);
   }
-}
-
-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 = GetStream();
-  if (!stream_sp)
-    return;
 
-  Flags options = GetOptions();
-  if (options.Test(LLDB_LOG_OPTION_THREADSAFE)) {
-    static std::recursive_mutex g_LogThreadedMutex;
-    std::lock_guard<std::recursive_mutex> guard(g_LogThreadedMutex);
-    *stream_sp << message;
-    stream_sp->flush();
-  } else {
-    *stream_sp << message;
-    stream_sp->flush();
-  }
+  output.Write("message", message);
 }
 
 void Log::Format(llvm::StringRef file, llvm::StringRef function,
                  const llvm::formatv_object_base &payload) {
   std::string message_string;
   llvm::raw_string_ostream message(message_string);
-  WriteHeader(message, file, function);
-  message << payload << "\n";
+
+  switch (m_output_format.load(std::memory_order_relaxed)) {
+  case Log::OutputFormat::JSON: {
+    JSONWriter json_writer(message);
+    BuildMessage(json_writer, GetOptions(), file, function, payload.str());
+    break;
+  }
+  case Log::OutputFormat::Plain: {
+    PlainTextWriter plain_writer(message);
+    BuildMessage(plain_writer, GetOptions(), file, function, payload.str());
+    break;
+  }
+  }
+
   WriteMessage(message.str());
 }
 
Index: lldb/source/Interpreter/CommandObject.cpp
===================================================================
--- lldb/source/Interpreter/CommandObject.cpp
+++ lldb/source/Interpreter/CommandObject.cpp
@@ -1069,6 +1069,7 @@
     { eArgTypeFileLineColumn, "linespec", CommandCompletions::eNoCompletion, { nullptr, false }, "A source specifier in the form file:line[:column]" },
     { eArgTypeLogCategory, "log-category", CommandCompletions::eNoCompletion, { nullptr, false }, "The name of a category within a log channel, e.g. all (try \"log list\" to see a list of all channels and their categories." },
     { eArgTypeLogChannel, "log-channel", CommandCompletions::eNoCompletion, { nullptr, false }, "The name of a log channel, e.g. process.gdb-remote (try \"log list\" to see a list of all channels and their categories)." },
+    { eArgTypeLogFormat, "log-format", CommandCompletions::eLogFormatCompletion, { nullptr, false }, "One of LLDB's supported log file formats." },
     { eArgTypeMethod, "method", CommandCompletions::eNoCompletion, { nullptr, false }, "A C++ method name." },
     { eArgTypeName, "name", CommandCompletions::eTypeCategoryNameCompletion, { nullptr, false }, "Help text goes here." },
     { eArgTypeNewPathPrefix, "new-path-prefix", CommandCompletions::eNoCompletion, { nullptr, false }, "Help text goes here." },
Index: lldb/source/Commands/Options.td
===================================================================
--- lldb/source/Commands/Options.td
+++ lldb/source/Commands/Options.td
@@ -443,6 +443,8 @@
     Desc<"Append to the log file instead of overwriting.">;
   def log_file_function : Option<"file-function", "F">, Group<1>,
     Desc<"Prepend the names of files and function that generate the logs.">;
+  def log_format : Option<"format", "O">, Group<1>, Arg<"LogFormat">,
+    Desc<"Specify the used log format for the enabled channels.">;
 }
 
 let Command = "reproducer dump" in {
Index: lldb/source/Commands/CommandObjectLog.cpp
===================================================================
--- lldb/source/Commands/CommandObjectLog.cpp
+++ lldb/source/Commands/CommandObjectLog.cpp
@@ -117,6 +117,16 @@
       case 'F':
         log_options |= LLDB_LOG_OPTION_PREPEND_FILE_FUNCTION;
         break;
+      case 'O': {
+        Log::OutputFormatMapping mapping = Log::GetOutputFormatNameMapping();
+        auto found_format = mapping.find(option_arg);
+        if (found_format == mapping.end()) {
+          error.SetErrorString("Unknown log format: " + option_arg.str());
+          break;
+        }
+        log_format = found_format->second;
+        break;
+      }
       default:
         llvm_unreachable("Unimplemented option");
       }
@@ -127,6 +137,7 @@
     void OptionParsingStarting(ExecutionContext *execution_context) override {
       log_file.Clear();
       log_options = 0;
+      log_format = Log::OutputFormat::Plain;
     }
 
     llvm::ArrayRef<OptionDefinition> GetDefinitions() override {
@@ -137,6 +148,7 @@
 
     FileSpec log_file;
     uint32_t log_options = 0;
+    Log::OutputFormat log_format = Log::OutputFormat::Plain;
   };
 
   void
@@ -168,6 +180,10 @@
     bool success =
         GetDebugger().EnableLog(channel, args.GetArgumentArrayRef(), log_file,
                                 m_options.log_options, error_stream);
+    if (success)
+      success |=
+          Log::SetLogChannelFormat(channel, m_options.log_format, error_stream);
+
     result.GetErrorStream() << error_stream.str();
 
     if (success)
Index: lldb/source/Commands/CommandCompletions.cpp
===================================================================
--- lldb/source/Commands/CommandCompletions.cpp
+++ lldb/source/Commands/CommandCompletions.cpp
@@ -78,6 +78,7 @@
       {eRemoteDiskDirectoryCompletion,
        CommandCompletions::RemoteDiskDirectories},
       {eTypeCategoryNameCompletion, CommandCompletions::TypeCategoryNames},
+      {eLogFormatCompletion, CommandCompletions::LogFormats},
       {eNoCompletion, nullptr} // This one has to be last in the list.
   };
 
@@ -792,3 +793,10 @@
         return true;
       });
 }
+
+void CommandCompletions::LogFormats(CommandInterpreter &,
+                                    CompletionRequest &request,
+                                    SearchFilter *) {
+  for (const auto &key_value : Log::GetOutputFormatNameMapping())
+    request.TryCompleteCurrentArg(key_value.first());
+}
Index: lldb/include/lldb/lldb-enumerations.h
===================================================================
--- lldb/include/lldb/lldb-enumerations.h
+++ lldb/include/lldb/lldb-enumerations.h
@@ -547,6 +547,7 @@
   eArgTypeLineNum,
   eArgTypeLogCategory,
   eArgTypeLogChannel,
+  eArgTypeLogFormat,
   eArgTypeMethod,
   eArgTypeName,
   eArgTypeNewPathPrefix,
Index: lldb/include/lldb/Utility/Log.h
===================================================================
--- lldb/include/lldb/Utility/Log.h
+++ lldb/include/lldb/Utility/Log.h
@@ -19,6 +19,7 @@
 #include "llvm/ADT/StringRef.h"
 #include "llvm/Support/Error.h"
 #include "llvm/Support/FormatVariadic.h"
+#include "llvm/Support/JSON.h"
 #include "llvm/Support/ManagedStatic.h"
 #include "llvm/Support/RWMutex.h"
 
@@ -55,6 +56,23 @@
     uint32_t flag;
   };
 
+  /// The format used when emitting log messages.
+  enum class OutputFormat {
+    /// Log messages are printed as plain text.
+    Plain,
+    /// Log messages are printed as JSON objects.
+    JSON,
+  };
+
+  typedef llvm::StringMap<OutputFormat> OutputFormatMapping;
+  /// Returns the mapping from format names to their \b OutputFormat value.
+  static OutputFormatMapping GetOutputFormatNameMapping() {
+    return {
+        {"plain", OutputFormat::Plain},
+        {"json", OutputFormat::JSON},
+    };
+  }
+
   // This class describes a log channel. It also encapsulates the behavior
   // necessary to enable a log channel in an atomic manner.
   class Channel {
@@ -110,6 +128,16 @@
                                 llvm::ArrayRef<const char *> categories,
                                 llvm::raw_ostream &error_stream);
 
+  /// Sets the log format for the specified channel.
+  ///
+  /// \param channel A string identifying the channel name such as 'lldb'.
+  /// \param format The log format that the channel should have.
+  /// \param error_stream On error, contains an error that should be displayed
+  ///                     to the user.
+  /// \return True iff the channel format was set successfully.
+  static bool SetLogChannelFormat(llvm::StringRef channel, OutputFormat format,
+                                  llvm::raw_ostream &error_stream);
+
   static bool ListChannelCategories(llvm::StringRef channel,
                                     llvm::raw_ostream &stream);
 
@@ -179,12 +207,12 @@
   llvm::sys::RWMutex m_mutex;
 
   std::shared_ptr<llvm::raw_ostream> m_stream_sp;
+  /// Log output format of the current channel.
+  std::atomic<OutputFormat> m_output_format = {OutputFormat::Plain};
   std::atomic<uint32_t> m_options{0};
   std::atomic<uint32_t> m_mask{0};
 
-  void WriteHeader(llvm::raw_ostream &OS, llvm::StringRef file,
-                   llvm::StringRef function);
-  void WriteMessage(const std::string &message);
+  void WriteMessage(llvm::StringRef message);
 
   void Format(llvm::StringRef file, llvm::StringRef function,
               const llvm::formatv_object_base &payload);
Index: lldb/include/lldb/Interpreter/CommandCompletions.h
===================================================================
--- lldb/include/lldb/Interpreter/CommandCompletions.h
+++ lldb/include/lldb/Interpreter/CommandCompletions.h
@@ -50,6 +50,7 @@
     eRemoteDiskFileCompletion = (1u << 22),
     eRemoteDiskDirectoryCompletion = (1u << 23),
     eTypeCategoryNameCompletion = (1u << 24),
+    eLogFormatCompletion = (1u << 25),
     // This item serves two purposes.  It is the last element in the enum, so
     // you can add custom enums starting from here in your Option class. Also
     // if you & in this bit the base code will not process the option.
@@ -151,6 +152,10 @@
   static void TypeCategoryNames(CommandInterpreter &interpreter,
                                 CompletionRequest &request,
                                 SearchFilter *searcher);
+
+  /// Completes LLDB log format names.
+  static void LogFormats(CommandInterpreter &interpreter,
+                         CompletionRequest &request, SearchFilter *searcher);
 };
 
 } // namespace lldb_private
Index: lldb/docs/index.rst
===================================================================
--- lldb/docs/index.rst
+++ lldb/docs/index.rst
@@ -160,6 +160,7 @@
    design/overview
    design/reproducers
    design/sbapi
+   design/logging
 
 .. toctree::
    :hidden:
Index: lldb/docs/design/logging.rst
===================================================================
--- /dev/null
+++ lldb/docs/design/logging.rst
@@ -0,0 +1,99 @@
+Logging
+=======
+
+LLDB can create logs that describe events occuring during a debug session. These
+logs are intended to be used as an aid when trying to understand LLDB's
+behaviour from a developer perspective. Users are usually not expected to
+enable or read logs.
+
+LLDB's logging framework organizes logs into channels each identified by
+a name (e.g., ``lldb``, ```dwarf```, etc.). Each channel is further divided
+into several categories which are also identified by a name (e.g., the``api``
+category in the ``lldb`` channel is used to log information about SB API calls).
+
+Each log message is associated with a specific category in a specific channel.
+A message is only emitted when their respective category is enabled.
+
+There are two ways to enable and disable logging in lldb. The ``log``
+command offers the ``enable`` and ``disable`` subcommands which take a channel
+and a list of categories to enable/disable. From the SB API the
+`SBDebugger.EnableLog` function can also be used to enable a log channel and
+category.
+
+LLDB allows configuring format that log messages are emitted in and what
+metainformation should be attached to each log message. These options can
+be set for each logging channel (but not separately for each logging category).
+The output of each channel can also be directed to write to a log file,
+to the standard output of the LLDB process or a logging callback specified
+by the user (when using `SBDebugger.EnableLog`).
+
+Supported log formats in LLDB are plain text and JSON. The metainformation
+that can be added to log messages includes timestamps, LLDB's own pid, or the
+backtraces of where the log message was generated. See the options of the
+``log enable`` command for a full list of ways to configure a logging channel.
+
+JSON log format
+---------------
+
+While the plain text log format is intended to be human-readable, the JSON
+log format is only intended to be read by other programs. These other programs
+can post-process the log files to filter them or present them in a more
+sophisticated way such as a table.
+
+The JSON log format used by LLDB to log messages is not expected to change, but
+it is also not guaranteed to be stable across LLDB releases. Users should not
+rely on the format to be stable.
+
+The current JSON log format puts each log message in its own JSON object. Each
+object also contains a trailing comma character (``,``). The intended way of
+parsing a JSON log file is strip the last trailing comma character and then
+surround the whole contents with brackets (``[]``). This way the list of
+JSON objects printed by LLDB will form one single top-level JSON array object
+that a normal JSON parser can parse. The listing below contains an example log
+file in the JSON format.
+
+::
+
+    {"timestamp":24028401.002, "message":"A log message"},
+    {"timestamp":24028401.004, "message":"Another log message"},
+
+
+Each JSON message object can contain several fields. The only mandatory field
+in a message object is the ``message`` field. All other fields are optional
+and are only created when the respective option in their logging channel is
+set.
+
+.. list-table:: JSON message fields
+   :header-rows: 1
+   :widths: 1 1 10
+
+   * - Field name
+     - JavaScript Type
+     - Description
+   * - ``message``
+     - String
+     - The log message itself.
+   * - ``sequence-id``
+     - Number
+     - A number uniquely identifying a log message within one debugging session.
+   * - ``timestamp``
+     - Number
+     - The number of seconds since the host systems epoch (usually UNIX time).
+   * - ``pid``
+     - Number
+     - The process id of the LLDB process itself.
+   * - ``tid``
+     - Number
+     - The thread id of the thread in the LLDB process that generated the log message.
+   * - ``thread-name``
+     - String
+     - The host specific name of the thread that generated the log message.
+   * - ``stacktrace``
+     - String
+     - A textual representation of the stacktrace to where the log message was generated from.
+   * - ``function``
+     - String
+     - The name of the function within the log message is generated.
+   * - ``file``
+     - String
+     - The path to the LLDB source file where the log message is generated.
_______________________________________________
lldb-commits mailing list
lldb-commits@lists.llvm.org
https://lists.llvm.org/cgi-bin/mailman/listinfo/lldb-commits

Reply via email to