core/tests/logger.cpp

0001 // SPDX-License-Identifier: LGPL-3.0-or-later
0002 // Copyright (C) 2026 Wouter Deconinck
0003 //
0004 // Tests for the LogSvc, the LoggerMixin and the LoggedService base class
0005 //
0006 #include <algorithms/logger.h>
0007
0008 #include <catch2/catch_test_macros.hpp>
0009 #include <catch2/matchers/catch_matchers_string.hpp>
0010
0011 #include <ios>
0012 #include <ostream>
0013 #include <string>
0014 #include <string_view>
0015 #include <vector>
0016
0017 using namespace algorithms;
0018
0019 namespace {
0020
0021 struct Message {
0022   LogLevel level;
0023   std::string caller;
0024   std::string msg;
0025   bool operator==(const Message&) const = default;
0026 };
0027
0028 std::vector<Message>& messages() {
0029   static std::vector<Message> m;
0030   return m;
0031 }
0032
0033 // Replace the LogSvc action with one that records all messages
0034 void capture() {
0035   messages().clear();
0036   LogSvc::instance().init([](LogLevel l, std::string_view caller, std::string_view msg) {
0037     messages().push_back({l, std::string{caller}, std::string{msg}});
0038   });
0039 }
0040
0041 class TestLogger : public LoggerMixin {
0042 public:
0043   TestLogger() : LoggerMixin("TestLogger") {}
0044   explicit TestLogger(LogLevel threshold) : LoggerMixin("TestLogger", threshold) {}
0045
0046   using LoggerMixin::critical;
0047   using LoggerMixin::debug;
0048   using LoggerMixin::endmsg;
0049   using LoggerMixin::error;
0050   using LoggerMixin::info;
0051   using LoggerMixin::raise;
0052   using LoggerMixin::trace;
0053   using LoggerMixin::warning;
0054
0055   using LoggerMixin::aboveCriticalThreshold;
0056   using LoggerMixin::aboveDebugThreshold;
0057   using LoggerMixin::aboveErrorThreshold;
0058   using LoggerMixin::aboveInfoThreshold;
0059   using LoggerMixin::aboveTraceThreshold;
0060   using LoggerMixin::aboveWarningThreshold;
0061 };
0062
0063 class CustomError : public Error {
0064 public:
0065   CustomError(std::string_view msg) : Error{msg, "CustomError"} {}
0066 };
0067
0068 class TestLoggedSvc : public LoggedService<TestLoggedSvc> {
0069 public:
0070   void init() {}
0071   void hello() const { info() << "hello" << endmsg; }
0072
0073   ALGORITHMS_DEFINE_LOGGED_SERVICE(TestLoggedSvc)
0074 };
0075
0076 const std::vector<LogLevel> kAllLevels{LogLevel::kTrace,   LogLevel::kDebug, LogLevel::kInfo,
0077                                        LogLevel::kWarning, LogLevel::kError, LogLevel::kCritical};
0078
0079 } // namespace
0080
0081 // Must run before any test replaces the default action
0082 TEST_CASE("LogSvc has a default action that prints messages", "[logger]") {
0083   CHECK_NOTHROW(LogSvc::instance().report(LogLevel::kInfo, "caller", "default action message"));
0084 }
0085
0086 TEST_CASE("Log levels have names", "[logger]") {
0087   STATIC_REQUIRE(logLevelName(LogLevel::kTrace) == "TRACE");
0088
0089   // evaluated at run time as well, since the names are used at run time
0090   std::vector<std::string_view> names;
0091   for (const auto level : kAllLevels) {
0092     names.push_back(logLevelName(level));
0093   }
0094   CHECK(names == std::vector<std::string_view>{"TRACE", "DEBUG", "INFO", "WARNING", "ERROR",
0095                                                "CRITICAL"});
0096
0097   auto unknown = static_cast<LogLevel>(42);
0098   CHECK(logLevelName(unknown) == "UNKNOWN");
0099 }
0100
0101 TEST_CASE("LogSvc provides the default log level", "[logger]") {
0102   auto& svc = LogSvc::instance();
0103   CHECK(svc.defaultLevel() == LogLevel::kInfo);
0104   CHECK(TestLogger{}.level() == LogLevel::kInfo);
0105
0106   svc.defaultLevel(LogLevel::kDebug);
0107   CHECK(svc.defaultLevel() == LogLevel::kDebug);
0108   CHECK(TestLogger{}.level() == LogLevel::kDebug);
0109   CHECK(detail::LoggerStream{"caller", LogLevel::kInfo}.threshold() == LogLevel::kDebug);
0110
0111   svc.defaultLevel(LogLevel::kInfo);
0112   CHECK(TestLogger{}.level() == LogLevel::kInfo);
0113 }
0114
0115 TEST_CASE("LogSvc init without arguments keeps the current action", "[logger]") {
0116   capture();
0117   LogSvc::instance().init();
0118   LogSvc::instance().report(LogLevel::kWarning, "caller", "still captured");
0119   CHECK(messages() == std::vector<Message>{{LogLevel::kWarning, "caller", "still captured"}});
0120 }
0121
0122 TEST_CASE("LoggerMixin streams report messages at or above threshold", "[logger]") {
0123   capture();
0124   const TestLogger logger{LogLevel::kTrace};
0125
0126   logger.trace() << "t" << TestLogger::endmsg;
0127   logger.debug() << "d" << TestLogger::endmsg;
0128   logger.info() << "i" << TestLogger::endmsg;
0129   logger.warning() << "w" << TestLogger::endmsg;
0130   logger.error() << "e" << TestLogger::endmsg;
0131   logger.critical() << "c" << TestLogger::endmsg;
0132
0133   CHECK(messages() == std::vector<Message>{{LogLevel::kTrace, "TestLogger", "t"},
0134                                            {LogLevel::kDebug, "TestLogger", "d"},
0135                                            {LogLevel::kInfo, "TestLogger", "i"},
0136                                            {LogLevel::kWarning, "TestLogger", "w"},
0137                                            {LogLevel::kError, "TestLogger", "e"},
0138                                            {LogLevel::kCritical, "TestLogger", "c"}});
0139 }
0140
0141 TEST_CASE("LoggerMixin streams suppress messages below threshold", "[logger]") {
0142   capture();
0143   const TestLogger logger{LogLevel::kCritical};
0144
0145   logger.trace() << "t" << std::hex << 255 << std::endl;
0146   logger.debug() << "d" << TestLogger::endmsg;
0147   logger.info() << "i" << TestLogger::endmsg;
0148   logger.warning() << "w" << TestLogger::endmsg;
0149   logger.error() << "e" << TestLogger::endmsg;
0150   logger.critical() << "c" << TestLogger::endmsg;
0151
0152   CHECK(messages() == std::vector<Message>{{LogLevel::kCritical, "TestLogger", "c"}});
0153 }
0154
0155 TEST_CASE("LoggerMixin streams support stream manipulators", "[logger]") {
0156   capture();
0157   const TestLogger logger;
0158
0159   logger.info() << std::hex << 255 << std::endl;
0160   logger.info() << std::dec << 255 << TestLogger::endmsg;
0161
0162   CHECK(messages() == std::vector<Message>{{LogLevel::kInfo, "TestLogger", "ff\n"},
0163                                            {LogLevel::kInfo, "TestLogger", "255"}});
0164 }
0165
0166 TEST_CASE("LoggerMixin streams report unflushed messages at the end of the statement",
0167           "[logger]") {
0168   capture();
0169   const TestLogger logger;
0170
0171   logger.info() << "without endmsg " << 1;
0172   logger.info() << "with endmsg" << TestLogger::endmsg;
0173   logger.info() << TestLogger::endmsg;
0174   logger.debug() << "suppressed without endmsg";
0175
0176   CHECK(messages() == std::vector<Message>{{LogLevel::kInfo, "TestLogger", "without endmsg 1"},
0177                                            {LogLevel::kInfo, "TestLogger", "with endmsg"},
0178                                            {LogLevel::kInfo, "TestLogger", ""}});
0179 }
0180
0181 TEST_CASE("LoggerMixin reports plain messages at or above threshold", "[logger]") {
0182   capture();
0183   const TestLogger logger{LogLevel::kTrace};
0184
0185   logger.trace("t");
0186   logger.debug("d");
0187   logger.info("i");
0188   logger.warning("w");
0189   logger.error("e");
0190   logger.critical("c");
0191
0192   CHECK(messages() == std::vector<Message>{{LogLevel::kTrace, "TestLogger", "t"},
0193                                            {LogLevel::kDebug, "TestLogger", "d"},
0194                                            {LogLevel::kInfo, "TestLogger", "i"},
0195                                            {LogLevel::kWarning, "TestLogger", "w"},
0196                                            {LogLevel::kError, "TestLogger", "e"},
0197                                            {LogLevel::kCritical, "TestLogger", "c"}});
0198 }
0199
0200 TEST_CASE("LoggerMixin suppresses plain messages below threshold", "[logger]") {
0201   capture();
0202   const TestLogger logger{LogLevel::kCritical};
0203
0204   logger.trace("t");
0205   logger.debug("d");
0206   logger.info("i");
0207   logger.warning("w");
0208   logger.error("e");
0209   logger.critical("c");
0210
0211   CHECK(messages() == std::vector<Message>{{LogLevel::kCritical, "TestLogger", "c"}});
0212 }
0213
0214 TEST_CASE("LoggerMixin reports formatted messages at or above threshold", "[logger]") {
0215   capture();
0216   const TestLogger logger{LogLevel::kTrace};
0217
0218   logger.trace("t{}", 0);
0219   logger.debug("d{}", 1);
0220   logger.info("i{}", 2);
0221   logger.warning("w{}", 3);
0222   logger.error("e{}", 4);
0223   logger.critical("c{}", 5);
0224
0225   CHECK(messages() == std::vector<Message>{{LogLevel::kTrace, "TestLogger", "t0"},
0226                                            {LogLevel::kDebug, "TestLogger", "d1"},
0227                                            {LogLevel::kInfo, "TestLogger", "i2"},
0228                                            {LogLevel::kWarning, "TestLogger", "w3"},
0229                                            {LogLevel::kError, "TestLogger", "e4"},
0230                                            {LogLevel::kCritical, "TestLogger", "c5"}});
0231 }
0232
0233 TEST_CASE("LoggerMixin suppresses formatted messages below threshold", "[logger]") {
0234   capture();
0235   const TestLogger logger{LogLevel::kCritical};
0236
0237   logger.trace("t{}", 0);
0238   logger.debug("d{}", 1);
0239   logger.info("i{}", 2);
0240   logger.warning("w{}", 3);
0241   logger.error("e{}", 4);
0242   logger.critical("c{}", 5);
0243
0244   CHECK(messages() == std::vector<Message>{{LogLevel::kCritical, "TestLogger", "c5"}});
0245 }
0246
0247 TEST_CASE("LoggerMixin level can be changed", "[logger]") {
0248   capture();
0249   TestLogger logger{LogLevel::kCritical};
0250
0251   logger.info() << "suppressed" << TestLogger::endmsg;
0252   logger.level(LogLevel::kInfo);
0253   CHECK(logger.level() == LogLevel::kInfo);
0254   logger.info() << "reported" << TestLogger::endmsg;
0255   logger.info("plain");
0256
0257   CHECK(messages() == std::vector<Message>{{LogLevel::kInfo, "TestLogger", "reported"},
0258                                            {LogLevel::kInfo, "TestLogger", "plain"}});
0259 }
0260
0261 TEST_CASE("LoggerMixin reports its threshold", "[logger]") {
0262   for (const auto level : kAllLevels) {
0263     const TestLogger logger{level};
0264     CAPTURE(logLevelName(level));
0265     CHECK(logger.aboveTraceThreshold() == (level >= LogLevel::kTrace));
0266     CHECK(logger.aboveDebugThreshold() == (level >= LogLevel::kDebug));
0267     CHECK(logger.aboveInfoThreshold() == (level >= LogLevel::kInfo));
0268     CHECK(logger.aboveWarningThreshold() == (level >= LogLevel::kWarning));
0269     CHECK(logger.aboveErrorThreshold() == (level >= LogLevel::kError));
0270     CHECK(logger.aboveCriticalThreshold() == (level >= LogLevel::kCritical));
0271   }
0272 }
0273
0274 TEST_CASE("LoggerMixin raises errors and logs them", "[logger]") {
0275   capture();
0276   const TestLogger logger;
0277
0278   CHECK_THROWS_AS(logger.raise("default error"), Error);
0279   CHECK_THROWS_WITH(logger.raise("default error"), "default error");
0280   try {
0281     logger.raise<CustomError>("custom error");
0282     FAIL("raise did not throw");
0283   } catch (const CustomError& e) {
0284     CHECK(std::string{e.what()} == "custom error");
0285     CHECK(std::string{e.type()} == "CustomError");
0286   }
0287
0288   CHECK(messages() == std::vector<Message>{{LogLevel::kError, "TestLogger", "default error"},
0289                                            {LogLevel::kError, "TestLogger", "default error"},
0290                                            {LogLevel::kError, "TestLogger", "custom error"}});
0291 }
0292
0293 TEST_CASE("LoggerStream threshold can be changed", "[logger]") {
0294   capture();
0295   detail::LoggerStream stream{"stream", LogLevel::kInfo, LogLevel::kWarning};
0296   CHECK(stream.threshold() == LogLevel::kWarning);
0297
0298   stream << "suppressed" << TestLogger::endmsg;
0299   stream.threshold(LogLevel::kInfo);
0300   CHECK(stream.threshold() == LogLevel::kInfo);
0301   stream << "reported" << TestLogger::endmsg;
0302
0303   CHECK(messages() == std::vector<Message>{{LogLevel::kInfo, "stream", "reported"}});
0304 }
0305
0306 TEST_CASE("LoggedService logs with the service name", "[logger]") {
0307   capture();
0308   const auto& svc = TestLoggedSvc::instance();
0309
0310   CHECK(svc.name() == "TestLoggedSvc");
0311   CHECK(std::string_view{TestLoggedSvc::kName} == "TestLoggedSvc");
0312   CHECK(ServiceSvc::instance().has<TestLoggedSvc>());
0313   svc.hello();
0314
0315   CHECK(messages() == std::vector<Message>{{LogLevel::kInfo, "TestLoggedSvc", "hello"}});
0316 }