Add CaptureFD for log testing (and some glog patterns)

Summary:
Without a gadget like this, it's really hard to test logging output. With it, it's really easy. I found about 50 callsites to the various functions across several projects, so folly seems appropriate.

PS The patterns are functions for two reasons:
- Static variables are a pain.
- This leaves the option of adding an optional argument, so you can grep for a particular kind of error string.

Test Plan: unit test

Reviewed By: yfeldblum@fb.com

Subscribers: folly-diffs@, yfeldblum

FB internal diff: D1933439

Signature: t1:1933439:1427345479:5b3d1c6566a026fdbccb16b382211688e327ea1a

diff --git a/folly/experimental/TestUtil.cpp b/folly/experimental/TestUtil.cpp
index ebeb7aec854df6eea4e21d49a3d1b3ec2ff01e85..26e26b0ae81a6e7e352dc095d4235391cf6ae2fd 100644 (file)
--- a/folly/experimental/TestUtil.cpp
+++ b/folly/experimental/TestUtil.cpp
@@ -19,10 +19,13 @@
 #include <sys/types.h>
 #include <sys/stat.h>
 #include <fcntl.h>
+#include <unistd.h>
 
 #include <boost/regex.hpp>
 #include <folly/Conv.h>
 #include <folly/Exception.h>
+#include <folly/File.h>
+#include <folly/FileUtil.h>
 
 namespace folly {
 namespace test {
@@ -134,5 +137,47 @@ bool hasNoPCREPatternMatch(StringPiece pattern, StringPiece target) {
 
 }  // namespace detail
 
+CaptureFD::CaptureFD(int fd) : fd_(fd), readOffset_(0) {
+  oldFDCopy_ = dup(fd_);
+  PCHECK(oldFDCopy_ != -1) << "Could not copy FD " << fd_;
+
+  int file_fd = open(file_.path().c_str(), O_WRONLY|O_CREAT, 0600);
+  PCHECK(dup2(file_fd, fd_) != -1) << "Could not replace FD " << fd_
+    << " with " << file_fd;
+  PCHECK(close(file_fd) != -1) << "Could not close " << file_fd;
+}
+
+void CaptureFD::release() {
+  if (oldFDCopy_ != fd_) {
+    PCHECK(dup2(oldFDCopy_, fd_) != -1) << "Could not restore old FD "
+      << oldFDCopy_ << " into " << fd_;
+    PCHECK(close(oldFDCopy_) != -1) << "Could not close " << oldFDCopy_;
+    oldFDCopy_ = fd_;  // Make this call idempotent
+  }
+}
+
+CaptureFD::~CaptureFD() {
+  release();
+}
+
+std::string CaptureFD::read() {
+  std::string contents;
+  std::string filename = file_.path().native();
+  PCHECK(folly::readFile(filename.c_str(), contents));
+  return contents;
+}
+
+std::string CaptureFD::readIncremental() {
+  std::string filename = file_.path().native();
+  // Yes, I know that I could just keep the file open instead. So sue me.
+  folly::File f(openNoInt(filename.c_str(), O_RDONLY), true);
+  auto size = lseek(f.fd(), 0, SEEK_END) - readOffset_;
+  std::unique_ptr<char[]> buf(new char[size]);
+  auto bytes_read = folly::preadFull(f.fd(), buf.get(), size, readOffset_);
+  PCHECK(size == bytes_read);
+  readOffset_ += size;
+  return std::string(buf.get(), size);
+}
+
 }  // namespace test
 }  // namespace folly

diff --git a/folly/experimental/TestUtil.h b/folly/experimental/TestUtil.h
index a949162c5aec9637685d8a46839832d13a64d3cb..dbf847686004bfb6f438e46a1bc02e91c8b94012 100644 (file)
--- a/folly/experimental/TestUtil.h
+++ b/folly/experimental/TestUtil.h
@@ -139,6 +139,58 @@ namespace detail {
   bool hasNoPCREPatternMatch(StringPiece pattern, StringPiece target);
 }  // namespace detail
 
+/**
+ * Use these patterns together with CaptureFD and EXPECT_PCRE_MATCH() to
+ * test for the presence (or absence) of log lines at a particular level:
+ *
+ *   CaptureFD stderr(2);
+ *   LOG(INFO) << "All is well";
+ *   EXPECT_NO_PCRE_MATCH(glogErrOrWarnPattern(), stderr.readIncremental());
+ *   LOG(ERROR) << "Uh-oh";
+ *   EXPECT_PCRE_MATCH(glogErrorPattern(), stderr.readIncremental());
+ */
+inline std::string glogErrorPattern() { return ".*(^|\n)E[0-9].*"; }
+inline std::string glogWarningPattern() { return ".*(^|\n)W[0-9].*"; }
+// Error OR warning
+inline std::string glogErrOrWarnPattern() { return ".*(^|\n)[EW][0-9].*"; }
+
+/**
+ * Temporarily capture a file descriptor by redirecting it into a file.
+ * You can consume its output either all-at-once or incrementally.
+ * Great for testing logging (see also glog*Pattern()).
+ */
+class CaptureFD {
+public:
+  explicit CaptureFD(int fd);
+  ~CaptureFD();
+
+  /**
+   * Restore the captured FD to its original state. It can be useful to do
+   * this before the destructor so that you can read() the captured data and
+   * log about it to the formerly captured stderr or stdout.
+   */
+  void release();
+
+  /**
+   * Reads the whole file into a string, but does not remove the redirect.
+   */
+  std::string read();
+
+  /**
+   * Read any bytes that were appended to the file since the last
+   * readIncremental.  Great for testing line-by-line output.
+   */
+  std::string readIncremental();
+
+private:
+  TemporaryFile file_;
+
+  int fd_;
+  int oldFDCopy_;  // equal to fd_ after restore()
+
+  off_t readOffset_;  // for incremental reading
+};
+
 }  // namespace test
 }  // namespace folly
 

diff --git a/folly/experimental/test/TestUtilTest.cpp b/folly/experimental/test/TestUtilTest.cpp
index c479e76feb2aac5d790fc7238edb691f50bd32f7..d434c9b735326a1ff01739cc63f4376aac331bd0 100644 (file)
--- a/folly/experimental/test/TestUtilTest.cpp
+++ b/folly/experimental/test/TestUtilTest.cpp
@@ -115,6 +115,26 @@ TEST(PCREPatternMatch, Simple) {
   EXPECT_NO_PCRE_MATCH(".*ac.*", "gabca");
 }
 
+TEST(CaptureFD, GlogPatterns) {
+  CaptureFD stderr(2);
+  LOG(INFO) << "All is well";
+  EXPECT_NO_PCRE_MATCH(glogErrOrWarnPattern(), stderr.readIncremental());
+  {
+    LOG(ERROR) << "Uh-oh";
+    auto s = stderr.readIncremental();
+    EXPECT_PCRE_MATCH(glogErrorPattern(), s);
+    EXPECT_NO_PCRE_MATCH(glogWarningPattern(), s);
+    EXPECT_PCRE_MATCH(glogErrOrWarnPattern(), s);
+  }
+  {
+    LOG(WARNING) << "Oops";
+    auto s = stderr.readIncremental();
+    EXPECT_NO_PCRE_MATCH(glogErrorPattern(), s);
+    EXPECT_PCRE_MATCH(glogWarningPattern(), s);
+    EXPECT_PCRE_MATCH(glogErrOrWarnPattern(), s);
+  }
+}
+
 int main(int argc, char *argv[]) {
   testing::InitGoogleTest(&argc, argv);
   gflags::ParseCommandLineFlags(&argc, &argv, true);