From: Adam Simpkins Date: Sat, 2 Dec 2017 00:53:51 +0000 (-0800) Subject: logging: update initialization code to use the new LogConfig logic X-Git-Tag: v2017.12.04.00~4 X-Git-Url: http://plrg.eecs.uci.edu/git/?p=folly.git;a=commitdiff_plain;h=6072ce3be8548bae30fdd48afe67e986074f5a5b logging: update initialization code to use the new LogConfig logic Summary: Replace the initLoggingGlogStyle() function with a more generic initLogging() function that accepts a log config string to be parsed with parseLogConfig(). Reviewed By: bolinfest, yfeldblum Differential Revision: D6342086 fbshipit-source-id: fb1bffd11f190b70e03e2ccbf2b30be08d655242 --- diff --git a/folly/experimental/logging/Init.cpp b/folly/experimental/logging/Init.cpp index d1bc050f..59d4f8b8 100644 --- a/folly/experimental/logging/Init.cpp +++ b/folly/experimental/logging/Init.cpp @@ -15,66 +15,58 @@ */ #include -#include -#include -#include -#include -#include +#include +#include +#include #include -#include - -using std::shared_ptr; -using std::string; -using std::vector; namespace folly { -void initLogLevels(StringPiece configString, LogLevel defaultRootLevel) { - // Set the default root category log level first - LoggerDB::get()->getCategory(".")->setLevel(defaultRootLevel); +/** + * The base logging settings to be applied in initLogging(), + * before any user-specified settings. + * + * This defines a log handler named "default" that writes to stderr, + * and configures the root log category to log to this handler and have a log + * level setting of WARN. + * + * Note that the default log handler uses async=false, so that log messages are + * written immediately to stderr from the thread that generated the log + * message. This is often undesirable, as it can slow down normal processing + * waiting for logging I/O. However, using async=true has some trade-offs of + * its own: it causes a new thread to be started, and not all message may get + * flushed to stderr if the program crashes. For now, using async=false seems + * like the safer trade-off here, but many programs may wish to change this + * default. + * + * The user-specified config string may override any of these values. + * If the user-specified config string ends up not using the default log + * handler, the handler will be automatically forgotten by the LoggerDB code. + */ +constexpr StringPiece kDefaultLoggingConfig = + ".=WARN:default; default=file,stream=stderr,async=false"; - // Then apply the configuration string - if (!configString.empty()) { - auto ret = LoggerDB::get()->processConfigString(configString); - if (!ret.empty()) { - throw LoggingConfigError(ret); - } - } -} +void initLogging(StringPiece configString) { + // Register the FileHandlerFactory + // + // TODO: In the future it would be nice to build a better mechanism so that + // additional LogHandlerFactory objects could be automatically registered on + // startup if they are linked into our current executable. + LoggerDB::get()->registerHandlerFactory( + std::make_unique()); -void initLoggingGlogStyle( - StringPiece configString, - LogLevel defaultRootLevel, - bool asyncWrites) { - // Configure log levels - initLogLevels(configString, defaultRootLevel); + // Parse the default log level settings before processing the input config + // string. + auto config = parseLogConfig(kDefaultLoggingConfig); - // Create the LogHandler - std::shared_ptr writer; - folly::File file{STDERR_FILENO, false}; - LogHandlerConfig handlerConfig{"file", {{"stream", "stderr"}}}; - if (asyncWrites) { - writer = std::make_shared(std::move(file)); - handlerConfig.options.emplace("async", "true"); - } else { - writer = std::make_shared(std::move(file)); - handlerConfig.options.emplace("async", "false"); + // Then apply the configuration string + if (!configString.empty()) { + auto inputConfig = parseLogConfig(configString); + config.update(inputConfig); } - auto handler = std::make_shared( - handlerConfig, std::make_shared(), std::move(writer)); - // Add the handler to the root category. - LoggerDB::get()->getCategory(".")->addHandler(std::move(handler)); + // Now apply the configuration to the LoggerDB + LoggerDB::get()->updateConfig(config); } -LoggingConfigError::LoggingConfigError(const vector& errors) - : invalid_argument{computeMessage(errors)} {} - -std::string LoggingConfigError::computeMessage(const vector& errors) { - string msg = "error parsing logging configuration:"; - for (const auto& error : errors) { - msg += "\n" + error; - } - return msg; -} } // namespace folly diff --git a/folly/experimental/logging/Init.h b/folly/experimental/logging/Init.h index 2b924abe..8cbf8d3e 100644 --- a/folly/experimental/logging/Init.h +++ b/folly/experimental/logging/Init.h @@ -20,46 +20,26 @@ * during program start-up. */ -#include -#include -#include - #include -#include namespace folly { /** - * Configure log category levels based on a configuration string. + * Initialize the logging library. * - * This can be used to process a logging configuration string (such as received - * via a command line flag) during program start-up. - */ -void initLogLevels( - folly::StringPiece configString = "", - LogLevel defaultRootLevel = LogLevel::WARNING); - -/** - * Initialize the logging library to write glog-style messages to stderr. + * The input string will be parsed with parseLogConfig() and then applied to + * the main LoggerDB singleton. * - * This initializes the log category levels as specified (using - * initLogLevels()), and adds a log handler that prints messages in glog-style - * format to stderr. - */ -void initLoggingGlogStyle( - folly::StringPiece configString = "", - LogLevel defaultRootLevel = LogLevel::WARNING, - bool asyncWrites = true); - -/** - * LoggingConfigError may be thrown by initLogLevels() if an error occurs - * parsing the configuration string. + * Before it is applied, the input configuration settings are first combined + * with some basic defaults on the root log category. The defaults set the + * root log level to WARN, and attach a log handler named "default" that writes + * messages to stderr. However, these base settings can be overridden if the + * input string specifies alternate settings for the root log category. + * + * Note that it is safe for code to use logging functions before calling + * initLogging(). However, messages logged before initLogging() is called will + * be ignored since no log handler objects have been defined. */ -class LoggingConfigError : public std::invalid_argument { - public: - explicit LoggingConfigError(const std::vector& errors); +void initLogging(folly::StringPiece configString = ""); - private: - std::string computeMessage(const std::vector& errors); -}; } // namespace folly diff --git a/folly/experimental/logging/LoggerDB.cpp b/folly/experimental/logging/LoggerDB.cpp index 2611e23c..299f2d71 100644 --- a/folly/experimental/logging/LoggerDB.cpp +++ b/folly/experimental/logging/LoggerDB.cpp @@ -107,40 +107,6 @@ void LoggerDB::setLevel(LogCategory* category, LogLevel level, bool inherit) { category->setLevelLocked(level, inherit); } -std::vector LoggerDB::processConfigString( - folly::StringPiece config) { - std::vector errors; - if (config.empty()) { - return errors; - } - - std::vector pieces; - folly::split(",", config, pieces); - for (const auto& p : pieces) { - auto idx = p.rfind('='); - if (idx == folly::StringPiece::npos) { - errors.emplace_back( - folly::sformat("missing '=' in logger configuration: \"{}\"", p)); - continue; - } - - auto category = p.subpiece(0, idx); - auto level_str = p.subpiece(idx + 1); - LogLevel level; - try { - level = stringToLogLevel(level_str); - } catch (const std::exception&) { - errors.emplace_back(folly::sformat( - "invalid log level \"{}\" for category \"{}\"", level_str, category)); - continue; - } - - setLevel(category, level); - } - - return errors; -} - LogConfig LoggerDB::getConfig() const { auto handlerInfo = handlerInfo_.rlock(); diff --git a/folly/experimental/logging/LoggerDB.h b/folly/experimental/logging/LoggerDB.h index a0038b3f..8ad4aaea 100644 --- a/folly/experimental/logging/LoggerDB.h +++ b/folly/experimental/logging/LoggerDB.h @@ -111,18 +111,6 @@ class LoggerDB { */ void resetConfig(const LogConfig& config); - /** - * Apply a configuration string specifying a series a log levels. - * - * The string format is a comma separated list of = sections. - * e.g.: "foo=DBG3,log.bar=WARN" - * - * Returns a list of error messages for each error encountered trying to - * parse the config string. The return value will be an empty vector if no - * errors were encountered. - */ - std::vector processConfigString(folly::StringPiece config); - /** * Remove all registered LogHandlers on all LogCategory objects. * diff --git a/folly/experimental/logging/example/main.cpp b/folly/experimental/logging/example/main.cpp index be4ba77a..72608df1 100644 --- a/folly/experimental/logging/example/main.cpp +++ b/folly/experimental/logging/example/main.cpp @@ -38,7 +38,7 @@ int main(int argc, char* argv[]) { // Call folly::init() and then initialize log levels and handlers folly::init(&argc, &argv); - initLoggingGlogStyle(FLAGS_logging, LogLevel::INFO); + folly::initLogging(FLAGS_logging); // All XLOG() statements in this file will log to the category // folly.experimental.logging.example.main diff --git a/folly/experimental/logging/test/AsyncFileWriterTest.cpp b/folly/experimental/logging/test/AsyncFileWriterTest.cpp index 753b07e7..eefcf746 100644 --- a/folly/experimental/logging/test/AsyncFileWriterTest.cpp +++ b/folly/experimental/logging/test/AsyncFileWriterTest.cpp @@ -615,8 +615,7 @@ TEST(AsyncFileWriter, discard) { int main(int argc, char* argv[]) { testing::InitGoogleTest(&argc, argv); folly::init(&argc, &argv); - // Don't use async logging in the async logging tests :-) - folly::initLoggingGlogStyle(FLAGS_logging, LogLevel::INFO, /* async */ false); + folly::initLogging(FLAGS_logging); return RUN_ALL_TESTS(); } diff --git a/folly/experimental/logging/test/FatalHelper.cpp b/folly/experimental/logging/test/FatalHelper.cpp index 3d65511f..3d4a0a64 100644 --- a/folly/experimental/logging/test/FatalHelper.cpp +++ b/folly/experimental/logging/test/FatalHelper.cpp @@ -19,10 +19,6 @@ #include DEFINE_string(logging, "", "Logging category configuration string"); -DEFINE_string( - handler_style, - "async", - "Log handler style: async, immediate, or none"); DEFINE_string( category, @@ -61,14 +57,6 @@ static InitChecker initChecker; namespace { int runHelper() { - if (FLAGS_handler_style == "async") { - initLoggingGlogStyle(FLAGS_logging, LogLevel::INFO, true); - } else if (FLAGS_handler_style == "immediate") { - initLoggingGlogStyle(FLAGS_logging, LogLevel::INFO, false); - } else if (FLAGS_handler_style != "none") { - XLOGF(FATAL, "unknown log handler style \"{}\"", FLAGS_handler_style); - } - if (!FLAGS_category.empty()) { folly::Logger logger{FLAGS_category}; FB_LOG(logger, FATAL, "crashing to category ", FLAGS_category); @@ -98,6 +86,7 @@ std::string fbLogFatalCheck() { int main(int argc, char* argv[]) { // Call folly::init() and then initialize log levels and handlers folly::init(&argc, &argv); + folly::initLogging(FLAGS_logging); // Do most of the work in a separate helper function. // diff --git a/folly/experimental/logging/test/LoggerDBTest.cpp b/folly/experimental/logging/test/LoggerDBTest.cpp index ee8e4ff6..844c22bd 100644 --- a/folly/experimental/logging/test/LoggerDBTest.cpp +++ b/folly/experimental/logging/test/LoggerDBTest.cpp @@ -73,27 +73,3 @@ TEST(LoggerDB, flushAllHandlers) { EXPECT_EQ(2, h2->getFlushCount()); EXPECT_EQ(2, h3->getFlushCount()); } - -TEST(LoggerDB, processConfigString) { - LoggerDB db{LoggerDB::TESTING}; - db.processConfigString("foo.bar=dbg5"); - EXPECT_EQ(LogLevel::DBG5, db.getCategory("foo.bar")->getLevel()); - EXPECT_EQ(LogLevel::DBG5, db.getCategory("foo.bar")->getEffectiveLevel()); - EXPECT_EQ(LogLevel::MAX_LEVEL, db.getCategory("foo")->getLevel()); - EXPECT_EQ(LogLevel::ERR, db.getCategory("foo")->getEffectiveLevel()); - EXPECT_EQ(LogLevel::ERR, db.getCategory("")->getLevel()); - EXPECT_EQ(LogLevel::ERR, db.getCategory("")->getEffectiveLevel()); - - EXPECT_EQ(LogLevel::MAX_LEVEL, db.getCategory("foo.bar.test")->getLevel()); - EXPECT_EQ( - LogLevel::DBG5, db.getCategory("foo.bar.test")->getEffectiveLevel()); - - db.processConfigString("sys=warn,foo.test=debug,foo.test.stuff=warn"); - EXPECT_EQ(LogLevel::WARN, db.getCategory("sys")->getLevel()); - EXPECT_EQ(LogLevel::WARN, db.getCategory("sys")->getEffectiveLevel()); - EXPECT_EQ(LogLevel::DEBUG, db.getCategory("foo.test")->getLevel()); - EXPECT_EQ(LogLevel::DEBUG, db.getCategory("foo.test")->getEffectiveLevel()); - EXPECT_EQ(LogLevel::WARN, db.getCategory("foo.test.stuff")->getLevel()); - EXPECT_EQ( - LogLevel::DEBUG, db.getCategory("foo.test.stuff")->getEffectiveLevel()); -} diff --git a/folly/experimental/logging/test/fatal_test.py b/folly/experimental/logging/test/fatal_test.py index 132b708b..04dc9ed0 100644 --- a/folly/experimental/logging/test/fatal_test.py +++ b/folly/experimental/logging/test/fatal_test.py @@ -69,17 +69,19 @@ class FatalTests(unittest.TestCase): subprocess.check_output([self.helper, '--crash=no']) def test_async(self): - err = self.run_helper('--handler_style=async') + handler_setings = 'default=file,stream=stderr,async=true' + err = self.run_helper('--logging=;' + handler_setings) self.assertRegex(err, self.get_crash_regex()) def test_immediate(self): - err = self.run_helper('--handler_style=immediate') + handler_setings = 'default=file,stream=stderr,async=false' + err = self.run_helper('--logging=;' + handler_setings) self.assertRegex(err, self.get_crash_regex()) def test_none(self): # The fatal message should be printed directly to stderr when there # are no logging handlers configured. - err = self.run_helper('--handler_style=none') + err = self.run_helper('--logging=ERR:') self.assertRegex(err, self.get_crash_regex(glog=False)) def test_other_category(self):