Author: Raphael Isemann Date: 2026-06-29T08:49:29Z New Revision: 41ef9d77f7826ec45e83ab4c6b83a96d735830c6
URL: https://github.com/llvm/llvm-project/commit/41ef9d77f7826ec45e83ab4c6b83a96d735830c6 DIFF: https://github.com/llvm/llvm-project/commit/41ef9d77f7826ec45e83ab4c6b83a96d735830c6.diff LOG: [lldb] Add option to log in JSONL format (#205758) This patch adds a -j option to the log command that prints all log messages as their own single-line JSON objects. The resulting output log file is then a valid JSONL file with the message and metadata as their own fields. The motivation for this change is that writing any tooling that analyzses LLDB logs is currently very difficult to get right. Our current log messages often span multiple lines, and even the metadata (e.g., stacktraces) span multiple lines. Even worse, the message content is effectively arbitrary bytes (such as memory values) that need can only be parsed back into a series of log messages via several heuristics. assisted-by: claude Added: Modified: lldb/include/lldb/Utility/Log.h lldb/source/Commands/CommandObjectLog.cpp lldb/source/Commands/Options.td lldb/source/Utility/Log.cpp lldb/test/API/commands/log/basic/TestLogging.py lldb/unittests/Utility/LogTest.cpp Removed: ################################################################################ diff --git a/lldb/include/lldb/Utility/Log.h b/lldb/include/lldb/Utility/Log.h index 9da33f5f39562..73b9764508cbf 100644 --- a/lldb/include/lldb/Utility/Log.h +++ b/lldb/include/lldb/Utility/Log.h @@ -31,6 +31,9 @@ namespace llvm { class raw_ostream; +namespace json { +class Object; +} } // Logging Options #define LLDB_LOG_OPTION_VERBOSE (1u << 1) @@ -41,6 +44,7 @@ class raw_ostream; #define LLDB_LOG_OPTION_BACKTRACE (1U << 7) #define LLDB_LOG_OPTION_APPEND (1U << 8) #define LLDB_LOG_OPTION_PREPEND_FILE_FUNCTION (1U << 9) +#define LLDB_LOG_OPTION_JSON (1U << 10) // Logging Functions namespace lldb_private { @@ -288,7 +292,11 @@ class Log final { void WriteHeader(llvm::raw_ostream &OS, llvm::StringRef file, llvm::StringRef function); + void WriteJSONHeader(llvm::json::Object &obj, llvm::StringRef file, + llvm::StringRef function); void WriteMessage(llvm::StringRef message); + void EmitJSONMessage(llvm::StringRef file, llvm::StringRef function, + llvm::StringRef message); void Format(llvm::StringRef file, llvm::StringRef function, const llvm::formatv_object_base &payload); diff --git a/lldb/source/Commands/CommandObjectLog.cpp b/lldb/source/Commands/CommandObjectLog.cpp index e51a85e9f0308..945dc6210bfea 100644 --- a/lldb/source/Commands/CommandObjectLog.cpp +++ b/lldb/source/Commands/CommandObjectLog.cpp @@ -129,6 +129,9 @@ class CommandObjectLogEnable : public CommandObjectParsed { case 'F': log_options |= LLDB_LOG_OPTION_PREPEND_FILE_FUNCTION; break; + case 'j': + log_options |= LLDB_LOG_OPTION_JSON; + break; default: llvm_unreachable("Unimplemented option"); } diff --git a/lldb/source/Commands/Options.td b/lldb/source/Commands/Options.td index 1f525c07f852a..f118f219f5ec1 100644 --- a/lldb/source/Commands/Options.td +++ b/lldb/source/Commands/Options.td @@ -915,6 +915,9 @@ let Command = "log enable" in { : Option<"file-function", "F">, Group<1>, Desc<"Prepend the names of files and function that generate the logs.">; + def log_json : Option<"json", "j">, + Group<1>, + Desc<"Emit each log message as its own JSON object.">; } let Command = "log dump" in { diff --git a/lldb/source/Utility/Log.cpp b/lldb/source/Utility/Log.cpp index 6b077a3766e9f..09b4eb05f2edd 100644 --- a/lldb/source/Utility/Log.cpp +++ b/lldb/source/Utility/Log.cpp @@ -15,6 +15,7 @@ #include "llvm/Support/Casting.h" #include "llvm/Support/Chrono.h" +#include "llvm/Support/JSON.h" #include "llvm/Support/ManagedStatic.h" #include "llvm/Support/Path.h" #include "llvm/Support/Signals.h" @@ -47,6 +48,10 @@ llvm::ManagedStatic<Log::ChannelMap> Log::g_channel_map; // LLDB_LOG_ERROR is not enabled, error messages are logged to the error log. static std::atomic<Log *> g_error_log = nullptr; +// Shared sequence counter used by both the text and JSON header writers so +// sequence numbers stay consistent regardless of output format. +static uint32_t g_sequence_id = 0; + void Log::ForEachCategory( const Log::ChannelMap::value_type &entry, llvm::function_ref<void(llvm::StringRef, llvm::StringRef)> lambda) { @@ -145,6 +150,10 @@ Log::MaskType Log::GetMask() const { void Log::PutCString(const char *cstr) { PutString(cstr); } void Log::PutString(llvm::StringRef str) { + if (GetOptions().Test(LLDB_LOG_OPTION_JSON)) { + EmitJSONMessage("", "", str); + return; + } std::string FinalMessage; llvm::raw_string_ostream Stream(FinalMessage); WriteHeader(Stream, "", ""); @@ -304,7 +313,6 @@ bool Log::GetVerbose() const { void Log::WriteHeader(llvm::raw_ostream &OS, llvm::StringRef file, llvm::StringRef function) { Flags options = GetOptions(); - 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 << " "; @@ -343,6 +351,45 @@ void Log::WriteHeader(llvm::raw_ostream &OS, llvm::StringRef file, } } +void Log::WriteJSONHeader(llvm::json::Object &obj, llvm::StringRef file, + llvm::StringRef function) { + Flags options = GetOptions(); + if (options.Test(LLDB_LOG_OPTION_PREPEND_SEQUENCE)) + obj["sequence"] = ++g_sequence_id; + + if (options.Test(LLDB_LOG_OPTION_PREPEND_TIMESTAMP)) { + auto now = std::chrono::duration<double>( + std::chrono::system_clock::now().time_since_epoch()); + obj["timestamp"] = now.count(); + } + + if (options.Test(LLDB_LOG_OPTION_PREPEND_PROC_AND_THREAD)) { + obj["pid"] = static_cast<int64_t>(getpid()); + obj["tid"] = static_cast<int64_t>(llvm::get_threadid()); + } + + if (options.Test(LLDB_LOG_OPTION_PREPEND_THREAD_NAME)) { + llvm::SmallString<32> thread_name; + llvm::get_thread_name(thread_name); + // Value(StringRef) stores by reference; copy into a std::string so the + // Value owns the data and we don't dangle once `thread_name` goes away. + obj["thread_name"] = std::string(thread_name); + } + + if (options.Test(LLDB_LOG_OPTION_BACKTRACE)) { + std::string backtrace; + llvm::raw_string_ostream backtrace_os(backtrace); + llvm::sys::PrintStackTrace(backtrace_os); + obj["backtrace"] = std::move(backtrace); + } + + if (options.Test(LLDB_LOG_OPTION_PREPEND_FILE_FUNCTION) && + (!file.empty() || !function.empty())) { + obj["file"] = llvm::sys::path::filename(file); + obj["function"] = function; + } +} + // If we have a callback registered, then we call the logging callback. If we // have a valid file handle, we also log to the file. void Log::WriteMessage(llvm::StringRef message) { @@ -356,6 +403,10 @@ void Log::WriteMessage(llvm::StringRef message) { void Log::Format(llvm::StringRef file, llvm::StringRef function, const llvm::formatv_object_base &payload) { + if (GetOptions().Test(LLDB_LOG_OPTION_JSON)) { + EmitJSONMessage(file, function, payload.str()); + return; + } std::string message_string; llvm::raw_string_ostream message(message_string); WriteHeader(message, file, function); @@ -363,6 +414,17 @@ void Log::Format(llvm::StringRef file, llvm::StringRef function, WriteMessage(message_string); } +void Log::EmitJSONMessage(llvm::StringRef file, llvm::StringRef function, + llvm::StringRef message) { + llvm::json::Object obj; + WriteJSONHeader(obj, file, function); + obj["message"] = message; + std::string out; + llvm::raw_string_ostream os(out); + os << llvm::json::Value(std::move(obj)) << "\n"; + WriteMessage(out); +} + StreamLogHandler::StreamLogHandler(int fd, bool should_close, size_t buffer_size) : m_stream(fd, should_close, buffer_size == 0) { diff --git a/lldb/test/API/commands/log/basic/TestLogging.py b/lldb/test/API/commands/log/basic/TestLogging.py index daa32dc85753d..eacf8d83390f7 100644 --- a/lldb/test/API/commands/log/basic/TestLogging.py +++ b/lldb/test/API/commands/log/basic/TestLogging.py @@ -4,6 +4,7 @@ import os +import json import lldb from lldbsuite.test.decorators import * from lldbsuite.test.lldbtest import * @@ -94,3 +95,32 @@ def test_all_log_options(self): self.runCmd("log disable lldb") self.assertTrue(os.path.isfile(self.log_file)) + + # Check that -j produces a valid JSONL log file where every line is a JSON + # object and the requested metadata flags surface as JSON fields rather + # than line prefixes. + def test_json_output(self): + if os.path.exists(self.log_file): + os.remove(self.log_file) + + self.runCmd("log enable -j -s -T -p -F -f '%s' lldb commands" % self.log_file) + self.runCmd("help log") + self.runCmd("log disable lldb") + + self.assertTrue(os.path.isfile(self.log_file)) + with open(self.log_file, "r") as f: + lines = f.readlines() + + self.assertGreater(len(lines), 0, "log file should not be empty") + for line in lines: + # Every line must parse as JSON on its own. + obj = json.loads(line) + self.assertIsInstance(obj, dict) + self.assertIn("message", obj) + # The flags we passed must turn into JSON fields. + self.assertIn("sequence", obj) + self.assertIn("timestamp", obj) + self.assertIn("pid", obj) + self.assertIn("tid", obj) + self.assertIn("file", obj) + self.assertIn("function", obj) diff --git a/lldb/unittests/Utility/LogTest.cpp b/lldb/unittests/Utility/LogTest.cpp index 602d019adac54..fed0a5274b948 100644 --- a/lldb/unittests/Utility/LogTest.cpp +++ b/lldb/unittests/Utility/LogTest.cpp @@ -12,6 +12,7 @@ #include "lldb/Utility/Log.h" #include "lldb/Utility/StreamString.h" #include "llvm/ADT/BitmaskEnum.h" +#include "llvm/Support/JSON.h" #include "llvm/Support/ManagedStatic.h" #include "llvm/Support/Threading.h" #include <thread> @@ -335,6 +336,51 @@ TEST_F(LogChannelEnabledTest, log_options) { logAndTakeOutput("Hello World")); } +TEST_F(LogChannelEnabledTest, JSONLOutput) { + std::string Err; + + // With JSON, every line must parse as JSON and contain exactly the message we + // logged. + EXPECT_TRUE(EnableChannel( + getLogHandler(), /*log_options=*/LLDB_LOG_OPTION_JSON, "chan", {}, Err)); + llvm::StringRef Msg = logAndTakeOutput("Hello \"World\"\nsecond line"); + ASSERT_TRUE(Msg.ends_with("\n")); + ASSERT_EQ(Msg.count('\n'), 1u) << "expected one JSON object per line"; + llvm::Expected<llvm::json::Value> Parsed = llvm::json::parse(Msg); + ASSERT_TRUE(static_cast<bool>(Parsed)) << llvm::toString(Parsed.takeError()); + llvm::json::Object *Obj = Parsed->getAsObject(); + ASSERT_NE(Obj, nullptr); + EXPECT_EQ(Obj->getString("message").value_or(""), + "Hello \"World\"\nsecond line"); + EXPECT_EQ(Obj->size(), 1u); + + // Combining JSON with metadata flags: each metadata flag becomes a JSON + // field instead of a prefix on the line. + uint32_t Opts = LLDB_LOG_OPTION_JSON | LLDB_LOG_OPTION_PREPEND_SEQUENCE | + LLDB_LOG_OPTION_PREPEND_TIMESTAMP | + LLDB_LOG_OPTION_PREPEND_PROC_AND_THREAD | + LLDB_LOG_OPTION_PREPEND_THREAD_NAME | + LLDB_LOG_OPTION_BACKTRACE | + LLDB_LOG_OPTION_PREPEND_FILE_FUNCTION; + EXPECT_TRUE(EnableChannel(getLogHandler(), Opts, "chan", {}, Err)); + Msg = logAndTakeOutput("payload"); + Parsed = llvm::json::parse(Msg); + ASSERT_TRUE(static_cast<bool>(Parsed)) << llvm::toString(Parsed.takeError()); + Obj = Parsed->getAsObject(); + ASSERT_NE(Obj, nullptr); + EXPECT_EQ(Obj->getString("message").value_or(""), "payload"); + EXPECT_TRUE(Obj->getInteger("sequence").has_value()); + EXPECT_TRUE(Obj->getNumber("timestamp").has_value()); + EXPECT_EQ(Obj->getInteger("pid").value_or(-1), + static_cast<int64_t>(::getpid())); + EXPECT_EQ(Obj->getInteger("tid").value_or(-1), + static_cast<int64_t>(llvm::get_threadid())); + EXPECT_TRUE(Obj->getString("thread_name").has_value()); + EXPECT_TRUE(Obj->getString("backtrace").has_value()); + EXPECT_EQ(Obj->getString("file").value_or(""), "LogTest.cpp"); + EXPECT_EQ(Obj->getString("function").value_or(""), "logAndTakeOutput"); +} + TEST_F(LogChannelEnabledTest, LLDB_LOG_ERROR) { LLDB_LOG_ERROR(getLog(), llvm::Error::success(), "Foo failed: {0}"); ASSERT_EQ("", takeOutput()); _______________________________________________ lldb-commits mailing list [email protected] https://lists.llvm.org/cgi-bin/mailman/listinfo/lldb-commits
