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