From 78307e3ff5e75a490a4059fd72e2c659385cda7b Mon Sep 17 00:00:00 2001 From: Adam Simpkins Date: Thu, 15 Jun 2017 11:03:52 -0700 Subject: [PATCH] logging: add a LoggerDB::internalWarning() function Summary: A few places in the logging code need to report issues when something goes wrong in the logging code itself. This adds a new LoggerDB::internalWarning() method for use in these places. This provides a default implementation that logs these warnings with _CrtDbgReport() on Windows, and writes to stderr on non-Windows platforms. The default implementation can also be overridden for programs that want some alternative behavior. Reviewed By: wez Differential Revision: D5157731 fbshipit-source-id: e27f5587d58b3941fca8d5b38c8c3edbcb75d7f3 --- folly/experimental/logging/LogCategory.cpp | 21 +++--- folly/experimental/logging/LoggerDB.cpp | 86 ++++++++++++++++++++++ folly/experimental/logging/LoggerDB.h | 49 ++++++++++++ 3 files changed, 145 insertions(+), 11 deletions(-) diff --git a/folly/experimental/logging/LogCategory.cpp b/folly/experimental/logging/LogCategory.cpp index 7b915139..6f02c9dc 100644 --- a/folly/experimental/logging/LogCategory.cpp +++ b/folly/experimental/logging/LogCategory.cpp @@ -71,17 +71,16 @@ void LogCategory::processMessage(const LogMessage& message) const { try { handlers[n]->handleMessage(message, this); } catch (const std::exception& ex) { - // If a LogHandler throws an exception, complain about this fact on - // stderr to avoid swallowing the error information completely. We - // don't propagate the exception up to our caller: most code does not - // prepare for log statements to throw. We also want to continue - // trying to log the message to any other handlers attached to ourself - // or one of our parent categories. - fprintf( - stderr, - "WARNING: log handler for category %s threw an error: %s\n", - name_.c_str(), - folly::exceptionStr(ex).c_str()); + // Use LoggerDB::internalWarning() to report the error, but continue + // trying to log the message to any other handlers attached to ourself or + // one of our parent categories. + LoggerDB::internalWarning( + __FILE__, + __LINE__, + "log handler for category \"", + name_, + "\" threw an error: ", + folly::exceptionStr(ex)); } } diff --git a/folly/experimental/logging/LoggerDB.cpp b/folly/experimental/logging/LoggerDB.cpp index 953570b4..4886fb9a 100644 --- a/folly/experimental/logging/LoggerDB.cpp +++ b/folly/experimental/logging/LoggerDB.cpp @@ -15,10 +15,17 @@ */ #include +#if _WIN32 +#include +#endif + +#include +#include #include #include #include #include +#include namespace folly { @@ -215,4 +222,83 @@ LogCategory* LoggerDB::xlogInitCategory( isInitialized->store(true, std::memory_order_release); return category; } + +std::atomic LoggerDB::warningHandler_; + +void LoggerDB::internalWarningImpl( + folly::StringPiece filename, + int lineNumber, + std::string&& msg) noexcept { + auto handler = warningHandler_.load(); + if (handler) { + handler(filename, lineNumber, std::move(msg)); + } else { + defaultInternalWarningImpl(filename, lineNumber, std::move(msg)); + } +} + +void LoggerDB::setInternalWarningHandler(InternalWarningHandler handler) { + // This API is intentionally pretty basic. It has a number of limitations: + // + // - We only support plain function pointers, and not full std::function + // objects. This makes it possible to use std::atomic to access the + // handler pointer, and also makes it safe to store in a zero-initialized + // file-static pointer. + // + // - We don't support any void* argument to the handler. The caller is + // responsible for storing any callback state themselves. + // + // - When replacing or unsetting a handler we don't make any guarantees about + // when the old handler will stop being called. It may still be called + // from other threads briefly even after setInternalWarningHandler() + // returns. This is also a consequence of using std::atomic rather than a + // full lock. + // + // This provides the minimum capabilities needed to customize the handler, + // while still keeping the implementation simple and safe to use even before + // main(). + warningHandler_.store(handler); +} + +void LoggerDB::defaultInternalWarningImpl( + folly::StringPiece filename, + int lineNumber, + std::string&& msg) noexcept { + // Rate limit to 10 messages every 5 seconds. + // + // We intentonally use a leaky Meyer's singleton here over folly::Singleton: + // - We want this code to work even before main() + // - This singleton does not depend on any other singletons. + static auto* rateLimiter = + new logging::IntervalRateLimiter{10, std::chrono::seconds(5)}; + if (!rateLimiter->check()) { + return; + } + +#if _WIN32 + // Use _CrtDbgReport() to report the error + _CrtDbgReport( + _CRT_WARN, filename, lineNumber, "folly::logging", "%s", msg.c_str()); +#else + if (folly::kIsDebug) { + // Write directly to file descriptor 2. + // + // It's possible the application has closed fd 2 and is using it for + // something other than stderr. However we have no good way to detect + // this, which is the main reason we only write to stderr in debug build + // modes. assert() also writes directly to stderr on failure, which seems + // like a reasonable precedent. + // + // Another option would be to use openlog() and syslog(). However + // calling openlog() may inadvertently affect the behavior of other parts + // of the program also using syslog(). + // + // We don't check for write errors here, since there's not much else we can + // do if it fails. + auto fullMsg = folly::to( + "logging warning:", filename, ":", lineNumber, ": ", msg, "\n"); + folly::writeFull(STDERR_FILENO, fullMsg.data(), fullMsg.size()); + } +#endif +} } diff --git a/folly/experimental/logging/LoggerDB.h b/folly/experimental/logging/LoggerDB.h index 82a65a1c..b1a1f249 100644 --- a/folly/experimental/logging/LoggerDB.h +++ b/folly/experimental/logging/LoggerDB.h @@ -15,6 +15,7 @@ */ #pragma once +#include #include #include #include @@ -118,6 +119,43 @@ class LoggerDB { */ explicit LoggerDB(TestConstructorArg); + /** + * internalWarning() is used to report a problem when something goes wrong + * internally in the logging library. + * + * We can't log these messages through the normal logging flow since logging + * itself has failed. + * + * Example scenarios where this is used: + * - We fail to write to a log file (for instance, when the disk is full) + * - A LogHandler throws an unexpected exception + */ + template + static void internalWarning( + folly::StringPiece file, + int lineNumber, + Args&&... args) noexcept { + internalWarningImpl( + file, lineNumber, folly::to(std::forward(args)...)); + } + + using InternalWarningHandler = + void (*)(folly::StringPiece file, int lineNumber, std::string&&); + + /** + * Set a function to be called when the logging library generates an internal + * warning. + * + * The supplied handler should never throw exceptions. + * + * If a null handler is supplied, the default built-in handler will be used. + * + * The default handler reports the message with _CrtDbgReport(_CRT_WARN) on + * Windows, and prints the message to stderr on other platforms. It also + * rate limits messages if they are arriving too quickly. + */ + static void setInternalWarningHandler(InternalWarningHandler handler); + private: using LoggerNameMap = std::unordered_map< folly::StringPiece, @@ -138,6 +176,15 @@ class LoggerDB { folly::StringPiece name, LogCategory* parent); + static void internalWarningImpl( + folly::StringPiece filename, + int lineNumber, + std::string&& msg) noexcept; + static void defaultInternalWarningImpl( + folly::StringPiece filename, + int lineNumber, + std::string&& msg) noexcept; + /** * A map of LogCategory objects by name. * @@ -145,5 +192,7 @@ class LoggerDB { * have to be in canonical form. */ folly::Synchronized loggersByName_; + + static std::atomic warningHandler_; }; } -- 2.34.1