[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

99 ↗

(On Diff #438918)

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

lldb/source/Utility/Log.cpp

35–39 ↗

(On Diff #438918)

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

399 ↗

(On Diff #438918)

remove #if

400–404 ↗

(On Diff #438918)

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

407 ↗

(On Diff #438918)

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 ↗

(On Diff #439164)

Doxygen comment?

lldb/source/Utility/Log.cpp

406 ↗

(On Diff #439164)

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 ↗

(On Diff #439164)

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 ↗

(On Diff #439164)

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

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

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

[JDevlieghere]

lldb/source/Host/common/Host.cpp

110

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/Host/Host.h

 //===-- Host.h --------------------------------------------------*- C++ -*-===//
 //
 // 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
 //
 //===----------------------------------------------------------------------===//
 
 #ifndef LLDB_HOST_HOST_H
 #define LLDB_HOST_HOST_H
 
 #include "lldb/Host/File.h"
 #include "lldb/Host/HostThread.h"
 #include "lldb/Utility/Environment.h"
 #include "lldb/Utility/FileSpec.h"
+#include "lldb/Utility/Log.h"
 #include "lldb/Utility/Timeout.h"
 #include "lldb/lldb-private-forward.h"
 #include "lldb/lldb-private.h"
 #include <cerrno>
 #include <cstdarg>
 #include <map>
 #include <string>
 #include <type_traits>
public:
   ///
   /// \return
   ///     A thread handle that can be used to cancel the thread that
   ///     was spawned to monitor \a pid.
   static llvm::Expected<HostThread>
   StartMonitoringChildProcess(const MonitorChildProcessCallback &callback,
                               lldb::pid_t pid);
 
+  /// Emit the given message to the operating system's log.
+  void SystemLog(std::string message);
+
   /// Get the process ID for the calling process.
   ///
   /// \return
   ///     The process ID for the current process.
   static lldb::pid_t GetCurrentProcessID();
 
   static void Kill(lldb::pid_t pid, int signo);
 
public:
   static std::unique_ptr<Connection>
   CreateDefaultConnection(llvm::StringRef url);
 
 protected:
   static uint32_t FindProcessesImpl(const ProcessInstanceInfoMatch &match_info,
                                     ProcessInstanceInfoList &proc_infos);
 };
 
+class SystemLogHandler : public LogHandler {
+public:
+  SystemLogHandler();
+  void Emit(llvm::StringRef message) override;
+};
+
 } // namespace lldb_private
 
 namespace llvm {
 template <> struct format_provider<lldb_private::WaitStatus> {
   /// Options = "" gives a human readable description of the status Options =
   /// "g" gives a gdb-remote protocol status (e.g., X09)
   static void format(const lldb_private::WaitStatus &WS, raw_ostream &OS,
                      llvm::StringRef Options);
 };
 } // namespace llvm
 
 #endif // LLDB_HOST_HOST_H

lldb/source/Host/common/Host.cpp

llvm::Expected<HostThread> Host::StartMonitoringChildProcess(
   ::snprintf(thread_name, sizeof(thread_name),
              "<lldb.host.wait4(pid=%" PRIu64 ")>", pid);
   assert(pid <= UINT32_MAX);
   return ThreadLauncher::LaunchThread(thread_name, [pid, callback] {
     return MonitorChildProcessThreadFunction(pid, callback);
   });
 }
 
+#if !defined(__APPLE__)
+void Host::SystemLog(std::string message) {
+  fprintf(stderr, "%s", message.c_str());
+}
+#endif
+
 #ifndef __linux__
 // Scoped class that will disable thread canceling when it is constructed, and
 // exception safely restore the previous value it when it goes out of scope.
 class ScopedPThreadCancelDisabler {
 public:
   ScopedPThreadCancelDisabler() {
     // Disable the ability for this thread to be cancelled
     int err = ::pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &m_old_state);
uint32_t Host::FindProcesses(const ProcessInstanceInfoMatch &match_info,
   if (repro::Generator *g = repro::Reproducer::Instance().GetGenerator()) {
     g->GetOrCreate<repro::ProcessInfoProvider>()
         .GetNewProcessInfoRecorder()
         ->Record(process_infos);
   }
 
   return result;
 }
+
+SystemLogHandler::SystemLogHandler() {}
+
+void SystemLogHandler::Emit(llvm::StringRef message) {
+  Host::SystemLog(std::string(message));
+}

lldb/source/Host/macosx/objcxx/Host.mm

 
 #include "../cfcpp/CFCBundle.h"
 #include "../cfcpp/CFCMutableArray.h"
 #include "../cfcpp/CFCMutableDictionary.h"
 #include "../cfcpp/CFCReleaser.h"
 #include "../cfcpp/CFCString.h"
 
 #include <objc/objc-auto.h>
+#include <os/log.h>
 
 #include <CoreFoundation/CoreFoundation.h>
 #include <Foundation/Foundation.h>
 
 #ifndef _POSIX_SPAWN_DISABLE_ASLR
 #define _POSIX_SPAWN_DISABLE_ASLR 0x0100
 #endif
 
 extern "C" {
 int __pthread_chdir(const char *path);
 int __pthread_fchdir(int fildes);
 }
 
 using namespace lldb;
 using namespace lldb_private;
 
+static os_log_t g_os_log;
+static std::once_flag g_os_log_once;
+
+void Host::SystemLog(std::string message) {
+  if (__builtin_available(macos 10.12, iOS 10, tvOS 10, watchOS 3, *)) {
+    os_log(g_os_log, "%{public}s", message.c_str());
+  } else {
+    fprintf(stderr, "%s", message.c_str());
+  }
+}
+
 bool Host::GetBundleDirectory(const FileSpec &file,
                               FileSpec &bundle_directory) {
 #if defined(__APPLE__)
   if (FileSystem::Instance().IsDirectory(file)) {
     char path[PATH_MAX];
     if (file.GetPath(path, sizeof(path))) {
       CFCBundle bundle(path);
       if (bundle.GetPath(path, sizeof(path))) {