Logging: provide a way to safely disable logging in a forked process

[labath]

Summary

We had a bug where if we had forked (in the ProcessLauncherPosixFork)
while another thread was writing a log message, we would deadlock. This
happened because the fork child inherited the locked log rwmutex, which
would never get unlocked. This meant the child got stuck trying to
disable all log channels.

The bug existed for a while but only started being apparent after
D37930, which started using ThreadLauncher (which uses logging) instead
of std::thread (which does not) for launching TaskPool threads.

The fix is to provide a lock free way to disable logging, which should
be used in this case, and this case only.

[clayborg]

Who is holding the lock and then fork'ing? Seems like we should fix that? I thought all log calls should be "lock, log, unlock". Why is this causing problems?

[clayborg]

Never mind, re-reading your original comment made it clear.

[eugene]

DisableUnlocked methods makes me uneasy.
Maybe we can take a log lock before forking and then properly release it in both parent and child processes?

[labath]

Solve the problem using pthread_atfork().

This way the locks are properly taken before forking and released in both child
and parent processes. This behavior is encapsulated within the Log class and is
completely transparent to all fork users (but it requires a tiny bit of
system-specific code).

[clayborg]

Much better.

[labath]

The previous fix had a problem where a more paraniod libc (e.g., android, but I
suspect freebds would do that as well) would detect that the
thread unlocking the mutex is not the same one as the one that locked, and
refused to comply.

The new fix is a combination of the first two solutions: we disable the logging
via custom code after forking, but we still do it via pthread_atfork to avoid
this detail leaking outside the Log implementation. The added benefit is that
forking code does not need to worry about logging at all, as it will be
automatically disabled.

[eugene]

source/Utility/Log.cpp

333

A little comment here describing nature of a deadlock if we don't disable logging would be nice.

include/lldb/Utility/Log.h

public:
   static bool DisableLogChannel(llvm::StringRef channel,
                                 llvm::ArrayRef<const char *> categories,
                                 llvm::raw_ostream &error_stream);
 
   static bool ListChannelCategories(llvm::StringRef channel, llvm::raw_ostream &stream);
 
   static void DisableAllLogChannels();
 
+  // Only use if no other threads are executing and calling the locking version
+  // is known to be unsafe (for example, this happens right after forking, if we
+  // have forked while another thread was holding the log mutex)).
+  static void DisableAllLogChannelsUnlocked();
+
   static void ListAllLogChannels(llvm::raw_ostream &stream);
 
   //------------------------------------------------------------------
   // Member functions
   //
   // These functions are safe to call at any time you have a Log* obtained from
   // the Channel class. If logging is disabled between you obtaining the Log
   // object and writing to it, the output will be silently discarded.
std::shared_ptr<llvm::raw_ostream> GetStream() {
     llvm::sys::ScopedReader lock(m_mutex);
     return m_stream_sp;
   }
 
   void Enable(const std::shared_ptr<llvm::raw_ostream> &stream_sp,
               uint32_t options, uint32_t flags);
 
   void Disable(uint32_t flags);
+  void DisableUnlocked(uint32_t flags);
 
   typedef llvm::StringMap<Log> ChannelMap;
   static llvm::ManagedStatic<ChannelMap> g_channel_map;
 
   static void ListCategories(llvm::raw_ostream &stream,
                              const ChannelMap::value_type &entry);
   static uint32_t GetFlags(llvm::raw_ostream &stream, const ChannelMap::value_type &entry,
                            llvm::ArrayRef<const char *> categories);

source/Host/posix/ProcessLauncherPosixFork.cpp

static void DupDescriptor(int error_fd, const FileSpec &file_spec, int fd,
   ::close(target_fd);
   return;
 }
 
 static void LLVM_ATTRIBUTE_NORETURN ChildFunc(int error_fd,
                                               const ProcessLaunchInfo &info) {
   // First, make sure we disable all logging. If we are logging to stdout, our
   // logs can be mistaken for inferior output.
-  Log::DisableAllLogChannels();
+  Log::DisableAllLogChannelsUnlocked();
 
   // Do not inherit setgid powers.
   if (setgid(getgid()) != 0)
     ExitWithError(error_fd, "setgid");
 
   if (info.GetFlags().Test(eLaunchFlagLaunchInSeparateProcessGroup)) {
     if (setpgid(0, 0) != 0)
       ExitWithError(error_fd, "setpgid");

source/Utility/Log.cpp

if (mask | flags) {
     m_options.store(options, std::memory_order_relaxed);
     m_stream_sp = stream_sp;
     m_channel.log_ptr.store(this, std::memory_order_relaxed);
   }
 }
 
 void Log::Disable(uint32_t flags) {
   llvm::sys::ScopedWriter lock(m_mutex);
+  DisableUnlocked(flags);
+}
 
+void Log::DisableUnlocked(uint32_t flags) {
   uint32_t mask = m_mask.fetch_and(~flags, std::memory_order_relaxed);
   if (!(mask & ~flags)) {
     m_stream_sp.reset();
     m_channel.log_ptr.store(nullptr, std::memory_order_relaxed);
   }
 }
 
 const Flags Log::GetOptions() const {
bool Log::ListChannelCategories(llvm::StringRef channel,
   return true;
 }
 
 void Log::DisableAllLogChannels() {
   for (auto &entry : *g_channel_map)
     entry.second.Disable(UINT32_MAX);
 }
 
+void Log::DisableAllLogChannelsUnlocked() {
+  for (auto &entry : *g_channel_map)
+    entry.second.DisableUnlocked(UINT32_MAX);
+}
+
 void Log::ListAllLogChannels(llvm::raw_ostream &stream) {
   if (g_channel_map->empty()) {
     stream << "No logging channels are currently registered.\n";
     return;
   }
 
   for (const auto &channel : *g_channel_map)
     ListCategories(stream, channel);

 
 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";
   WriteMessage(message.str());
 }