From d813309e034cb32436eb804f70d94da7bdb406cd Mon Sep 17 00:00:00 2001 From: Pavel Labath Date: Mon, 23 Oct 2017 19:41:17 +0000 Subject: [PATCH] Logging: Disable logging after fork() 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 use pthread_atfork to disable logging in the forked child. Reviewers: zturner, eugene, clayborg Subscribers: lldb-commits Differential Revision: https://reviews.llvm.org/D38938 llvm-svn: 316368 --- lldb/include/lldb/Utility/Log.h | 5 +++++ lldb/include/lldb/Utility/Logging.h | 2 +- lldb/source/Host/posix/ProcessLauncherPosixFork.cpp | 4 ---- lldb/source/Initialization/SystemInitializerCommon.cpp | 2 +- lldb/source/Utility/Log.cpp | 16 ++++++++++++++++ lldb/source/Utility/Logging.cpp | 2 +- 6 files changed, 24 insertions(+), 7 deletions(-) diff --git a/lldb/include/lldb/Utility/Log.h b/lldb/include/lldb/Utility/Log.h index d856fc8..80a80fc 100644 --- a/lldb/include/lldb/Utility/Log.h +++ b/lldb/include/lldb/Utility/Log.h @@ -96,6 +96,9 @@ public: } }; + + static void Initialize(); + //------------------------------------------------------------------ // Static accessors for logging channels //------------------------------------------------------------------ @@ -193,6 +196,8 @@ private: static uint32_t GetFlags(llvm::raw_ostream &stream, const ChannelMap::value_type &entry, llvm::ArrayRef categories); + static void DisableLoggingChild(); + Log(const Log &) = delete; void operator=(const Log &) = delete; }; diff --git a/lldb/include/lldb/Utility/Logging.h b/lldb/include/lldb/Utility/Logging.h index 865097e..2c75a3b 100644 --- a/lldb/include/lldb/Utility/Logging.h +++ b/lldb/include/lldb/Utility/Logging.h @@ -62,7 +62,7 @@ Log *GetLogIfAllCategoriesSet(uint32_t mask); Log *GetLogIfAnyCategoriesSet(uint32_t mask); -void InitializeLog(); +void InitializeLldbChannel(); } // namespace lldb_private diff --git a/lldb/source/Host/posix/ProcessLauncherPosixFork.cpp b/lldb/source/Host/posix/ProcessLauncherPosixFork.cpp index fb235d7..ac1d901 100644 --- a/lldb/source/Host/posix/ProcessLauncherPosixFork.cpp +++ b/lldb/source/Host/posix/ProcessLauncherPosixFork.cpp @@ -95,10 +95,6 @@ static void DupDescriptor(int error_fd, const FileSpec &file_spec, int fd, 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(); - // Do not inherit setgid powers. if (setgid(getgid()) != 0) ExitWithError(error_fd, "setgid"); diff --git a/lldb/source/Initialization/SystemInitializerCommon.cpp b/lldb/source/Initialization/SystemInitializerCommon.cpp index e76ba41..8535470 100644 --- a/lldb/source/Initialization/SystemInitializerCommon.cpp +++ b/lldb/source/Initialization/SystemInitializerCommon.cpp @@ -70,7 +70,7 @@ void SystemInitializerCommon::Initialize() { #endif llvm::EnablePrettyStackTrace(); - InitializeLog(); + Log::Initialize(); HostInfo::Initialize(); static Timer::Category func_cat(LLVM_PRETTY_FUNCTION); Timer scoped_timer(func_cat, LLVM_PRETTY_FUNCTION); diff --git a/lldb/source/Utility/Log.cpp b/lldb/source/Utility/Log.cpp index a80b106..78050db 100644 --- a/lldb/source/Utility/Log.cpp +++ b/lldb/source/Utility/Log.cpp @@ -32,6 +32,7 @@ #include // for getpid #else #include +#include #endif using namespace lldb_private; @@ -181,6 +182,13 @@ void Log::Warning(const char *format, ...) { Printf("warning: %s", Content.c_str()); } +void Log::Initialize() { +#ifdef LLVM_ON_UNIX + pthread_atfork(nullptr, nullptr, &Log::DisableLoggingChild); +#endif + InitializeLldbChannel(); +} + void Log::Register(llvm::StringRef name, Channel &channel) { auto iter = g_channel_map->try_emplace(name, channel); assert(iter.second == true); @@ -321,3 +329,11 @@ void Log::Format(llvm::StringRef file, llvm::StringRef function, message << payload << "\n"; WriteMessage(message.str()); } + +void Log::DisableLoggingChild() { + // Disable logging by clearing out the atomic variable after forking -- if we + // forked while another thread held the channel mutex, we would deadlock when + // trying to write to the log. + for (auto &c: *g_channel_map) + c.second.m_channel.log_ptr.store(nullptr, std::memory_order_relaxed); +} diff --git a/lldb/source/Utility/Logging.cpp b/lldb/source/Utility/Logging.cpp index 0bd6d66..c9a6ef1 100644 --- a/lldb/source/Utility/Logging.cpp +++ b/lldb/source/Utility/Logging.cpp @@ -51,7 +51,7 @@ static constexpr Log::Category g_categories[] = { static Log::Channel g_log_channel(g_categories, LIBLLDB_LOG_DEFAULT); -void lldb_private::InitializeLog() { +void lldb_private::InitializeLldbChannel() { Log::Register("lldb", g_log_channel); } -- 2.7.4