logging: add support for streaming operators
authorAdam Simpkins <simpkins@fb.com>
Tue, 13 Jun 2017 01:33:05 +0000 (18:33 -0700)
committerFacebook Github Bot <facebook-github-bot@users.noreply.github.com>
Tue, 13 Jun 2017 01:38:15 +0000 (18:38 -0700)
Summary:
Update the logging library so that FB_LOG() and FB_LOGF() also accept
streaming style arguments:

  FB_LOG(logger) << "logs can be written like this now: " << 1234;
  FB_LOG(logger, "both styles can be used") << " together";
  FB_LOGF(logger, "test: {}, {}", 1234, 5678) << " and with FB_LOGF() too";

Streaming support does make the upcoming XLOG() macros more complicated to
implement, since the macro has to expand to a single ternary `?` expression.
However I was able to come up with a solution that works and has minimal
overhead.

Reviewed By: wez

Differential Revision: D5082979

fbshipit-source-id: 11734e39c02ad28aceb44bbfbd137d781caa30cf

13 files changed:
CMakeLists.txt
folly/Makefile.am
folly/experimental/logging/LogCategory.cpp
folly/experimental/logging/LogCategory.h
folly/experimental/logging/LogStream.cpp [new file with mode: 0644]
folly/experimental/logging/LogStream.h [new file with mode: 0644]
folly/experimental/logging/LogStreamProcessor.cpp [new file with mode: 0644]
folly/experimental/logging/LogStreamProcessor.h [new file with mode: 0644]
folly/experimental/logging/Logger.cpp
folly/experimental/logging/Logger.h
folly/experimental/logging/Makefile.am
folly/experimental/logging/test/LogStreamTest.cpp [new file with mode: 0644]
folly/experimental/logging/test/LoggerTest.cpp

index 9bb0f26fd95be82884591469f71e22c11354bebe..deb87fd41495849daf76dd25ad5ca4847f6f3337 100755 (executable)
@@ -324,6 +324,7 @@ if (BUILD_TESTS)
           LogLevelTest.cpp
           LogMessageTest.cpp
           LogNameTest.cpp
+          LogStreamTest.cpp
 
     DIRECTORY fibers/test/
       TEST fibers_test SOURCES FibersTest.cpp
index ca6b94098ad6de8ed7ce24e0191da3b4bcca14b1..9b177ccbd80ba8701e2c9a9cce57af14adf572ad 100644 (file)
@@ -126,6 +126,8 @@ nobase_follyinclude_HEADERS = \
        experimental/logging/LogLevel.h \
        experimental/logging/LogMessage.h \
        experimental/logging/LogName.h \
+       experimental/logging/LogStream.h \
+       experimental/logging/LogStreamProcessor.h \
        experimental/logging/Logger.h \
        experimental/logging/LoggerDB.h \
        experimental/NestedCommandLineApp.h \
index f6fcc1098f62dcb00e0ab4177fe7ab0b31be6b1e..f1b2856ccce56bbb7dec09e3b8a81bf15d5a9e5e 100644 (file)
@@ -42,7 +42,7 @@ LogCategory::LogCategory(StringPiece name, LogCategory* parent)
   parent_->firstChild_ = this;
 }
 
-void LogCategory::processMessage(const LogMessage& message) {
+void LogCategory::processMessage(const LogMessage& message) const {
   // Make a copy of any attached LogHandlers, so we can release the handlers_
   // lock before holding them.
   //
index ea6aca22e9d2898f82da74ce03aedc5ec179c845..a94471339f626da8320a24e7d71be60ad0c8d2cd 100644 (file)
@@ -98,6 +98,23 @@ class LogCategory {
     return effectiveLevel_.load(std::memory_order_relaxed);
   }
 
+  /**
+   * 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 effectiveLevel_.load(std::memory_order_relaxed) <= level;
+  }
+
   /**
    * Set the log level for this LogCategory.
    *
@@ -123,7 +140,7 @@ class LogCategory {
    * LogHandlers attached to this LogCategory, without any additional log level
    * checks (apart from the ones done in the LogHandlers).
    */
-  void processMessage(const LogMessage& message);
+  void processMessage(const LogMessage& message) const;
 
   /**
    * Get the LoggerDB that this LogCategory belongs to.
diff --git a/folly/experimental/logging/LogStream.cpp b/folly/experimental/logging/LogStream.cpp
new file mode 100644 (file)
index 0000000..947d76d
--- /dev/null
@@ -0,0 +1,54 @@
+/*
+ * 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/LogStream.h>
+
+namespace folly {
+
+LogStreamBuffer::int_type LogStreamBuffer::overflow(int_type ch) {
+  auto currentSize = str_.size();
+  size_t newSize;
+  if (currentSize == 0) {
+    newSize = kInitialCapacity;
+  } else {
+    // Increase by 1.25 each time
+    newSize = currentSize + (currentSize >> 2);
+  }
+
+  try {
+    str_.resize(newSize);
+
+    if (ch == EOF) {
+      setp((&str_.front()) + currentSize, (&str_.front()) + newSize);
+      return 'x';
+    } else {
+      str_[currentSize] = static_cast<char>(ch);
+      setp((&str_.front()) + currentSize + 1, (&str_.front()) + newSize);
+      return ch;
+    }
+  } catch (const std::exception& ex) {
+    // Return EOF to indicate that the operation failed.
+    // In general the only exception we really expect to see here is
+    // std::bad_alloc() from the str_.resize() call.
+    return EOF;
+  }
+}
+
+LogStream::LogStream() {
+  rdbuf(&buffer_);
+}
+
+LogStream::~LogStream() {}
+}
diff --git a/folly/experimental/logging/LogStream.h b/folly/experimental/logging/LogStream.h
new file mode 100644 (file)
index 0000000..82987f1
--- /dev/null
@@ -0,0 +1,79 @@
+/*
+ * 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 <ostream>
+
+#include <folly/experimental/logging/LogCategory.h>
+#include <folly/experimental/logging/LogMessage.h>
+
+namespace folly {
+
+/**
+ * A std::streambuf implementation for use by LogStream
+ */
+class LogStreamBuffer : public std::streambuf {
+ public:
+  LogStreamBuffer() {
+    // We intentionally do not reserve any string buffer space initially,
+    // since this will not be needed for XLOG() and XLOGF() statements
+    // that do not use the streaming API.  (e.g., XLOG(INFO, "test ", 1234) )
+  }
+
+  bool empty() const {
+    return str_.empty();
+  }
+
+  std::string extractString() {
+    str_.resize(pptr() - (&str_.front()));
+    return std::move(str_);
+  }
+
+  int_type overflow(int_type ch) override;
+
+ private:
+  enum : size_t { kInitialCapacity = 256 };
+  std::string str_;
+};
+
+/**
+ * A std::ostream implementation for use by the logging macros.
+ *
+ * All-in-all this is pretty similar to std::stringstream, but lets us
+ * destructively extract an rvalue-reference to the underlying string.
+ */
+class LogStream : public std::ostream {
+ public:
+  // Explicitly declare the default constructor and destructor, but only
+  // define them in the .cpp file.  This prevents them from being inlined at
+  // each FB_LOG() or XLOG() statement.  Inlining them just causes extra code
+  // bloat, with minimal benefit--for debug log statements these never even get
+  // called in the common case where the log statement is disabled.
+  LogStream();
+  ~LogStream();
+
+  bool empty() const {
+    return buffer_.empty();
+  }
+
+  std::string extractString() {
+    return buffer_.extractString();
+  }
+
+ private:
+  LogStreamBuffer buffer_;
+};
+}
diff --git a/folly/experimental/logging/LogStreamProcessor.cpp b/folly/experimental/logging/LogStreamProcessor.cpp
new file mode 100644 (file)
index 0000000..e70df78
--- /dev/null
@@ -0,0 +1,63 @@
+/*
+ * 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/LogStreamProcessor.h>
+
+#include <cassert>
+
+#include <folly/experimental/logging/LogStream.h>
+
+namespace folly {
+void LogStreamProcessor::operator&(std::ostream& stream) noexcept {
+  // Note that processMessage() is not noexcept and theoretically may throw.
+  // However, the only exception that should be possible is std::bad_alloc if
+  // we fail to allocate memory.  We intentionally let our noexcept specifier
+  // crash in that case, since the program likely won't be able to continue
+  // anyway.
+  //
+  // Any other error here is unexpected and we also want to fail hard
+  // in that situation too.
+  auto& logStream = static_cast<LogStream&>(stream);
+  category_->processMessage(LogMessage{category_,
+                                       level_,
+                                       filename_,
+                                       lineNumber_,
+                                       extractMessageString(logStream)});
+}
+
+void LogStreamProcessor::operator&(LogStream&& stream) noexcept {
+  // This version of operator&() is generally only invoked when
+  // no streaming arguments were supplied to the logging macro.
+  // Therefore we don't bother calling extractMessageString(stream),
+  // and just directly use message_.
+  assert(stream.empty());
+
+  category_->processMessage(LogMessage{
+      category_, level_, filename_, lineNumber_, std::move(message_)});
+}
+
+std::string LogStreamProcessor::extractMessageString(
+    LogStream& stream) noexcept {
+  if (stream.empty()) {
+    return std::move(message_);
+  }
+
+  if (message_.empty()) {
+    return stream.extractString();
+  }
+  message_.append(stream.extractString());
+  return std::move(message_);
+}
+}
diff --git a/folly/experimental/logging/LogStreamProcessor.h b/folly/experimental/logging/LogStreamProcessor.h
new file mode 100644 (file)
index 0000000..b68de95
--- /dev/null
@@ -0,0 +1,188 @@
+/*
+ * 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/Conv.h>
+#include <folly/Format.h>
+#include <folly/experimental/logging/LogCategory.h>
+#include <folly/experimental/logging/LogMessage.h>
+
+namespace folly {
+
+class LogStream;
+
+/**
+ * LogStreamProcessor receives a LogStream and logs it.
+ *
+ * This class is primarily intended to be used through the FB_LOG*() macros.
+ * Its API is designed to support these macros, and is not designed for other
+ * use.
+ *
+ * The operator&() method is used to trigger the logging.
+ * This operator is used because it has lower precedence than <<, but higher
+ * precedence than the ? ternary operator, allowing it to bind with the correct
+ * precedence in the log macro implementations.
+ */
+class LogStreamProcessor {
+ public:
+  enum AppendType { APPEND };
+  enum FormatType { FORMAT };
+
+  /**
+   * LogStreamProcessor constructor for use with a LOG() macro with no extra
+   * arguments.
+   *
+   * Note that the filename argument is not copied.  The caller should ensure
+   * that it points to storage that will remain valid for the lifetime of the
+   * LogStreamProcessor.  (This is always the case for the __FILE__
+   * preprocessor macro.)
+   */
+  LogStreamProcessor(
+      const LogCategory* category,
+      LogLevel level,
+      folly::StringPiece filename,
+      unsigned int lineNumber,
+      AppendType) noexcept
+      : category_{category},
+        level_{level},
+        filename_{filename},
+        lineNumber_{lineNumber} {}
+
+  /**
+   * LogStreamProcessor constructor for use with a LOG() macro with arguments
+   * to be concatenated with folly::to<std::string>()
+   *
+   * Note that the filename argument is not copied.  The caller should ensure
+   * that it points to storage that will remain valid for the lifetime of the
+   * LogStreamProcessor.  (This is always the case for the __FILE__
+   * preprocessor macro.)
+   */
+  template <typename... Args>
+  LogStreamProcessor(
+      const LogCategory* category,
+      LogLevel level,
+      const char* filename,
+      unsigned int lineNumber,
+      AppendType,
+      Args&&... args) noexcept
+      : category_{category},
+        level_{level},
+        filename_{filename},
+        lineNumber_{lineNumber},
+        message_{createLogString(std::forward<Args>(args)...)} {}
+
+  /**
+   * LogStreamProcessor constructor for use with a LOG() macro with arguments
+   * to be concatenated with folly::to<std::string>()
+   *
+   * Note that the filename argument is not copied.  The caller should ensure
+   * that it points to storage that will remain valid for the lifetime of the
+   * LogStreamProcessor.  (This is always the case for the __FILE__
+   * preprocessor macro.)
+   */
+  template <typename... Args>
+  LogStreamProcessor(
+      const LogCategory* category,
+      LogLevel level,
+      const char* filename,
+      unsigned int lineNumber,
+      FormatType,
+      folly::StringPiece fmt,
+      Args&&... args) noexcept
+      : category_{category},
+        level_{level},
+        filename_{filename},
+        lineNumber_{lineNumber},
+        message_{formatLogString(fmt, std::forward<Args>(args)...)} {}
+
+  /**
+   * This version of operator&() is typically used when the user specifies
+   * log arguments using the << stream operator.  The operator<<() generally
+   * returns a std::ostream&
+   */
+  void operator&(std::ostream& stream) noexcept;
+
+  /**
+   * This version of operator&() is used when no extra arguments are specified
+   * with the << operator.  In this case the & operator is applied directly to
+   * the temporary LogStream object.
+   */
+  void operator&(LogStream&& stream) noexcept;
+
+ private:
+  std::string extractMessageString(LogStream& stream) noexcept;
+
+  /**
+   * Construct a log message string using folly::to<std::string>()
+   *
+   * This function attempts to avoid throwing exceptions.  If an error occurs
+   * during formatting, a message including the error details is returned
+   * instead.  This is done to help ensure that log statements do not generate
+   * exceptions, but instead just log an error string when something goes wrong.
+   */
+  template <typename... Args>
+  std::string createLogString(Args&&... args) noexcept {
+    try {
+      return folly::to<std::string>(std::forward<Args>(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.
+      return folly::to<std::string>(
+          "error constructing log message: ", ex.what());
+    }
+  }
+
+  /**
+   * Construct a log message string using folly::sformat()
+   *
+   * This function attempts to avoid throwing exceptions.  If an error occurs
+   * during formatting, a message including the error details is returned
+   * instead.  This is done to help ensure that log statements do not generate
+   * exceptions, but instead just log an error string when something goes wrong.
+   */
+  template <typename... Args>
+  std::string formatLogString(folly::StringPiece fmt, Args&&... args) noexcept {
+    try {
+      return folly::sformat(fmt, std::forward<Args>(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.
+      return folly::to<std::string>(
+          "error formatting log message: ",
+          ex.what(),
+          "; format string: \"",
+          fmt,
+          "\"");
+    }
+  }
+
+  const LogCategory* const category_;
+  LogLevel const level_;
+  folly::StringPiece filename_;
+  unsigned int lineNumber_;
+  std::string message_;
+};
+}
index 63ad5ae06c740f5284fa1cf9a22fe2cbbe3f82ab..eb8a96168ccbde1d66accf471c789f4a69cc0995 100644 (file)
@@ -31,22 +31,4 @@ 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});
-}
 }
index 4f743d1d051689a366e6a88f4df0bb68dd348f95..ab9bd24f0950c346704dad1923ba6bb1b1172d31 100644 (file)
 #include <folly/Format.h>
 #include <folly/experimental/logging/LogCategory.h>
 #include <folly/experimental/logging/LogLevel.h>
+#include <folly/experimental/logging/LogStream.h>
+#include <folly/experimental/logging/LogStreamProcessor.h>
+
+/**
+ * Helper macro for implementing FB_LOG() and FB_LOGF().
+ *
+ * This macro generally should not be used directly by end users.
+ */
+#define FB_LOG_IMPL(logger, level, type, ...)               \
+  (!(logger).getCategory()->logCheck(level))                \
+      ? (void)0                                             \
+      : ::folly::LogStreamProcessor{(logger).getCategory(), \
+                                    (level),                \
+                                    __FILE__,               \
+                                    __LINE__,               \
+                                    (type),                 \
+                                    ##__VA_ARGS__} &        \
+          ::folly::LogStream()
 
 /**
  * Log a message to the specified logger.
  *
  * This macro avoids evaluating the log arguments unless the log level check
  * succeeds.
+ *
+ * Beware that the logger argument is evaluated twice, so this argument should
+ * be an expression with no side-effects.
  */
-#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)
+#define FB_LOG(logger, level, ...)         \
+  FB_LOG_IMPL(                             \
+      logger,                              \
+      ::folly::LogLevel::level,            \
+      ::folly::LogStreamProcessor::APPEND, \
+      ##__VA_ARGS__)
 
 /**
  * Log a message to the specified logger, using a folly::format() string.
  *
  * This macro avoids evaluating the log arguments unless the log level check
  * succeeds.
+ *
+ * Beware that the logger argument is evaluated twice, so this argument should
+ * be an expression with no side-effects.
  */
-#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)
+#define FB_LOGF(logger, level, fmt, arg1, ...) \
+  FB_LOG_IMPL(                                 \
+      logger,                                  \
+      ::folly::LogLevel::level,                \
+      ::folly::LogStreamProcessor::FORMAT,     \
+      fmt,                                     \
+      arg1,                                    \
+      ##__VA_ARGS__)
 
 namespace folly {
 
@@ -91,114 +111,6 @@ class Logger {
    */
   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<std::string>()
-   */
-  template <typename... Args>
-  void log(
-      LogLevel level,
-      folly::StringPiece filename,
-      unsigned int lineNumber,
-      Args&&... args) const {
-    std::string msg;
-    try {
-      msg = folly::to<std::string>(std::forward<Args>(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<std::string>("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 <typename... Args>
-  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>(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<std::string>(
-          "error formatting log message: ",
-          ex.what(),
-          "; format string: ",
-          fmt);
-    }
-    log(level, filename, lineNumber, std::move(msg));
-  }
-
   /**
    * Get the LogCategory that this Logger refers to.
    */
index 3501af15c0668e7dd857d12621cfa29d2681e8d7..683017cf72d09b5f5e328d555b0fce544b4d0f08 100644 (file)
@@ -9,7 +9,9 @@ libfollylogging_la_SOURCES = \
        LogHandler.cpp \
        LogLevel.cpp \
        LogMessage.cpp \
-       LogName.cpp
+       LogName.cpp \
+       LogStream.cpp \
+       LogStreamProcessor.cpp
 
 libfollylogging_la_LIBADD = $(top_builddir)/libfolly.la
 libfollylogging_la_LDFLAGS = $(AM_LDFLAGS) -version-info $(LT_VERSION)
diff --git a/folly/experimental/logging/test/LogStreamTest.cpp b/folly/experimental/logging/test/LogStreamTest.cpp
new file mode 100644 (file)
index 0000000..29fea09
--- /dev/null
@@ -0,0 +1,38 @@
+/*
+ * 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/LogStream.h>
+#include <folly/portability/GTest.h>
+
+using namespace folly;
+
+TEST(LogStream, simple) {
+  LogStream ls;
+  ls << "test";
+  ls << " foobar";
+
+  EXPECT_EQ("test foobar", ls.extractString());
+}
+
+TEST(LogStream, largeMessage) {
+  std::string largeString(4096, 'a');
+
+  LogStream ls;
+  ls << "prefix ";
+  ls << largeString;
+  ls << " suffix";
+
+  EXPECT_EQ("prefix " + largeString + " suffix", ls.extractString());
+}
index e9b5d4b90af5b9a48756e85bde428fcf8365e8e1..64c52c2edb6e51e048e7a13676edb2788b0279f5 100644 (file)
@@ -34,6 +34,14 @@ class LoggerTest : public ::testing::Test {
     category->setLevel(LogLevel::DEBUG, true);
   }
 
+  static StringPiece pathBasename(StringPiece path) {
+    auto idx = path.rfind('/');
+    if (idx == StringPiece::npos) {
+      return path.str();
+    }
+    return path.subpiece(idx + 1);
+  }
+
   LoggerDB db_{LoggerDB::TESTING};
   Logger logger_{&db_, "test"};
   std::shared_ptr<TestLogHandler> handler_;
@@ -41,13 +49,14 @@ class LoggerTest : public ::testing::Test {
 
 TEST_F(LoggerTest, basic) {
   // Simple log message
-  logger_.log(LogLevel::WARN, "src/myproject/myfile.cpp", 1234, "hello world");
+  auto expectedLine = __LINE__ + 1;
+  FB_LOG(logger_, WARN, "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("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
+  EXPECT_EQ(expectedLine, 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());
@@ -57,13 +66,14 @@ TEST_F(LoggerTest, basic) {
 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 expectedLine = __LINE__ + 1;
+  FB_LOG(subLogger, ERROR, "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("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
+  EXPECT_EQ(expectedLine, 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());
@@ -71,20 +81,15 @@ TEST_F(LoggerTest, subCategory) {
 }
 
 TEST_F(LoggerTest, formatMessage) {
-  logger_.logf(
-      LogLevel::WARN,
-      "log.cpp",
-      9,
-      "num events: {:06d}, duration: {:6.3f}",
-      1234,
-      5.6789);
+  auto expectedLine = __LINE__ + 1;
+  FB_LOGF(logger_, WARN, "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("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
+  EXPECT_EQ(expectedLine, 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());
@@ -94,23 +99,17 @@ TEST_F(LoggerTest, formatMessage) {
 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!");
+  FB_LOGF(
+      logger_, WARN, "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}",
+      "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("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
   EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel());
   EXPECT_FALSE(messages[0].first.containsNewlines());
   EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory());
@@ -119,13 +118,14 @@ TEST_F(LoggerTest, follyFormatError) {
 
 TEST_F(LoggerTest, toString) {
   // Use the log API that calls folly::to<string>
-  logger_.log(LogLevel::DBG5, "log.cpp", 3, "status=", 5, " name=", "foobar");
+  auto expectedLine = __LINE__ + 1;
+  FB_LOG(logger_, DBG5, "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("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
+  EXPECT_EQ(expectedLine, 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());
@@ -148,7 +148,8 @@ TEST_F(LoggerTest, toStringError) {
   // 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 expectedLine = __LINE__ + 1;
+  FB_LOG(logger_, DBG1, "status=", obj, " name=", "foobar");
 
   auto& messages = handler_->getMessages();
   ASSERT_EQ(1, messages.size());
@@ -156,24 +157,64 @@ TEST_F(LoggerTest, toStringError) {
       "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("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
+  EXPECT_EQ(expectedLine, 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, streamingArgs) {
+  auto& messages = handler_->getMessages();
+
+  // Test with only streaming arguments
+  std::string foo = "bar";
+  FB_LOG(logger_, WARN) << "foo=" << foo << ", test=0x" << std::hex << 35;
+  ASSERT_EQ(1, messages.size());
+  EXPECT_EQ("foo=bar, test=0x23", messages[0].first.getMessage());
+  EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
+  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);
+  messages.clear();
+
+  // Test with both function-style and streaming arguments
+  FB_LOG(logger_, WARN, "foo=", foo) << " hello, "
+                                     << "world: " << 34;
+  ASSERT_EQ(1, messages.size());
+  EXPECT_EQ("foo=bar hello, world: 34", messages[0].first.getMessage());
+  EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
+  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);
+  messages.clear();
+
+  // Test with format-style and streaming arguments
+  FB_LOGF(logger_, WARN, "foo={}, x={}", foo, 34) << ", also " << 12;
+  ASSERT_EQ(1, messages.size());
+  EXPECT_EQ("foo=bar, x=34, also 12", messages[0].first.getMessage());
+  EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
+  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);
+  messages.clear();
+}
+
 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 expectedLine = __LINE__ + 1;
+  FB_LOG(logger_, WARN, "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("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
+  EXPECT_EQ(expectedLine, 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());
@@ -229,7 +270,7 @@ TEST_F(LoggerTest, logMacros) {
   EXPECT_EQ(
       "error formatting log message: "
       "invalid format argument {}: argument index out of range, max=1; "
-      "format string: whoops: {}, {}",
+      "format string: \"whoops: {}, {}\"",
       messages[0].first.getMessage());
   messages.clear();
 }