folly/experimental/logging/LoggerDB.cpp

   1 /*
   2  * Copyright 2004-present Facebook, Inc.
   3  *
   4  * Licensed under the Apache License, Version 2.0 (the "License");
   5  * you may not use this file except in compliance with the License.
   6  * You may obtain a copy of the License at
   7  *
   8  *   http://www.apache.org/licenses/LICENSE-2.0
   9  *
  10  * Unless required by applicable law or agreed to in writing, software
  11  * distributed under the License is distributed on an "AS IS" BASIS,
  12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  13  * See the License for the specific language governing permissions and
  14  * limitations under the License.
  15  */
  16 #include <folly/experimental/logging/LoggerDB.h>
  17
  18 #include <set>
  19
  20 #include <folly/Conv.h>
  21 #include <folly/FileUtil.h>
  22 #include <folly/String.h>
  23 #include <folly/experimental/logging/LogCategory.h>
  24 #include <folly/experimental/logging/LogHandler.h>
  25 #include <folly/experimental/logging/LogLevel.h>
  26 #include <folly/experimental/logging/Logger.h>
  27 #include <folly/experimental/logging/RateLimiter.h>
  28
  29 namespace folly {
  30
  31 namespace {
  32 class LoggerDBSingleton {
  33  public:
  34   explicit LoggerDBSingleton(LoggerDB* db) : db_{db} {}
  35   ~LoggerDBSingleton() {
  36     // We intentionally leak the LoggerDB object on destruction.
  37     // We want Logger objects to remain valid for the entire lifetime of the
  38     // program, without having to worry about destruction ordering issues, or
  39     // making the Logger perform reference counting on the LoggerDB.
  40     //
  41     // Therefore the main LoggerDB object, and all of the LogCategory objects
  42     // it contains, are always intentionally leaked.
  43     //
  44     // However, we do call db_->cleanupHandlers() to destroy any registered
  45     // LogHandler objects.  The LogHandlers can be user-defined objects and may
  46     // hold resources that should be cleaned up.  This also ensures that the
  47     // LogHandlers flush all outstanding messages before we exit.
  48     db_->cleanupHandlers();
  49   }
  50
  51   LoggerDB* getDB() const {
  52     return db_;
  53   }
  54
  55  private:
  56   LoggerDB* db_;
  57 };
  58 }
  59
  60 LoggerDB* LoggerDB::get() {
  61   // Intentionally leaky singleton
  62   static LoggerDBSingleton singleton{new LoggerDB()};
  63   return singleton.getDB();
  64 }
  65
  66 LoggerDB::LoggerDB() {
  67   // Create the root log category, and set the level to ERROR by default
  68   auto rootUptr = std::make_unique<LogCategory>(this);
  69   LogCategory* root = rootUptr.get();
  70   auto ret =
  71       loggersByName_.wlock()->emplace(root->getName(), std::move(rootUptr));
  72   DCHECK(ret.second);
  73
  74   root->setLevelLocked(LogLevel::ERROR, false);
  75 }
  76
  77 LoggerDB::LoggerDB(TestConstructorArg) : LoggerDB() {}
  78
  79 LogCategory* LoggerDB::getCategory(StringPiece name) {
  80   return getOrCreateCategoryLocked(*loggersByName_.wlock(), name);
  81 }
  82
  83 LogCategory* FOLLY_NULLABLE LoggerDB::getCategoryOrNull(StringPiece name) {
  84   auto loggersByName = loggersByName_.rlock();
  85
  86   auto it = loggersByName->find(name);
  87   if (it == loggersByName->end()) {
  88     return nullptr;
  89   }
  90   return it->second.get();
  91 }
  92
  93 void LoggerDB::setLevel(folly::StringPiece name, LogLevel level, bool inherit) {
  94   auto loggersByName = loggersByName_.wlock();
  95   LogCategory* category = getOrCreateCategoryLocked(*loggersByName, name);
  96   category->setLevelLocked(level, inherit);
  97 }
  98
  99 void LoggerDB::setLevel(LogCategory* category, LogLevel level, bool inherit) {
 100   auto loggersByName = loggersByName_.wlock();
 101   category->setLevelLocked(level, inherit);
 102 }
 103
 104 std::vector<std::string> LoggerDB::processConfigString(
 105     folly::StringPiece config) {
 106   std::vector<std::string> errors;
 107   if (config.empty()) {
 108     return errors;
 109   }
 110
 111   std::vector<StringPiece> pieces;
 112   folly::split(",", config, pieces);
 113   for (const auto& p : pieces) {
 114     auto idx = p.rfind('=');
 115     if (idx == folly::StringPiece::npos) {
 116       errors.emplace_back(
 117           folly::sformat("missing '=' in logger configuration: \"{}\"", p));
 118       continue;
 119     }
 120
 121     auto category = p.subpiece(0, idx);
 122     auto level_str = p.subpiece(idx + 1);
 123     LogLevel level;
 124     try {
 125       level = stringToLogLevel(level_str);
 126     } catch (const std::exception& ex) {
 127       errors.emplace_back(folly::sformat(
 128           "invalid log level \"{}\" for category \"{}\"", level_str, category));
 129       continue;
 130     }
 131
 132     setLevel(category, level);
 133   }
 134
 135   return errors;
 136 }
 137
 138 LogCategory* LoggerDB::getOrCreateCategoryLocked(
 139     LoggerNameMap& loggersByName,
 140     StringPiece name) {
 141   auto it = loggersByName.find(name);
 142   if (it != loggersByName.end()) {
 143     return it->second.get();
 144   }
 145
 146   StringPiece parentName = LogName::getParent(name);
 147   LogCategory* parent = getOrCreateCategoryLocked(loggersByName, parentName);
 148   return createCategoryLocked(loggersByName, name, parent);
 149 }
 150
 151 LogCategory* LoggerDB::createCategoryLocked(
 152     LoggerNameMap& loggersByName,
 153     StringPiece name,
 154     LogCategory* parent) {
 155   auto uptr = std::make_unique<LogCategory>(name, parent);
 156   LogCategory* logger = uptr.get();
 157   auto ret = loggersByName.emplace(logger->getName(), std::move(uptr));
 158   DCHECK(ret.second);
 159   return logger;
 160 }
 161
 162 void LoggerDB::cleanupHandlers() {
 163   // Get a copy of all categories, so we can call clearHandlers() without
 164   // holding the loggersByName_ lock.  We don't need to worry about LogCategory
 165   // lifetime, since LogCategory objects always live for the lifetime of the
 166   // LoggerDB.
 167   std::vector<LogCategory*> categories;
 168   {
 169     auto loggersByName = loggersByName_.wlock();
 170     categories.reserve(loggersByName->size());
 171     for (const auto& entry : *loggersByName) {
 172       categories.push_back(entry.second.get());
 173     }
 174   }
 175
 176   for (auto* category : categories) {
 177     category->clearHandlers();
 178   }
 179 }
 180
 181 size_t LoggerDB::flushAllHandlers() {
 182   // Build a set of all LogHandlers.  We use a set to avoid calling flush()
 183   // more than once on the same handler if it is registered on multiple
 184   // different categories.
 185   std::set<std::shared_ptr<LogHandler>> handlers;
 186   {
 187     auto loggersByName = loggersByName_.wlock();
 188     for (const auto& entry : *loggersByName) {
 189       for (const auto& handler : entry.second->getHandlers()) {
 190         handlers.emplace(handler);
 191       }
 192     }
 193   }
 194
 195   // Call flush() on each handler
 196   for (const auto& handler : handlers) {
 197     handler->flush();
 198   }
 199   return handlers.size();
 200 }
 201
 202 LogLevel LoggerDB::xlogInit(
 203     StringPiece categoryName,
 204     std::atomic<LogLevel>* xlogCategoryLevel,
 205     LogCategory** xlogCategory) {
 206   // Hold the lock for the duration of the operation
 207   // xlogInit() may be called from multiple threads simultaneously.
 208   // Only one needs to perform the initialization.
 209   auto loggersByName = loggersByName_.wlock();
 210   if (xlogCategory != nullptr && *xlogCategory != nullptr) {
 211     // The xlogCategory was already initialized before we acquired the lock
 212     return (*xlogCategory)->getEffectiveLevel();
 213   }
 214
 215   auto* category = getOrCreateCategoryLocked(*loggersByName, categoryName);
 216   if (xlogCategory) {
 217     // Set *xlogCategory before we update xlogCategoryLevel below.
 218     // This is important, since the XLOG() macros check xlogCategoryLevel to
 219     // tell if *xlogCategory has been initialized yet.
 220     *xlogCategory = category;
 221   }
 222   auto level = category->getEffectiveLevel();
 223   xlogCategoryLevel->store(level, std::memory_order_release);
 224   category->registerXlogLevel(xlogCategoryLevel);
 225   return level;
 226 }
 227
 228 LogCategory* LoggerDB::xlogInitCategory(
 229     StringPiece categoryName,
 230     LogCategory** xlogCategory,
 231     std::atomic<bool>* isInitialized) {
 232   // Hold the lock for the duration of the operation
 233   // xlogInitCategory() may be called from multiple threads simultaneously.
 234   // Only one needs to perform the initialization.
 235   auto loggersByName = loggersByName_.wlock();
 236   if (isInitialized->load(std::memory_order_acquire)) {
 237     // The xlogCategory was already initialized before we acquired the lock
 238     return *xlogCategory;
 239   }
 240
 241   auto* category = getOrCreateCategoryLocked(*loggersByName, categoryName);
 242   *xlogCategory = category;
 243   isInitialized->store(true, std::memory_order_release);
 244   return category;
 245 }
 246
 247 std::atomic<LoggerDB::InternalWarningHandler> LoggerDB::warningHandler_;
 248
 249 void LoggerDB::internalWarningImpl(
 250     folly::StringPiece filename,
 251     int lineNumber,
 252     std::string&& msg) noexcept {
 253   auto handler = warningHandler_.load();
 254   if (handler) {
 255     handler(filename, lineNumber, std::move(msg));
 256   } else {
 257     defaultInternalWarningImpl(filename, lineNumber, std::move(msg));
 258   }
 259 }
 260
 261 void LoggerDB::setInternalWarningHandler(InternalWarningHandler handler) {
 262   // This API is intentionally pretty basic.  It has a number of limitations:
 263   //
 264   // - We only support plain function pointers, and not full std::function
 265   //   objects.  This makes it possible to use std::atomic to access the
 266   //   handler pointer, and also makes it safe to store in a zero-initialized
 267   //   file-static pointer.
 268   //
 269   // - We don't support any void* argument to the handler.  The caller is
 270   //   responsible for storing any callback state themselves.
 271   //
 272   // - When replacing or unsetting a handler we don't make any guarantees about
 273   //   when the old handler will stop being called.  It may still be called
 274   //   from other threads briefly even after setInternalWarningHandler()
 275   //   returns.  This is also a consequence of using std::atomic rather than a
 276   //   full lock.
 277   //
 278   // This provides the minimum capabilities needed to customize the handler,
 279   // while still keeping the implementation simple and safe to use even before
 280   // main().
 281   warningHandler_.store(handler);
 282 }
 283
 284 void LoggerDB::defaultInternalWarningImpl(
 285     folly::StringPiece filename,
 286     int lineNumber,
 287     std::string&& msg) noexcept {
 288   // Rate limit to 10 messages every 5 seconds.
 289   //
 290   // We intentonally use a leaky Meyer's singleton here over folly::Singleton:
 291   // - We want this code to work even before main()
 292   // - This singleton does not depend on any other singletons.
 293   static auto* rateLimiter =
 294       new logging::IntervalRateLimiter{10, std::chrono::seconds(5)};
 295   if (!rateLimiter->check()) {
 296     return;
 297   }
 298
 299   if (folly::kIsDebug) {
 300     // Write directly to file descriptor 2.
 301     //
 302     // It's possible the application has closed fd 2 and is using it for
 303     // something other than stderr.  However we have no good way to detect
 304     // this, which is the main reason we only write to stderr in debug build
 305     // modes.  assert() also writes directly to stderr on failure, which seems
 306     // like a reasonable precedent.
 307     //
 308     // Another option would be to use openlog() and syslog().  However
 309     // calling openlog() may inadvertently affect the behavior of other parts
 310     // of the program also using syslog().
 311     //
 312     // We don't check for write errors here, since there's not much else we can
 313     // do if it fails.
 314     auto fullMsg = folly::to<std::string>(
 315         "logging warning:", filename, ":", lineNumber, ": ", msg, "\n");
 316     folly::writeFull(STDERR_FILENO, fullMsg.data(), fullMsg.size());
 317   }
 318 }
 319 }