diff options
Diffstat (limited to 'src/zencore/logging.cpp')
| -rw-r--r-- | src/zencore/logging.cpp | 459 |
1 files changed, 250 insertions, 209 deletions
diff --git a/src/zencore/logging.cpp b/src/zencore/logging.cpp index e79c4b41c..3206e380b 100644 --- a/src/zencore/logging.cpp +++ b/src/zencore/logging.cpp @@ -2,208 +2,144 @@ #include "zencore/logging.h" +#include <zencore/logging/ansicolorsink.h> +#include <zencore/logging/logger.h> +#include <zencore/logging/messageonlyformatter.h> +#include <zencore/logging/nullsink.h> +#include <zencore/logging/registry.h> #include <zencore/string.h> #include <zencore/testing.h> #include <zencore/thread.h> #include <zencore/memory/llm.h> -ZEN_THIRD_PARTY_INCLUDES_START -#include <spdlog/details/registry.h> -#include <spdlog/sinks/null_sink.h> -#include <spdlog/sinks/stdout_color_sinks.h> -#include <spdlog/spdlog.h> -ZEN_THIRD_PARTY_INCLUDES_END +#include <mutex> #if ZEN_PLATFORM_WINDOWS # pragma section(".zlog$a", read) -# pragma section(".zlog$f", read) -# pragma section(".zlog$m", read) -# pragma section(".zlog$s", read) +# pragma section(".zlog$l", read) # pragma section(".zlog$z", read) #endif +namespace { + +// Bootstrap logger: a minimal stdout logger that exists for the entire lifetime +// of the process. TheDefaultLogger points here before InitializeLogging() runs +// (and is restored here after ShutdownLogging()) so that log macros always have +// a usable target — no null checks or lazy init required on the common path. +zen::Ref<zen::logging::Logger> s_BootstrapLogger = [] { + zen::logging::SinkPtr Sink(new zen::logging::AnsiColorStdoutSink()); + return zen::Ref<zen::logging::Logger>(new zen::logging::Logger("", Sink)); +}(); + +} // namespace + namespace zen { -// We shadow the underlying spdlog default logger, in order to avoid a bunch of overhead -LoggerRef TheDefaultLogger; +LoggerRef TheDefaultLogger{*s_BootstrapLogger}; } // namespace zen namespace zen::logging { -using MemoryBuffer_t = fmt::basic_memory_buffer<char, 250>; +static bool g_LoggingInitialized = false; -struct LoggingContext +bool +IsLoggingInitialized() { - inline LoggingContext(); - inline ~LoggingContext(); - - zen::logging::MemoryBuffer_t MessageBuffer; + return g_LoggingInitialized; +} - inline std::string_view Message() const { return std::string_view(MessageBuffer.data(), MessageBuffer.size()); } -}; +////////////////////////////////////////////////////////////////////////// -LoggingContext::LoggingContext() +LoggerRef +LogCategory::Logger() { -} + // This should be thread safe since zen::logging::Get() will return + // the same logger instance for the same category name. Also the + // LoggerRef is simply a pointer. + if (!m_LoggerRef) + { + m_LoggerRef = zen::logging::Get(m_CategoryName); + } -LoggingContext::~LoggingContext() -{ + return m_LoggerRef; } -////////////////////////////////////////////////////////////////////////// - static inline bool -IsErrorLevel(int LogLevel) +IsErrorLevel(LogLevel InLevel) { - return (LogLevel == zen::logging::level::Err || LogLevel == zen::logging::level::Critical); + return (InLevel == Err || InLevel == Critical); }; -static_assert(sizeof(spdlog::source_loc) == sizeof(SourceLocation)); -static_assert(offsetof(spdlog::source_loc, filename) == offsetof(SourceLocation, filename)); -static_assert(offsetof(spdlog::source_loc, line) == offsetof(SourceLocation, line)); -static_assert(offsetof(spdlog::source_loc, funcname) == offsetof(SourceLocation, funcname)); - void -EmitLogMessage(LoggerRef& Logger, int LogLevel, const std::string_view Message) +EmitLogMessage(LoggerRef& Logger, const LogPoint& Lp, fmt::format_args Args) { ZEN_MEMSCOPE(ELLMTag::Logging); - const spdlog::level::level_enum InLevel = (spdlog::level::level_enum)LogLevel; - Logger.SpdLogger->log(InLevel, Message); - if (IsErrorLevel(LogLevel)) + + if (!Logger) { - if (LoggerRef ErrLogger = zen::logging::ErrorLog()) - { - ErrLogger.SpdLogger->log(InLevel, Message); - } + Logger = zen::logging::ConsoleLog(); } -} -void -EmitLogMessage(LoggerRef& Logger, int LogLevel, std::string_view Format, fmt::format_args Args) -{ - ZEN_MEMSCOPE(ELLMTag::Logging); - zen::logging::LoggingContext LogCtx; - fmt::vformat_to(fmt::appender(LogCtx.MessageBuffer), Format, Args); - zen::logging::EmitLogMessage(Logger, LogLevel, LogCtx.Message()); -} + Logger->Log(Lp, Args); -void -EmitLogMessage(LoggerRef& Logger, const SourceLocation& InLocation, int LogLevel, const std::string_view Message) -{ - ZEN_MEMSCOPE(ELLMTag::Logging); - const spdlog::source_loc& Location = *reinterpret_cast<const spdlog::source_loc*>(&InLocation); - const spdlog::level::level_enum InLevel = (spdlog::level::level_enum)LogLevel; - Logger.SpdLogger->log(Location, InLevel, Message); - if (IsErrorLevel(LogLevel)) + if (IsErrorLevel(Lp.Level)) { if (LoggerRef ErrLogger = zen::logging::ErrorLog()) { - ErrLogger.SpdLogger->log(Location, InLevel, Message); + ErrLogger->Log(Lp, Args); } } } void -EmitLogMessage(LoggerRef& Logger, const SourceLocation& InLocation, int LogLevel, std::string_view Format, fmt::format_args Args) -{ - ZEN_MEMSCOPE(ELLMTag::Logging); - zen::logging::LoggingContext LogCtx; - fmt::vformat_to(fmt::appender(LogCtx.MessageBuffer), Format, Args); - zen::logging::EmitLogMessage(Logger, InLocation, LogLevel, LogCtx.Message()); -} - -void -EmitConsoleLogMessage(int LogLevel, const std::string_view Message) +EmitConsoleLogMessage(const LogPoint& Lp, fmt::format_args Args) { ZEN_MEMSCOPE(ELLMTag::Logging); - const spdlog::level::level_enum InLevel = (spdlog::level::level_enum)LogLevel; - ConsoleLog().SpdLogger->log(InLevel, Message); -} - -#define ZEN_COLOR_YELLOW "\033[0;33m" -#define ZEN_COLOR_RED "\033[0;31m" -#define ZEN_BRIGHT_COLOR_RED "\033[1;31m" -#define ZEN_COLOR_RESET "\033[0m" - -void -EmitConsoleLogMessage(int LogLevel, std::string_view Format, fmt::format_args Args) -{ - ZEN_MEMSCOPE(ELLMTag::Logging); - zen::logging::LoggingContext LogCtx; - - // We are not using a format option for console which include log level since it would interfere with normal console output - - const spdlog::level::level_enum InLevel = (spdlog::level::level_enum)LogLevel; - switch (InLevel) - { - case spdlog::level::level_enum::warn: - fmt::format_to(fmt::appender(LogCtx.MessageBuffer), ZEN_COLOR_YELLOW "Warning: " ZEN_COLOR_RESET); - break; - case spdlog::level::level_enum::err: - fmt::format_to(fmt::appender(LogCtx.MessageBuffer), ZEN_BRIGHT_COLOR_RED "Error: " ZEN_COLOR_RESET); - break; - case spdlog::level::level_enum::critical: - fmt::format_to(fmt::appender(LogCtx.MessageBuffer), ZEN_COLOR_RED "Critical: " ZEN_COLOR_RESET); - break; - default: - break; - } - fmt::vformat_to(fmt::appender(LogCtx.MessageBuffer), Format, Args); - zen::logging::EmitConsoleLogMessage(LogLevel, LogCtx.Message()); + ConsoleLog()->Log(Lp, Args); } } // namespace zen::logging -namespace zen::logging::level { +namespace zen::logging { -spdlog::level::level_enum -to_spdlog_level(LogLevel NewLogLevel) -{ - return static_cast<spdlog::level::level_enum>((int)NewLogLevel); -} +constinit std::string_view LevelNames[] = {std::string_view("trace", 5), + std::string_view("debug", 5), + std::string_view("info", 4), + std::string_view("warning", 7), + std::string_view("error", 5), + std::string_view("critical", 8), + std::string_view("off", 3)}; LogLevel -to_logging_level(spdlog::level::level_enum NewLogLevel) -{ - return static_cast<LogLevel>((int)NewLogLevel); -} - -constinit std::string_view LevelNames[] = {ZEN_LEVEL_NAME_TRACE, - ZEN_LEVEL_NAME_DEBUG, - ZEN_LEVEL_NAME_INFO, - ZEN_LEVEL_NAME_WARNING, - ZEN_LEVEL_NAME_ERROR, - ZEN_LEVEL_NAME_CRITICAL, - ZEN_LEVEL_NAME_OFF}; - -level::LogLevel ParseLogLevelString(std::string_view Name) { - for (int Level = 0; Level < level::LogLevelCount; ++Level) + for (int Level = 0; Level < LogLevelCount; ++Level) { if (LevelNames[Level] == Name) - return static_cast<level::LogLevel>(Level); + { + return static_cast<LogLevel>(Level); + } } if (Name == "warn") { - return level::Warn; + return Warn; } if (Name == "err") { - return level::Err; + return Err; } - return level::Off; + return Off; } std::string_view -ToStringView(level::LogLevel Level) +ToStringView(LogLevel Level) { - if (int(Level) < level::LogLevelCount) + if (int(Level) < LogLevelCount) { return LevelNames[int(Level)]; } @@ -211,17 +147,17 @@ ToStringView(level::LogLevel Level) return "None"; } -} // namespace zen::logging::level +} // namespace zen::logging ////////////////////////////////////////////////////////////////////////// namespace zen::logging { RwLock LogLevelsLock; -std::string LogLevels[level::LogLevelCount]; +std::string LogLevels[LogLevelCount]; void -ConfigureLogLevels(level::LogLevel Level, std::string_view Loggers) +ConfigureLogLevels(LogLevel Level, std::string_view Loggers) { ZEN_MEMSCOPE(ELLMTag::Logging); @@ -229,55 +165,69 @@ ConfigureLogLevels(level::LogLevel Level, std::string_view Loggers) LogLevels[Level] = Loggers; } -void -RefreshLogLevels(level::LogLevel* DefaultLevel) +// Iterate all configured per-logger level overrides, calling Fn(LoggerName, Level) for each entry. +// Caller must hold LogLevelsLock (shared or exclusive). +template<typename Fn> +static void +ForEachConfiguredLevel(Fn&& Callback) { - ZEN_MEMSCOPE(ELLMTag::Logging); - - spdlog::details::registry::log_levels Levels; - + for (int i = 0; i < LogLevelCount; ++i) { - RwLock::SharedLockScope _(LogLevelsLock); + LogLevel Level = LogLevel(i); + std::string_view Spec = LogLevels[i]; - for (int i = 0; i < level::LogLevelCount; ++i) + while (!Spec.empty()) { - level::LogLevel CurrentLevel{i}; - - std::string_view Spec = LogLevels[i]; - - while (!Spec.empty()) + std::string_view Entry; + if (auto CommaPos = Spec.find_first_of(','); CommaPos != std::string_view::npos) { - std::string LoggerName; - - if (auto CommaPos = Spec.find_first_of(','); CommaPos != std::string_view::npos) - { - LoggerName = Spec.substr(0, CommaPos); - Spec.remove_prefix(CommaPos + 1); - } - else - { - LoggerName = Spec; - Spec = {}; - } - - Levels[LoggerName] = to_spdlog_level(CurrentLevel); + Entry = Spec.substr(0, CommaPos); + Spec.remove_prefix(CommaPos + 1); } + else + { + Entry = Spec; + Spec = {}; + } + + Callback(Entry, Level); } } +} + +// Find the configured level override for a named logger, if any. +// Patterns may contain wildcards (e.g. "proxy*" matches "proxy" and "proxy.http"). +// Caller must hold LogLevelsLock (shared or exclusive). +static std::optional<LogLevel> +FindConfiguredLevel(std::string_view Name) +{ + std::optional<LogLevel> Result; + ForEachConfiguredLevel([&](std::string_view Pattern, LogLevel Level) { + if (MatchLoggerPattern(Pattern, Name)) + { + Result = Level; + } + }); + return Result; +} + +void +RefreshLogLevels(LogLevel* DefaultLevel) +{ + ZEN_MEMSCOPE(ELLMTag::Logging); + + std::vector<std::pair<std::string, LogLevel>> Levels; - if (DefaultLevel) - { - spdlog::level::level_enum SpdDefaultLevel = to_spdlog_level(*DefaultLevel); - spdlog::details::registry::instance().set_levels(Levels, &SpdDefaultLevel); - } - else { - spdlog::details::registry::instance().set_levels(Levels, nullptr); + RwLock::SharedLockScope _(LogLevelsLock); + ForEachConfiguredLevel([&](std::string_view Entry, LogLevel Level) { Levels.emplace_back(std::string(Entry), Level); }); } + + Registry::Instance().SetLevels(Levels, DefaultLevel); } void -RefreshLogLevels(level::LogLevel DefaultLevel) +RefreshLogLevels(LogLevel DefaultLevel) { RefreshLogLevels(&DefaultLevel); } @@ -289,21 +239,21 @@ RefreshLogLevels() } void -SetLogLevel(level::LogLevel NewLogLevel) +SetLogLevel(LogLevel NewLogLevel) { - spdlog::set_level(to_spdlog_level(NewLogLevel)); + Registry::Instance().SetGlobalLevel(NewLogLevel); } -level::LogLevel +LogLevel GetLogLevel() { - return level::to_logging_level(spdlog::get_level()); + return Registry::Instance().GetGlobalLevel(); } LoggerRef Default() { - ZEN_ASSERT(TheDefaultLogger); + ZEN_ASSERT(g_LoggingInitialized, "logging::InitializeLogging() must be called before using the logger"); return TheDefaultLogger; } @@ -312,10 +262,10 @@ SetDefault(std::string_view NewDefaultLoggerId) { ZEN_MEMSCOPE(ELLMTag::Logging); - auto NewDefaultLogger = spdlog::get(std::string(NewDefaultLoggerId)); + Ref<Logger> NewDefaultLogger = Registry::Instance().Get(std::string(NewDefaultLoggerId)); ZEN_ASSERT(NewDefaultLogger); - spdlog::set_default_logger(NewDefaultLogger); + Registry::Instance().SetDefaultLogger(NewDefaultLogger); TheDefaultLogger = LoggerRef(*NewDefaultLogger); } @@ -338,11 +288,11 @@ SetErrorLog(std::string_view NewErrorLoggerId) } else { - auto NewErrorLogger = spdlog::get(std::string(NewErrorLoggerId)); + Ref<Logger> NewErrorLogger = Registry::Instance().Get(std::string(NewErrorLoggerId)); ZEN_ASSERT(NewErrorLogger); - TheErrorLogger = LoggerRef(*NewErrorLogger.get()); + TheErrorLogger = LoggerRef(*NewErrorLogger.Get()); } } @@ -353,39 +303,84 @@ Get(std::string_view Name) { ZEN_MEMSCOPE(ELLMTag::Logging); - std::shared_ptr<spdlog::logger> Logger = spdlog::get(std::string(Name)); + Ref<Logger> FoundLogger = Registry::Instance().Get(std::string(Name)); - if (!Logger) + if (!FoundLogger) { g_LoggerMutex.WithExclusiveLock([&] { - Logger = spdlog::get(std::string(Name)); + FoundLogger = Registry::Instance().Get(std::string(Name)); - if (!Logger) + if (!FoundLogger) { - Logger = Default().SpdLogger->clone(std::string(Name)); - spdlog::apply_logger_env_levels(Logger); - spdlog::register_logger(Logger); + FoundLogger = Default()->Clone(std::string(Name)); + Registry::Instance().Register(FoundLogger); + + // Apply any per-logger level override that was configured before this + // logger was created (e.g. via --log-debug=proxy). + RwLock::SharedLockScope LevelsLock(LogLevelsLock); + std::optional<LogLevel> Override = FindConfiguredLevel(Name); + if (Override) + { + FoundLogger->SetLevel(*Override); + } } }); } - return *Logger; + return LoggerRef(*FoundLogger); } -std::once_flag ConsoleInitFlag; -std::shared_ptr<spdlog::logger> ConLogger; +std::once_flag ConsoleInitFlag; +Ref<Logger> ConLogger; void SuppressConsoleLog() { + ZEN_MEMSCOPE(ELLMTag::Logging); + if (ConLogger) { - spdlog::drop("console"); + Registry::Instance().Drop("console"); ConLogger = {}; } - ConLogger = spdlog::null_logger_mt("console"); + + SinkPtr NullSinkPtr(new NullSink()); + ConLogger = Ref<Logger>(new Logger("console", std::vector<SinkPtr>{NullSinkPtr})); + Registry::Instance().Register(ConLogger); } +#define ZEN_COLOR_YELLOW "\033[0;33m" +#define ZEN_COLOR_RED "\033[0;31m" +#define ZEN_BRIGHT_COLOR_RED "\033[1;31m" +#define ZEN_COLOR_RESET "\033[0m" + +class ConsoleFormatter : public Formatter +{ +public: + void Format(const LogMessage& Msg, MemoryBuffer& Dest) override + { + switch (Msg.GetLevel()) + { + case Warn: + fmt::format_to(fmt::appender(Dest), ZEN_COLOR_YELLOW "Warning: " ZEN_COLOR_RESET); + break; + case Err: + fmt::format_to(fmt::appender(Dest), ZEN_BRIGHT_COLOR_RED "Error: " ZEN_COLOR_RESET); + break; + case Critical: + fmt::format_to(fmt::appender(Dest), ZEN_COLOR_RED "Critical: " ZEN_COLOR_RESET); + break; + default: + break; + } + + helpers::AppendStringView(Msg.GetPayload(), Dest); + Dest.push_back('\n'); + } + + std::unique_ptr<Formatter> Clone() const override { return std::make_unique<ConsoleFormatter>(); } +}; + LoggerRef ConsoleLog() { @@ -394,22 +389,24 @@ ConsoleLog() std::call_once(ConsoleInitFlag, [&] { if (!ConLogger) { - ConLogger = spdlog::stdout_color_mt("console"); - spdlog::apply_logger_env_levels(ConLogger); - - ConLogger->set_pattern("%v"); + SinkPtr ConsoleSink(new AnsiColorStdoutSink()); + ConsoleSink->SetFormatter(std::make_unique<ConsoleFormatter>()); + ConLogger = Ref<Logger>(new Logger("console", std::vector<SinkPtr>{ConsoleSink})); + Registry::Instance().Register(ConLogger); } }); - return *ConLogger; + return LoggerRef(*ConLogger); } void ResetConsoleLog() { + ZEN_MEMSCOPE(ELLMTag::Logging); + LoggerRef ConLog = ConsoleLog(); - ConLog.SpdLogger->set_pattern("%v"); + ConLog->SetFormatter(std::make_unique<ConsoleFormatter>()); } void @@ -417,14 +414,18 @@ InitializeLogging() { ZEN_MEMSCOPE(ELLMTag::Logging); - TheDefaultLogger = *spdlog::default_logger_raw(); + TheDefaultLogger = LoggerRef(*Registry::Instance().DefaultLoggerRaw()); + g_LoggingInitialized = true; } void ShutdownLogging() { - spdlog::shutdown(); - TheDefaultLogger = {}; + ZEN_MEMSCOPE(ELLMTag::Logging); + + g_LoggingInitialized = false; + Registry::Instance().Shutdown(); + TheDefaultLogger = LoggerRef(*s_BootstrapLogger); } bool @@ -457,29 +458,21 @@ EnableVTMode() void FlushLogging() { - spdlog::details::registry::instance().flush_all(); + Registry::Instance().FlushAll(); } } // namespace zen::logging namespace zen { -bool -LoggerRef::ShouldLog(int Level) const +LoggerRef::LoggerRef(logging::Logger& InLogger) : m_Logger(static_cast<logging::LoggerBase*>(&InLogger)) { - return SpdLogger->should_log(static_cast<spdlog::level::level_enum>(Level)); } void -LoggerRef::SetLogLevel(logging::level::LogLevel NewLogLevel) -{ - SpdLogger->set_level(to_spdlog_level(NewLogLevel)); -} - -logging::level::LogLevel -LoggerRef::GetLogLevel() +LoggerRef::Flush() { - return logging::level::to_logging_level(SpdLogger->level()); + (*this)->Flush(); } thread_local ScopedActivityBase* t_ScopeStack = nullptr; @@ -540,6 +533,8 @@ logging_forcelink() using namespace std::literals; +TEST_SUITE_BEGIN("core.logging"); + TEST_CASE("simple.bread") { ExtendableStringBuilder<256> Crumbs; @@ -588,6 +583,52 @@ TEST_CASE("simple.bread") } } +TEST_CASE("MatchLoggerPattern") +{ + // Exact match + CHECK(logging::MatchLoggerPattern("proxy", "proxy")); + CHECK_FALSE(logging::MatchLoggerPattern("proxy", "prox")); + CHECK_FALSE(logging::MatchLoggerPattern("proxy", "proxyz")); + + // Trailing wildcard + CHECK(logging::MatchLoggerPattern("proxy*", "proxy")); + CHECK(logging::MatchLoggerPattern("proxy*", "proxy.http")); + CHECK(logging::MatchLoggerPattern("proxy*", "proxy.anything")); + CHECK_FALSE(logging::MatchLoggerPattern("proxy*", "prox")); + CHECK_FALSE(logging::MatchLoggerPattern("proxy*", "other")); + + // Leading wildcard + CHECK(logging::MatchLoggerPattern("*store", "store")); + CHECK(logging::MatchLoggerPattern("*store", "buildstore")); + CHECK_FALSE(logging::MatchLoggerPattern("*store", "stores")); + + // Wildcard in the middle + CHECK(logging::MatchLoggerPattern("zen*store", "zenstore")); + CHECK(logging::MatchLoggerPattern("zen*store", "zen.buildstore")); + CHECK_FALSE(logging::MatchLoggerPattern("zen*store", "zen.stores")); + + // Multiple wildcards + CHECK(logging::MatchLoggerPattern("*proxy*", "proxy")); + CHECK(logging::MatchLoggerPattern("*proxy*", "proxy.http")); + CHECK(logging::MatchLoggerPattern("*proxy*", "myproxy.http")); + CHECK_FALSE(logging::MatchLoggerPattern("*proxy*", "other")); + + // Single-char wildcard + CHECK(logging::MatchLoggerPattern("prox?", "proxy")); + CHECK_FALSE(logging::MatchLoggerPattern("prox?", "prox")); + CHECK_FALSE(logging::MatchLoggerPattern("prox?", "proxyy")); + + // Star matches empty + CHECK(logging::MatchLoggerPattern("*", "anything")); + CHECK(logging::MatchLoggerPattern("*", "")); + + // Empty pattern + CHECK(logging::MatchLoggerPattern("", "")); + CHECK_FALSE(logging::MatchLoggerPattern("", "notempty")); +} + +TEST_SUITE_END(); + #endif } // namespace zen |