logging: add ImmediateFileWriter

Summary:
Add an ImmediateFileWriter class that implements the LogWriter interface by
immediately writing data it receives to a file descriptor.

This LogWriter implementation can be used by users that want to ensure log
messages are immediately flushed to a file as soon as they are written, at the
expense of possibly having logging I/O block their normal process threads.

Reviewed By: wez

Differential Revision: D5083105

fbshipit-source-id: 15cd071834e1784fe50e1d6d6ce403b9bc907047

CMakeLists.txt

@@ -320,6 +320,7 @@ if (BUILD_TESTS)
           XlogHeader1.h
           XlogHeader2.h
         SOURCES
+          ImmediateFileWriterTest.cpp
           LogCategoryTest.cpp
           LoggerDBTest.cpp
           LoggerTest.cpp

folly/Makefile.am

@@ -121,6 +121,7 @@ nobase_follyinclude_HEADERS = \
 	experimental/JemallocNodumpAllocator.h \
 	experimental/JSONSchema.h \
 	experimental/LockFreeRingBuffer.h \
+	experimental/logging/ImmediateFileWriter.h \
 	experimental/logging/LogCategory.h \
 	experimental/logging/LogFormatter.h \
 	experimental/logging/Logger.h \

folly/experimental/logging/ImmediateFileWriter.cpp

+/*
+ * 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/ImmediateFileWriter.h>
+
+#include <folly/FileUtil.h>
+#include <folly/String.h>
+#include <folly/experimental/logging/LoggerDB.h>
+
+using folly::StringPiece;
+
+namespace folly {
+
+ImmediateFileWriter::ImmediateFileWriter(StringPiece path)
+    : file_{path.str(), O_WRONLY | O_APPEND | O_CREAT} {}
+
+ImmediateFileWriter::ImmediateFileWriter(folly::File&& file)
+    : file_{std::move(file)} {}
+
+void ImmediateFileWriter::writeMessage(StringPiece buffer) {
+  // Write the data.
+  // We are doing direct file descriptor writes here, so there is no buffering
+  // of log message data.  Each message is immediately written to the output.
+  auto ret = folly::writeFull(file_.fd(), buffer.data(), buffer.size());
+  if (ret < 0) {
+    int errnum = errno;
+    LoggerDB::internalWarning(
+        __FILE__,
+        __LINE__,
+        "error writing to log file ",
+        file_.fd(),
+        ": ",
+        errnoStr(errnum));
+  }
+}
+}

folly/experimental/logging/ImmediateFileWriter.h

+/*
+ * 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/File.h>
+#include <folly/Range.h>
+#include <folly/experimental/logging/LogWriter.h>
+
+namespace folly {
+
+/**
+ * A LogWriter implementation that immediately writes to a file descriptor when
+ * it is invoked.
+ *
+ * The downside of this class is that logging I/O occurs directly in your
+ * normal program threads, so that logging I/O may block or slow down normal
+ * processing.
+ *
+ * However, one benefit of this class is that log messages are written out
+ * immediately, so if your program crashes, all log messages generated before
+ * the crash will have already been written, and no messages will be lost.
+ */
+class ImmediateFileWriter : public LogWriter {
+ public:
+  /**
+   * Construct an ImmediateFileWriter that appends to the file at the specified
+   * path.
+   */
+  explicit ImmediateFileWriter(folly::StringPiece path);
+
+  /**
+   * Construct an ImmediateFileWriter that writes to the specified File object.
+   */
+  explicit ImmediateFileWriter(folly::File&& file);
+
+  void writeMessage(folly::StringPiece buffer) override;
+
+ private:
+  ImmediateFileWriter(ImmediateFileWriter const&) = delete;
+  ImmediateFileWriter& operator=(ImmediateFileWriter const&) = delete;
+
+  folly::File file_;
+};
+}

folly/experimental/logging/Makefile.am

@@ -3,6 +3,7 @@ SUBDIRS = .
 lib_LTLIBRARIES = libfollylogging.la
 
 libfollylogging_la_SOURCES = \
+	ImmediateFileWriter.cpp \
 	LogCategory.cpp \
 	Logger.cpp \
 	LoggerDB.cpp \

folly/experimental/logging/test/ImmediateFileWriterTest.cpp

+/*
+ * 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.
+ */
+#ifndef _WIN32
+#include <unistd.h>
+#endif
+
+#include <folly/Conv.h>
+#include <folly/Exception.h>
+#include <folly/FileUtil.h>
+#include <folly/experimental/TestUtil.h>
+#include <folly/experimental/logging/ImmediateFileWriter.h>
+#include <folly/experimental/logging/LoggerDB.h>
+#include <folly/portability/GMock.h>
+#include <folly/portability/GTest.h>
+
+using namespace folly;
+using folly::test::TemporaryFile;
+
+TEST(ImmediateFileWriter, readBatch) {
+  TemporaryFile tmpFile{"logging_test"};
+  ImmediateFileWriter writer{folly::File{tmpFile.fd(), false}};
+
+  // Write several messages
+  for (int n = 0; n < 10; ++n) {
+    writer.writeMessage(folly::to<std::string>("message ", n, "\n"));
+  }
+
+  // Read the log file and confirm it contains all of the expected messages
+  std::string data;
+  auto ret = folly::readFile(tmpFile.path().native().c_str(), data);
+  ASSERT_TRUE(ret);
+
+  std::string expected =
+      "message 0\n"
+      "message 1\n"
+      "message 2\n"
+      "message 3\n"
+      "message 4\n"
+      "message 5\n"
+      "message 6\n"
+      "message 7\n"
+      "message 8\n"
+      "message 9\n";
+  EXPECT_EQ(expected, data);
+}
+
+TEST(ImmediateFileWriter, immediateRead) {
+  TemporaryFile tmpFile{"logging_test"};
+  ImmediateFileWriter writer{tmpFile.path().native()};
+
+  // Write several messages, and read each one back immediately
+  // after we write it.
+  folly::File readf{tmpFile.path().native()};
+  for (int n = 0; n < 10; ++n) {
+    writer.writeMessage(folly::to<std::string>("message ", n, "\n"));
+
+    std::array<char, 1024> buf;
+    auto sizeRead = folly::readFull(readf.fd(), buf.data(), buf.size());
+    ASSERT_GT(sizeRead, 0);
+    EXPECT_EQ(
+        folly::to<std::string>("message ", n, "\n"),
+        StringPiece(buf.data(), sizeRead));
+  }
+}
+
+#ifndef _WIN32
+namespace {
+static std::vector<std::string>* internalWarnings;
+
+void handleLoggingError(
+    StringPiece /* file */,
+    int /* lineNumber */,
+    std::string&& msg) {
+  internalWarnings->emplace_back(std::move(msg));
+}
+}
+
+TEST(ImmediateFileWriter, ioError) {
+  std::array<int, 2> fds;
+  auto rc = pipe(fds.data());
+  folly::checkUnixError(rc, "failed to create pipe");
+  signal(SIGPIPE, SIG_IGN);
+
+  // Set the LoggerDB internal warning handler so we can record the messages
+  std::vector<std::string> logErrors;
+  internalWarnings = &logErrors;
+  LoggerDB::setInternalWarningHandler(handleLoggingError);
+
+  // Create an ImmediateFileWriter that refers to a pipe whose read end is
+  // closed, then log a bunch of messages to it.
+  ::close(fds[0]);
+
+  size_t numMessages = 100;
+  {
+    ImmediateFileWriter writer{folly::File{fds[1], true}};
+    for (size_t n = 0; n < numMessages; ++n) {
+      writer.writeMessage(folly::to<std::string>("message ", n, "\n"));
+      sched_yield();
+    }
+  }
+
+  LoggerDB::setInternalWarningHandler(nullptr);
+
+  // ImmediateFileWriter should have generated one warning
+  // for each attempt to log a message.
+  //
+  // (The default internalWarning() handler would have rate limited these
+  // messages, but our test handler does not perform rate limiting.)
+  for (const auto& msg : logErrors) {
+    EXPECT_THAT(msg, testing::HasSubstr("error writing to log file"));
+    EXPECT_THAT(msg, testing::HasSubstr("Broken pipe"));
+  }
+  EXPECT_EQ(numMessages, logErrors.size());
+}
+#endif