diff --git a/toolbelt/BUILD.bazel b/toolbelt/BUILD.bazel index 081ede1..a3b03f9 100644 --- a/toolbelt/BUILD.bazel +++ b/toolbelt/BUILD.bazel @@ -50,6 +50,18 @@ cc_test( ], ) +cc_test( + name = "logging_test", + size = "small", + srcs = ["logging_test.cc"], + deps = [ + ":toolbelt", + "@com_google_absl//absl/status", + "@com_google_absl//absl/status:statusor", + "@com_google_googletest//:gtest_main", + ], +) + cc_test( name = "table_test", size = "small", diff --git a/toolbelt/logging.h b/toolbelt/logging.h index ca8f177..e190eb9 100644 --- a/toolbelt/logging.h +++ b/toolbelt/logging.h @@ -78,6 +78,86 @@ class Logger { virtual void Log(LogLevel level, uint64_t timestamp, const std::string &source, std::string text); + inline void VerboseDebug(const std::string& str) { + Log(LogLevel::kVERBOSE_DEBUG, str); + } + inline void Debug(const std::string& str) { + Log(LogLevel::kDBG, str); + } + inline void Info(const std::string& str) { + Log(LogLevel::kINFO, str); + } + inline void Warn(const std::string& str) { + Log(LogLevel::kWARNING, str); + } + inline void Error(const std::string& str) { + Log(LogLevel::kERROR, str); + } + inline void Fatal(const std::string& str) { + Log(LogLevel::kFATAL, str); + } + inline void VerboseDebug(std::string&& str) { + Log(LogLevel::kVERBOSE_DEBUG, std::move(str)); + } + inline void Debug(std::string&& str) { + Log(LogLevel::kDBG, std::move(str)); + } + inline void Info(std::string&& str) { + Log(LogLevel::kINFO, std::move(str)); + } + inline void Warn(std::string&& str) { + Log(LogLevel::kWARNING, std::move(str)); + } + inline void Error(std::string&& str) { + Log(LogLevel::kERROR, std::move(str)); + } + inline void Fatal(std::string&& str) { + Log(LogLevel::kFATAL, std::move(str)); + } + + template + void VerboseDebug(const char* fmt, Ts&&... args) { + if (!_enabled || LogLevel::kVERBOSE_DEBUG < min_level_) { + return; + } + Log(LogLevel::kVERBOSE_DEBUG, fmt::format(fmt, std::forward(args)...)); + } + + template + void Debug(const char* fmt, Ts&&... args) { + if (!_enabled || LogLevel::kDBG < min_level_) { + return; + } + Log(LogLevel::DBG, fmt::format(fmt, std::forward(args)...)); + } + template + void Info(const char* fmt, Ts&&... args) { + if (!_enabled || LogLevel::kINFO < min_level_) { + return; + } + Log(LogLevel::kINFO, fmt::format(fmt, std::forward(args)...)); + } + template + void Warn(const char* fmt, Ts&&... args) { + if (!_enabled || LogLevel::kWARNING < min_level_) { + return; + } + Log(LogLevel::kWARNING, fmt::format(fmt, std::forward(args)...)); + } + template + void Error(const char* fmt, Ts&&... args) { + if (!_enabled || LogLevel::kERROR < min_level_) { + return; + } + Log(LogLevel::kERROR, fmt::format(fmt, std::forward(args)...)); + } + template + void Fatal(const char* fmt, Ts&&... args) { + if (!_enabled || LogLevel::kFATAL < min_level_) { + return; + } + Log(LogLevel::kFATAL, fmt::format(fmt, std::forward(args)...)); + } void SetTheme(LogTheme theme); // All logged messages with a level below the min level will be diff --git a/toolbelt/logging_test.cc b/toolbelt/logging_test.cc new file mode 100644 index 0000000..09b433d --- /dev/null +++ b/toolbelt/logging_test.cc @@ -0,0 +1,238 @@ +#include "logging.h" +#include + +#include + +#include +#include + +TEST(LoggingTest, Disabled) { + toolbelt::Logger logger("foobar", false); + logger.log(toolbelt::LogLevel::kINFO, "this should not be logged"); +} + +TEST(LoggingTest, Levels) { + toolbelt::Logger logger; + + struct Level { + std::string name; + toolbelt::LogLevel level; + } levels[] = { + {"verbose", toolbelt::LogLevel::kVERBOSE_DEBUG}, + {"debug", toolbelt::LogLevel::kDBG}, + {"info", toolbelt::LogLevel::kINFO}, + {"warning", toolbelt::LogLevel::kWARNING}, + {"error", toolbelt::LogLevel::kERROR}, + {"fatal", toolbelt::LogLevel::FATAL}, + }; + + for (auto& level : levels) { + logger.setLogLevel(level.name); + ASSERT_EQ(level.level, logger.getLogLevel()); + } + logger.setLogLevel(toolbelt::LogLevel::kINFO); + + logger.log(toolbelt::LogLevel::kVERBOSE_DEBUG, "verbose debug"); + logger.log(toolbelt::LogLevel::kDBG, "debug"); + logger.log(toolbelt::LogLevel::kINFO, "info"); + logger.log(toolbelt::LogLevel::kWARNING, "warning"); + logger.log(toolbelt::LogLevel::kERROR, "error"); + + EXPECT_DEATH(logger.log(toolbelt::LogLevel::FATAL, "fatal"), "fatal"); +} + +static void ReadAndCheck(FILE* fp, const char* s) { + char buf[256] = {}; + fgets(buf, sizeof(buf), fp); + ASSERT_NE(nullptr, strstr(buf, s)); +} + +TEST(LoggingTest, Output) { + toolbelt::Logger logger; + + int pipes[2]; + (void)pipe(pipes); + + FILE* logger_fp = fdopen(pipes[1], "w"); + FILE* read_fp = fdopen(pipes[0], "r"); + ASSERT_NE(nullptr, logger_fp); + ASSERT_NE(nullptr, read_fp); + + logger.setOutputStream(logger_fp); + + toolbelt::LogLevel levels[] = { + toolbelt::LogLevel::kVERBOSE_DEBUG, + toolbelt::LogLevel::kDBG, + toolbelt::LogLevel::kINFO, + toolbelt::LogLevel::kWARNING, + toolbelt::LogLevel::kERROR, + }; + + for (auto& min_level : levels) { + logger.setLogLevel(min_level); + for (auto& level : levels) { + logger.log(level, "foobar"); + fflush(logger_fp); + if (level >= min_level) { + ReadAndCheck(read_fp, "foobar"); + } + } + } + + fclose(logger_fp); + fclose(read_fp); +} + +TEST(LoggingTest, Plain) { + toolbelt::Logger defaultLogger("default", true, toolbelt::LogTheme::DEFAULT); + toolbelt::Logger lightLogger("light", true, toolbelt::LogTheme::LIGHT); + toolbelt::Logger darkLogger("dark", true, toolbelt::LogTheme::DARK); + + defaultLogger.setDisplayMode(toolbelt::LogDisplayMode::PLAIN); + lightLogger.setDisplayMode(toolbelt::LogDisplayMode::PLAIN); + darkLogger.setDisplayMode(toolbelt::LogDisplayMode::PLAIN); + + toolbelt::LogLevel levels[] = { + toolbelt::LogLevel::kVERBOSE_DEBUG, + toolbelt::LogLevel::kDBG, + toolbelt::LogLevel::kINFO, + toolbelt::LogLevel::kWARNING, + toolbelt::LogLevel::kERROR, + }; + + std::string message = "test "; + for (int i = 0; i < 100; i++) { + for (auto& level : levels) { + defaultLogger.setLogLevel(level); + lightLogger.setLogLevel(level); + darkLogger.setLogLevel(level); + + defaultLogger.log(level, message); + lightLogger.log(level, message); + darkLogger.log(level, message); + } + message += "test "; + } +} + +TEST(LoggingTest, Color) { + toolbelt::Logger defaultLogger("default", true, toolbelt::LogTheme::DEFAULT); + toolbelt::Logger lightLogger("light", true, toolbelt::LogTheme::LIGHT); + toolbelt::Logger darkLogger("dark", true, toolbelt::LogTheme::DARK); + + defaultLogger.setDisplayMode(toolbelt::LogDisplayMode::COLOR); + lightLogger.setDisplayMode(toolbelt::LogDisplayMode::COLOR); + darkLogger.setDisplayMode(toolbelt::LogDisplayMode::COLOR); + + + toolbelt::LogLevel levels[] = { + toolbelt::LogLevel::kVERBOSE_DEBUG, + toolbelt::LogLevel::kDBG, + toolbelt::LogLevel::kINFO, + toolbelt::LogLevel::kWARNING, + toolbelt::LogLevel::kERROR, + }; + + std::string message = "test "; + for (int i = 0; i < 100; i++) { + for (auto& level : levels) { + defaultLogger.setLogLevel(level); + lightLogger.setLogLevel(level); + darkLogger.setLogLevel(level); + + defaultLogger.log(level, message); + lightLogger.log(level, message); + darkLogger.log(level, message); + } + message += "test "; + } +} + +TEST(LoggingTest, Columnar) { + toolbelt::Logger defaultLogger("default", true, toolbelt::LogTheme::DEFAULT); + toolbelt::Logger lightLogger("light", true, toolbelt::LogTheme::LIGHT); + toolbelt::Logger darkLogger("dark", true, toolbelt::LogTheme::DARK); + + defaultLogger.setDisplayMode(toolbelt::LogDisplayMode::COLUMNAR, 120); + lightLogger.setDisplayMode(toolbelt::LogDisplayMode::COLUMNAR, 120); + darkLogger.setDisplayMode(toolbelt::LogDisplayMode::COLUMNAR, 120); + + toolbelt::LogLevel levels[] = { + toolbelt::LogLevel::kVERBOSE_DEBUG, + toolbelt::LogLevel::kDBG, + toolbelt::LogLevel::kINFO, + toolbelt::LogLevel::kWARNING, + toolbelt::LogLevel::kERROR, + }; + + std::string message = "test "; + for (int i = 0; i < 100; i++) { + for (auto& level : levels) { + defaultLogger.setLogLevel(level); + lightLogger.setLogLevel(level); + darkLogger.setLogLevel(level); + + defaultLogger.log(level, message); + lightLogger.log(level, message); + darkLogger.log(level, message); + } + message += "test "; + } +} + +TEST(LoggingTest, ColumnarSplit) { + toolbelt::Logger defaultLogger("default", true, toolbelt::LogTheme::DEFAULT); + defaultLogger.setDisplayMode(toolbelt::LogDisplayMode::COLUMNAR, 60); + defaultLogger.log( + toolbelt::LogLevel::kINFO, + "now is the time for all good men to come to the aid of the party\n"); + defaultLogger.log( + toolbelt::LogLevel::kINFO, "the quick brown fox\njumps over the\nlazy dog"); +} + + +TEST(LoggingTest, ColumnarLongSubsystem) { + toolbelt::Logger longLogger( + "this_is_a_very_long_subsystem_name_just_to_get_coverage_of_a_line", + true, + toolbelt::LogTheme::DEFAULT); + longLogger.setDisplayMode(toolbelt::LogDisplayMode::COLUMNAR, 60); + longLogger.log( + toolbelt::LogLevel::kINFO, + "now is the time for all good men to come to the aid of the party\n"); + longLogger.log( + toolbelt::LogLevel::kINFO, "the quick brown fox\njumps over the\nlazy dog"); +} + +TEST(LoggingTest, Tee) { + toolbelt::Logger logger("tee_test", true); + logger.setDisplayMode(toolbelt::LogDisplayMode::COLOR); + + const std::string teeFile = "/tmp/foo/bar/tee_test.log"; + auto status = logger.setTeeFile(teeFile); + ASSERT_TRUE(status.ok()) << status.toString(); + + logger.log(toolbelt::LogLevel::kINFO, "this is a test message"); + + std::ifstream teeStream(teeFile); + ASSERT_TRUE(teeStream.is_open()); + std::string line; + std::getline(teeStream, line); + ASSERT_NE(line.find("this is a test message"), std::string::npos); + teeStream.close(); + + std::string tee2 = "/tmp/bar/foo/tee_test2.log"; + // Use another tee file. This will close the previous one. + status = logger.setTeeFile(tee2); + ASSERT_TRUE(status.ok()) << status.toString(); + logger.log(toolbelt::LogLevel::kINFO, "this is another test message"); + std::ifstream teeStream2(tee2); + ASSERT_TRUE(teeStream2.is_open()); + std::getline(teeStream2, line); + ASSERT_NE(line.find("this is another test message"), std::string::npos); + teeStream2.close(); + + // Clean up + remove(teeFile.c_str()); + remove(tee2.c_str()); +}