logging: add XLOG() and XLOGF() logging macros
authorAdam Simpkins <simpkins@fb.com>
Thu, 15 Jun 2017 18:03:46 +0000 (11:03 -0700)
committerFacebook Github Bot <facebook-github-bot@users.noreply.github.com>
Thu, 15 Jun 2017 18:06:06 +0000 (11:06 -0700)
Summary:
This adds new `XLOG()` and `XLOGF()` macros to the logging library.  These are
similar to `FB_LOG()` and `FB_LOGF()`, but do not require a Logger argument.
Instead, the log category is picked automatically based on the current file
name.  The basic algorithm for picking the category name is to replace
directory separators with '.', and to strip off the filename extension.

For instance, all `XLOG()` statements in `src/foo/bar.cpp` will log to the
category `src.foo.bar`.  This also works correctly in header files: `XLOG()`
statements in `src/foo/mylib.h` will log to `src.foo.mylib`

This should generally result in a good log category hierarchy without the user
having to spend additional time picking category names--we simply re-use the
decisions that they already made for their directory layout.

In general I expect the `XLOG()` macros to be convenient enough that users will
use `XLOG()` in almost all cases rather than using `FB_LOG()`.

The log category name used by `XLOG()` statements can be overridden using
`XLOG_SET_CATEGORY()`, but this only works in .cpp files, not in header files.

Reviewed By: wez

Differential Revision: D4920257

fbshipit-source-id: 7ffafd9a4c87e6fb5eb35d86e0eb86ef1ed5be95

17 files changed:
CMakeLists.txt
folly/Makefile.am
folly/experimental/logging/LogCategory.cpp
folly/experimental/logging/LogCategory.h
folly/experimental/logging/LogLevel.cpp
folly/experimental/logging/LogLevel.h
folly/experimental/logging/LoggerDB.cpp
folly/experimental/logging/LoggerDB.h
folly/experimental/logging/Makefile.am
folly/experimental/logging/test/LogLevelTest.cpp
folly/experimental/logging/test/XlogFile1.cpp [new file with mode: 0644]
folly/experimental/logging/test/XlogFile2.cpp [new file with mode: 0644]
folly/experimental/logging/test/XlogHeader1.h [new file with mode: 0644]
folly/experimental/logging/test/XlogHeader2.h [new file with mode: 0644]
folly/experimental/logging/test/XlogTest.cpp [new file with mode: 0644]
folly/experimental/logging/xlog.cpp [new file with mode: 0644]
folly/experimental/logging/xlog.h [new file with mode: 0644]

index deb87fd..9fee09f 100755 (executable)
@@ -317,6 +317,8 @@ if (BUILD_TESTS)
       TEST logging-test
         HEADERS
           TestLogHandler.h
+          XlogHeader1.h
+          XlogHeader2.h
         SOURCES
           LogCategoryTest.cpp
           LoggerDBTest.cpp
@@ -325,6 +327,9 @@ if (BUILD_TESTS)
           LogMessageTest.cpp
           LogNameTest.cpp
           LogStreamTest.cpp
+          XlogFile1.cpp
+          XlogFile2.cpp
+          XlogTest.cpp
 
     DIRECTORY fibers/test/
       TEST fibers_test SOURCES FibersTest.cpp
index 9b177cc..28b736b 100644 (file)
@@ -130,6 +130,7 @@ nobase_follyinclude_HEADERS = \
        experimental/logging/LogStreamProcessor.h \
        experimental/logging/Logger.h \
        experimental/logging/LoggerDB.h \
+       experimental/logging/xlog.h \
        experimental/NestedCommandLineApp.h \
        experimental/observer/detail/Core.h \
        experimental/observer/detail/GraphCycleDetector.h \
index f1b2856..3eec18f 100644 (file)
@@ -121,11 +121,16 @@ void LogCategory::setLevel(LogLevel level, bool inherit) {
 }
 
 void LogCategory::setLevelLocked(LogLevel level, bool inherit) {
-  // Truncate to LogLevel::MAX_LEVEL to make sure it does not conflict
-  // with our flag bits.
+  // Clamp the value to MIN_LEVEL and MAX_LEVEL.
+  //
+  // This makes sure that UNINITIALIZED is always less than any valid level
+  // value, and that level values cannot conflict with our flag bits.
   if (level > LogLevel::MAX_LEVEL) {
     level = LogLevel::MAX_LEVEL;
+  } else if (level < LogLevel::MIN_LEVEL) {
+    level = LogLevel::MIN_LEVEL;
   }
+
   // Make sure the inherit flag is always off for the root logger.
   if (!parent_) {
     inherit = false;
@@ -161,6 +166,11 @@ void LogCategory::updateEffectiveLevel(LogLevel newEffectiveLevel) {
     return;
   }
 
+  // Update all of the values in xlogLevels_
+  for (auto* levelPtr : xlogLevels_) {
+    levelPtr->store(newEffectiveLevel, std::memory_order_release);
+  }
+
   // Update all children loggers
   LogCategory* child = firstChild_;
   while (child != nullptr) {
@@ -180,4 +190,8 @@ void LogCategory::parentLevelUpdated(LogLevel parentEffectiveLevel) {
   auto newEffectiveLevel = std::min(myLevel, parentEffectiveLevel);
   updateEffectiveLevel(newEffectiveLevel);
 }
+
+void LogCategory::registerXlogLevel(std::atomic<LogLevel>* levelPtr) {
+  xlogLevels_.push_back(levelPtr);
+}
 }
index a944713..e589400 100644 (file)
@@ -129,19 +129,6 @@ class LogCategory {
    */
   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) const;
-
   /**
    * Get the LoggerDB that this LogCategory belongs to.
    *
@@ -163,6 +150,21 @@ class LogCategory {
    */
   void clearHandlers();
 
+  /* Internal methods for use by other parts of the logging library code */
+
+  /**
+   * Process a log message.
+   *
+   * This method generally should be invoked only through the logging macros,
+   * 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) const;
+
   /**
    * Note: setLevelLocked() may only be called while holding the main
    * LoggerDB lock.
@@ -171,6 +173,18 @@ class LogCategory {
    */
   void setLevelLocked(LogLevel level, bool inherit);
 
+  /**
+   * Register a std::atomic<LogLevel> value used by XLOG*() macros to check the
+   * effective level for this category.
+   *
+   * The LogCategory will keep this value updated whenever its effective log
+   * level changes.
+   *
+   * This function should only be invoked by LoggerDB, and the LoggerDB lock
+   * must be held when calling it.
+   */
+  void registerXlogLevel(std::atomic<LogLevel>* levelPtr);
+
  private:
   enum : uint32_t { FLAG_INHERIT = 0x80000000 };
 
@@ -228,5 +242,14 @@ class LogCategory {
    */
   LogCategory* firstChild_{nullptr};
   LogCategory* nextSibling_{nullptr};
+
+  /**
+   * A list of LogLevel values used by XLOG*() statements for this LogCategory.
+   * The XLOG*() statements will check these values.  We ensure they are kept
+   * up-to-date each time the effective log level changes for this category.
+   *
+   * This list may only be accessed while holding the main LoggerDB lock.
+   */
+  std::vector<std::atomic<LogLevel>*> xlogLevels_;
 };
 }
index 25408f5..a60e024 100644 (file)
@@ -45,7 +45,9 @@ LogLevel stringToLogLevel(StringPiece name) {
     lowerName.subtract(1);
   }
 
-  if (lowerName == "none") {
+  if (lowerName == "uninitialized") {
+    return LogLevel::UNINITIALIZED;
+  } else if (lowerName == "none") {
     return LogLevel::NONE;
   } else if (lowerName == "debug") {
     return LogLevel::DEBUG;
@@ -80,7 +82,9 @@ LogLevel stringToLogLevel(StringPiece name) {
 }
 
 string logLevelToString(LogLevel level) {
-  if (level == LogLevel::NONE) {
+  if (level == LogLevel::UNINITIALIZED) {
+    return "LogLevel::UNINITIALIZED";
+  } else if (level == LogLevel::NONE) {
     return "LogLevel::NONE";
   } else if (level == LogLevel::DEBUG) {
     return "LogLevel::DEBUG";
index 347a795..c5f1920 100644 (file)
@@ -34,7 +34,9 @@ namespace folly {
  * DBG1 is one level higher of verbosity, etc.
  */
 enum class LogLevel : uint32_t {
-  NONE = 0,
+  UNINITIALIZED = 0,
+  NONE = 1,
+  MIN_LEVEL = 1,
 
   DEBUG = 900,
   DBG0 = 1000,
index bf88714..953570b 100644 (file)
@@ -170,4 +170,49 @@ void LoggerDB::cleanupHandlers() {
     category->clearHandlers();
   }
 }
+
+LogLevel LoggerDB::xlogInit(
+    StringPiece categoryName,
+    std::atomic<LogLevel>* xlogCategoryLevel,
+    LogCategory** xlogCategory) {
+  // Hold the lock for the duration of the operation
+  // xlogInit() may be called from multiple threads simultaneously.
+  // Only one needs to perform the initialization.
+  auto loggersByName = loggersByName_.wlock();
+  if (xlogCategory != nullptr && *xlogCategory != nullptr) {
+    // The xlogCategory was already initialized before we acquired the lock
+    return (*xlogCategory)->getEffectiveLevel();
+  }
+
+  auto* category = getOrCreateCategoryLocked(*loggersByName, categoryName);
+  if (xlogCategory) {
+    // Set *xlogCategory before we update xlogCategoryLevel below.
+    // This is important, since the XLOG() macros check xlogCategoryLevel to
+    // tell if *xlogCategory has been initialized yet.
+    *xlogCategory = category;
+  }
+  auto level = category->getEffectiveLevel();
+  xlogCategoryLevel->store(level, std::memory_order_release);
+  category->registerXlogLevel(xlogCategoryLevel);
+  return level;
+}
+
+LogCategory* LoggerDB::xlogInitCategory(
+    StringPiece categoryName,
+    LogCategory** xlogCategory,
+    std::atomic<bool>* isInitialized) {
+  // Hold the lock for the duration of the operation
+  // xlogInitCategory() may be called from multiple threads simultaneously.
+  // Only one needs to perform the initialization.
+  auto loggersByName = loggersByName_.wlock();
+  if (isInitialized->load(std::memory_order_acquire)) {
+    // The xlogCategory was already initialized before we acquired the lock
+    return *xlogCategory;
+  }
+
+  auto* category = getOrCreateCategoryLocked(*loggersByName, categoryName);
+  *xlogCategory = category;
+  isInitialized->store(true, std::memory_order_release);
+  return category;
+}
 }
index 635e6f9..82a65a1 100644 (file)
@@ -90,6 +90,21 @@ class LoggerDB {
    */
   void cleanupHandlers();
 
+  /**
+   * Initialize the LogCategory* and std::atomic<LogLevel> used by an XLOG()
+   * statement.
+   *
+   * Returns the current effective LogLevel of the category.
+   */
+  LogLevel xlogInit(
+      folly::StringPiece categoryName,
+      std::atomic<LogLevel>* xlogCategoryLevel,
+      LogCategory** xlogCategory);
+  LogCategory* xlogInitCategory(
+      folly::StringPiece categoryName,
+      LogCategory** xlogCategory,
+      std::atomic<bool>* isInitialized);
+
   enum TestConstructorArg { TESTING };
 
   /**
index 683017c..4d85e79 100644 (file)
@@ -11,7 +11,8 @@ libfollylogging_la_SOURCES = \
        LogMessage.cpp \
        LogName.cpp \
        LogStream.cpp \
-       LogStreamProcessor.cpp
+       LogStreamProcessor.cpp \
+       xlog.cpp
 
 libfollylogging_la_LIBADD = $(top_builddir)/libfolly.la
 libfollylogging_la_LDFLAGS = $(AM_LDFLAGS) -version-info $(LT_VERSION)
index 5f0af08..0537948 100644 (file)
 using namespace folly;
 
 TEST(LogLevel, fromString) {
+  EXPECT_EQ(LogLevel::UNINITIALIZED, stringToLogLevel("uninitialized"));
+  EXPECT_EQ(LogLevel::UNINITIALIZED, stringToLogLevel("UnInitialized"));
+  EXPECT_EQ(
+      LogLevel::UNINITIALIZED, stringToLogLevel("LogLevel::UNINITIALIZED"));
+
   EXPECT_EQ(LogLevel::NONE, stringToLogLevel("none"));
   EXPECT_EQ(LogLevel::NONE, stringToLogLevel("NONE"));
   EXPECT_EQ(LogLevel::NONE, stringToLogLevel("NoNe"));
@@ -68,6 +73,8 @@ TEST(LogLevel, fromString) {
 }
 
 TEST(LogLevel, toString) {
+  EXPECT_EQ(
+      "LogLevel::UNINITIALIZED", logLevelToString(LogLevel::UNINITIALIZED));
   EXPECT_EQ("LogLevel::NONE", logLevelToString(LogLevel::NONE));
   EXPECT_EQ("LogLevel::INFO", logLevelToString(LogLevel::INFO));
   EXPECT_EQ("LogLevel::WARN", logLevelToString(LogLevel::WARN));
@@ -98,6 +105,7 @@ TEST(LogLevel, toStringAndBack) {
   };
 
   // Check all of the named levels
+  checkLevel(LogLevel::UNINITIALIZED);
   checkLevel(LogLevel::NONE);
   checkLevel(LogLevel::DEBUG);
   checkLevel(LogLevel::DBG0);
diff --git a/folly/experimental/logging/test/XlogFile1.cpp b/folly/experimental/logging/test/XlogFile1.cpp
new file mode 100644 (file)
index 0000000..2d43930
--- /dev/null
@@ -0,0 +1,23 @@
+/*
+ * 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 <folly/experimental/logging/test/XlogHeader1.h>
+#include <folly/experimental/logging/xlog.h>
+
+namespace logging_test {
+void testXlogFile1Dbg1(folly::StringPiece msg) {
+  XLOG(DBG1, "file1: ", msg);
+}
+}
diff --git a/folly/experimental/logging/test/XlogFile2.cpp b/folly/experimental/logging/test/XlogFile2.cpp
new file mode 100644 (file)
index 0000000..db91671
--- /dev/null
@@ -0,0 +1,23 @@
+/*
+ * 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 <folly/experimental/logging/test/XlogHeader1.h>
+#include <folly/experimental/logging/xlog.h>
+
+namespace logging_test {
+void testXlogFile2Dbg1(folly::StringPiece msg) {
+  XLOG(DBG1, "file2: ", msg);
+}
+}
diff --git a/folly/experimental/logging/test/XlogHeader1.h b/folly/experimental/logging/test/XlogHeader1.h
new file mode 100644 (file)
index 0000000..262989e
--- /dev/null
@@ -0,0 +1,35 @@
+/*
+ * 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 <folly/Range.h>
+#include <folly/experimental/logging/xlog.h>
+
+namespace logging_test {
+
+// A sample functions that uses XLOGF() macros in a header file.
+inline void testXlogHdrLoop(size_t numIters, folly::StringPiece arg) {
+  XLOGF(DBG1, "starting: {}", arg);
+  for (size_t n = 0; n < numIters; ++n) {
+    XLOGF(DBG5, "test: {}", arg);
+  }
+  XLOGF(DBG1, "finished: {}", arg);
+}
+
+// Prototypes for functions defined in XlogFile1.cpp and XlogFile2.cpp
+void testXlogFile1Dbg1(folly::StringPiece msg);
+void testXlogFile2Dbg1(folly::StringPiece msg);
+}
diff --git a/folly/experimental/logging/test/XlogHeader2.h b/folly/experimental/logging/test/XlogHeader2.h
new file mode 100644 (file)
index 0000000..93735a6
--- /dev/null
@@ -0,0 +1,25 @@
+/*
+ * 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 <folly/Range.h>
+#include <folly/experimental/logging/xlog.h>
+
+namespace logging_test {
+inline void testXlogHdrFunction(folly::StringPiece str, int value) {
+  XLOG(DBG3, "test: ", str, "=", value);
+}
+}
diff --git a/folly/experimental/logging/test/XlogTest.cpp b/folly/experimental/logging/test/XlogTest.cpp
new file mode 100644 (file)
index 0000000..3e70b2a
--- /dev/null
@@ -0,0 +1,180 @@
+/*
+ * 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 <folly/experimental/logging/LogCategory.h>
+#include <folly/experimental/logging/LogHandler.h>
+#include <folly/experimental/logging/LogMessage.h>
+#include <folly/experimental/logging/LoggerDB.h>
+#include <folly/experimental/logging/test/TestLogHandler.h>
+#include <folly/experimental/logging/test/XlogHeader1.h>
+#include <folly/experimental/logging/test/XlogHeader2.h>
+#include <folly/experimental/logging/xlog.h>
+#include <folly/portability/GTest.h>
+
+using namespace folly;
+using std::make_shared;
+
+XLOG_SET_CATEGORY("xlog_test.main_file");
+
+// Note that the XLOG* macros always use the main LoggerDB singleton.
+// There is no way to get them to use a test LoggerDB during unit tests.
+//
+// Therefore any configuration we do here affects the main log category
+// settings for the entire program.  Fortunately all of the other unit tests do
+// use testing LoggerDB objects.
+
+TEST(Xlog, xlog) {
+  auto handler = make_shared<TestLogHandler>();
+  LoggerDB::get()->getCategory("xlog_test")->addHandler(handler);
+  auto& messages = handler->getMessages();
+
+  // info messages are not enabled initially.
+  EXPECT_FALSE(XLOG_IS_ON(INFO));
+  EXPECT_TRUE(XLOG_IS_ON(ERR));
+  XLOG(INFO, "testing 1");
+  EXPECT_EQ(0, messages.size());
+  messages.clear();
+
+  // Increase the log level, then log a message.
+  LoggerDB::get()->setLevel("xlog_test.main_file", LogLevel::DBG1);
+
+  XLOG(DBG1, "testing: ", 1, 2, 3);
+  ASSERT_EQ(1, messages.size());
+  EXPECT_EQ("testing: 123", messages[0].first.getMessage());
+  EXPECT_TRUE(messages[0].first.getFileName().endsWith("XlogTest.cpp"))
+      << "unexpected file name: " << messages[0].first.getFileName();
+  EXPECT_EQ(LogLevel::DBG1, messages[0].first.getLevel());
+  EXPECT_EQ("xlog_test.main_file", messages[0].first.getCategory()->getName());
+  EXPECT_EQ("xlog_test", messages[0].second->getName());
+  messages.clear();
+
+  XLOGF(WARN, "number: {:>3d}; string: {}", 12, "foo");
+  ASSERT_EQ(1, messages.size());
+  EXPECT_EQ("number:  12; string: foo", messages[0].first.getMessage());
+  EXPECT_TRUE(messages[0].first.getFileName().endsWith("XlogTest.cpp"))
+      << "unexpected file name: " << messages[0].first.getFileName();
+  EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel());
+  EXPECT_EQ("xlog_test.main_file", messages[0].first.getCategory()->getName());
+  EXPECT_EQ("xlog_test", messages[0].second->getName());
+  messages.clear();
+
+  XLOG(DBG2, "this log check should not pass");
+  EXPECT_EQ(0, messages.size());
+  messages.clear();
+
+  // Test stream arguments to XLOG()
+  XLOG(INFO) << "stream test: " << 1 << ", two, " << 3;
+  ASSERT_EQ(1, messages.size());
+  EXPECT_EQ("stream test: 1, two, 3", messages[0].first.getMessage());
+  EXPECT_TRUE(messages[0].first.getFileName().endsWith("XlogTest.cpp"))
+      << "unexpected file name: " << messages[0].first.getFileName();
+  EXPECT_EQ(LogLevel::INFO, messages[0].first.getLevel());
+  EXPECT_EQ("xlog_test.main_file", messages[0].first.getCategory()->getName());
+  EXPECT_EQ("xlog_test", messages[0].second->getName());
+  messages.clear();
+}
+
+TEST(Xlog, perFileCategoryHandling) {
+  using namespace logging_test;
+
+  auto handler = make_shared<TestLogHandler>();
+  LoggerDB::get()
+      ->getCategory("folly.experimental.logging.test")
+      ->addHandler(handler);
+  LoggerDB::get()->setLevel("folly.experimental.logging.test", LogLevel::DBG9);
+  auto& messages = handler->getMessages();
+
+  // Use the simple helper function in XlogHeader2
+  testXlogHdrFunction("factor", 99);
+  ASSERT_EQ(1, messages.size());
+  EXPECT_EQ("test: factor=99", messages[0].first.getMessage());
+  EXPECT_TRUE(messages[0].first.getFileName().endsWith("XlogHeader2.h"))
+      << "unexpected file name: " << messages[0].first.getFileName();
+  EXPECT_EQ(LogLevel::DBG3, messages[0].first.getLevel());
+  EXPECT_EQ(
+      "folly.experimental.logging.test.XlogHeader2",
+      messages[0].first.getCategory()->getName());
+  EXPECT_EQ("folly.experimental.logging.test", messages[0].second->getName());
+  messages.clear();
+
+  // Test the loop function from XlogHeader1
+  testXlogHdrLoop(3, "hello world");
+  ASSERT_EQ(5, messages.size());
+  EXPECT_EQ("starting: hello world", messages[0].first.getMessage());
+  EXPECT_TRUE(messages[0].first.getFileName().endsWith("XlogHeader1.h"))
+      << "unexpected file name: " << messages[0].first.getFileName();
+  EXPECT_EQ(LogLevel::DBG1, messages[0].first.getLevel());
+  EXPECT_EQ(
+      "folly.experimental.logging.test.XlogHeader1",
+      messages[0].first.getCategory()->getName());
+  EXPECT_EQ("folly.experimental.logging.test", messages[0].second->getName());
+
+  EXPECT_EQ("test: hello world", messages[1].first.getMessage());
+  EXPECT_EQ("test: hello world", messages[2].first.getMessage());
+  EXPECT_EQ("test: hello world", messages[3].first.getMessage());
+  EXPECT_EQ("finished: hello world", messages[4].first.getMessage());
+  EXPECT_EQ(LogLevel::DBG5, messages[1].first.getLevel());
+  EXPECT_EQ(LogLevel::DBG5, messages[2].first.getLevel());
+  EXPECT_EQ(LogLevel::DBG5, messages[3].first.getLevel());
+  EXPECT_EQ(LogLevel::DBG1, messages[4].first.getLevel());
+  messages.clear();
+
+  // Reduce the log level so that the messages inside the loop
+  // should not be logged.
+  LoggerDB::get()->setLevel("folly.experimental.logging.test", LogLevel::DBG2);
+  testXlogHdrLoop(300, "hello world");
+  ASSERT_EQ(2, messages.size());
+  EXPECT_EQ("starting: hello world", messages[0].first.getMessage());
+  EXPECT_EQ("finished: hello world", messages[1].first.getMessage());
+  messages.clear();
+
+  // Call the helpers function in XlogFile1.cpp and XlogFile2.cpp and makes
+  // sure their categories are reported correctly.
+  testXlogFile1Dbg1("foobar 1234");
+  ASSERT_EQ(1, messages.size());
+  EXPECT_EQ("file1: foobar 1234", messages[0].first.getMessage());
+  EXPECT_EQ(
+      "folly.experimental.logging.test.XlogFile1",
+      messages[0].first.getCategory()->getName());
+  messages.clear();
+
+  testXlogFile2Dbg1("hello world");
+  ASSERT_EQ(1, messages.size());
+  EXPECT_EQ("file2: hello world", messages[0].first.getMessage());
+  EXPECT_EQ(
+      "folly.experimental.logging.test.XlogFile2",
+      messages[0].first.getCategory()->getName());
+  messages.clear();
+
+  // Adjust the log level and make sure the changes take effect for the .cpp
+  // file categories
+  LoggerDB::get()->setLevel("folly.experimental.logging.test", LogLevel::INFO);
+  testXlogFile1Dbg1("log check should fail now");
+  testXlogFile2Dbg1("this should fail too");
+  EXPECT_EQ(0, messages.size());
+  messages.clear();
+
+  LoggerDB::get()->setLevel(
+      "folly.experimental.logging.test.XlogFile1", LogLevel::DBG1);
+  testXlogFile1Dbg1("this log check should pass now");
+  testXlogFile2Dbg1("but this one should still fail");
+  ASSERT_EQ(1, messages.size());
+  EXPECT_EQ(
+      "file1: this log check should pass now", messages[0].first.getMessage());
+  EXPECT_EQ(
+      "folly.experimental.logging.test.XlogFile1",
+      messages[0].first.getCategory()->getName());
+  messages.clear();
+}
diff --git a/folly/experimental/logging/xlog.cpp b/folly/experimental/logging/xlog.cpp
new file mode 100644 (file)
index 0000000..92390a2
--- /dev/null
@@ -0,0 +1,88 @@
+/*
+ * 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 <folly/experimental/logging/xlog.h>
+#include <folly/Synchronized.h>
+
+using folly::StringPiece;
+
+namespace folly {
+
+namespace {
+/**
+ * buck copies header files from their original location in the source tree
+ * and places them under buck-out/ with a path like
+ * buck-out/<rule-name-components>/<original-path>
+ *
+ * We want to strip off the buck-out/<rule-name-components> portion,
+ * so that the filename we use is just the original path in the source tree.
+ *
+ * The <rule-name-component> section should always end in a path component that
+ * includes a '#': it's format is <rule-name>#<parameters>, where <parameters>
+ * is a comma separated list that never includes '/'.
+ *
+ * Search for the first path component with a '#', and strip off everything up
+ * to this component.
+ */
+StringPiece stripBuckOutPrefix(StringPiece filename) {
+  size_t idx = 0;
+  while (true) {
+    auto end = filename.find('/', idx);
+    if (end == StringPiece::npos) {
+      // We were unable to find where the buck-out prefix should end.
+      return filename;
+    }
+
+    auto component = filename.subpiece(idx, end - idx);
+    if (component.find('#') != StringPiece::npos) {
+      return filename.subpiece(end + 1);
+    }
+    idx = end + 1;
+  }
+}
+} // unnamed namespace
+
+std::string getXlogCategoryNameForFile(StringPiece filename) {
+  // Buck mangles the directory layout for header files.  Rather than including
+  // them from their original location, it moves them into deep directories
+  // inside buck-out, and includes them from there.
+  //
+  // If this path looks like a buck header directory, try to strip off the
+  // buck-specific portion.
+  if (filename.startsWith("buck-out/")) {
+    filename = stripBuckOutPrefix(filename);
+  }
+
+  std::string categoryName = filename.str();
+
+  // Translate slashes to dots, to turn the directory layout into
+  // a category hierarchy.
+  size_t lastDot = std::string::npos;
+  for (size_t n = 0; n < categoryName.size(); ++n) {
+    if (categoryName[n] == '/') {
+      categoryName[n] = '.';
+      lastDot = std::string::npos;
+    } else if (categoryName[n] == '.') {
+      lastDot = n;
+    }
+  }
+
+  // Strip off the filename extension, if one was present.
+  if (lastDot != std::string::npos) {
+    categoryName.resize(lastDot);
+  }
+  return categoryName;
+}
+}
diff --git a/folly/experimental/logging/xlog.h b/folly/experimental/logging/xlog.h
new file mode 100644 (file)
index 0000000..452041f
--- /dev/null
@@ -0,0 +1,396 @@
+/*
+ * 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 <folly/Likely.h>
+#include <folly/Range.h>
+#include <folly/experimental/logging/LogStream.h>
+#include <folly/experimental/logging/Logger.h>
+#include <folly/experimental/logging/LoggerDB.h>
+
+/*
+ * This file contains the XLOG() and XLOGF() macros.
+ *
+ * These macros make it easy to use the logging library without having to
+ * manually pick log category names.  All XLOG() and XLOGF() statements in a
+ * given file automatically use a LogCategory based on the current file name.
+ *
+ * For instance, in src/foo/bar.cpp, the default log category name will be
+ * "src.foo.bar"
+ *
+ * If desired, the log category name used by XLOG() in a .cpp file may be
+ * overridden using XLOG_SET_CATEGORY() macro.
+ */
+
+/**
+ * Log a message to this file's default log category.
+ *
+ * By default the log category name is automatically picked based on the
+ * current filename.  In src/foo/bar.cpp the log category name "src.foo.bar"
+ * will be used.  In "lib/stuff/foo.h" the log category name will be
+ * "lib.stuff.foo"
+ *
+ * Note that the filename is based on the __FILE__ macro defined by the
+ * compiler.  This is typically dependent on the filename argument that you
+ * give to the compiler.  For example, if you compile src/foo/bar.cpp by
+ * invoking the compiler inside src/foo and only give it "bar.cpp" as an
+ * argument, the category name will simply be "bar".  In general XLOG() works
+ * best if you always invoke the compiler from the root directory of your
+ * project repository.
+ */
+#define XLOG(level, ...)                   \
+  XLOG_IMPL(                               \
+      ::folly::LogLevel::level,            \
+      ::folly::LogStreamProcessor::APPEND, \
+      ##__VA_ARGS__)
+
+/**
+ * Log a message to this file's default log category, using a format string.
+ */
+#define XLOGF(level, fmt, arg1, ...)       \
+  XLOG_IMPL(                               \
+      ::folly::LogLevel::level,            \
+      ::folly::LogStreamProcessor::FORMAT, \
+      fmt,                                 \
+      arg1,                                \
+      ##__VA_ARGS__)
+
+/**
+ * Helper macro used to implement XLOG() and XLOGF()
+ *
+ * Beware that the level argument is evalutated twice.
+ *
+ * This macro is somewhat tricky:
+ *
+ * - In order to support streaming argument support (with the << operator),
+ *   the macro must expand to a single ternary ? expression.  This is the only
+ *   way we can avoid evaluating the log arguments if the log check fails,
+ *   and still have the macro behave as expected when used as the body of an if
+ *   or else statement.
+ *
+ * - We need to store some static-scope local state in order to track the
+ *   LogCategory to use.  This is a bit tricky to do and still meet the
+ *   requirements of being a single expression, but fortunately static
+ *   variables inside a lambda work for this purpose.
+ *
+ *   Inside header files, each XLOG() statement defines to static variables:
+ *   - the LogLevel for this category
+ *   - a pointer to the LogCategory
+ *
+ *   If the __INCLUDE_LEVEL__ macro is available (both gcc and clang support
+ *   this), then we we can detect when we are inside a .cpp file versus a
+ *   header file.  If we are inside a .cpp file, we can avoid declaring these
+ *   variables once per XLOG() statement, and instead we only declare one copy
+ *   of these variables for the entire file.
+ *
+ * - We want to make sure this macro is safe to use even from inside static
+ *   initialization code that runs before main.  We also want to make the log
+ *   admittance check as cheap as possible, so that disabled debug logs have
+ *   minimal overhead, and can be left in place even in performance senstive
+ *   code.
+ *
+ *   In order to do this, we rely on zero-initialization of variables with
+ *   static storage duration.  The LogLevel variable will always be
+ *   0-initialized before any code runs.  Therefore the very first time an
+ *   XLOG() statement is hit the initial log level check will always pass
+ *   (since all level values are greater or equal to 0), and we then do a
+ *   second check to see if the log level and category variables need to be
+ *   initialized.  On all subsequent calls, disabled log statements can be
+ *   skipped with just a single check of the LogLevel.
+ */
+#define XLOG_IMPL(level, type, ...)                        \
+  (!XLOG_IS_ON_IMPL(level)) ? static_cast<void>(0)         \
+                            : ::folly::LogStreamProcessor( \
+                                  XLOG_GET_CATEGORY(),     \
+                                  (level),                 \
+                                  __FILE__,                \
+                                  __LINE__,                \
+                                  (type),                  \
+                                  ##__VA_ARGS__) &         \
+          ::folly::LogStream()
+
+/**
+ * Check if and XLOG() statement with the given log level would be enabled.
+ */
+#define XLOG_IS_ON(level) XLOG_IS_ON_IMPL(::folly::LogLevel::level)
+
+/**
+ * Helper macro to implement of XLOG_IS_ON()
+ *
+ * This macro is used in the XLOG() implementation, and therefore must be as
+ * cheap as possible.  It stores the category's LogLevel as a local static
+ * variable.  The very first time this macro is evaluated it will look up the
+ * correct LogCategory and initialize the LogLevel.  Subsequent calls then
+ * are only a single conditional log level check.
+ *
+ * The LogCategory object keeps track of this local LogLevel variable and
+ * automatically keeps it up-to-date when the category's effective level is
+ * changed.
+ *
+ * Most of this code must live in the macro definition itself, and cannot be
+ * moved into a helper function: The getXlogCategoryName() call must be made as
+ * part of the macro expansion in order to work correctly.  We also want to
+ * avoid calling it whenever possible.  Therefore most of the logic must be
+ * done in the macro expansion.
+ *
+ * See XlogLevelInfo for the implementation details.
+ */
+#define XLOG_IS_ON_IMPL(level)                                                 \
+  ([] {                                                                        \
+    static ::folly::XlogLevelInfo<XLOG_IS_IN_HEADER_FILE> _xlogLevel_;         \
+    const auto _xlogLevelToCheck_ = (level);                                   \
+    /*                                                                         \
+     * Do an initial relaxed check.  If this fails we know the category level  \
+     * is initialized and the log admittance check failed.                     \
+     * Use LIKELY() to optimize for the case of disabled debug statements:     \
+     * we disabled debug statements to be cheap.  If the log message is        \
+     * enabled then this check will still be minimal perf overhead compared to \
+     * the overall cost of logging it.                                         \
+     */                                                                        \
+    if (LIKELY(                                                                \
+            _xlogLevelToCheck_ <                                               \
+            _xlogLevel_.getLevel(                                              \
+                &_xlogFileScopeInfo_, std::memory_order_relaxed))) {           \
+      return false;                                                            \
+    }                                                                          \
+    /*                                                                         \
+     * Load the level value with memory_order_acquire, and check               \
+     * to see if it is initialized or not.                                     \
+     */                                                                        \
+    auto _xlogCurrentLevel_ =                                                  \
+        _xlogLevel_.getLevel(&_xlogFileScopeInfo_, std::memory_order_acquire); \
+    if (UNLIKELY(_xlogCurrentLevel_ == ::folly::LogLevel::UNINITIALIZED)) {    \
+      _xlogCurrentLevel_ = _xlogLevel_.init(                                   \
+          getXlogCategoryName(__FILE__), &_xlogFileScopeInfo_);                \
+    }                                                                          \
+    return _xlogLevelToCheck_ >= _xlogCurrentLevel_;                           \
+  }())
+
+/**
+ * Get a pointer to the LogCategory that will be used by XLOG() statements in
+ * this file.
+ *
+ * This macro is used in the XLOG() implementation, and therefore must be as
+ * cheap as possible.  It stores the LogCategory* pointer as a local static
+ * variable.  Only the first invocation has to look up the log category by
+ * name.  Subsequent invocations re-use the already looked-up LogCategory
+ * pointer.
+ *
+ * Most of this code must live in the macro definition itself, and cannot be
+ * moved into a helper function: The getXlogCategoryName() call must be made as
+ * part of the macro expansion in order to work correctly.  We also want to
+ * avoid calling it whenever possible.  Therefore most of the logic must be
+ * done in the macro expansion.
+ *
+ * See XlogCategoryInfo for the implementation details.
+ */
+#define XLOG_GET_CATEGORY()                                                  \
+  [] {                                                                       \
+    static ::folly::XlogCategoryInfo<XLOG_IS_IN_HEADER_FILE> _xlogCategory_; \
+    if (!_xlogCategory_.isInitialized()) {                                   \
+      return _xlogCategory_.init(getXlogCategoryName(__FILE__));             \
+    }                                                                        \
+    return _xlogCategory_.getCategory(&_xlogFileScopeInfo_);                 \
+  }()
+
+/**
+ * XLOG_SET_CATEGORY() can be used to explicitly define the log category name
+ * used by all XLOG() and XLOGF() calls in this translation unit.
+ *
+ * This overrides the default behavior of picking a category name based on the
+ * current filename.
+ *
+ * This should be used at the top-level scope in a .cpp file, before any XLOG()
+ * or XLOGF() macros have been used in the file.
+ *
+ * XLOG_SET_CATEGORY() cannot be used inside header files.
+ */
+#ifdef __INCLUDE_LEVEL__
+#define XLOG_SET_CATEGORY(category)                              \
+  namespace {                                                    \
+  static_assert(                                                 \
+      __INCLUDE_LEVEL__ == 0,                                    \
+      "XLOG_SET_CATEGORY() should not be used in header files"); \
+  inline std::string getXlogCategoryName(const char*) {          \
+    return category;                                             \
+  }                                                              \
+  }
+#else
+#define XLOG_SET_CATEGORY(category)                     \
+  namespace {                                           \
+  inline std::string getXlogCategoryName(const char*) { \
+    return category;                                    \
+  }                                                     \
+  }
+#endif
+
+/**
+ * XLOG_IS_IN_HEADER_FILE evaluates to false if we can definitively tell if we
+ * are not in a header file.  Otherwise, it evaluates to true.
+ */
+#ifdef __INCLUDE_LEVEL__
+#define XLOG_IS_IN_HEADER_FILE bool(__INCLUDE_LEVEL__ > 0)
+#else
+// Without __INCLUDE_LEVEL__ we canot tell if we are in a header file or not,
+// and must pessimstically assume we are always in a header file.
+#define XLOG_IS_IN_HEADER_FILE true
+#endif
+
+namespace folly {
+
+class XlogFileScopeInfo {
+ public:
+#ifdef __INCLUDE_LEVEL__
+  std::atomic<::folly::LogLevel> level;
+  ::folly::LogCategory* category;
+#endif
+};
+
+/**
+ * A file-static XlogLevelInfo and XlogCategoryInfo object is declared for each
+ * XLOG() statement.
+ *
+ * We intentionally do not provide constructors for these structures, and rely
+ * on their members to be zero-initialized when the program starts.  This
+ * ensures that everything will work as desired even if XLOG() statements are
+ * used during dynamic object initialization before main().
+ */
+template <bool IsInHeaderFile>
+struct XlogLevelInfo {
+ public:
+  inline LogLevel getLevel(XlogFileScopeInfo*, std::memory_order order) {
+    return level_.load(order);
+  }
+
+  inline LogLevel init(folly::StringPiece categoryName, XlogFileScopeInfo*) {
+    return LoggerDB::get()->xlogInit(categoryName, &level_, nullptr);
+  }
+
+ private:
+  // This member will always be zero-initialized on program start.
+  std::atomic<LogLevel> level_;
+};
+
+template <bool IsInHeaderFile>
+struct XlogCategoryInfo {
+ public:
+  bool isInitialized() {
+    return isInitialized_.load(std::memory_order_acquire);
+  }
+
+  LogCategory* init(folly::StringPiece categoryName) {
+    return LoggerDB::get()->xlogInitCategory(
+        categoryName, &category_, &isInitialized_);
+  }
+
+  LogCategory* getCategory(XlogFileScopeInfo*) {
+    return category_;
+  }
+
+ private:
+  // These variables will always be zero-initialized on program start.
+  std::atomic<bool> isInitialized_;
+  LogCategory* category_;
+};
+
+#ifdef __INCLUDE_LEVEL__
+/**
+ * Specialization of XlogLevelInfo for XLOG() statements in the .cpp file being
+ * compiled.  In this case we only define a single file-static LogLevel object
+ * for the entire file, rather than defining one for each XLOG() statement.
+ */
+template <>
+struct XlogLevelInfo<false> {
+ public:
+  inline LogLevel getLevel(
+      XlogFileScopeInfo* fileScopeInfo,
+      std::memory_order order) {
+    return fileScopeInfo->level.load(order);
+  }
+
+  inline LogLevel init(
+      folly::StringPiece categoryName,
+      XlogFileScopeInfo* fileScopeInfo) {
+    return LoggerDB::get()->xlogInit(
+        categoryName, &fileScopeInfo->level, &fileScopeInfo->category);
+  }
+};
+
+/**
+ * Specialization of XlogCategoryInfo for XLOG() statements in the .cpp file
+ * being compiled.  In this case we only define a single file-static LogLevel
+ * object for the entire file, rather than defining one for each XLOG()
+ * statement.
+ */
+template <>
+struct XlogCategoryInfo<false> {
+ public:
+  constexpr bool isInitialized() {
+    // XlogLevelInfo<false>::check() is always called before XlogCategoryInfo
+    // is used, and it will will have already initialized fileScopeInfo.
+    // Therefore we never have to check if it is initialized yet here.
+    return true;
+  }
+  LogCategory* init(folly::StringPiece) {
+    // This method is never used given that isInitialized() always returns true
+    abort();
+    return nullptr;
+  }
+  LogCategory* getCategory(XlogFileScopeInfo* fileScopeInfo) {
+    return fileScopeInfo->category;
+  }
+};
+#endif
+
+/**
+ * Get the default XLOG() category name for the given filename.
+ *
+ * This function returns the category name that will be used by XLOG() if
+ * XLOG_SET_CATEGORY() has not been used.
+ */
+std::string getXlogCategoryNameForFile(folly::StringPiece filename);
+}
+
+/*
+ * We intentionally use an unnamed namespace inside a header file here.
+ *
+ * We want each .cpp file that uses xlog.h to get its own separate
+ * implementation of the following functions and variables.
+ */
+namespace {
+/**
+ * The default getXlogCategoryName() implementation.
+ * This will be used if XLOG_SET_CATEGORY() has not been used yet.
+ *
+ * This is a template purely so that XLOG_SET_CATEGORY() can define a more
+ * specific version if desired, allowing XLOG_SET_CATEGORY() to override this
+ * implementation once it has been used.  The template paramete
+ */
+template <typename T>
+inline std::string getXlogCategoryName(const T* filename) {
+  return ::folly::getXlogCategoryNameForFile(filename);
+}
+
+/**
+ * File-scope LogLevel and LogCategory data for XLOG() statements,
+ * if __INCLUDE_LEVEL__ is supported.
+ *
+ * This allows us to only have one LogLevel and LogCategory pointer for the
+ * entire .cpp file, rather than needing a separate copy for each XLOG()
+ * statement.
+ */
+::folly::XlogFileScopeInfo _xlogFileScopeInfo_;
+}