[lldb] Add support for specifying a log handler

[JDevlieghere]

Summary

This patch adds a new flag to log enable allowing the user to specify a log handler. This makes it possible to enable logging to a circular buffer (D127937) or with OSLog (D128321) as well as the default stream handler. As is the patch is more of an RFC/POC. It needs some cleaning up as well as a test case, which I'll add if everyone is happy with the direction.

[clayborg]

lldb/include/lldb/lldb-private-enumerations.h

229

Maybe "eLogHandlerCircular"?

230

remove #if. See inlined comments in https://reviews.llvm.org/D128321

lldb/source/Commands/CommandObjectLog.cpp

37

remove #if (see https://reviews.llvm.org/D128321)

41

170

Do we want to define a "eLogHandlerDefault" which points to "eLogHandlerStream"?

lldb/source/Commands/Options.td

438–439

Maybe "--type" or "--kind" would be better? Handler seems like an internal name. Maybe also mention what it will default to if not specified? Can the user see a list of the valid values or do we need to supply these in the description?

lldb/source/Core/Debugger.cpp

1418

remove #if (see https://reviews.llvm.org/D128321)

[mib]

lldb/source/Core/Debugger.cpp

1409–1411

Many (or most) arguments passed to this function might not be used depending on the kind of LogHandler you're instantiating. This is fine for now but if we add other handlers in the future that take different argument, it might become very confusing on which one to use.

May be we could use a parameter pack with some template specialization to make this more robust ?

1440

I find it confusing to negate should_close but to initialize it to true.

Since it’s not modified anywhere else, IMO it might be better to inline the value with a comment (/*should_close=*/), instead of using the variable.

1462

Ditto

[mib]

lldb/source/Commands/CommandObjectLog.cpp

170

I was hoping we could use a type alias for this, that marks eLogHandlerStream as eLogHandlerDefault but I couldn't find of a nice C++ way to do it :/

[JDevlieghere]

lldb/source/Commands/Options.td

438–439

I think the concept of a "log handler" is sufficiently well known that it should be easy for a a (power) user to understand. I'm concerned that "type" and "kind" are a tad too high level, and therefore could easily be confused with the log category and channel. For example, when someone asks to enable the "gdb packet log", is that a category, channel, type or kind?

lldb/source/Core/Debugger.cpp

1409–1411

What did you have in mind? We don't know a-priori what the type will be. You could template the function in the enum value, but you still wouldn't know which arguments to pass before dispatching to the right function.

[clayborg]

lldb/source/Commands/CommandObjectLog.cpp

26

Question: how does one see these values and their descriptions? Do the descriptions get displayed anywhere? If they do, then my comments below make sense, if the don't, then ignore below comments and maybe roll all that documentation into the main description for this command.

30

It doesn't seem very clear to the user what "stream" means here. Is says it will use one, but what is a stream? Maybe expand on this will output the log to the debugger stderr or to a file if used with the -f option? Maybe "default" is a better user facing term here?

34–35

circular makes more sense to use as the name IMHO. Not sure what rotating means for a log handler. Maybe expand on if this is enabled, you can see the cached log lines by using "log dump" and it will keep X amount of messages? Or does the user need to specify a size of a buffer somewhere?

40

Just saying that we will use the system log handler doesn't really explain what is going on here. Maybe "Log messages to the OS's default system log."

140–142

Can we also add the valid values that users can choose from in this error message? If the user types "log enable -h wrong", how does the user know what the valid values to use are?

lldb/source/Commands/Options.td

438–439

How can the user see the available options? I always have to type an incorrect value in for enums and then I see a correction saying "you can only specify 'a', 'b', or 'c'"

440–441

Should this be moved to the enum description?

[JDevlieghere]

lldb/source/Commands/CommandObjectLog.cpp

26

The values are printed in the help output:

-h <log-handler> ( --log-handler <log-handler> )
     Specify a log handler which determines where log messages are written.
     Values: default | circular | os

The usage/description is not. As far as I can tell, it isn't printed anywhere. I talked it over with @jingham and it should get printed in the help <log-hander> output but currently that's not the case.

(lldb) help <log-handler>
  <log-handler> -- The log handle that will be used to write out log messages.

To make that work we need to tie the actual enum to the ArgumentTableEntry in in CommandObject.cpp. I think that's something we should do, but that's outside the scope of this patch.

lldb/source/Commands/Options.td

438–439

This is part of the help output.

[labath]

lldb/source/Commands/CommandObjectLog.cpp

170

Were you maybe looking for something like:

enum {
 foo_1,
 foo_2,
 ...,
  foo_default = foo_47
};

[JDevlieghere]

Add eLogHandlerDefault = eLogHandlerStream.

[JDevlieghere]

Improve help and error message

[mib]

lldb/source/Commands/CommandObjectLog.cpp

170

That could do :) ! I was thinking of doing :

enum {
foo_1,
foo_2,
...
};

using foo_default = foo_1;

But I don't think this works.

lldb/include/lldb/Core/Debugger.h

public:
 
   bool GetCloseInputOnEOF() const;
 
   void SetCloseInputOnEOF(bool b);
 
   bool EnableLog(llvm::StringRef channel,
                  llvm::ArrayRef<const char *> categories,
                  llvm::StringRef log_file, uint32_t log_options,
-                 size_t buffer_size, llvm::raw_ostream &error_stream);
+                 size_t buffer_size, LogHandlerKind log_handler_kind,
+                 llvm::raw_ostream &error_stream);
 
   void SetLoggingCallback(lldb::LogOutputCallback log_callback, void *baton);
 
   // Properties Functions
   enum StopDisassemblyType {
     eStopDisassemblyTypeNever = 0,
     eStopDisassemblyTypeNoDebugInfo,
     eStopDisassemblyTypeNoSource,

lldb/include/lldb/lldb-enumerations.h

enum CommandArgumentType {
   eArgTypeWatchpointID,
   eArgTypeWatchpointIDRange,
   eArgTypeWatchType,
   eArgRawInput,
   eArgTypeCommand,
   eArgTypeColumnNum,
   eArgTypeModuleUUID,
   eArgTypeSaveCoreStyle,
+  eArgTypeLogHandler,
   eArgTypeLastArg // Always keep this entry as the last entry in this
                   // enumeration!!
 };
 
 /// Symbol types.
 // Symbol holds the SymbolType in a 6-bit field (m_type), so if you get over 63
 // entries you will have to resize that field.
 enum SymbolType {

lldb/include/lldb/lldb-private-enumerations.h

 enum StatisticKind {
   ExpressionSuccessful = 0,
   ExpressionFailure = 1,
   FrameVarSuccess = 2,
   FrameVarFailure = 3,
   StatisticMax = 4
 };
 
+// Enumeration that can be used to specify a log handler.
+enum LogHandlerKind {
+  eLogHandlerStream,
+  eLogHandlerCallback,
+  eLogHandlerCircular,
+  eLogHandlerSystem,
+  eLogHandlerDefault = eLogHandlerStream,
+};
 
 inline std::string GetStatDescription(lldb_private::StatisticKind K) {
    switch (K) {
    case StatisticKind::ExpressionSuccessful:
      return "Number of expr evaluation successes";
    case StatisticKind::ExpressionFailure:
      return "Number of expr evaluation failures";
    case StatisticKind::FrameVarSuccess:

lldb/source/API/SBDebugger.cpp

bool SBDebugger::EnableLog(const char *channel, const char **categories) {
   LLDB_INSTRUMENT_VA(this, channel, categories);
 
   if (m_opaque_sp) {
     uint32_t log_options =
         LLDB_LOG_OPTION_PREPEND_TIMESTAMP | LLDB_LOG_OPTION_PREPEND_THREAD_NAME;
     std::string error;
     llvm::raw_string_ostream error_stream(error);
     return m_opaque_sp->EnableLog(channel, GetCategoryArray(categories), "",
-                                  log_options, /*buffer_size=*/0, error_stream);
+                                  log_options, /*buffer_size=*/0,
+                                  eLogHandlerStream, error_stream);
   } else
     return false;
 }
 
 void SBDebugger::SetLoggingCallback(lldb::LogOutputCallback log_callback,
                                     void *baton) {
   LLDB_INSTRUMENT_VA(this, log_callback, baton);
 

lldb/source/Commands/CommandObjectLog.cpp

 //===-- CommandObjectLog.cpp ----------------------------------------------===//
 //
 // Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
 // See https://llvm.org/LICENSE.txt for license information.
 // SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
 //
 //===----------------------------------------------------------------------===//
 
 #include "CommandObjectLog.h"
 #include "lldb/Core/Debugger.h"
 #include "lldb/Host/OptionParser.h"
 #include "lldb/Interpreter/CommandReturnObject.h"
 #include "lldb/Interpreter/OptionArgParser.h"
+#include "lldb/Interpreter/OptionValueEnumeration.h"
 #include "lldb/Interpreter/OptionValueUInt64.h"
 #include "lldb/Interpreter/Options.h"
 #include "lldb/Utility/Args.h"
 #include "lldb/Utility/FileSpec.h"
 #include "lldb/Utility/Log.h"
 #include "lldb/Utility/Stream.h"
 #include "lldb/Utility/Timer.h"
 
 using namespace lldb;
 using namespace lldb_private;
 
+static constexpr OptionEnumValueElement g_log_handler_type[] = {
+    {
+        eLogHandlerDefault,
+        "default",
+        "Use the default (stream) log handler",
+    },
+    {
+        eLogHandlerStream,
+        "stream",
+        "Write log messages to the debugger output stream or to a file if one "
+        "is specified. A buffer size (in bytes) can be specified with -b. If "
+        "no buffer size is specified the output is unbuffered.",
+    },
+    {
+        eLogHandlerCircular,
+        "circular",
+        "Write log messages to a fixed size circular buffer. A buffer size "
+        "(number of messages) must be specified with -b.",
+    },
+    {
+        eLogHandlerSystem,
+        "os",
+        "Write log messages to the operating system log.",
+    },
+};
+
+static constexpr OptionEnumValues LogHandlerType() {
+  return OptionEnumValues(g_log_handler_type);
+}
+
 #define LLDB_OPTIONS_log_enable
 #include "CommandOptions.inc"
 
 /// Common completion logic for log enable/disable.
 static void CompleteEnableDisable(CompletionRequest &request) {
   size_t arg_index = request.GetCursorIndex();
   if (arg_index == 0) { // We got: log enable/disable x[tab]
     for (llvm::StringRef channel : Log::ListChannels())
Status SetOptionValue(uint32_t option_idx, llvm::StringRef option_arg,
       Status error;
       const int short_option = m_getopt_table[option_idx].val;
 
       switch (short_option) {
       case 'f':
         log_file.SetFile(option_arg, FileSpec::Style::native);
         FileSystem::Instance().Resolve(log_file);
         break;
+      case 'h':
+        handler = (LogHandlerKind)OptionArgParser::ToOptionEnum(
+            option_arg, GetDefinitions()[option_idx].enum_values, 0, error);
+        if (!error.Success())
+          error.SetErrorStringWithFormat(
+              "unrecognized value for log handler '%s'",
+              option_arg.str().c_str());
+        break;
       case 'b':
         error =
             buffer_size.SetValueFromString(option_arg, eVarSetOperationAssign);
         break;
       case 'v':
         log_options |= LLDB_LOG_OPTION_VERBOSE;
         break;
       case 's':
         log_options |= LLDB_LOG_OPTION_PREPEND_SEQUENCE;
         break;
       case 'T':
         log_options |= LLDB_LOG_OPTION_PREPEND_TIMESTAMP;
         break;
       case 'p':
         log_options |= LLDB_LOG_OPTION_PREPEND_PROC_AND_THREAD;
         break;
       case 'n':
         log_options |= LLDB_LOG_OPTION_PREPEND_THREAD_NAME;
         break;
Status SetOptionValue(uint32_t option_idx, llvm::StringRef option_arg,
       }
 
       return error;
     }
 
     void OptionParsingStarting(ExecutionContext *execution_context) override {
       log_file.Clear();
       buffer_size.Clear();
+      handler = eLogHandlerStream;
       log_options = 0;
     }
 
     llvm::ArrayRef<OptionDefinition> GetDefinitions() override {
       return llvm::makeArrayRef(g_log_enable_options);
     }
 
     FileSpec log_file;
     OptionValueUInt64 buffer_size;
+    LogHandlerKind handler = eLogHandlerStream;
     uint32_t log_options = 0;
   };
 
   void
   HandleArgumentCompletion(CompletionRequest &request,
                            OptionElementVector &opt_element_vector) override {
     CompleteEnableDisable(request);
   }
 
 protected:
   bool DoExecute(Args &args, CommandReturnObject &result) override {
     if (args.GetArgumentCount() < 2) {
       result.AppendErrorWithFormat(
           "%s takes a log channel and one or more log types.\n",
           m_cmd_name.c_str());
       return false;
     }
 
+    if (m_options.handler == eLogHandlerCircular &&
+        m_options.buffer_size.GetCurrentValue() == 0) {
+      result.AppendError(
+          "the circular buffer handler requires a non-zero buffer size.\n");
+      return false;
+    }
+
     // Store into a std::string since we're about to shift the channel off.
     const std::string channel = std::string(args[0].ref());
     args.Shift(); // Shift off the channel
     char log_file[PATH_MAX];
     if (m_options.log_file)
       m_options.log_file.GetPath(log_file, sizeof(log_file));
     else
       log_file[0] = '\0';
 
     std::string error;
     llvm::raw_string_ostream error_stream(error);
     bool success = GetDebugger().EnableLog(
         channel, args.GetArgumentArrayRef(), log_file, m_options.log_options,
-        m_options.buffer_size.GetCurrentValue(), error_stream);
+        m_options.buffer_size.GetCurrentValue(), m_options.handler,
+        error_stream);
     result.GetErrorStream() << error_stream.str();
 
     if (success)
       result.SetStatus(eReturnStatusSuccessFinishNoResult);
     else
       result.SetStatus(eReturnStatusFailed);
     return result.Succeeded();
   }

lldb/source/Commands/Options.td

def history_end_index : Option<"end-index", "e">, Group<1>,
     Desc<"Index at which to stop printing history commands.">;
   def history_clear : Option<"clear", "C">, Group<2>,
     Desc<"Clears the current command history.">;
 }
 
 let Command = "log enable" in {
   def log_file : Option<"file", "f">, Group<1>, Arg<"Filename">,
     Desc<"Set the destination file to log to.">;
+  def log_handler : Option<"log-handler", "h">, Group<1>,
+    EnumArg<"LogHandler", "LogHandlerType()">, Desc<"Specify a log handler which determines where log messages are written.">;
   def log_buffer_size : Option<"buffer", "b">, Group<1>, Arg<"UnsignedInteger">,
-    Desc<"Set the log to be buffered, using the specified buffer size.">;
+    Desc<"Set the log to be buffered, using the specified buffer size, if supported by the log handler.">;
   def log_verbose : Option<"verbose", "v">, Group<1>,
     Desc<"Enable verbose logging.">;
   def log_sequence : Option<"sequence", "s">, Group<1>,
     Desc<"Prepend all log lines with an increasing integer sequence id.">;
   def log_timestamp : Option<"timestamp", "T">, Group<1>,
     Desc<"Prepend all log lines with a timestamp.">;
   def log_pid_tid : Option<"pid-tid", "p">, Group<1>,
     Desc<"Prepend all log lines with the process and thread ID that generates "
     "the log line.">;
   def log_thread_name : Option<"thread-name", "n">, Group<1>,
     Desc<"Prepend all log lines with the thread name for the thread that "
     "generates the log line.">;

lldb/source/Core/Debugger.cpp

 void Debugger::ReportError(std::string message,
                            llvm::Optional<lldb::user_id_t> debugger_id,
                            std::once_flag *once) {
 
   ReportDiagnosticImpl(DiagnosticEventData::Type::Error, std::move(message),
                        debugger_id, once);
 }
 
+static std::shared_ptr<LogHandler>
+CreateLogHandler(LogHandlerKind log_handler_kind, int fd, bool should_close,
+                 size_t buffer_size) {
+  switch (log_handler_kind) {
+  case eLogHandlerStream:
+    return std::make_shared<StreamLogHandler>(fd, should_close, buffer_size);
+  case eLogHandlerCircular:
+    return std::make_shared<RotatingLogHandler>(buffer_size);
+  case eLogHandlerSystem:
+    return std::make_shared<SystemLogHandler>();
+  case eLogHandlerCallback:
+    return {};
+  }
+  return {};
+}
+
 bool Debugger::EnableLog(llvm::StringRef channel,
                          llvm::ArrayRef<const char *> categories,
                          llvm::StringRef log_file, uint32_t log_options,
-                         size_t buffer_size, llvm::raw_ostream &error_stream) {
-  const bool should_close = true;
+                         size_t buffer_size, LogHandlerKind log_handler_kind,
+                         llvm::raw_ostream &error_stream) {
 
   std::shared_ptr<LogHandler> log_handler_sp;
   if (m_callback_handler_sp) {
     log_handler_sp = m_callback_handler_sp;
     // For now when using the callback mode you always get thread & timestamp.
     log_options |=
         LLDB_LOG_OPTION_PREPEND_TIMESTAMP | LLDB_LOG_OPTION_PREPEND_THREAD_NAME;
   } else if (log_file.empty()) {
-    log_handler_sp = std::make_shared<StreamLogHandler>(
-        GetOutputFile().GetDescriptor(), !should_close, buffer_size);
+    log_handler_sp =
+        CreateLogHandler(log_handler_kind, GetOutputFile().GetDescriptor(),
+                         /*should_close=*/false, buffer_size);
   } else {
     auto pos = m_stream_handlers.find(log_file);
     if (pos != m_stream_handlers.end())
       log_handler_sp = pos->second.lock();
     if (!log_handler_sp) {
       File::OpenOptions flags =
           File::eOpenOptionWriteOnly | File::eOpenOptionCanCreate;
       if (log_options & LLDB_LOG_OPTION_APPEND)
         flags |= File::eOpenOptionAppend;
       else
         flags |= File::eOpenOptionTruncate;
       llvm::Expected<FileUP> file = FileSystem::Instance().Open(
           FileSpec(log_file), flags, lldb::eFilePermissionsFileDefault, false);
       if (!file) {
         error_stream << "Unable to open log file '" << log_file
                      << "': " << llvm::toString(file.takeError()) << "\n";
         return false;
       }
 
-      log_handler_sp = std::make_shared<StreamLogHandler>(
-          (*file)->GetDescriptor(), should_close, buffer_size);
+      log_handler_sp =
+          CreateLogHandler(log_handler_kind, (*file)->GetDescriptor(),
+                           /*should_close=*/true, buffer_size);
       m_stream_handlers[log_file] = log_handler_sp;
     }
   }
   assert(log_handler_sp);
 
   if (log_options == 0)
     log_options = LLDB_LOG_OPTION_PREPEND_THREAD_NAME;
 

lldb/source/Interpreter/CommandObject.cpp

CommandObject::ArgumentTableEntry CommandObject::g_arguments_data[] = {
     { eArgTypePlatform, "platform-name", CommandCompletions::ePlatformPluginCompletion, { nullptr, false }, "The name of an installed platform plug-in . Type 'platform list' to see a complete list of installed platforms." },
     { eArgTypeWatchpointID, "watchpt-id", CommandCompletions::eNoCompletion, { nullptr, false }, "Watchpoint IDs are positive integers." },
     { eArgTypeWatchpointIDRange, "watchpt-id-list", CommandCompletions::eNoCompletion, { nullptr, false }, "For example, '1-3' or '1 to 3'." },
     { eArgTypeWatchType, "watch-type", CommandCompletions::eNoCompletion, { nullptr, false }, "Specify the type for a watchpoint." },
     { eArgRawInput, "raw-input", CommandCompletions::eNoCompletion, { nullptr, false }, "Free-form text passed to a command without prior interpretation, allowing spaces without requiring quotes.  To pass arguments and free form text put two dashes ' -- ' between the last argument and any raw input." },
     { eArgTypeCommand, "command", CommandCompletions::eNoCompletion, { nullptr, false }, "An LLDB Command line command element." },
     { eArgTypeColumnNum, "column", CommandCompletions::eNoCompletion, { nullptr, false }, "Column number in a source file." },
     { eArgTypeModuleUUID, "module-uuid", CommandCompletions::eModuleUUIDCompletion, { nullptr, false }, "A module UUID value." },
-    { eArgTypeSaveCoreStyle, "corefile-style", CommandCompletions::eNoCompletion, { nullptr, false }, "The type of corefile that lldb will try to create, dependant on this target's capabilities." }
+    { eArgTypeSaveCoreStyle, "corefile-style", CommandCompletions::eNoCompletion, { nullptr, false }, "The type of corefile that lldb will try to create, dependant on this target's capabilities." },
+    { eArgTypeLogHandler, "log-handler", CommandCompletions::eNoCompletion, { nullptr, false }, "The log handle that will be used to write out log messages." },
     // clang-format on
 };
 
 const CommandObject::ArgumentTableEntry *CommandObject::GetArgumentTable() {
   // If this assertion fires, then the table above is out of date with the
   // CommandArgumentType enumeration
   static_assert((sizeof(CommandObject::g_arguments_data) /
                  sizeof(CommandObject::ArgumentTableEntry)) == eArgTypeLastArg,
                 "");
   return CommandObject::g_arguments_data;
 }

lldb/tools/lldb-test/lldb-test.cpp

int main(int argc, const char *argv[]) {
   Dbg->GetCommandInterpreter().HandleCommand(
       "settings set target.inherit-tcc true",
       /*add_to_history*/ eLazyBoolNo, Result);
   Dbg->GetCommandInterpreter().HandleCommand(
       "settings set target.detach-on-error false",
       /*add_to_history*/ eLazyBoolNo, Result);
 
   if (!opts::Log.empty())
-    Dbg->EnableLog("lldb", {"all"}, opts::Log, 0, 0, errs());
+    Dbg->EnableLog("lldb", {"all"}, opts::Log, 0, 0, eLogHandlerStream, errs());
 
   if (opts::BreakpointSubcommand)
     return opts::breakpoint::evaluateBreakpoints(*Dbg);
   if (opts::ObjectFileSubcommand)
     return dumpObjectFiles(*Dbg);
   if (opts::SymbolsSubcommand)
     return opts::symbols::dumpSymbols(*Dbg);
   if (opts::IRMemoryMapSubcommand)
     return opts::irmemorymap::evaluateMemoryMapCommands(*Dbg);
   if (opts::AssertSubcommand)
     return opts::assert::lldb_assert(*Dbg);
 
   WithColor::error() << "No command specified.\n";
   return 1;
 }