Add minimal threadsafe logging class to SDK, including tests (#305)

sdk/include/host/Log.hpp

@@ -0,0 +1,158 @@
+//******************************************************************************
+// Copyright (c) 2020, The Regents of the University of California (Regents).
+// All Rights Reserved. See LICENSE for license details.
+//------------------------------------------------------------------------------
+#pragma once
+
+#include <fstream>
+#include <functional>
+#include <iostream>
+#include <mutex>
+#include <sstream>
+#include <string>
+#include <utility>
+
+namespace Keystone {
+
+class Logger {
+ public:
+  Logger() = default;
+  Logger(bool enable) : enabled_{enable} {}
+  Logger(const Logger&)            = delete;
+  Logger& operator=(const Logger&) = delete;
+  ~Logger();
+
+  /* Directs all logs to the file at PATH. Returns whether it was successful.
+
+    If APPEND is true, writes start at the end of the file. Otherwise, the file
+    is cleared and written to from the start.
+
+    Do NOT have multiple logs write to the same file as there will be
+    synchronization issues. */
+  inline bool DirectToFile(const std::string& path, bool append = false) {
+    const std::lock_guard<std::mutex> lock{mtx_};
+    return ResetOutputStream_(new std::ofstream{
+        path, append ? std::ios_base::app : std::ios_base::out});
+  }
+
+  /* Direct all logs to STDOUT. Returns whether it was successful. */
+  inline bool DirectToSTDOUT() {
+    const std::lock_guard<std::mutex> lock{mtx_};
+    return ResetOutputStream_(&std::cout);
+  }
+
+  /* Direct all logs to STDERR. Returns whether it was successful. */
+  inline bool DirectToSTDERR() {
+    const std::lock_guard<std::mutex> lock{mtx_};
+    return ResetOutputStream_(&std::cerr);
+  }
+
+  /* Output all logs to the specified destination (e.g., STDOUT or a file).
+     All provided logs except LogDebug are enabled when initialized. */
+  inline Logger& Enable() {
+    const std::lock_guard<std::mutex> lock{mtx_};
+    enabled_ = true;
+    return *this;
+  }
+
+  /* Prevent the outputting of all logs to the specified destination (e.g.,
+   STDOUT or a file). All provided logs except LogDebug are enabled when
+   initialized. */
+  inline Logger& Disable() {
+    const std::lock_guard<std::mutex> lock{mtx_};
+    enabled_ = false;
+    return *this;
+  }
+
+  /* Wrapper around the ostream << operator. */
+  template <typename T>
+  inline const Logger& operator<<(T&& to_write) const {
+    const std::lock_guard<std::mutex> lock{mtx_};
+    if (enabled_) {
+      *os_ << std::forward<T>(to_write);
+    }
+    return *this;
+  }
+
+ private:
+  mutable std::mutex mtx_{};
+  std::ostream* os_{&std::cout};
+  bool enabled_{true};
+
+  bool ResetOutputStream_(std::ostream* replacement);
+
+  inline void ForceWrite_() { os_->flush(); }
+};
+
+extern Logger LogDebug;
+extern Logger LogInfo;
+extern Logger LogWarn;
+extern Logger LogError;
+
+enum class FormatMethod { Pretty, JSON, Default };
+
+template <typename T>
+class Formattable {
+ public:
+  void Format(
+      std::ostream& os, FormatMethod method = FormatMethod::Default) const {
+    switch (method) {
+      case FormatMethod::JSON:
+      case FormatMethod::Default:
+        FormatAsJSON(os);
+        break;
+      case FormatMethod::Pretty:
+        FormatAsPretty(os);
+    }
+  }
+
+  virtual void FormatAsJSON(std::ostream& os) const   = 0;
+  virtual void FormatAsPretty(std::ostream& os) const = 0;
+};
+
+template <typename T, FormatMethod M>
+class DoFormat {
+ public:
+  explicit DoFormat(const T& to_format) : formattable_{std::cref(to_format)} {}
+
+  std::string ToString() const {
+    std::ostringstream oss{};
+    oss << *this;
+    return oss.str();
+  }
+
+  friend std::ostream& operator<<(std::ostream& os, const DoFormat<T, M>& f) {
+    f.formattable_.get().Format(os, M);
+    return os;
+  }
+
+ private:
+  std::reference_wrapper<const T> formattable_;
+};
+
+/* Convenience helpers. */
+template <typename T>
+DoFormat<T, FormatMethod::JSON>
+FormatAsJSON(const T& to_format) {
+  return DoFormat<T, FormatMethod::JSON>{to_format};
+}
+
+template <typename T>
+DoFormat<T, FormatMethod::Pretty>
+FormatAsPretty(const T& to_format) {
+  return DoFormat<T, FormatMethod::Pretty>{to_format};
+}
+
+template <typename T>
+DoFormat<T, FormatMethod::Default>
+FormatAsDefault(const T& to_format) {
+  return DoFormat<T, FormatMethod::Default>{to_format};
+}
+
+template <typename T>
+DoFormat<T, FormatMethod::Default>
+Format(const T& to_format) {
+  return DoFormat<T, FormatMethod::Default>{to_format};
+}
+
+}  // namespace Keystone

sdk/src/host/Log.cpp

@@ -0,0 +1,45 @@
+//******************************************************************************
+// Copyright (c) 2020, The Regents of the University of California (Regents).
+// All Rights Reserved. See LICENSE for license details.
+//------------------------------------------------------------------------------
+#include "Log.hpp"
+
+namespace Keystone {
+
+/* Close and free the ofstream if applicable. */
+static void
+DestroyIfFile(std::ostream* os) {
+  if (os != &std::cout && os != &std::cerr) {
+    dynamic_cast<std::ofstream*>(os)->close();
+    delete os;
+  }
+}
+
+Logger::~Logger() {
+  ForceWrite_();
+  DestroyIfFile(os_);
+}
+
+bool
+Logger::ResetOutputStream_(std::ostream* replacement) {
+  if (!replacement) {
+    return false;
+  }
+
+  if (replacement->fail()) {
+    DestroyIfFile(replacement);
+    return false;
+  }
+
+  ForceWrite_();
+  DestroyIfFile(os_);
+  os_ = replacement;
+  return true;
+}
+
+Logger LogDebug{false};
+Logger LogInfo{};
+Logger LogWarn{};
+Logger LogError{};
+
+}  // namespace Keystone

sdk/tests/keystone_test.cpp

@@ -2,10 +2,15 @@
 // Copyright (c) 2020, The Regents of the University of California (Regents).
 // All Rights Reserved. See LICENSE for license details.
 //------------------------------------------------------------------------------
+
 #include <getopt.h>
 #include <keystone.h>
+
 #include <cstdio>
 #include <iostream>
+#include <string>
+#include <thread>
+
 #include "gtest/gtest.h"
 
 #define EYRIE_RT "eyrie-rt"
@@ -87,6 +92,129 @@ TEST(Enclave_Run, RunTest) {
   EXPECT_EQ(enclave.run(), Error::Success);
 }
 
+TEST(LoggingTest, RedirectsWithoutError) {
+  /* Tests if we can direct to the standard streams or files without error. */
+  Keystone::Logger logger{};
+  EXPECT_TRUE(logger.DirectToSTDOUT());
+  EXPECT_TRUE(logger.DirectToSTDERR());
+  EXPECT_TRUE(logger.DirectToFile("a.txt"));
+  EXPECT_TRUE(logger.DirectToSTDOUT());  // back to a standard stream
+}
+
+TEST(LoggingTest, RedirectsToFile) {
+  /* Tests if logs are written to a file after directing to it. */
+  constexpr const char* file_name = "log.txt";
+  std::cout << "Started\n";
+
+  {
+    Keystone::Logger log{};
+    EXPECT_TRUE(log.DirectToFile(file_name));
+    log << "Hello, here's a number: " << 17;
+  }
+
+  std::ifstream fin{file_name};
+  std::string buf{};
+  std::getline(fin, buf);
+  EXPECT_EQ("Hello, here's a number: 17", buf);
+  fin.close();
+}
+
+TEST(LoggingTest, RedirectsAwayFromFile) {
+  /* Tests if we stop writing to a file after directing away from it. */
+  constexpr const char* file_name = "log.txt";
+
+  {
+    Keystone::Logger log{};
+
+    EXPECT_TRUE(log.DirectToFile(file_name));
+    log << "[file]";
+
+    EXPECT_TRUE(log.DirectToSTDOUT());
+    log << "[cout]";
+
+    EXPECT_TRUE(log.DirectToSTDERR());
+    log << "[cerr]";
+  }
+
+  std::ifstream fin{file_name};
+  std::string buf{};
+  std::getline(fin, buf);
+  EXPECT_EQ("[file]", buf);
+}
+
+TEST(LoggingTest, RespondsToDisableEnable) {
+  /* Tests if the log starts/stops writing in response to enable/disable. */
+  constexpr const char* file_name = "log.txt";
+
+  {
+    Keystone::Logger log{};
+    EXPECT_TRUE(log.DirectToFile(file_name));
+    log << "a";
+    log.Disable();
+    log << "b";
+    log.Enable();
+    log << "c";
+  }
+
+  std::ifstream fin{file_name};
+  std::string buf{};
+  std::getline(fin, buf);
+  EXPECT_EQ("ac", buf);
+}
+
+TEST(LoggingTest, AppendsFile) {
+  /* Tests if the log correctly appends the file if the append option
+     is selected. */
+  constexpr const char* file_name = "log.txt";
+
+  {
+    std::ofstream fout{file_name};
+    fout << "logs:";
+    fout.flush();
+  }
+
+  {
+    Keystone::Logger log{};
+    EXPECT_TRUE(log.DirectToFile(file_name, true));
+    log << "my log";
+  }
+
+  std::ifstream fin{file_name};
+  std::string buf{};
+  std::getline(fin, buf);
+  EXPECT_EQ("logs:my log", buf);
+}
+
+TEST(LoggingTest, ConcurrentWrites) {
+  /* Tests if we write to the same log from two threads without error. */
+
+  /* We pick a large number to increase the chance of overlap in
+     scheduling between the two threads. */
+  constexpr auto n_chars          = 1000000;
+  constexpr auto c                = 'x';
+  constexpr const char* file_name = "log.txt";
+  {
+    Keystone::Logger log{};
+    EXPECT_TRUE(log.DirectToFile(file_name));
+    auto log_half = [&]() {
+      for (auto half = n_chars / 2; half; --half) {
+        log << c;
+      }
+    };
+    std::thread t1{log_half};
+    std::thread t2{log_half};
+
+    t1.join();
+    t2.join();
+  }
+
+  std::ifstream fin{file_name};
+  EXPECT_TRUE(fin.is_open());
+  std::string buf{};
+  std::getline(fin, buf);
+  EXPECT_EQ(std::string(n_chars, c), buf);
+}
+
 int
 main(int argc, char** argv) {
   ::testing::InitGoogleTest(&argc, argv);