From: Adam Simpkins Date: Tue, 13 Jun 2017 01:33:03 +0000 (-0700) Subject: add a new logging library X-Git-Tag: v2017.06.19.00~32 X-Git-Url: http://plrg.eecs.uci.edu/git/?p=folly.git;a=commitdiff_plain;h=e9c1c0434713e921c98288e932c05f228a734886 add a new logging library Summary: This begins adding a new logging library for efficient, hierarchical logging. This includes the basic library framework, plus a README file with a brief overview and the motivation for creating a new logging library. Reviewed By: wez Differential Revision: D4911867 fbshipit-source-id: 359623e11feeaa547f3ac2c369bf806ee6996554 --- diff --git a/CMakeLists.txt b/CMakeLists.txt index a8895f73..9bb0f26f 100755 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -313,6 +313,18 @@ if (BUILD_TESTS) #TEST async_io_test SOURCES AsyncIOTest.cpp TEST fs_util_test SOURCES FsUtilTest.cpp + DIRECTORY experimental/logging/test/ + TEST logging-test + HEADERS + TestLogHandler.h + SOURCES + LogCategoryTest.cpp + LoggerDBTest.cpp + LoggerTest.cpp + LogLevelTest.cpp + LogMessageTest.cpp + LogNameTest.cpp + DIRECTORY fibers/test/ TEST fibers_test SOURCES FibersTest.cpp diff --git a/folly/Makefile.am b/folly/Makefile.am index 435b93a9..ca6b9409 100644 --- a/folly/Makefile.am +++ b/folly/Makefile.am @@ -2,12 +2,7 @@ if FOLLY_TESTMAIN MAYBE_INIT = init endif -if EXCEPTION_TRACER -MAYBE_EXCEPTION_TRACER = experimental/exception_tracer -endif - -SUBDIRS = . experimental $(MAYBE_INIT) test io/test experimental/io/test \ - stats/test $(MAYBE_EXCEPTION_TRACER) +SUBDIRS = . experimental $(MAYBE_INIT) test io/test stats/test ACLOCAL_AMFLAGS = -I m4 @@ -126,6 +121,13 @@ nobase_follyinclude_HEADERS = \ experimental/JemallocNodumpAllocator.h \ experimental/JSONSchema.h \ experimental/LockFreeRingBuffer.h \ + experimental/logging/LogCategory.h \ + experimental/logging/LogHandler.h \ + experimental/logging/LogLevel.h \ + experimental/logging/LogMessage.h \ + experimental/logging/LogName.h \ + experimental/logging/Logger.h \ + experimental/logging/LoggerDB.h \ experimental/NestedCommandLineApp.h \ experimental/observer/detail/Core.h \ experimental/observer/detail/GraphCycleDetector.h \ diff --git a/folly/configure.ac b/folly/configure.ac index 1d7595fb..e7c73c85 100644 --- a/folly/configure.ac +++ b/folly/configure.ac @@ -607,6 +607,7 @@ AC_CONFIG_FILES([Makefile test/function_benchmark/Makefile experimental/Makefile experimental/io/test/Makefile + experimental/logging/Makefile experimental/symbolizer/Makefile init/Makefile stats/test/Makefile]) diff --git a/folly/experimental/Makefile.am b/folly/experimental/Makefile.am index f67636da..b32b1003 100644 --- a/folly/experimental/Makefile.am +++ b/folly/experimental/Makefile.am @@ -1,3 +1,7 @@ if HAVE_LIBDWARF -SUBDIRS = symbolizer +MAYBE_SYMBOLIZER = symbolizer endif +if EXCEPTION_TRACER +MAYBE_EXCEPTION_TRACER = exception_tracer +endif +SUBDIRS = io/test logging $(MAYBE_SYMBOLIZER) $(MAYBE_EXCEPTION_TRACER) diff --git a/folly/experimental/logging/LogCategory.cpp b/folly/experimental/logging/LogCategory.cpp new file mode 100644 index 00000000..f6fcc109 --- /dev/null +++ b/folly/experimental/logging/LogCategory.cpp @@ -0,0 +1,183 @@ +/* + * Copyright 2004-present Facebook, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#include + +#include + +#include +#include +#include +#include +#include + +namespace folly { + +LogCategory::LogCategory(LoggerDB* db) + : effectiveLevel_{LogLevel::ERROR}, + level_{static_cast(LogLevel::ERROR)}, + parent_{nullptr}, + name_{}, + db_{db} {} + +LogCategory::LogCategory(StringPiece name, LogCategory* parent) + : effectiveLevel_{parent->getEffectiveLevel()}, + level_{static_cast(LogLevel::MAX_LEVEL) | FLAG_INHERIT}, + parent_{parent}, + name_{LogName::canonicalize(name)}, + db_{parent->getDB()}, + nextSibling_{parent_->firstChild_} { + parent_->firstChild_ = this; +} + +void LogCategory::processMessage(const LogMessage& message) { + // Make a copy of any attached LogHandlers, so we can release the handlers_ + // lock before holding them. + // + // In the common case there will only be a small number of handlers. Use a + // std::array in this case to avoid a heap allocation for the vector. + const std::shared_ptr* handlers = nullptr; + size_t numHandlers = 0; + constexpr uint32_t kSmallOptimizationSize = 5; + std::array, kSmallOptimizationSize> handlersArray; + std::vector> handlersVector; + { + auto lockedHandlers = handlers_.rlock(); + numHandlers = lockedHandlers->size(); + if (numHandlers <= kSmallOptimizationSize) { + for (size_t n = 0; n < numHandlers; ++n) { + handlersArray[n] = (*lockedHandlers)[n]; + } + handlers = handlersArray.data(); + } else { + handlersVector = *lockedHandlers; + handlers = handlersVector.data(); + } + } + + for (size_t n = 0; n < numHandlers; ++n) { + try { + handlers[n]->log(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()); + } + } + + // Propagate the message up to our parent LogCategory. + // + // Maybe in the future it might be worth adding a flag to control if a + // LogCategory should propagate messages to its parent or not. (This would + // be similar to log4j's "additivity" flag.) + // For now I don't have a strong use case for this. + if (parent_) { + parent_->processMessage(message); + } +} + +void LogCategory::addHandler(std::shared_ptr handler) { + auto handlers = handlers_.wlock(); + handlers->emplace_back(std::move(handler)); +} + +void LogCategory::clearHandlers() { + std::vector> emptyHandlersList; + // Swap out the handlers list with the handlers_ lock held. + { + auto handlers = handlers_.wlock(); + handlers->swap(emptyHandlersList); + } + // Destroy emptyHandlersList now that the handlers_ lock is released. + // This way we don't hold the handlers_ lock while invoking any of the + // LogHandler destructors. +} + +void LogCategory::setLevel(LogLevel level, bool inherit) { + // We have to set the level through LoggerDB, since we require holding + // the LoggerDB lock to iterate through our children in case our effective + // level changes. + db_->setLevel(this, level, inherit); +} + +void LogCategory::setLevelLocked(LogLevel level, bool inherit) { + // Truncate to LogLevel::MAX_LEVEL to make sure it does not conflict + // with our flag bits. + if (level > LogLevel::MAX_LEVEL) { + level = LogLevel::MAX_LEVEL; + } + // Make sure the inherit flag is always off for the root logger. + if (!parent_) { + inherit = false; + } + auto newValue = static_cast(level); + if (inherit) { + newValue |= FLAG_INHERIT; + } + + // Update the stored value + uint32_t oldValue = level_.exchange(newValue, std::memory_order_acq_rel); + + // Break out early if the value has not changed. + if (oldValue == newValue) { + return; + } + + // Update the effective log level + LogLevel newEffectiveLevel; + if (inherit) { + newEffectiveLevel = std::min(level, parent_->getEffectiveLevel()); + } else { + newEffectiveLevel = level; + } + updateEffectiveLevel(newEffectiveLevel); +} + +void LogCategory::updateEffectiveLevel(LogLevel newEffectiveLevel) { + auto oldEffectiveLevel = + effectiveLevel_.exchange(newEffectiveLevel, std::memory_order_acq_rel); + // Break out early if the value did not change. + if (newEffectiveLevel == oldEffectiveLevel) { + return; + } + + // Update all children loggers + LogCategory* child = firstChild_; + while (child != nullptr) { + child->parentLevelUpdated(newEffectiveLevel); + child = child->nextSibling_; + } +} + +void LogCategory::parentLevelUpdated(LogLevel parentEffectiveLevel) { + uint32_t levelValue = level_.load(std::memory_order_acquire); + auto inherit = (levelValue & FLAG_INHERIT); + if (!inherit) { + return; + } + + auto myLevel = static_cast(levelValue & ~FLAG_INHERIT); + auto newEffectiveLevel = std::min(myLevel, parentEffectiveLevel); + updateEffectiveLevel(newEffectiveLevel); +} +} diff --git a/folly/experimental/logging/LogCategory.h b/folly/experimental/logging/LogCategory.h new file mode 100644 index 00000000..ea6aca22 --- /dev/null +++ b/folly/experimental/logging/LogCategory.h @@ -0,0 +1,215 @@ +/* + * Copyright 2004-present Facebook, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#pragma once + +#include +#include +#include +#include + +#include +#include +#include + +namespace folly { + +class LoggerDB; +class LogHandler; +class LogMessage; + +/** + * LogCategory stores all of the logging configuration for a specific + * log category. + * + * This class is separate from Logger to allow multiple Logger objects to all + * refer to the same log category. Logger can be thought of as a small wrapper + * class that behaves like a pointer to a LogCategory object. + */ +class LogCategory { + public: + /** + * Create the root LogCategory. + * + * This should generally only be invoked by LoggerDB. + */ + explicit LogCategory(LoggerDB* db); + + /** + * Create a new LogCategory. + * + * This should only be invoked by LoggerDB, while holding the main LoggerDB + * lock. + * + * The name argument should already be in canonical form. + * + * This constructor automatically adds this new LogCategory to the parent + * category's firstChild_ linked-list. + */ + LogCategory(folly::StringPiece name, LogCategory* parent); + + /** + * Get the name of this log category. + */ + const std::string& getName() const { + return name_; + } + + /** + * Get the level for this log category. + */ + LogLevel getLevel() const { + return static_cast( + level_.load(std::memory_order_acquire) & ~FLAG_INHERIT); + } + + /** + * Get the effective level for this log category. + * + * This is the minimum log level of this category and all of its parents. + * Log messages below this level will be ignored, while messages at or + * above this level need to be processed by this category or one of its + * parents. + */ + LogLevel getEffectiveLevel() const { + return effectiveLevel_.load(std::memory_order_acquire); + } + + /** + * Get the effective log level using std::memory_order_relaxed. + * + * This is primarily used for log message checks. Most other callers should + * use getEffectiveLevel() above to be more conservative with regards to + * memory ordering. + */ + LogLevel getEffectiveLevelRelaxed() const { + return effectiveLevel_.load(std::memory_order_relaxed); + } + + /** + * Set the log level for this LogCategory. + * + * Messages logged to a specific log category will be ignored unless the + * message log level is greater than the LogCategory's effective log level. + * + * If inherit is true, LogCategory's effective log level is the minimum of + * its level and its parent category's effective log level. If inherit is + * false, the LogCategory's effective log level is simply its log level. + * (Setting inherit to false is necessary if you want a child LogCategory to + * use a less verbose level than its parent categories.) + */ + void setLevel(LogLevel level, bool inherit = true); + + /** + * Process a log message. + * + * This method generally should be invoked through the Logger APIs, + * rather than calling this directly. + * + * This method assumes that log level admittance checks have already been + * performed. This method unconditionally passes the message to the + * LogHandlers attached to this LogCategory, without any additional log level + * checks (apart from the ones done in the LogHandlers). + */ + void processMessage(const LogMessage& message); + + /** + * Get the LoggerDB that this LogCategory belongs to. + * + * This is almost always the main LoggerDB singleton returned by + * LoggerDB::get(). The logging unit tests are the main location that + * creates alternative LoggerDB objects. + */ + LoggerDB* getDB() const { + return db_; + } + + /** + * Attach a LogHandler to this category. + */ + void addHandler(std::shared_ptr handler); + + /** + * Remove all LogHandlers from this category. + */ + void clearHandlers(); + + /** + * Note: setLevelLocked() may only be called while holding the main + * LoggerDB lock. + * + * This method should only be invoked by LoggerDB. + */ + void setLevelLocked(LogLevel level, bool inherit); + + private: + enum : uint32_t { FLAG_INHERIT = 0x80000000 }; + + // Forbidden copy constructor and assignment operator + LogCategory(LogCategory const&) = delete; + LogCategory& operator=(LogCategory const&) = delete; + + void updateEffectiveLevel(LogLevel newEffectiveLevel); + void parentLevelUpdated(LogLevel parentEffectiveLevel); + + /** + * The minimum log level of this category and all of its parents. + */ + std::atomic effectiveLevel_{LogLevel::MAX_LEVEL}; + + /** + * The current log level for this category. + * + * The most significant bit is used to indicate if this logger should + * inherit its parent's effective log level. + */ + std::atomic level_{0}; + + /** + * Our parent LogCategory in the category hierarchy. + * + * For instance, if our log name is "foo.bar.abc", our parent category + * is "foo.bar". + */ + LogCategory* const parent_{nullptr}; + + /** + * Our log category name. + */ + const std::string name_; + + /** + * The list of LogHandlers attached to this category. + */ + folly::Synchronized>> handlers_; + + /** + * A pointer to the LoggerDB that we belong to. + * + * This is almost always the main LoggerDB singleton. Unit tests are the + * main place where we use other LoggerDB objects besides the singleton. + */ + LoggerDB* const db_{nullptr}; + + /** + * Pointers to children and sibling loggers. + * These pointers should only ever be accessed while holding the main + * LoggerDB lock. (These are only modified when creating new loggers, + * which occurs with the main LoggerDB lock held.) + */ + LogCategory* firstChild_{nullptr}; + LogCategory* nextSibling_{nullptr}; +}; +} diff --git a/folly/experimental/logging/LogHandler.cpp b/folly/experimental/logging/LogHandler.cpp new file mode 100644 index 00000000..567e2b91 --- /dev/null +++ b/folly/experimental/logging/LogHandler.cpp @@ -0,0 +1,30 @@ +/* + * Copyright 2004-present Facebook, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#include + +#include + +namespace folly { + +void LogHandler::log( + const LogMessage& message, + const LogCategory* handlerCategory) { + if (message.getLevel() < getLevel()) { + return; + } + handleMessage(message, handlerCategory); +} +} diff --git a/folly/experimental/logging/LogHandler.h b/folly/experimental/logging/LogHandler.h new file mode 100644 index 00000000..585468d8 --- /dev/null +++ b/folly/experimental/logging/LogHandler.h @@ -0,0 +1,87 @@ +/* + * Copyright 2004-present Facebook, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#pragma once + +#include + +#include + +namespace folly { + +class LogCategory; +class LogMessage; + +/** + * LogHandler represents a generic API for processing log messages. + * + * LogHandlers have an associated log level. The LogHandler will discard any + * messages below its log level. This allows specific LogHandlers to perform + * additional filtering of messages even if the messages were enabled at the + * LogCategory level. For instance, a single LogCategory may have two + * LogHandlers attached, one that logs locally to a file, and one that sends + * messages to a remote logging service. The local LogHandler may be + * configured to record all messages, but the remote LogHandler may want to + * only process ERROR messages and above, even when debug logging is enabled + * for this LogCategory. + * + * By default the LogHandler level is set to LogLevel::NONE, which means that + * all log messages will be processed. + */ +class LogHandler { + public: + LogHandler() = default; + virtual ~LogHandler() = default; + + /** + * log() is called when a log message is processed by a LogCategory that this + * handler is attached to. + * + * log() performs a level check, and calls handleMessage() if it passes. + * + * @param message The LogMessage objet. + * @param handlerCategory The LogCategory that invoked log(). This is the + * category that this LogHandler is attached to. Note that this may be + * different than the category that this message was originally logged + * at. message->getCategory() returns the category of the log message. + */ + void log(const LogMessage& message, const LogCategory* handlerCategory); + + LogLevel getLevel() const { + return level_.load(std::memory_order_acquire); + } + void setLevel(LogLevel level) { + return level_.store(level, std::memory_order_release); + } + + protected: + /** + * handleMessage() is invoked to process a LogMessage. + * + * This must be implemented by LogHandler subclasses. + * + * handleMessage() will always be invoked from the thread that logged the + * message. LogMessage::getThreadID() contains the thread ID, but the + * LogHandler can also include any other thread-local state they desire, and + * this will always be data for the thread that originated the log message. + */ + virtual void handleMessage( + const LogMessage& message, + const LogCategory* handlerCategory) = 0; + + private: + std::atomic level_{LogLevel::NONE}; +}; +} diff --git a/folly/experimental/logging/LogLevel.cpp b/folly/experimental/logging/LogLevel.cpp new file mode 100644 index 00000000..25408f51 --- /dev/null +++ b/folly/experimental/logging/LogLevel.cpp @@ -0,0 +1,112 @@ +/* + * Copyright 2004-present Facebook, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#include + +#include +#include + +#include + +using std::string; + +namespace folly { + +LogLevel stringToLogLevel(StringPiece name) { + string lowerNameStr; + lowerNameStr.reserve(name.size()); + for (char c : name) { + lowerNameStr.push_back(static_cast(std::tolower(c))); + } + StringPiece lowerName{lowerNameStr}; + + // If the string is of the form "LogLevel::foo" or "LogLevel(foo)" + // strip it down just to "foo". This makes sure we can process both + // the "LogLevel::DEBUG" and "LogLevel(1234)" formats produced by + // logLevelToString(). + constexpr StringPiece lowercasePrefix{"loglevel::"}; + constexpr StringPiece wrapperPrefix{"loglevel("}; + if (lowerName.startsWith(lowercasePrefix)) { + lowerName.advance(lowercasePrefix.size()); + } else if (lowerName.startsWith(wrapperPrefix) && lowerName.endsWith(")")) { + lowerName.advance(wrapperPrefix.size()); + lowerName.subtract(1); + } + + if (lowerName == "none") { + return LogLevel::NONE; + } else if (lowerName == "debug") { + return LogLevel::DEBUG; + } else if (lowerName == "info") { + return LogLevel::INFO; + } else if (lowerName == "warn" || lowerName == "warning") { + return LogLevel::WARN; + } else if (lowerName == "error" || lowerName == "err") { + return LogLevel::ERR; + } else if (lowerName == "critical") { + return LogLevel::CRITICAL; + } else if (lowerName == "max" || lowerName == "max_level") { + return LogLevel::MAX_LEVEL; + } + + if (lowerName.startsWith("dbg")) { + auto remainder = lowerName.subpiece(3); + auto level = folly::tryTo(remainder).value_or(-1); + if (level < 0 || level > 100) { + throw std::range_error("invalid dbg logger level: " + name.str()); + } + return LogLevel::DBG0 - level; + } + + // Try as an plain integer if all else fails + try { + auto level = folly::to(lowerName); + return static_cast(level); + } catch (const std::exception& ex) { + throw std::range_error("invalid logger name " + name.str()); + } +} + +string logLevelToString(LogLevel level) { + if (level == LogLevel::NONE) { + return "LogLevel::NONE"; + } else if (level == LogLevel::DEBUG) { + return "LogLevel::DEBUG"; + } else if (level == LogLevel::INFO) { + return "LogLevel::INFO"; + } else if (level == LogLevel::WARN) { + return "LogLevel::WARN"; + } else if (level == LogLevel::ERR) { + return "LogLevel::ERR"; + } else if (level == LogLevel::CRITICAL) { + return "LogLevel::CRITICAL"; + } else if (level == LogLevel::MAX_LEVEL) { + return "LogLevel::MAX_LEVEL"; + } + + if (static_cast(level) <= static_cast(LogLevel::DBG0) && + static_cast(level) > static_cast(LogLevel::DEBUG)) { + auto num = + static_cast(LogLevel::DBG0) - static_cast(level); + return folly::to("LogLevel::DBG", num); + } + return folly::to("LogLevel(", static_cast(level), ")"); +} + +std::ostream& operator<<(std::ostream& os, LogLevel level) { + os << logLevelToString(level); + return os; +} +} diff --git a/folly/experimental/logging/LogLevel.h b/folly/experimental/logging/LogLevel.h new file mode 100644 index 00000000..347a7953 --- /dev/null +++ b/folly/experimental/logging/LogLevel.h @@ -0,0 +1,129 @@ +/* + * Copyright 2004-present Facebook, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#pragma once + +#include +#include +#include + +#include + +namespace folly { + +/** + * Log level values. + * + * Higher levels are more important than lower ones. + * + * However, the numbers in the DBG* level names are reversed, and can be + * thought of as debug verbosity levels. Increasing DBG* numbers mean + * increasing level of verbosity. DBG0 is the least verbose debug level, + * DBG1 is one level higher of verbosity, etc. + */ +enum class LogLevel : uint32_t { + NONE = 0, + + DEBUG = 900, + DBG0 = 1000, + DBG1 = 999, + DBG2 = 998, + DBG3 = 997, + DBG4 = 996, + DBG5 = 995, + DBG6 = 994, + DBG7 = 993, + DBG8 = 992, + DBG9 = 991, + + INFO = 2000, + WARN = 3000, + WARNING = 3000, + + // Unfortunately Windows headers #define ERROR + // On Windows platforms we avoid defining ERROR. However we make it + // available on other platforms, to make it easier to convert code from + // other log libraries that also use ERROR as their log level name (e.g., + // glog). + ERR = 4000, +#ifndef ERROR + ERROR = 4000, +#endif + + CRITICAL = 5000, + + // The most significant bit is used by LogCategory to store a flag value, + // so the maximum value has that bit cleared. + // + // (We call this MAX_LEVEL instead of MAX just since MAX() is commonly + // defined as a preprocessor macro by some C headers.) + MAX_LEVEL = 0x7fffffff, +}; + +/* + * Support adding and subtracting integers from LogLevels, to create slightly + * adjusted log level values. + */ +inline LogLevel operator+(LogLevel level, uint32_t value) { + auto newValue = static_cast(level) + value; + // Cap the result at LogLevel::MAX_LEVEL + if (newValue > static_cast(LogLevel::MAX_LEVEL)) { + return LogLevel::MAX_LEVEL; + } + return static_cast(newValue); +} +inline LogLevel& operator+=(LogLevel& level, uint32_t value) { + level = level + value; + return level; +} +inline LogLevel operator-(LogLevel level, uint32_t value) { + return static_cast(static_cast(level) - value); +} +inline LogLevel& operator-=(LogLevel& level, uint32_t value) { + level = level - value; + return level; +} + +/* + * Comparisons between LogLevel values + */ +inline bool operator<=(LogLevel a, LogLevel b) { + return static_cast(a) <= static_cast(b); +} +inline bool operator<(LogLevel a, LogLevel b) { + return static_cast(a) < static_cast(b); +} +inline bool operator>=(LogLevel a, LogLevel b) { + return static_cast(a) >= static_cast(b); +} +inline bool operator>(LogLevel a, LogLevel b) { + return static_cast(a) > static_cast(b); +} + +/** + * Construct a LogLevel from a string name. + */ +LogLevel stringToLogLevel(folly::StringPiece name); + +/** + * Get a human-readable string representing the LogLevel. + */ +std::string logLevelToString(LogLevel level); + +/** + * Print a LogLevel in a human readable format. + */ +std::ostream& operator<<(std::ostream& os, LogLevel level); +} diff --git a/folly/experimental/logging/LogMessage.cpp b/folly/experimental/logging/LogMessage.cpp new file mode 100644 index 00000000..3ec39603 --- /dev/null +++ b/folly/experimental/logging/LogMessage.cpp @@ -0,0 +1,134 @@ +/* + * Copyright 2004-present Facebook, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#include + +#include + +using std::chrono::system_clock; + +namespace folly { + +LogMessage::LogMessage( + const LogCategory* category, + LogLevel level, + StringPiece filename, + unsigned int lineNumber, + std::string&& msg) + : category_{category}, + level_{level}, + threadID_{getOSThreadID()}, + timestamp_{system_clock::now()}, + filename_{filename}, + lineNumber_{lineNumber}, + rawMessage_{std::move(msg)} { + sanitizeMessage(); +} + +LogMessage::LogMessage( + const LogCategory* category, + LogLevel level, + system_clock::time_point timestamp, + StringPiece filename, + unsigned int lineNumber, + std::string&& msg) + : category_{category}, + level_{level}, + threadID_{getOSThreadID()}, + timestamp_{timestamp}, + filename_{filename}, + lineNumber_{lineNumber}, + rawMessage_{std::move(msg)} { + sanitizeMessage(); +} + +StringPiece LogMessage::getFileBaseName() const { +#if _WIN32 + // Windows allows either backwards or forwards slash as path separator + auto idx1 = filename_.rfind('\\'); + auto idx2 = filename_.rfind('/'); + StringPiece::size_type idx; + if (idx1 == StringPiece::npos) { + idx = idx2; + } else if (idx2 == StringPiece::npos) { + idx = idx1; + } else { + idx = std::max(idx1, idx2); + } +#else + auto idx = filename_.rfind('/'); +#endif + if (idx == StringPiece::npos) { + return filename_; + } + return filename_.subpiece(idx + 1); +} + +void LogMessage::sanitizeMessage() { + // Compute how long the sanitized string will be. + size_t sanitizedLength = 0; + for (const char c : rawMessage_) { + if (c == '\\') { + // Backslashes are escaped as two backslashes + sanitizedLength += 2; + } else if (static_cast(c) < 0x20) { + // Newlines and tabs are emitted directly with no escaping. + // All other control characters are emitted as \xNN (4 characters) + if (c == '\n') { + sanitizedLength += 1; + containsNewlines_ = true; + } else if (c == '\t') { + sanitizedLength += 1; + } else { + sanitizedLength += 4; + } + } else if (c == 0x7f) { + // Bytes above the ASCII range are emitted as \xNN (4 characters) + sanitizedLength += 4; + } else { + // This character will be emitted as-is, with no escaping. + ++sanitizedLength; + } + } + + // If nothing is different, just use rawMessage_ directly, + // and don't populate message_. + if (sanitizedLength == rawMessage_.size()) { + return; + } + + message_.reserve(sanitizedLength); + for (const char c : rawMessage_) { + if (c == '\\') { + message_.push_back('\\'); + message_.push_back('\\'); + } else if (static_cast(c) < 0x20) { + if (c == '\n' || c == '\t') { + message_.push_back(c); + } else { + static constexpr StringPiece hexdigits{"0123456789abcdef"}; + std::array data{ + {'\\', 'x', hexdigits[(c >> 4) & 0xf], hexdigits[c & 0xf]}}; + message_.append(data.data(), data.size()); + } + } else if (c == 0x7f) { + constexpr std::array data{{'\\', 'x', '7', 'f'}}; + message_.append(data.data(), data.size()); + } else { + message_.push_back(c); + } + } +} +} diff --git a/folly/experimental/logging/LogMessage.h b/folly/experimental/logging/LogMessage.h new file mode 100644 index 00000000..ab859433 --- /dev/null +++ b/folly/experimental/logging/LogMessage.h @@ -0,0 +1,152 @@ +/* + * Copyright 2004-present Facebook, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#pragma once + +#include +#include +#include + +#include +#include + +namespace folly { + +class LogCategory; + +/** + * LogMessage represents a single message to be logged. + * + * LogMessage objects are relatively temporary objects, that only exist for the + * time it takes to invoke all of the appropriate LogHandlers. These generally + * only live in the thread that logged the message, and are not modified once + * created. (That said, LogHandler implementations may copy and store + * LogMessage objects for later use if desired.) + */ +class LogMessage { + public: + LogMessage( + const LogCategory* category, + LogLevel level, + folly::StringPiece filename, + unsigned int lineNumber, + std::string&& msg); + LogMessage( + const LogCategory* category, + LogLevel level, + folly::StringPiece filename, + unsigned int lineNumber, + folly::StringPiece msg) + : LogMessage(category, level, filename, lineNumber, msg.str()) {} + + /** + * Construct a LogMessage with an explicit timestamp. + * This is primarily intended for use in unit tests, so the tests can get + * deterministic behavior with regards to timestamps. + */ + LogMessage( + const LogCategory* category, + LogLevel level, + std::chrono::system_clock::time_point timestamp, + folly::StringPiece filename, + unsigned int lineNumber, + std::string&& msg); + + const LogCategory* getCategory() const { + return category_; + } + + LogLevel getLevel() const { + return level_; + } + + folly::StringPiece getFileName() const { + return filename_; + } + folly::StringPiece getFileBaseName() const; + + unsigned int getLineNumber() const { + return lineNumber_; + } + + std::chrono::system_clock::time_point getTimestamp() const { + return timestamp_; + } + + uint64_t getThreadID() const { + return threadID_; + } + + const std::string& getMessage() const { + // If no characters needed to be sanitized, message_ will be empty. + if (message_.empty()) { + return rawMessage_; + } + return message_; + } + + const std::string& getRawMessage() const { + return rawMessage_; + } + + bool containsNewlines() const { + return containsNewlines_; + } + + private: + void sanitizeMessage(); + + const LogCategory* const category_{nullptr}; + LogLevel const level_{static_cast(0)}; + uint64_t const threadID_{0}; + std::chrono::system_clock::time_point const timestamp_; + + /** + * The name of the source file that generated this log message. + */ + folly::StringPiece const filename_; + + /** + * The line number in the source file that generated this log message. + */ + unsigned int const lineNumber_{0}; + + /** + * containsNewlines_ will be true if the message contains internal newlines. + * + * This allows log handlers that perform special handling of multi-line + * messages to easily detect if a message contains multiple lines or not. + */ + bool containsNewlines_{false}; + + /** + * rawMessage_ contains the original message. + * + * This may contain arbitrary binary data, including unprintable characters + * and nul bytes. + */ + std::string const rawMessage_; + + /** + * message_ contains a sanitized version of the log message. + * + * nul bytes and unprintable characters have been escaped. + * This message may still contain newlines, however. LogHandler classes + * are responsible for deciding how they want to handle log messages with + * internal newlines. + */ + std::string message_; +}; +} diff --git a/folly/experimental/logging/LogName.cpp b/folly/experimental/logging/LogName.cpp new file mode 100644 index 00000000..8bf8398f --- /dev/null +++ b/folly/experimental/logging/LogName.cpp @@ -0,0 +1,127 @@ +/* + * Copyright 2004-present Facebook, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#include + +namespace folly { + +std::string LogName::canonicalize(StringPiece input) { + std::string cname; + cname.reserve(input.size()); + + // Ignore trailing '.'s + size_t end = input.size(); + while (end > 0 && input[end - 1] == '.') { + --end; + } + + bool ignoreDot = true; + for (size_t idx = 0; idx < end; ++idx) { + if (ignoreDot && input[idx] == '.') { + continue; + } + cname.push_back(input[idx]); + ignoreDot = (input[idx] == '.'); + } + return cname; +} + +size_t LogName::hash(StringPiece name) { + // Code based on StringPiece::hash(), but which ignores leading and + // trailing '.' characters, as well as multiple consecutive '.' characters, + // so equivalent names result in the same hash. + uint32_t hash = 5381; + + size_t end = name.size(); + while (end > 0 && name[end - 1] == '.') { + --end; + } + + bool ignoreDot = true; + for (size_t idx = 0; idx < end; ++idx) { + if (ignoreDot && name[idx] == '.') { + continue; + } + hash = ((hash << 5) + hash) + name[idx]; + // If this character was a '.', ignore subsequent consecutive '.'s + ignoreDot = (name[idx] == '.'); + } + return hash; +} + +int LogName::cmp(StringPiece a, StringPiece b) { + // Ignore trailing '.'s + auto stripTrailingDots = [](StringPiece& s) { + while (!s.empty() && s.back() == '.') { + s.uncheckedSubtract(1); + } + }; + stripTrailingDots(a); + stripTrailingDots(b); + + // Advance ptr until it no longer points to a '.' + // This is used to skip over consecutive sequences of '.' characters. + auto skipOverDots = [](StringPiece& s) { + while (!s.empty() && s.front() == '.') { + s.uncheckedAdvance(1); + } + }; + + bool ignoreDot = true; + while (true) { + if (ignoreDot) { + skipOverDots(a); + skipOverDots(b); + } + if (a.empty()) { + return b.empty() ? 0 : -1; + } else if (b.empty()) { + return 1; + } + if (a.front() != b.front()) { + return a.front() - b.front(); + } + ignoreDot = (a.front() == '.'); + a.uncheckedAdvance(1); + b.uncheckedAdvance(1); + } +} + +StringPiece LogName::getParent(StringPiece name) { + if (name.empty()) { + return name; + } + + ssize_t idx = name.size(); + + // Skip over any trailing '.' characters + while (idx > 0 && name[idx - 1] == '.') { + --idx; + } + + // Now walk backwards to the next '.' character + while (idx > 0 && name[idx - 1] != '.') { + --idx; + } + + // And again skip over any '.' characters, in case there are multiple + // repeated characters. + while (idx > 0 && name[idx - 1] == '.') { + --idx; + } + + return StringPiece(name.begin(), idx); +} +} diff --git a/folly/experimental/logging/LogName.h b/folly/experimental/logging/LogName.h new file mode 100644 index 00000000..dfe055fd --- /dev/null +++ b/folly/experimental/logging/LogName.h @@ -0,0 +1,87 @@ +/* + * Copyright 2004-present Facebook, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#pragma once + +#include + +namespace folly { + +/** + * The LogName class contains utility functions for processing log category + * names. It primarily handles canonicalization of names. + * + * For instance, "foo.bar", "foo..bar", and ".foo.bar..." all refer to the same + * log category. + */ +class LogName { + public: + /** + * Return a canonicalized version of the log name. + * + * Leading and trailing '.' characters are removed, and all sequences of + * consecutive '.' characters are replaced with a single '.' + */ + static std::string canonicalize(folly::StringPiece name); + + /** + * Hash a log name. + * + * The log name does not need to be pre-canonicalized. + * The hash for equivalent log names will always be equal. + */ + static size_t hash(folly::StringPiece name); + + /** + * Compare two log names. + * + * The log name does not need to be pre-canonicalized. + * Returns 0 if and only if the two names refer to the same log category. + * Otherwise, returns -1 if the canonical version of nameA is less than the + * canonical version of nameB. + */ + static int cmp(folly::StringPiece nameA, folly::StringPiece nameB); + + /** + * Get the name of the parent log category. + * + * Returns a StringPiece pointing into the input data. + * As a result, the parent log name may not be canonical if the input log + * name is not already canonical. + * + * If the input log name refers to the root log category, an empty + * StringPiece will be returned. + */ + static folly::StringPiece getParent(folly::StringPiece name); + + /** + * Hash functor that can be used with standard library containers. + */ + struct Hash { + size_t operator()(folly::StringPiece key) const { + return LogName::hash(key); + } + }; + + /** + * Equality functor that can be used with standard library containers. + */ + struct Equals { + bool operator()(folly::StringPiece a, folly::StringPiece b) const { + return LogName::cmp(a, b) == 0; + } + }; +}; +} diff --git a/folly/experimental/logging/Logger.cpp b/folly/experimental/logging/Logger.cpp new file mode 100644 index 00000000..63ad5ae0 --- /dev/null +++ b/folly/experimental/logging/Logger.cpp @@ -0,0 +1,52 @@ +/* + * Copyright 2004-present Facebook, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#include + +#include + +#include +#include +#include + +using std::string; + +namespace folly { + +Logger::Logger(StringPiece name) : Logger{LoggerDB::get()->getCategory(name)} {} + +Logger::Logger(LogCategory* cat) : category_(cat) {} + +Logger::Logger(LoggerDB* db, StringPiece name) + : Logger{db->getCategory(name)} {} + +void Logger::log( + LogLevel level, + StringPiece filename, + unsigned int lineNumber, + std::string&& msg) const { + category_->processMessage( + LogMessage{category_, level, filename, lineNumber, std::move(msg)}); +} + +void Logger::log( + LogLevel level, + StringPiece filename, + unsigned int lineNumber, + folly::StringPiece msg) const { + category_->processMessage( + LogMessage{category_, level, filename, lineNumber, msg}); +} +} diff --git a/folly/experimental/logging/Logger.h b/folly/experimental/logging/Logger.h new file mode 100644 index 00000000..4f743d1d --- /dev/null +++ b/folly/experimental/logging/Logger.h @@ -0,0 +1,212 @@ +/* + * Copyright 2004-present Facebook, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#pragma once + +#include +#include +#include +#include + +/** + * Log a message to the specified logger. + * + * This macro avoids evaluating the log arguments unless the log level check + * succeeds. + */ +#define FB_LOG(logger, level, msg, ...) \ + do { \ + const auto fbLogLevelTmp = ::folly::LogLevel::level; \ + const auto& fbLoggerTmp = (logger); \ + if (fbLoggerTmp.logCheck(fbLogLevelTmp)) { \ + fbLoggerTmp.log( \ + fbLogLevelTmp, __FILE__, __LINE__, (msg), ##__VA_ARGS__); \ + } \ + } while (0) + +/** + * Log a message to the specified logger, using a folly::format() string. + * + * The arguments will be processed using folly::format(). The format syntax + * is similar to Python format strings. + * + * This macro avoids evaluating the log arguments unless the log level check + * succeeds. + */ +#define FB_LOGF(logger, level, fmt, ...) \ + do { \ + const auto fbLogLevelTmp = ::folly::LogLevel::level; \ + const auto& fbLoggerTmp = (logger); \ + if (fbLoggerTmp.logCheck(fbLogLevelTmp)) { \ + fbLoggerTmp.logf( \ + fbLogLevelTmp, __FILE__, __LINE__, (fmt), ##__VA_ARGS__); \ + } \ + } while (0) + +namespace folly { + +class LoggerDB; +class LogMessage; + +/** + * Logger is the class you will normally use to log messages. + * + * The Logger is really just a small wrapper class that contains a pointer + * to the appropriate LogCategory object. It exists to allow for easy static + * initialization of log categories, as well as to provide fast checking of the + * current effective log level. + */ +class Logger { + public: + /** + * Construct a Logger for the given category name. + * + * A LogCategory object for this category will be created if one does not + * already exist. + */ + explicit Logger(folly::StringPiece name); + + /** + * Construct a Logger pointing to an existing LogCategory object. + */ + explicit Logger(LogCategory* cat); + + /** + * Construct a Logger for a specific LoggerDB object, rather than the main + * singleton. + * + * This is primarily intended for use in unit tests. + */ + Logger(LoggerDB* db, folly::StringPiece name); + + /** + * Get the effective level for this logger. + * + * This is the minimum log level of this logger, or any of its parents. + * Log messages below this level will be ignored, while messages at or + * above this level need to be processed by this logger or one of its + * parents. + */ + LogLevel getEffectiveLevel() const { + return category_->getEffectiveLevel(); + } + + /** + * Check whether this Logger or any of its parent Loggers would do anything + * with a log message at the given level. + */ + bool logCheck(LogLevel level) const { + // We load the effective level using std::memory_order_relaxed. + // + // We want to make log checks as lightweight as possible. It's fine if we + // don't immediately respond to changes made to the log level from other + // threads. We can wait until some other operation triggers a memory + // barrier before we honor the new log level setting. No other memory + // accesses depend on the log level value. Callers should not rely on all + // other threads to immediately stop logging as soon as they decrease the + // log level for a given category. + return category_->getEffectiveLevelRelaxed() <= level; + } + + /** + * Unconditionally log a message. + * + * The caller is responsible for calling logCheck() before log() to ensure + * that this log message should be admitted. This is typically done with one + * of the logging macros. + */ + void log( + LogLevel level, + folly::StringPiece filename, + unsigned int lineNumber, + std::string&& msg) const; + void log( + LogLevel level, + folly::StringPiece filename, + unsigned int lineNumber, + folly::StringPiece msg) const; + + /** + * Unconditionally log a message. + * + * This concatenates the arguments into a string using + * folly::to() + */ + template + void log( + LogLevel level, + folly::StringPiece filename, + unsigned int lineNumber, + Args&&... args) const { + std::string msg; + try { + msg = folly::to(std::forward(args)...); + } catch (const std::exception& ex) { + // This most likely means there was some error converting the arguments + // to strings. Handle the exception here, rather than letting it + // propagate up, since callers generally do not expect log statements to + // throw. + // + // Just log an error message letting indicating that something went wrong + // formatting the log message. + msg = + folly::to("error constructing log message: ", ex.what()); + } + log(level, filename, lineNumber, std::move(msg)); + } + + /** + * Unconditionally log a message using a format string. + * + * This uses folly::format() to format the message. + */ + template + void logf( + LogLevel level, + folly::StringPiece filename, + unsigned int lineNumber, + folly::StringPiece fmt, + Args&&... args) const { + std::string msg; + try { + msg = folly::sformat(fmt, std::forward(args)...); + } catch (const std::exception& ex) { + // This most likely means that the caller had a bug in their format + // string/arguments. Handle the exception here, rather than letting it + // propagate up, since callers generally do not expect log statements to + // throw. + // + // Log the format string by itself, to help the developer at least + // identify the buggy format string in their code. + msg = folly::to( + "error formatting log message: ", + ex.what(), + "; format string: ", + fmt); + } + log(level, filename, lineNumber, std::move(msg)); + } + + /** + * Get the LogCategory that this Logger refers to. + */ + LogCategory* getCategory() const { + return category_; + } + + private: + LogCategory* const category_{nullptr}; +}; +} diff --git a/folly/experimental/logging/LoggerDB.cpp b/folly/experimental/logging/LoggerDB.cpp new file mode 100644 index 00000000..bf887144 --- /dev/null +++ b/folly/experimental/logging/LoggerDB.cpp @@ -0,0 +1,173 @@ +/* + * Copyright 2004-present Facebook, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#include + +#include +#include +#include +#include + +namespace folly { + +namespace { +class LoggerDBSingleton { + public: + explicit LoggerDBSingleton(LoggerDB* db) : db_{db} {} + ~LoggerDBSingleton() { + // We intentionally leak the LoggerDB object on destruction. + // We want Logger objects to remain valid for the entire lifetime of the + // program, without having to worry about destruction ordering issues, or + // making the Logger perform reference counting on the LoggerDB. + // + // Therefore the main LoggerDB object, and all of the LogCategory objects + // it contains, are always intentionally leaked. + // + // However, we do call db_->cleanupHandlers() to destroy any registered + // LogHandler objects. The LogHandlers can be user-defined objects and may + // hold resources that should be cleaned up. + db_->cleanupHandlers(); + } + + LoggerDB* getDB() const { + return db_; + } + + private: + LoggerDB* db_; +}; +} + +LoggerDB* LoggerDB::get() { + // Intentionally leaky singleton + static LoggerDBSingleton singleton{new LoggerDB()}; + return singleton.getDB(); +} + +LoggerDB::LoggerDB() { + // Create the root log category, and set the level to ERROR by default + auto rootUptr = std::make_unique(this); + LogCategory* root = rootUptr.get(); + auto ret = + loggersByName_.wlock()->emplace(root->getName(), std::move(rootUptr)); + DCHECK(ret.second); + + root->setLevelLocked(LogLevel::ERROR, false); +} + +LoggerDB::LoggerDB(TestConstructorArg) : LoggerDB() {} + +LogCategory* LoggerDB::getCategory(StringPiece name) { + return getOrCreateCategoryLocked(*loggersByName_.wlock(), name); +} + +LogCategory* FOLLY_NULLABLE LoggerDB::getCategoryOrNull(StringPiece name) { + auto loggersByName = loggersByName_.rlock(); + + auto it = loggersByName->find(name); + if (it == loggersByName->end()) { + return nullptr; + } + return it->second.get(); +} + +void LoggerDB::setLevel(folly::StringPiece name, LogLevel level, bool inherit) { + auto loggersByName = loggersByName_.wlock(); + LogCategory* category = getOrCreateCategoryLocked(*loggersByName, name); + category->setLevelLocked(level, inherit); +} + +void LoggerDB::setLevel(LogCategory* category, LogLevel level, bool inherit) { + auto loggersByName = loggersByName_.wlock(); + 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& ex) { + errors.emplace_back(folly::sformat( + "invalid log level \"{}\" for category \"{}\"", level_str, category)); + continue; + } + + setLevel(category, level); + } + + return errors; +} + +LogCategory* LoggerDB::getOrCreateCategoryLocked( + LoggerNameMap& loggersByName, + StringPiece name) { + auto it = loggersByName.find(name); + if (it != loggersByName.end()) { + return it->second.get(); + } + + StringPiece parentName = LogName::getParent(name); + LogCategory* parent = getOrCreateCategoryLocked(loggersByName, parentName); + return createCategoryLocked(loggersByName, name, parent); +} + +LogCategory* LoggerDB::createCategoryLocked( + LoggerNameMap& loggersByName, + StringPiece name, + LogCategory* parent) { + auto uptr = std::make_unique(name, parent); + LogCategory* logger = uptr.get(); + auto ret = loggersByName.emplace(logger->getName(), std::move(uptr)); + DCHECK(ret.second); + return logger; +} + +void LoggerDB::cleanupHandlers() { + // Get a copy of all categories, so we can call clearHandlers() without + // holding the loggersByName_ lock. We don't need to worry about LogCategory + // lifetime, since LogCategory objects always live for the lifetime of the + // LoggerDB. + std::vector categories; + { + auto loggersByName = loggersByName_.wlock(); + categories.reserve(loggersByName->size()); + for (const auto& entry : *loggersByName) { + categories.push_back(entry.second.get()); + } + } + + for (auto* category : categories) { + category->clearHandlers(); + } +} +} diff --git a/folly/experimental/logging/LoggerDB.h b/folly/experimental/logging/LoggerDB.h new file mode 100644 index 00000000..635e6f9d --- /dev/null +++ b/folly/experimental/logging/LoggerDB.h @@ -0,0 +1,134 @@ +/* + * Copyright 2004-present Facebook, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#pragma once + +#include +#include +#include +#include +#include +#include +#include + +#include + +namespace folly { + +class LogCategory; +enum class LogLevel : uint32_t; + +/** + * LoggerDB stores the set of LogCategory objects. + */ +class LoggerDB { + public: + /** + * Get the main LoggerDB singleton. + */ + static LoggerDB* get(); + + /** + * Get the LogCategory for the specified name. + * + * This creates the LogCategory for the specified name if it does not exist + * already. + */ + LogCategory* getCategory(folly::StringPiece name); + + /** + * Get the LogCategory for the specified name, if it already exists. + * + * This returns nullptr if no LogCategory has been created yet for the + * specified name. + */ + LogCategory* FOLLY_NULLABLE getCategoryOrNull(folly::StringPiece name); + + /** + * Set the log level for the specified category. + * + * Messages logged to a specific log category will be ignored unless the + * message log level is greater than the LogCategory's effective log level. + * + * If inherit is true, LogCategory's effective log level is the minimum of + * its level and it's parent category's effective log level. If inherit is + * false, the LogCategory's effective log level is simply its log level. + * (Setting inherit to false is necessary if you want a child LogCategory to + * use a less verbose level than its parent categories.) + */ + void setLevel(folly::StringPiece name, LogLevel level, bool inherit = true); + void setLevel(LogCategory* category, LogLevel level, bool inherit = true); + + /** + * 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. + * + * This is called on the main LoggerDB object during shutdown. + */ + void cleanupHandlers(); + + enum TestConstructorArg { TESTING }; + + /** + * Construct a LoggerDB for testing purposes. + * + * Most callers should not need this function, and should use + * LoggerDB::get() to obtain the main LoggerDB singleton. This function + * exists mainly to allow testing LoggerDB objects in unit tests. + * It requires an explicit argument just to prevent callers from calling it + * unintentionally. + */ + explicit LoggerDB(TestConstructorArg); + + private: + using LoggerNameMap = std::unordered_map< + folly::StringPiece, + std::unique_ptr, + LogName::Hash, + LogName::Equals>; + + // Forbidden copy constructor and assignment operator + LoggerDB(LoggerDB const&) = delete; + LoggerDB& operator=(LoggerDB const&) = delete; + + LoggerDB(); + LogCategory* getOrCreateCategoryLocked( + LoggerNameMap& loggersByName, + folly::StringPiece name); + LogCategory* createCategoryLocked( + LoggerNameMap& loggersByName, + folly::StringPiece name, + LogCategory* parent); + + /** + * A map of LogCategory objects by name. + * + * Lookups can be performed using arbitrary StringPiece values that do not + * have to be in canonical form. + */ + folly::Synchronized loggersByName_; +}; +} diff --git a/folly/experimental/logging/Makefile.am b/folly/experimental/logging/Makefile.am new file mode 100644 index 00000000..3501af15 --- /dev/null +++ b/folly/experimental/logging/Makefile.am @@ -0,0 +1,15 @@ +SUBDIRS = . + +lib_LTLIBRARIES = libfollylogging.la + +libfollylogging_la_SOURCES = \ + LogCategory.cpp \ + Logger.cpp \ + LoggerDB.cpp \ + LogHandler.cpp \ + LogLevel.cpp \ + LogMessage.cpp \ + LogName.cpp + +libfollylogging_la_LIBADD = $(top_builddir)/libfolly.la +libfollylogging_la_LDFLAGS = $(AM_LDFLAGS) -version-info $(LT_VERSION) diff --git a/folly/experimental/logging/README.md b/folly/experimental/logging/README.md new file mode 100644 index 00000000..93a08588 --- /dev/null +++ b/folly/experimental/logging/README.md @@ -0,0 +1,119 @@ +Overview +-------- + +This is a flexible logging library for C++, targeted primarily at debug logging +support. It supports hierarchical log categories to easily control debug log +levels. It also aims to have minimal performance overhead for disabled log +statements, making it possible to keep debug log statements throughout the code +base, even in performance critical sections. This allows debug log messages to +be easily turned on for particular areas of the code at runtime when necessary +to help debug an issue, without having to worry about the overhead of log +messages during normal use. + +Log Categories +-------------- + +## Log Category Names + +All log messages get logged to a particular log category. Log category names +are hierarchical, separated by periods. For instance, `folly.io` and +`folly.futures` are both sub-categories of `folly`. `folly.io.async` is a +sub-category of `folly.io`. The root category's name is the empty string. + +## Log Level Checks + +When a message is logged to a given category, an admittance check is performed +to see if the log message should be enabled. The admittance check compares the +log level of the message against the effective level of that category. + +By default the effective level of a category is the minimum of its level and +the level set for any of its parent categories. This means that when you +increase the log verbosity for a particular category you automatically turn up +the verbosity for the entire tree of children categories underneath it. + +For example, setting the log level for the `folly` category to `WARN` means +that log messages to any sub-category under `folly` will be admitted if they +have a level of `WARN` or higher. If the level for `folly.io` is `DEBUG`, then +messages to all categories under `folly.io` will admit `DEBUG` and higher +messages, while the rest of the categories `folly` under folly would admit +`WARN` and higher messages. + +However, you can also configure specific log categories to turn off inheritance +of their parent log levels. This allows you to increase the log verbosity for +a large category tree, but still use a lower verbosity for specific +sub-categories. For example, if the `folly` category's level is set to +`DEBUG`, but you disable level inheritance for `folly.futures`, the +`folly.futures` level will not use it's parent's `DEBUG` log level, and will +only consider the level set locally on this category. + +Once a log message is admitted, it is processed by the `LogCategory` where it +was logged, as well as by all parent log categories, up to the root. + +## Log Handlers + +`LogHandler` objects can be attached to a log category. When a log message is +received at a given log category it will be given to all `LogHandler` objects +attached to that category. + +`LogHandler` objects can perform arbitrary actions based on the log message. +They may write the message to a local file, print it to `stderr` or `stdout`, +or send the message to a remote logging service. + +`LogHandlers` may perform their own additional log level check, but by default +`LogHandlers` process all messages received at the category they are attached +to. + +Motivation +---------- + +The goal of this logging library is to provide a flexible, easy to use logging +mechanism that allows debug log statements to be used liberally throughout a +code base. + +There are two primary design goals for this library: + +1. Log statements should be cheap when disabled. +2. It should be easy to control log levels for specific areas of the code base. + +While there are a number of other logging libraries for C++, none of the ones I +have seen fulfill both criteria. The Google logging library (glog) satisfies +the first goal, but not the second. Most of the other log libraries I have +examined satisfy the second goal, but not the first. + +In particular, for item 1, disabled log statements should boil down to a single +conditional check. Arguments for the log message should not be evaluated if +the log message is not enabled. Unfortunately, this generally means that +logging must be done using preprocessor macros. + +Item 2 largely boils down to having hierarchical logging categories, to allow +easily turning log levels up and down for specific sections of the code base. +For instance, this allows a service to enable a higher log level for its +primary functionality, while having slightly lower levels for libraries that it +depends on. + +Other Advantages +---------------- + +Beyond the primary goals mentioned above, this log library does have some other +advantages over glog: + +## Support for using `folly::format()` to generate formatted log messages + +Two separate mechanisms are provided for formatting log messages: basic +concatenation of arguments into string (using `folly::to()`), +and more flexible formatting using `folly::format()`. This provides convenient +and type-safe mechanisms for formatting log messages. + +## Escapes unprintable characters in log messages by default. + +This makes it safer to safer to log arbitrary input data, without worrying if +the data may contain potentially malicious terminal escape sequences. + +For instance, this helps avoid vulnerabilities like CVE-2013-1862 and +CVE-2009-4496. + +# Support for handling multi-line log messages + +The LogMessage class indicates if the message contains internal newlines, +making it easier for handlers to add a log header to each line of the message, +avoiding subsequent lines that do not start with the correct log header. diff --git a/folly/experimental/logging/test/LogCategoryTest.cpp b/folly/experimental/logging/test/LogCategoryTest.cpp new file mode 100644 index 00000000..39b091ee --- /dev/null +++ b/folly/experimental/logging/test/LogCategoryTest.cpp @@ -0,0 +1,173 @@ +/* + * Copyright 2004-present Facebook, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#include +#include +#include +#include +#include +#include + +using namespace folly; +using std::make_shared; +using std::shared_ptr; +using std::string; + +TEST(LogCategory, effectiveLevel) { + LoggerDB db{LoggerDB::TESTING}; + Logger foo{&db, "foo"}; + Logger foo2{&db, "..foo.."}; + EXPECT_EQ(foo.getCategory(), foo2.getCategory()); + + EXPECT_EQ(LogLevel::ERROR, db.getCategory("")->getLevel()); + EXPECT_EQ(LogLevel::ERROR, db.getCategory("")->getEffectiveLevel()); + + EXPECT_EQ(LogLevel::MAX_LEVEL, db.getCategory("foo.bar")->getLevel()); + EXPECT_EQ(LogLevel::ERROR, db.getCategory("foo.bar")->getEffectiveLevel()); + + db.setLevel(".foo", LogLevel::WARN); + EXPECT_EQ(LogLevel::MAX_LEVEL, db.getCategory("foo.bar")->getLevel()); + EXPECT_EQ(LogLevel::WARN, db.getCategory("foo.bar")->getEffectiveLevel()); + + db.setLevel(".", LogLevel::DBG0); + EXPECT_EQ(LogLevel::MAX_LEVEL, db.getCategory("foo.bar")->getLevel()); + EXPECT_EQ(LogLevel::DBG0, db.getCategory("foo.bar")->getEffectiveLevel()); + + // Test a newly created category under .foo + EXPECT_EQ(LogLevel::MAX_LEVEL, db.getCategory("foo.test.1234")->getLevel()); + EXPECT_EQ( + LogLevel::DBG0, db.getCategory("foo.test.1234")->getEffectiveLevel()); + + // Test a category that does not inherit its parent's log level + auto noinherit = db.getCategory("foo.test.noinherit"); + EXPECT_EQ(LogLevel::MAX_LEVEL, noinherit->getLevel()); + EXPECT_EQ(LogLevel::DBG0, noinherit->getEffectiveLevel()); + noinherit->setLevel(LogLevel::CRITICAL, false); + EXPECT_EQ(LogLevel::CRITICAL, noinherit->getEffectiveLevel()); + + // Modify the root logger's level + db.setLevel(".", LogLevel::ERROR); + EXPECT_EQ(LogLevel::MAX_LEVEL, db.getCategory("foo.test.1234")->getLevel()); + EXPECT_EQ( + LogLevel::WARN, db.getCategory("foo.test.1234")->getEffectiveLevel()); + EXPECT_EQ(LogLevel::MAX_LEVEL, db.getCategory("foo.test")->getLevel()); + EXPECT_EQ(LogLevel::WARN, db.getCategory("foo.test")->getEffectiveLevel()); + EXPECT_EQ(LogLevel::WARN, db.getCategory("foo")->getLevel()); + EXPECT_EQ(LogLevel::WARN, db.getCategory("foo")->getEffectiveLevel()); + EXPECT_EQ( + LogLevel::CRITICAL, db.getCategory("foo.test.noinherit")->getLevel()); + EXPECT_EQ( + LogLevel::CRITICAL, + db.getCategory("foo.test.noinherit")->getEffectiveLevel()); + + EXPECT_EQ(LogLevel::MAX_LEVEL, db.getCategory("bar.foo.test")->getLevel()); + EXPECT_EQ( + LogLevel::ERROR, db.getCategory("bar.foo.test")->getEffectiveLevel()); +} + +void testNumHandlers(size_t numHandlers) { + SCOPED_TRACE(folly::to("num_handlers= ", numHandlers)); + LoggerDB db{LoggerDB::TESTING}; + db.setLevel("", LogLevel::DEBUG); + + // Create the requested number of handlers for the foo.bar category + Logger foobar{&db, "foo.bar"}; + std::vector> handlers; + for (size_t n = 0; n < numHandlers; ++n) { + handlers.emplace_back(make_shared()); + foobar.getCategory()->addHandler(handlers.back()); + } + + // Add a handler to the root category, to confirm that messages are + // propagated up to the root correctly. + auto rootHandler = make_shared(); + auto rootCategory = db.getCategory(""); + rootCategory->addHandler(rootHandler); + + // Log a message to a child of the foobar category + Logger childLogger{&db, "foo.bar.child"}; + FB_LOG(childLogger, WARN, "beware"); + + // Make sure the message showed up at all of the handlers + for (const auto& handler : handlers) { + auto& messages = handler->getMessages(); + ASSERT_EQ(1, messages.size()); + EXPECT_EQ("beware", messages[0].first.getMessage()); + EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel()); + EXPECT_EQ(childLogger.getCategory(), messages[0].first.getCategory()); + EXPECT_EQ(foobar.getCategory(), messages[0].second); + } + { + auto& messages = rootHandler->getMessages(); + ASSERT_EQ(1, messages.size()); + EXPECT_EQ("beware", messages[0].first.getMessage()); + EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel()); + EXPECT_EQ(childLogger.getCategory(), messages[0].first.getCategory()); + EXPECT_EQ(rootCategory, messages[0].second); + } + + // Now log a message directly to foobar + FB_LOG(foobar, DBG1, "just testing"); + for (const auto& handler : handlers) { + auto& messages = handler->getMessages(); + ASSERT_EQ(2, messages.size()); + EXPECT_EQ("just testing", messages[1].first.getMessage()); + EXPECT_EQ(LogLevel::DBG1, messages[1].first.getLevel()); + EXPECT_EQ(foobar.getCategory(), messages[1].first.getCategory()); + EXPECT_EQ(foobar.getCategory(), messages[1].second); + } + { + auto& messages = rootHandler->getMessages(); + ASSERT_EQ(2, messages.size()); + EXPECT_EQ("just testing", messages[1].first.getMessage()); + EXPECT_EQ(LogLevel::DBG1, messages[1].first.getLevel()); + EXPECT_EQ(foobar.getCategory(), messages[1].first.getCategory()); + EXPECT_EQ(rootCategory, messages[1].second); + } + + // Log a message to a sibling of foobar + Logger siblingLogger{&db, "foo.sibling"}; + FB_LOG(siblingLogger, ERROR, "oh noes"); + for (const auto& handler : handlers) { + auto& messages = handler->getMessages(); + EXPECT_EQ(2, messages.size()); + } + { + auto& messages = rootHandler->getMessages(); + ASSERT_EQ(3, messages.size()); + EXPECT_EQ("oh noes", messages[2].first.getMessage()); + EXPECT_EQ(LogLevel::ERROR, messages[2].first.getLevel()); + EXPECT_EQ(siblingLogger.getCategory(), messages[2].first.getCategory()); + EXPECT_EQ(rootCategory, messages[2].second); + } +} + +TEST(LogCategory, numHandlers) { + // The LogCategory code behaves differently when there are 5 or fewer + // LogHandlers attached to a category vs when ther are more. + // + // Test with fewer than 5 handlers. + testNumHandlers(1); + testNumHandlers(2); + + // Test with exactly 5 handlers, as well as one fewer and one more, just + // to make sure we catch any corner cases. + testNumHandlers(4); + testNumHandlers(5); + testNumHandlers(6); + + // Test with significantly more than 5 handlers. + testNumHandlers(15); +} diff --git a/folly/experimental/logging/test/LogLevelTest.cpp b/folly/experimental/logging/test/LogLevelTest.cpp new file mode 100644 index 00000000..5f0af081 --- /dev/null +++ b/folly/experimental/logging/test/LogLevelTest.cpp @@ -0,0 +1,126 @@ +/* + * Copyright 2004-present Facebook, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#include +#include +#include +#include + +using namespace folly; + +TEST(LogLevel, fromString) { + EXPECT_EQ(LogLevel::NONE, stringToLogLevel("none")); + EXPECT_EQ(LogLevel::NONE, stringToLogLevel("NONE")); + EXPECT_EQ(LogLevel::NONE, stringToLogLevel("NoNe")); + EXPECT_EQ(LogLevel::NONE, stringToLogLevel("LogLevel::none")); + + EXPECT_EQ(LogLevel::DEBUG, stringToLogLevel("debug")); + EXPECT_EQ(LogLevel::DEBUG, stringToLogLevel("dEBug")); + EXPECT_EQ(LogLevel::DEBUG, stringToLogLevel("loglevel::dEBug")); + + EXPECT_EQ(LogLevel::INFO, stringToLogLevel("info")); + EXPECT_EQ(LogLevel::INFO, stringToLogLevel("INFO")); + EXPECT_EQ(LogLevel::INFO, stringToLogLevel("loglevel(INFO)")); + + EXPECT_EQ(LogLevel::WARN, stringToLogLevel("warn")); + EXPECT_EQ(LogLevel::WARN, stringToLogLevel("WARN")); + EXPECT_EQ(LogLevel::WARN, stringToLogLevel("warning")); + + EXPECT_EQ(LogLevel::ERR, stringToLogLevel("err")); + EXPECT_EQ(LogLevel::ERR, stringToLogLevel("eRr")); + EXPECT_EQ(LogLevel::ERR, stringToLogLevel("error")); + EXPECT_EQ(LogLevel::ERR, stringToLogLevel("ERROR")); + + EXPECT_EQ(LogLevel::CRITICAL, stringToLogLevel("critical")); + EXPECT_EQ(LogLevel::CRITICAL, stringToLogLevel("CRITICAL")); + + EXPECT_EQ(LogLevel::MAX_LEVEL, stringToLogLevel("max")); + EXPECT_EQ(LogLevel::MAX_LEVEL, stringToLogLevel("Max_Level")); + EXPECT_EQ(LogLevel::MAX_LEVEL, stringToLogLevel("LogLevel::MAX")); + EXPECT_EQ(LogLevel::MAX_LEVEL, stringToLogLevel("LogLevel::MAX_LEVEL")); + + EXPECT_EQ(LogLevel::DBG0, stringToLogLevel("dbg0")); + EXPECT_EQ(LogLevel::DBG5, stringToLogLevel("dbg5")); + EXPECT_EQ(LogLevel::DBG5, stringToLogLevel("DBG5")); + EXPECT_EQ(LogLevel::DBG9, stringToLogLevel("DBG9")); + EXPECT_EQ(LogLevel::DEBUG + 1, stringToLogLevel("DBG99")); + EXPECT_EQ(LogLevel::DEBUG, stringToLogLevel("900")); + EXPECT_EQ(LogLevel::DEBUG, stringToLogLevel("LogLevel(900)")); + + EXPECT_THROW(stringToLogLevel("foobar"), std::range_error); + EXPECT_THROW(stringToLogLevel("dbg"), std::range_error); + EXPECT_THROW(stringToLogLevel("dbgxyz"), std::range_error); + EXPECT_THROW(stringToLogLevel("dbg-1"), std::range_error); + EXPECT_THROW(stringToLogLevel("dbg12345"), std::range_error); + EXPECT_THROW(stringToLogLevel("900z"), std::range_error); +} + +TEST(LogLevel, toString) { + EXPECT_EQ("LogLevel::NONE", logLevelToString(LogLevel::NONE)); + EXPECT_EQ("LogLevel::INFO", logLevelToString(LogLevel::INFO)); + EXPECT_EQ("LogLevel::WARN", logLevelToString(LogLevel::WARN)); + EXPECT_EQ("LogLevel::WARN", logLevelToString(LogLevel::WARNING)); + EXPECT_EQ("LogLevel::DEBUG", logLevelToString(LogLevel::DEBUG)); + EXPECT_EQ("LogLevel::ERR", logLevelToString(LogLevel::ERR)); + EXPECT_EQ("LogLevel::CRITICAL", logLevelToString(LogLevel::CRITICAL)); + EXPECT_EQ("LogLevel::MAX_LEVEL", logLevelToString(LogLevel::MAX_LEVEL)); + + EXPECT_EQ("LogLevel::DBG0", logLevelToString(LogLevel::DBG0)); + EXPECT_EQ("LogLevel::DBG2", logLevelToString(LogLevel::DBG2)); + EXPECT_EQ("LogLevel::DBG5", logLevelToString(LogLevel::DBG5)); + EXPECT_EQ("LogLevel::DBG9", logLevelToString(LogLevel::DBG9)); + EXPECT_EQ("LogLevel::DBG97", logLevelToString(static_cast(903))); + EXPECT_EQ("LogLevel::DBG64", logLevelToString(LogLevel::DBG4 - 60)); + + EXPECT_EQ("LogLevel(1234)", logLevelToString(static_cast(1234))); +} + +TEST(LogLevel, toStringAndBack) { + // Check that stringToLogLevel(logLevelToString()) is the identity function + auto checkLevel = [](LogLevel level) { + auto stringForm = logLevelToString(level); + auto outputLevel = stringToLogLevel(stringForm); + EXPECT_EQ(level, outputLevel) + << "error converting " << level << " (" << static_cast(level) + << ") to string and back. String is " << stringForm; + }; + + // Check all of the named levels + checkLevel(LogLevel::NONE); + checkLevel(LogLevel::DEBUG); + checkLevel(LogLevel::DBG0); + checkLevel(LogLevel::DBG1); + checkLevel(LogLevel::DBG2); + checkLevel(LogLevel::DBG3); + checkLevel(LogLevel::DBG4); + checkLevel(LogLevel::DBG5); + checkLevel(LogLevel::DBG6); + checkLevel(LogLevel::DBG7); + checkLevel(LogLevel::DBG8); + checkLevel(LogLevel::DBG9); + checkLevel(LogLevel::INFO); + checkLevel(LogLevel::WARN); + checkLevel(LogLevel::WARNING); + checkLevel(LogLevel::ERR); + checkLevel(LogLevel::CRITICAL); + checkLevel(LogLevel::MAX_LEVEL); + + // Try with some random integer values + for (uint32_t numIters = 0; numIters < 10000; ++numIters) { + auto levelValue = + folly::Random::rand32(static_cast(LogLevel::MAX_LEVEL)); + checkLevel(static_cast(levelValue)); + } +} diff --git a/folly/experimental/logging/test/LogMessageTest.cpp b/folly/experimental/logging/test/LogMessageTest.cpp new file mode 100644 index 00000000..8d489568 --- /dev/null +++ b/folly/experimental/logging/test/LogMessageTest.cpp @@ -0,0 +1,74 @@ +/* + * Copyright 2004-present Facebook, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#include +#include +#include +#include +#include + +using namespace folly; + +#define CHECK_MSG(expected, value, hasNewlines) \ + { \ + SCOPED_TRACE( \ + "input string: \"" + folly::backslashify(value) + "\""); \ + LogMessage checkMsg{ \ + category, LogLevel::ERROR, __FILE__, __LINE__, std::string{value}}; \ + EXPECT_EQ(expected, checkMsg.getMessage()); \ + EXPECT_EQ(hasNewlines, checkMsg.containsNewlines()); \ + EXPECT_EQ(__FILE__, checkMsg.getFileName()); \ + EXPECT_EQ(__LINE__, checkMsg.getLineNumber()); \ + } + +TEST(LogMessage, sanitize) { + LoggerDB db{LoggerDB::TESTING}; + Logger logger{&db, "test"}; + auto* category = logger.getCategory(); + + CHECK_MSG("foo", "foo", false); + CHECK_MSG("foo\\\\bar", "foo\\bar", false); + CHECK_MSG("foo\\x01test", "foo\01test", false); + CHECK_MSG("test 1234 ", "test 1234 ", false); + CHECK_MSG("\\x07", "\a", false); + CHECK_MSG("\n", "\n", true); + CHECK_MSG("\t", "\t", false); + CHECK_MSG("\n\t\n", "\n\t\n", true); + // Test strings containing NUL bytes + CHECK_MSG("test\\x00.1234\\x00", std::string("test\0.1234\0", 11), false); + CHECK_MSG("test\\x00\n1234\\x00", std::string("test\0\n1234\0", 11), true); + // Test all ASCII characters except NUL + CHECK_MSG( + ("\\x01\\x02\\x03\\x04\\x05\\x06\\x07\\x08" + "\t\n\\x0b\\x0c\\x0d\\x0e\\x0f" + "\\x10\\x11\\x12\\x13\\x14\\x15\\x16\\x17" + "\\x18\\x19\\x1a\\x1b\\x1c\\x1d\\x1e\\x1f" + " !\"#$%&'()*+,-./0123456789:;<=>?" + "@ABCDEFGHIJKLMNOPQRSTUVWXYZ[\\\\]^_" + "`abcdefghijklmnopqrstuvwxyz{|}~\\x7f"), + ("\001\002\003\004\005\006\007" + "\010\011\012\013\014\015\016\017" + "\020\021\022\023\024\025\026\027" + "\030\031\032\033\034\035\036\037" + " !\"#$%&'()*+,-./0123456789:;<=>?" + "@ABCDEFGHIJKLMNOPQRSTUVWXYZ[\\]^_" + "`abcdefghijklmnopqrstuvwxyz{|}~\177"), + true); + + // Test some high-bit characters + CHECK_MSG("\x82\x83", "\x82\x83", false); + CHECK_MSG("\x82\n\x83\n", "\x82\n\x83\n", true); + CHECK_MSG("\x82\n\\x0c\x83\n", "\x82\n\f\x83\n", true); +} diff --git a/folly/experimental/logging/test/LogNameTest.cpp b/folly/experimental/logging/test/LogNameTest.cpp new file mode 100644 index 00000000..7c1b5d3d --- /dev/null +++ b/folly/experimental/logging/test/LogNameTest.cpp @@ -0,0 +1,67 @@ +/* + * Copyright 2004-present Facebook, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#include +#include + +using namespace folly; + +TEST(LogName, canonicalize) { + EXPECT_EQ("", LogName::canonicalize(".")); + EXPECT_EQ("", LogName::canonicalize("...")); + EXPECT_EQ("foo.bar", LogName::canonicalize(".foo..bar.")); + EXPECT_EQ("a.b.c", LogName::canonicalize("a.b.c")); + EXPECT_EQ("a.b.c", LogName::canonicalize("a..b.c...")); + EXPECT_EQ("a.b.c", LogName::canonicalize("....a.b.c")); + EXPECT_EQ("a.b.c", LogName::canonicalize("a.b.c....")); +} + +TEST(LogName, getParent) { + EXPECT_EQ("", LogName::getParent("foo")); + EXPECT_EQ("", LogName::getParent(".foo")); + EXPECT_EQ("foo", LogName::getParent("foo.bar")); + EXPECT_EQ("foo..bar", LogName::getParent("foo..bar..test")); + EXPECT_EQ("..foo..bar", LogName::getParent("..foo..bar..test..")); +} + +TEST(LogName, hash) { + EXPECT_EQ(LogName::hash("foo"), LogName::hash("foo.")); + EXPECT_EQ(LogName::hash(".foo..bar"), LogName::hash("foo.bar...")); + EXPECT_EQ(LogName::hash("a.b.c..d."), LogName::hash("..a.b.c.d.")); + EXPECT_EQ(LogName::hash(""), LogName::hash(".")); + EXPECT_EQ(LogName::hash(""), LogName::hash("....")); + + // Hashes for different category names should generally be different. + // This is not strictly required. This test is mainly to ensure that the + // code does not just hash all inputs to the same value. + EXPECT_NE(LogName::hash("foo"), LogName::hash("bar")); + EXPECT_NE(LogName::hash("a.b.c"), LogName::hash("abc")); +} + +TEST(LogName, cmp) { + EXPECT_EQ(0, LogName::cmp("foo", "foo.")); + EXPECT_EQ(0, LogName::cmp(".foo..bar", "foo.bar...")); + EXPECT_EQ(0, LogName::cmp(".foo.bar", "foo...bar...")); + EXPECT_EQ(0, LogName::cmp("a.b.c..d.", "..a.b.c.d.")); + EXPECT_EQ(0, LogName::cmp("", ".")); + EXPECT_EQ(0, LogName::cmp("", "....")); + + EXPECT_GT(LogName::cmp("foo", "bar"), 0); + EXPECT_LT(LogName::cmp("a.b.c", "abc"), 0); + EXPECT_LT(LogName::cmp("a...b.c", "a.bc"), 0); + EXPECT_GT(LogName::cmp("a...b.z", "a.b.c"), 0); + EXPECT_LT(LogName::cmp(".foo.bar", "foobar..."), 0); + EXPECT_GT(LogName::cmp("foobar", ".foo...bar"), 0); +} diff --git a/folly/experimental/logging/test/LoggerDBTest.cpp b/folly/experimental/logging/test/LoggerDBTest.cpp new file mode 100644 index 00000000..181214c3 --- /dev/null +++ b/folly/experimental/logging/test/LoggerDBTest.cpp @@ -0,0 +1,59 @@ +/* + * Copyright 2004-present Facebook, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#include +#include +#include + +using namespace folly; + +TEST(LoggerDB, lookupNameCanonicalization) { + LoggerDB db{LoggerDB::TESTING}; + Logger foo{&db, "foo"}; + Logger foo2{&db, "..foo.."}; + EXPECT_EQ(foo.getCategory(), foo2.getCategory()); + + Logger fooBar{&db, "foo.bar"}; + Logger fooBar2{&db, ".foo..bar"}; + EXPECT_EQ(fooBar.getCategory(), fooBar2.getCategory()); +} + +TEST(LoggerDB, getCategory) { + LoggerDB db{LoggerDB::TESTING}; +} + +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::ERROR, db.getCategory("foo")->getEffectiveLevel()); + EXPECT_EQ(LogLevel::ERROR, db.getCategory("")->getLevel()); + EXPECT_EQ(LogLevel::ERROR, 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/LoggerTest.cpp b/folly/experimental/logging/test/LoggerTest.cpp new file mode 100644 index 00000000..e9b5d4b9 --- /dev/null +++ b/folly/experimental/logging/test/LoggerTest.cpp @@ -0,0 +1,235 @@ +/* + * Copyright 2004-present Facebook, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#include +#include +#include +#include +#include +#include +#include + +using namespace folly; +using std::make_shared; + +class LoggerTest : public ::testing::Test { + protected: + void SetUp() override { + auto* category = logger_.getCategory(); + + handler_ = make_shared(); + category->addHandler(handler_); + category->setLevel(LogLevel::DEBUG, true); + } + + LoggerDB db_{LoggerDB::TESTING}; + Logger logger_{&db_, "test"}; + std::shared_ptr handler_; +}; + +TEST_F(LoggerTest, basic) { + // Simple log message + logger_.log(LogLevel::WARN, "src/myproject/myfile.cpp", 1234, "hello world"); + + auto& messages = handler_->getMessages(); + ASSERT_EQ(1, messages.size()); + EXPECT_EQ("hello world", messages[0].first.getMessage()); + EXPECT_EQ("src/myproject/myfile.cpp", messages[0].first.getFileName()); + EXPECT_EQ(1234, messages[0].first.getLineNumber()); + EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel()); + EXPECT_FALSE(messages[0].first.containsNewlines()); + EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory()); + EXPECT_EQ(logger_.getCategory(), messages[0].second); +} + +TEST_F(LoggerTest, subCategory) { + // Log from a sub-category. + Logger subLogger{&db_, "test.foo.bar"}; + subLogger.log(LogLevel::ERROR, "myfile.cpp", 99, "sub-category\nlog message"); + + auto& messages = handler_->getMessages(); + ASSERT_EQ(1, messages.size()); + EXPECT_EQ("sub-category\nlog message", messages[0].first.getMessage()); + EXPECT_EQ("myfile.cpp", messages[0].first.getFileName()); + EXPECT_EQ(99, messages[0].first.getLineNumber()); + EXPECT_EQ(LogLevel::ERROR, messages[0].first.getLevel()); + EXPECT_TRUE(messages[0].first.containsNewlines()); + EXPECT_EQ(subLogger.getCategory(), messages[0].first.getCategory()); + EXPECT_EQ(logger_.getCategory(), messages[0].second); +} + +TEST_F(LoggerTest, formatMessage) { + logger_.logf( + LogLevel::WARN, + "log.cpp", + 9, + "num events: {:06d}, duration: {:6.3f}", + 1234, + 5.6789); + + auto& messages = handler_->getMessages(); + ASSERT_EQ(1, messages.size()); + EXPECT_EQ( + "num events: 001234, duration: 5.679", messages[0].first.getMessage()); + EXPECT_EQ("log.cpp", messages[0].first.getFileName()); + EXPECT_EQ(9, messages[0].first.getLineNumber()); + EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel()); + EXPECT_FALSE(messages[0].first.containsNewlines()); + EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory()); + EXPECT_EQ(logger_.getCategory(), messages[0].second); +} + +TEST_F(LoggerTest, follyFormatError) { + // If we pass in a bogus format string, logf() should not throw. + // It should instead log a message, just complaining about the format error. + logger_.logf( + LogLevel::WARN, + "log.cpp", + 9, + "param1: {:06d}, param2: {:6.3f}", + 1234, + "hello world!"); + + auto& messages = handler_->getMessages(); + ASSERT_EQ(1, messages.size()); + EXPECT_EQ( + "error formatting log message: " + "invalid format argument {:6.3f}: invalid specifier 'f'; " + "format string: param1: {:06d}, param2: {:6.3f}", + messages[0].first.getMessage()); + EXPECT_EQ("log.cpp", messages[0].first.getFileName()); + EXPECT_EQ(9, messages[0].first.getLineNumber()); + EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel()); + EXPECT_FALSE(messages[0].first.containsNewlines()); + EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory()); + EXPECT_EQ(logger_.getCategory(), messages[0].second); +} + +TEST_F(LoggerTest, toString) { + // Use the log API that calls folly::to + logger_.log(LogLevel::DBG5, "log.cpp", 3, "status=", 5, " name=", "foobar"); + + auto& messages = handler_->getMessages(); + ASSERT_EQ(1, messages.size()); + EXPECT_EQ("status=5 name=foobar", messages[0].first.getMessage()); + EXPECT_EQ("log.cpp", messages[0].first.getFileName()); + EXPECT_EQ(3, messages[0].first.getLineNumber()); + EXPECT_EQ(LogLevel::DBG5, messages[0].first.getLevel()); + EXPECT_FALSE(messages[0].first.containsNewlines()); + EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory()); + EXPECT_EQ(logger_.getCategory(), messages[0].second); +} + +class ToStringFailure {}; + +[[noreturn]] void toAppend( + const ToStringFailure& /* arg */, + std::string* /* result */) { + throw std::runtime_error( + "error converting ToStringFailure object to a string"); +} + +TEST_F(LoggerTest, toStringError) { + // Use the folly::to log API, with an object that will throw + // an exception when we try to convert it to a string. + // + // The logging code should not throw, but should instead log a message + // with some detail about the failure. + ToStringFailure obj; + logger_.log(LogLevel::DBG1, "log.cpp", 3, "status=", obj, " name=", "foobar"); + + auto& messages = handler_->getMessages(); + ASSERT_EQ(1, messages.size()); + EXPECT_EQ( + "error constructing log message: " + "error converting ToStringFailure object to a string", + messages[0].first.getMessage()); + EXPECT_EQ("log.cpp", messages[0].first.getFileName()); + EXPECT_EQ(3, messages[0].first.getLineNumber()); + EXPECT_EQ(LogLevel::DBG1, messages[0].first.getLevel()); + EXPECT_FALSE(messages[0].first.containsNewlines()); + EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory()); + EXPECT_EQ(logger_.getCategory(), messages[0].second); +} + +TEST_F(LoggerTest, escapeSequences) { + // Escape characters (and any other unprintable characters) in the log + // message should be escaped when logged. + logger_.log(LogLevel::WARN, "termcap.cpp", 34, "hello \033[34mworld\033[0m!"); + + auto& messages = handler_->getMessages(); + ASSERT_EQ(1, messages.size()); + EXPECT_EQ("hello \\x1b[34mworld\\x1b[0m!", messages[0].first.getMessage()); + EXPECT_EQ("termcap.cpp", messages[0].first.getFileName()); + EXPECT_EQ(34, messages[0].first.getLineNumber()); + EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel()); + EXPECT_FALSE(messages[0].first.containsNewlines()); + EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory()); + EXPECT_EQ(logger_.getCategory(), messages[0].second); +} + +TEST_F(LoggerTest, logMacros) { + Logger foo{&db_, "test.foo.bar"}; + Logger foobar{&db_, "test.foo.bar"}; + Logger footest{&db_, "test.foo.test"}; + Logger footest1234{&db_, "test.foo.test.1234"}; + Logger other{&db_, "test.other"}; + db_.setLevel("test", LogLevel::ERROR); + db_.setLevel("test.foo", LogLevel::DBG2); + db_.setLevel("test.foo.test", LogLevel::DBG7); + + auto& messages = handler_->getMessages(); + + // test.other's effective level should be ERROR, so a warning + // message to it should be discarded + FB_LOG(other, WARN, "this should be discarded"); + ASSERT_EQ(0, messages.size()); + + // Disabled log messages should not evaluate their arguments + bool argumentEvaluated = false; + auto getValue = [&] { + argumentEvaluated = true; + return 5; + }; + FB_LOG(foobar, DBG3, "discarded message: ", getValue()); + EXPECT_FALSE(argumentEvaluated); + + FB_LOG(foobar, DBG1, "this message should pass: ", getValue()); + ASSERT_EQ(1, messages.size()); + EXPECT_EQ("this message should pass: 5", messages[0].first.getMessage()); + EXPECT_TRUE(argumentEvaluated); + messages.clear(); + + // Similar checks with FB_LOGF() + argumentEvaluated = false; + FB_LOGF(footest1234, DBG9, "failing log check: {}", getValue()); + EXPECT_FALSE(argumentEvaluated); + + FB_LOGF(footest1234, DBG5, "passing log: {:03}", getValue()); + ASSERT_EQ(1, messages.size()); + EXPECT_EQ("passing log: 005", messages[0].first.getMessage()); + EXPECT_TRUE(argumentEvaluated); + messages.clear(); + + // Bad format arguments should not throw + FB_LOGF(footest1234, ERROR, "whoops: {}, {}", getValue()); + ASSERT_EQ(1, messages.size()); + EXPECT_EQ( + "error formatting log message: " + "invalid format argument {}: argument index out of range, max=1; " + "format string: whoops: {}, {}", + messages[0].first.getMessage()); + messages.clear(); +} diff --git a/folly/experimental/logging/test/TestLogHandler.h b/folly/experimental/logging/test/TestLogHandler.h new file mode 100644 index 00000000..872113e5 --- /dev/null +++ b/folly/experimental/logging/test/TestLogHandler.h @@ -0,0 +1,45 @@ +/* + * Copyright 2004-present Facebook, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#pragma once + +#include +#include + +#include +#include + +namespace folly { + +/** + * A LogHandler that simply keeps a vector of all LogMessages it receives. + */ +class TestLogHandler : public LogHandler { + public: + std::vector>& getMessages() { + return messages_; + } + + protected: + void handleMessage( + const LogMessage& message, + const LogCategory* handlerCategory) override { + messages_.emplace_back(message, handlerCategory); + } + + private: + std::vector> messages_; +}; +}