[lldb] Add OSLog log handler

[JDevlieghere]

Summary

Add an OSLog log handler on macOS. These log messages end up in Console.app and will be part of a sysdiagnose, similar to os_signposts.

[clayborg]

I think we should allow this class to always exist and not conditionally compile it in or out. Then we add a new Host.h method to emit a log message in "lldb/Host/Host.h" and allow each host OS to emit a message. Maybe there is a default implementation that emits the message to stderr, and then we override this for in HostInfoMacOSX.h? Then each OS can use their OS logging API of choice.

lldb/include/lldb/Utility/Log.h

98

remove #if so everyone can use this and we can enable this in any log.

lldb/source/Utility/Log.cpp

35–39

move this to HostInfoMacOSX.h in the Host::EmitLogMessage() as mentioned in the main feedback comment

394

remove #if

395–399

move this to HostInfoMacOSX.h to be used in HostInfoMacOSX::EmitLogMessage(StringRef)

402

Be careful as "message.data()" might cause more data to be emitted. We will need to use "message.str().c_str()" to ensure it is NULL terminated. Though we could require that the "message" come in as NULL terminated already, so maybe we don't need to, but we should document it, and possibly add a:

assert(message.data()[message.size()] == '\0');

[JDevlieghere]

In D128321#3602129, @clayborg wrote:

I think we should allow this class to always exist and not conditionally compile it in or out. Then we add a new Host.h method to emit a log message in "lldb/Host/Host.h" and allow each host OS to emit a message. Maybe there is a default implementation that emits the message to stderr, and then we override this for in HostInfoMacOSX.h? Then each OS can use their OS logging API of choice.

Yeah, I considered that, but that would make Utility depend on Host which would (re)introduce the circular dependency between the two. The alternative would be to still make the class available unconditionally, but use target ifdefs to have different implementations.

[JDevlieghere]

Address remaining code review feedback

[aprantl]

lldb/include/lldb/Utility/Log.h

98

Doxygen comment?

lldb/source/Utility/Log.cpp

406

Can you add a FIXME for future reference that this ought to be moved into a macro into the header, so we can benefit from os_log's special compiler support and the only reason why we don't do this is that it's unsafe to include <os/log.h> in the LLVM headers?

[JDevlieghere]

lldb/source/Utility/Log.cpp

406

I'd be happy to add the comment, but it wouldn't be entirely true though. The log handers are meant to sit underneath the more general logging infrastructure and as you pointed out, you need a constant string in order to benefit from the os_log optimization. Unlike for os_signposts, I think it's very unlikely that we'd ever want to bypass our whole logging system for that.

[JDevlieghere]

lldb/source/Utility/Log.cpp

406

s/the comment/a comment/ -> describing what I said here :-)

[labath]

In D128321#3603007, @JDevlieghere wrote:

In D128321#3602129, @clayborg wrote:

I think we should allow this class to always exist and not conditionally compile it in or out. Then we add a new Host.h method to emit a log message in "lldb/Host/Host.h" and allow each host OS to emit a message. Maybe there is a default implementation that emits the message to stderr, and then we override this for in HostInfoMacOSX.h? Then each OS can use their OS logging API of choice.

Yeah, I considered that, but that would make Utility depend on Host which would (re)introduce the circular dependency between the two. The alternative would be to still make the class available unconditionally, but use target ifdefs to have different implementations.

We already have Host::SystemLog. Could we use that? Or change it so that it can be used?

As for the dependencies, I think we could structure things such that the SystemLogHandler lives in the Host module, and the general logging infrastructure is not aware of it. (The only one who would know about it would be the log enable command, which would pass it down as a generic reference.)

[JDevlieghere]

In D128321#3603947, @labath wrote:

In D128321#3603007, @JDevlieghere wrote:

In D128321#3602129, @clayborg wrote:

I think we should allow this class to always exist and not conditionally compile it in or out. Then we add a new Host.h method to emit a log message in "lldb/Host/Host.h" and allow each host OS to emit a message. Maybe there is a default implementation that emits the message to stderr, and then we override this for in HostInfoMacOSX.h? Then each OS can use their OS logging API of choice.

Yeah, I considered that, but that would make Utility depend on Host which would (re)introduce the circular dependency between the two. The alternative would be to still make the class available unconditionally, but use target ifdefs to have different implementations.

We already have Host::SystemLog. Could we use that? Or change it so that it can be used?

Not in its current state, no. The first problem is that it writes the message to the host log channel if it's enabled and in verbose mode. The second problem is that on macOS, it writes both to the system log and to stderr (all other platforms just write to stderr). If you look at its callers, it's clear that this function is really used for error reporting (the fact that it takes two log level "warning" and "error") is already a good indication of that. When I was looking at it yesterday I was thinking about ripping it out and replacing it with the diagnostics I added a little while ago.

As for the dependencies, I think we could structure things such that the SystemLogHandler lives in the Host module, and the general logging infrastructure is not aware of it. (The only one who would know about it would be the log enable command, which would pass it down as a generic reference.)

I also considered that, but that just delays the problem until I want to enable this handler for the always-on logging (as outlined in https://discourse.llvm.org/c/subprojects/lldb/8). I haven't really looked into where that logic would live, but the reproducers lived in Utility so I was expecting all of this to be there as well.

So both things combined, I still think the current approach makes the most sense. But if we really want this to live in Host (and deal with the dependency issues later) I can implement a new Host::SystemLog variant that essentially does what the SystemLogHander is doing and implement the log handler in Host based on that.

[clayborg]

So it seems like we are catering to our code organization here instead of doing the right thing and relying on the host layer. I would rather move the log code into the host layer or make log handlers actual plug-ins so that we can do the right thing here.

If we can make LogHandler objects plug-ins, where each plug-in has a name, then this can be used to specify the different types of logs using "--kind <name>" or "--type <name>". Then we don't run into these layering issues, because essentially we have small LogHandler implementations here. Any objection to making LogHandler subclasses into actual plug-ins?

[clayborg]

If we do add plug-ins, you could make an Apple specific plug-in named "darwin-os-log" or something that would only be compiled in for Apple builds, or we can do a generic "os-log" plug-in that uses the host layer.

[JDevlieghere]

In D128321#3606172, @clayborg wrote:

So it seems like we are catering to our code organization here instead of doing the right thing and relying on the host layer. I would rather move the log code into the host layer or make log handlers actual plug-ins so that we can do the right thing here.

If we can make LogHandler objects plug-ins, where each plug-in has a name, then this can be used to specify the different types of logs using "--kind <name>" or "--type <name>". Then we don't run into these layering issues, because essentially we have small LogHandler implementations here. Any objection to making LogHandler subclasses into actual plug-ins?

That wouldn't really solve my problem though. The plugin would still depend on host. And I would still need to depend on the plugin in Utility. So it's still a circle: Utility -> Log Handler Plugin -> Host -> Utility

[JDevlieghere]

• Move SystemLogHandler into Host
• Create a new SystemLog helper function

[labath]

In D128321#3605592, @JDevlieghere wrote:

I also considered that, but that just delays the problem until I want to enable this handler for the always-on logging (as outlined in https://discourse.llvm.org/c/subprojects/lldb/8). I haven't really looked into where that logic would live, but the reproducers lived in Utility so I was expecting all of this to be there as well.

I don't think that's a particularly big problem. Any code that's needed to enable always-on logging (to /a/ log handler) can stay in Utility. Only the code which actually enables it (and passes a specific log handler) needs to live outside. One way to do that would be to put something in the SystemInitializer class (like we did for reproducers). Another would be to use the shiny new global lldbinit file feature (which would allow site customization). :P

lldb/source/Host/common/Host.cpp

110 ↗

(On Diff #439588)

Why std::string? I'd expect StringRef (as that's what the LogHandler class uses), const char * (as that can avoid string copying sometimes) or a Twine (in case you want to be fancy), but a string seems like it combines the worst properties of all of these.

[labath]

lldb/source/Host/common/Host.cpp

110 ↗

(On Diff #439588)

Actually, I think we should just use a StringRef and use llvm::errs() for printing.

[JDevlieghere]

lldb/source/Host/common/Host.cpp

110 ↗

(On Diff #439588)

Right, I was optimizing for the Apple case where we need to go through a std::string to make sure it's null terminated. My reasoning was that if you pass in a StringRef you might end up with two copies if the original StringRef is already backed by a std::string.

[JDevlieghere]

In D128321#3607935, @labath wrote:

In D128321#3605592, @JDevlieghere wrote:

I also considered that, but that just delays the problem until I want to enable this handler for the always-on logging (as outlined in https://discourse.llvm.org/c/subprojects/lldb/8). I haven't really looked into where that logic would live, but the reproducers lived in Utility so I was expecting all of this to be there as well.

I don't think that's a particularly big problem. Any code that's needed to enable always-on logging (to /a/ log handler) can stay in Utility. Only the code which actually enables it (and passes a specific log handler) needs to live outside. One way to do that would be to put something in the SystemInitializer class (like we did for reproducers). Another would be to use the shiny new global lldbinit file feature (which would allow site customization). :P

Right, not sure why I didn't think of that myself. Alright that covers all my concerns. Given that this was Greg's suggestion I'm assuming he's happy with this as well. Thank you both for the review!

[JDevlieghere]

@labath Any chance I can nerd-snipe you into adding support for syslog (or whatever the modern equivalent is) on linux? :-)

lldb/include/lldb/Utility/Log.h

private:
   size_t GetFirstMessageIndex() const;
 
   std::unique_ptr<std::string[]> m_messages;
   const size_t m_size = 0;
   size_t m_next_index = 0;
   size_t m_total_count = 0;
 };
 
+class SystemLogHandler : public LogHandler {
+public:
+  SystemLogHandler();
+  void Emit(llvm::StringRef message) override;
+};
+
 class Log final {
 public:
   /// The underlying type of all log channel enums. Declare them as:
   /// enum class MyLog : MaskType {
   ///   Channel0 = Log::ChannelFlag<0>,
   ///   Channel1 = Log::ChannelFlag<1>,
   ///   ...,
   ///   LLVM_MARK_AS_BITMASK_ENUM(LastChannel),

lldb/source/Utility/Log.cpp

 
 #include <cassert>
 #if defined(_WIN32)
 #include <process.h>
 #else
 #include <unistd.h>
 #endif
 
+#if defined(__APPLE__)
+#include <os/log.h>
+static os_log_t g_os_log;
+static std::once_flag g_os_log_once;
+#endif
+
 using namespace lldb_private;
 
 llvm::ManagedStatic<Log::ChannelMap> Log::g_channel_map;
 
 void Log::ForEachCategory(
     const Log::ChannelMap::value_type &entry,
     llvm::function_ref<void(llvm::StringRef, llvm::StringRef)> lambda) {
   lambda("all", "all available logging categories");
void RotatingLogHandler::Dump(llvm::raw_ostream &stream) const {
   const size_t start_idx = GetFirstMessageIndex();
   const size_t stop_idx = start_idx + GetNumMessages();
   for (size_t i = start_idx; i < stop_idx; ++i) {
     const size_t idx = NormalizeIndex(i);
     stream << m_messages[idx];
   }
   stream.flush();
 }
+
+SystemLogHandler::SystemLogHandler() {
+#if defined(__APPLE__)
+  std::call_once(g_os_log_once, []() {
+    g_os_log = os_log_create("com.apple.dt.lldb", "lldb");
+  });
+#endif
+}
+
+void SystemLogHandler::Emit(llvm::StringRef message) {
+  std::string str(message);
+#if defined(__APPLE__)
+  if (__builtin_available(macos 10.12, iOS 10, tvOS 10, watchOS 3, *)) {
+    os_log(g_os_log, "%{public}s", str.c_str());
+  } else {
+    fprintf(stderr, "%s", str.c_str());
+  }
+#else
+  fprintf(stderr, "%s", str.c_str());
+#endif
+}