cpp-logger/test/pattern_layout_test.cxx

//
//  pattern_layout_test.cxx
//  logger_test
//
//  Created by Sam Jaffe on 4/13/19.
//

#include <thread>

#include <gmock/gmock.h>

#include "resource_factory/prototype_factory.hpp"

#include "logger/detail/data_accessors.h"
#include "logger/detail/layout.h"
#include "logger/exception.h"
#include "logger/log_manager.h"
#include "logger/logpacket.h"
#include "logger/properties.h"

// Thursday, April 4, 2019 6:17:20 PM GMT
namespace {
  constexpr const int NOW = 1554401840;
}

std::shared_ptr<logging::layout> GetPatternLayout(std::string const & fmt) {
  using namespace logging;
  using namespace logging::property;
  properties props{_obj({{"pattern", _v(fmt)}})};
  return layouts::instance().get("PatternLayout", props);
}

std::string DoFormat(std::string const & fmt, logging::logpacket const & pkt) {
  std::stringstream ss;
  GetPatternLayout(fmt)->format(ss, pkt);
  return ss.str();
}

using namespace logging;

logpacket getpkt(std::string const & msg, location_info info = {}) {
  return logpacket{{}, level::error, info, "UNIT_TEST", msg};
};

TEST(PatternLayoutTest, EmptyFormatterCanParse) {
  EXPECT_NO_THROW(GetPatternLayout(""));
}

TEST(PatternLayoutTest, ThrowsForEndOfStringAfterPct) {
  EXPECT_THROW(GetPatternLayout("%"), logging::format_parsing_exception);
}

TEST(PatternLayoutTest, RawStringFmtReturnsSelf) {
  using testing::Eq;
  EXPECT_THAT(DoFormat("TEST STRING", {}), Eq("TEST STRING"));
}

TEST(PatternLayoutTest, NCharReturnsNewLine) {
  using testing::Eq;
  EXPECT_THAT(DoFormat("%n", {}), Eq("\n"));
}

TEST(PatternLayoutTest, DoublePctIsLiteral) {
  using testing::Eq;
  EXPECT_THAT(DoFormat("%%", {}), Eq("%"));
}

TEST(PatternLayoutTest, CatchesRawContentBeforeFmt) {
  using testing::Eq;
  EXPECT_THAT(DoFormat("TEST%%", {}), Eq("TEST%"));
}

TEST(PatternLayoutTest, CatchesRawContentAfterFmt) {
  using testing::Eq;
  EXPECT_THAT(DoFormat("%%TEST", {}), Eq("%TEST"));
}

TEST(PatternLayoutTest, HandlesDateFormatter) {
  using testing::Eq;
  EXPECT_THAT(DoFormat("%d", {{NOW, 0}}), Eq("2019-04-04 18:17:20,000"));
}

TEST(PatternLayoutTest, FormatsMilliseconds) {
  using testing::Eq;
  EXPECT_THAT(DoFormat("%d", {{NOW, 123000}}), Eq("2019-04-04 18:17:20,123"));
}

TEST(PatternLayoutTest, ThrowsIfCustomFmtUnterminated) {
  using testing::Eq;
  EXPECT_THROW(GetPatternLayout("%d{%"), logging::format_parsing_exception);
}

TEST(PatternLayoutTest, SupportsCustomFormatWithBrace) {
  using testing::Eq;
  EXPECT_THAT(DoFormat("%d{%Y}", {{NOW, 0}}), Eq("2019"));
}

TEST(PatternLayoutTest, FormatsCustomMilliseconds) {
  using testing::Eq;
  EXPECT_THAT(DoFormat("%d{%_ms}", {{NOW, 123000}}), Eq("123"));
}

MATCHER(IsTimeZoneOffsetLike, "") {
  if (arg[0] != '+' && arg[0] != '-') {
    (*result_listener) << "A timezone should be +/- hhmm";
    return false;
  }
  int const hours = std::stoi(arg.substr(1, 2));
  int const minutes = std::stoi(arg.substr(3, 2));
  return hours <= 12 && minutes < 60;
}

TEST(PatternLayoutTest, FormatsTimeZone) {
  EXPECT_THAT(DoFormat("%d{%z}", {{NOW, 0}}), IsTimeZoneOffsetLike());
}

TEST(PatternLayoutTest, SupportsISO8601Format) {
  using testing::Eq;
  EXPECT_THAT(DoFormat("%d{ISO8601}", {{NOW, 0}}),
              Eq("2019-04-04T18:17:20.000Z"));
}

TEST(PatternLayoutTest, SupportsSingleDayFormat) {
  using testing::Eq;
  EXPECT_THAT(DoFormat("%d{ABSOLUTE}", {{NOW, 0}}), Eq("18:17:20,000"));
}

TEST(PatternLayoutTest, SupportsHumanDateFormat) {
  using testing::Eq;
  EXPECT_THAT(DoFormat("%d{DATE}", {{NOW, 0}}), Eq("04 Apr 2019 18:17:20,000"));
}

TEST(PatternLayoutTest, LoggerIdIsCToken) {
  using testing::Eq;
  EXPECT_THAT(DoFormat("%c", getpkt("HELLO")), Eq("UNIT_TEST"));
}

TEST(PatternLayoutTest, LogLevelIsPToken) {
  using testing::Eq;
  EXPECT_THAT(DoFormat("%p", getpkt("HELLO")), Eq("ERROR"));
}

TEST(PatternLayoutTest, LogMessageIsMToken) {
  using testing::Eq;
  EXPECT_THAT(DoFormat("%m", getpkt("HELLO")), Eq("HELLO"));
}

MATCHER_P2(Near, value, error, "") { return std::abs(arg - value) < error; }

TEST(PatternLayoutTest, CanOutputTimeSinceCreation) {
  // Because we're passing in a timestamp of {0, 0} with getpkt(), %r should
  // produce -1 * time_since_epoch_in_milliseconds().
  // Since time(NULL) returns seconds, whereas %r returns milliseconds, we
  // allow a margin of error of +/- 1 second
  EXPECT_THAT(std::stoll(DoFormat("%r", getpkt(""))),
              Near(-time(NULL) * 1000, 1000));
}

TEST(PatternLayoutTest, CanOutputLineNumber) {
  EXPECT_THAT(std::stoi(DoFormat("%L", getpkt("", log_here))),
              testing::Eq(__LINE__ - 1));
}

TEST(PatternLayoutTest, CanOutputFileName) {
  EXPECT_THAT(DoFormat("%F", getpkt("", log_here)),
              testing::EndsWith("pattern_layout_test.cxx"));
}

TEST(PatternLayoutTest, CanOutputCallingMethod) {
  EXPECT_THAT(DoFormat("%M", getpkt("", log_here)), testing::Eq("TestBody"));
}

logging::logpacket packet() { return getpkt("", log_here); }
struct stub {
  std::map<int, int> rval;
  std::map<int, int> operator()(logging::logpacket & out) {
    out = getpkt("", log_here);
    return rval;
  }
  std::map<int, int> const & operator()(logging::logpacket & out) const {
    out = getpkt("", log_here);
    return rval;
  }
  logging::logpacket operator()() { return getpkt("", log_here); }
  static logging::logpacket packet() { return getpkt("", log_here); }
};
namespace ns {
  logging::logpacket packet() { return getpkt("", log_here); }
  struct stub {
    logging::logpacket operator()() { return getpkt("", log_here); }
    static logging::logpacket packet() { return getpkt("", log_here); }
  };
}

TEST(PatternLayoutTest, CanOutputClassName) {
  EXPECT_THAT(DoFormat("%C", getpkt("", log_here)),
              testing::Eq("PatternLayoutTest_CanOutputClassName_Test"));
}

TEST(PatternLayoutTest, GlobalNamespaceClassIsEmptyString) {
  EXPECT_THAT(DoFormat("%C", packet()), testing::Eq(""));
}

TEST(PatternLayoutTest, NamespacesActLikeClassName) {
  EXPECT_THAT(DoFormat("%C", ns::packet()), testing::Eq("ns"));
}

TEST(PatternLayoutTest, StaticMethodClassIsClass) {
  EXPECT_THAT(DoFormat("%C", stub::packet()), testing::Eq("stub"));
}

TEST(PatternLayoutTest, NCMethodReturningComplexTypeReturnsCorrectClass) {
  logging::logpacket pkt;
  stub st{};
  (void)st(pkt);
  EXPECT_THAT(DoFormat("%C", pkt), testing::Eq("stub"));
}

TEST(PatternLayoutTest, ConstMethodReturningComplexTypeReturnsCorrectClass) {
  logging::logpacket pkt;
  stub const st{};
  (void)st(pkt);
  EXPECT_THAT(DoFormat("%C", pkt), testing::Eq("stub"));
}

TEST(PatternLayoutTest, CanLimitClassToNTokens) {
  EXPECT_THAT(DoFormat("%C{1}", ns::stub{}()), testing::Eq("stub"));
  EXPECT_THAT(DoFormat("%C{2}", ns::stub{}()), testing::Eq("ns::stub"));
}

TEST(PatternLayoutTest, CanOutputLocation) {
  auto message = DoFormat("%l", getpkt("", log_here));
  std::string regex = "PatternLayoutTest_CanOutputLocation_Test::TestBody "
                      "..*pattern_layout_test.cxx, [1-9][0-9]*.";
  EXPECT_THAT(message, testing::MatchesRegex(regex));
}

TEST(PatternLayoutTest, CanOutputThreadInfoAsThreadId) {
  using testing::Eq;
  std::stringstream ss;
  ss << std::this_thread::get_id();
  EXPECT_THAT(DoFormat("%t", getpkt("")), Eq(ss.str()));
}

TEST(PatternLayoutTest, OutputsThreadNameIfAvailable) {
  using testing::Eq;
  ::logging::detail::thread_info_helper::set_name("main");
  EXPECT_THAT(DoFormat("%t", getpkt("")), Eq("main"));
  ::logging::detail::thread_info_helper::set_name("");
}

TEST(PatternLayoutTest, ThreadNameIsThreadLocalStorage) {
  using testing::Ne;
  ::logging::detail::thread_info_helper::set_name("main");
  std::thread tr([]() { EXPECT_THAT(DoFormat("%t", getpkt("")), Ne("main")); });
  tr.join();
  ::logging::detail::thread_info_helper::set_name("");
}

TEST(PatternLayoutTest, ThrowsOnUnknownToken) {
  using testing::Eq;
  EXPECT_THROW(GetPatternLayout("%q"), logging::unknown_format_specifier);
}

TEST(PatternLayoutTest, TokenCanBeTruncatedInFormat) {
  using testing::Eq;
  EXPECT_THAT(DoFormat("%.3m", getpkt("HELLO")), Eq("HEL"));
  EXPECT_THAT(DoFormat("%.5c", getpkt("HELLO")), Eq("UNIT_"));
  EXPECT_THAT(DoFormat("%.2t", getpkt("HELLO")), Eq("0x"));
}

TEST(PatternLayoutTest, TokenCanBeLeftPadded) {
  using testing::Eq;
  EXPECT_THAT(DoFormat("%6m", getpkt("HELLO")), Eq(" HELLO"));
}

TEST(PatternLayoutTest, TokenCanBeRightPadded) {
  using testing::Eq;
  EXPECT_THAT(DoFormat("%-6m", getpkt("HELLO")), Eq("HELLO "));
}

TEST(PatternLayoutTest, TokenCanBeSizeBound) {
  using testing::Eq;
  EXPECT_THAT(DoFormat("%6.8m", getpkt("HELLO")), Eq(" HELLO"));
  EXPECT_THAT(DoFormat("%6.8m", getpkt("HELLO FRIEND")), Eq("HELLO FR"));
}

#include "header_test_obj.h"
#include "logger/logger.h"

using namespace logging;
using namespace logging::property;
// clang-format off
properties const PATTERN_HEADER_SCHEMA{_obj({
  {"configuration", _obj({
    {"appenders", _obj({
      {"Stub", _obj({
        {"PatternLayout", _obj({
          {"pattern", _v("%m")},
          {"header", _v("HEADER-")},
          {"footer", _v("-FOOTER")}
        })}
      })}
    })},
    {"loggers", _obj({
      {"root", _obj({{"appenders", _obj({{"ref", _v("Stub")}})}})}
    })}
  })}
})};
// clang-format on

using PatternLayoutHeaderTest = HeaderFooterTest;

TEST_F(PatternLayoutHeaderTest, ProvidesHeader) {
  manager mgr;
  mgr.configure(PATTERN_HEADER_SCHEMA);
  using testing::Eq;
  EXPECT_THAT(appender->sstream.str(), Eq("HEADER-"));
  mgr.get().log(level::error, "HELLO");
  EXPECT_THAT(appender->sstream.str(), Eq("HEADER-HELLO"));
}

TEST_F(PatternLayoutHeaderTest, ProvidesFooter) {
  using testing::Eq;
  {
    manager mgr;
    mgr.configure(PATTERN_HEADER_SCHEMA);
    appender->sstream.str("");
    mgr.get().log(level::error, "HELLO");
  }
  EXPECT_THAT(appender->sstream.str(), Eq("HELLO-FOOTER"));
}