// Copyright Epic Games, Inc. All Rights Reserved. #include "zencore/logging.h" #include #include #include #include #include #include #include #include #include #include #if ZEN_PLATFORM_WINDOWS # pragma section(".zlog$a", read) # pragma section(".zlog$l", read) # pragma section(".zlog$z", read) #endif namespace zen { LoggerRef TheDefaultLogger; } // namespace zen namespace zen::logging { ////////////////////////////////////////////////////////////////////////// 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); } return m_LoggerRef; } static inline bool IsErrorLevel(LogLevel InLevel) { return (InLevel == Err || InLevel == Critical); }; void EmitLogMessage(LoggerRef& Logger, const LogPoint& Lp, fmt::format_args Args) { ZEN_MEMSCOPE(ELLMTag::Logging); if (!Logger) { Logger = zen::logging::ConsoleLog(); } Logger->Log(Lp, Args); if (IsErrorLevel(Lp.Level)) { if (LoggerRef ErrLogger = zen::logging::ErrorLog()) { ErrLogger->Log(Lp, Args); } } } void EmitConsoleLogMessage(const LogPoint& Lp, fmt::format_args Args) { ZEN_MEMSCOPE(ELLMTag::Logging); ConsoleLog()->Log(Lp, Args); } } // namespace zen::logging namespace zen::logging { 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 ParseLogLevelString(std::string_view Name) { for (int Level = 0; Level < LogLevelCount; ++Level) { if (LevelNames[Level] == Name) { return static_cast(Level); } } if (Name == "warn") { return Warn; } if (Name == "err") { return Err; } return Off; } std::string_view ToStringView(LogLevel Level) { if (int(Level) < LogLevelCount) { return LevelNames[int(Level)]; } return "None"; } } // namespace zen::logging ////////////////////////////////////////////////////////////////////////// namespace zen::logging { RwLock LogLevelsLock; std::string LogLevels[LogLevelCount]; void ConfigureLogLevels(LogLevel Level, std::string_view Loggers) { ZEN_MEMSCOPE(ELLMTag::Logging); RwLock::ExclusiveLockScope _(LogLevelsLock); LogLevels[Level] = Loggers; } // Iterate all configured per-logger level overrides, calling Fn(LoggerName, Level) for each entry. // Caller must hold LogLevelsLock (shared or exclusive). template static void ForEachConfiguredLevel(Fn&& Callback) { for (int i = 0; i < LogLevelCount; ++i) { LogLevel Level = LogLevel(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) { 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 FindConfiguredLevel(std::string_view Name) { std::optional 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> Levels; { RwLock::SharedLockScope _(LogLevelsLock); ForEachConfiguredLevel([&](std::string_view Entry, LogLevel Level) { Levels.emplace_back(std::string(Entry), Level); }); } Registry::Instance().SetLevels(Levels, DefaultLevel); } void RefreshLogLevels(LogLevel DefaultLevel) { RefreshLogLevels(&DefaultLevel); } void RefreshLogLevels() { RefreshLogLevels(nullptr); } void SetLogLevel(LogLevel NewLogLevel) { Registry::Instance().SetGlobalLevel(NewLogLevel); } LogLevel GetLogLevel() { return Registry::Instance().GetGlobalLevel(); } LoggerRef Default() { ZEN_ASSERT(TheDefaultLogger, "logging::InitializeLogging() must be called before using the logger"); return TheDefaultLogger; } void SetDefault(std::string_view NewDefaultLoggerId) { ZEN_MEMSCOPE(ELLMTag::Logging); Ref NewDefaultLogger = Registry::Instance().Get(std::string(NewDefaultLoggerId)); ZEN_ASSERT(NewDefaultLogger); Registry::Instance().SetDefaultLogger(NewDefaultLogger); TheDefaultLogger = LoggerRef(*NewDefaultLogger); } LoggerRef TheErrorLogger; LoggerRef ErrorLog() { return TheErrorLogger; } void SetErrorLog(std::string_view NewErrorLoggerId) { ZEN_MEMSCOPE(ELLMTag::Logging); if (NewErrorLoggerId.empty()) { TheErrorLogger = {}; } else { Ref NewErrorLogger = Registry::Instance().Get(std::string(NewErrorLoggerId)); ZEN_ASSERT(NewErrorLogger); TheErrorLogger = LoggerRef(*NewErrorLogger.Get()); } } RwLock g_LoggerMutex; LoggerRef Get(std::string_view Name) { ZEN_MEMSCOPE(ELLMTag::Logging); Ref FoundLogger = Registry::Instance().Get(std::string(Name)); if (!FoundLogger) { g_LoggerMutex.WithExclusiveLock([&] { FoundLogger = Registry::Instance().Get(std::string(Name)); if (!FoundLogger) { 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 Override = FindConfiguredLevel(Name); if (Override) { FoundLogger->SetLevel(*Override); } } }); } return LoggerRef(*FoundLogger); } std::once_flag ConsoleInitFlag; Ref ConLogger; void SuppressConsoleLog() { ZEN_MEMSCOPE(ELLMTag::Logging); if (ConLogger) { Registry::Instance().Drop("console"); ConLogger = {}; } SinkPtr NullSinkPtr(new NullSink()); ConLogger = Ref(new Logger("console", std::vector{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 Clone() const override { return std::make_unique(); } }; LoggerRef ConsoleLog() { ZEN_MEMSCOPE(ELLMTag::Logging); std::call_once(ConsoleInitFlag, [&] { if (!ConLogger) { SinkPtr ConsoleSink(new AnsiColorStdoutSink()); ConsoleSink->SetFormatter(std::make_unique()); ConLogger = Ref(new Logger("console", std::vector{ConsoleSink})); Registry::Instance().Register(ConLogger); } }); return LoggerRef(*ConLogger); } void ResetConsoleLog() { ZEN_MEMSCOPE(ELLMTag::Logging); LoggerRef ConLog = ConsoleLog(); ConLog->SetFormatter(std::make_unique()); } void InitializeLogging() { ZEN_MEMSCOPE(ELLMTag::Logging); TheDefaultLogger = LoggerRef(*Registry::Instance().DefaultLoggerRaw()); } void ShutdownLogging() { ZEN_MEMSCOPE(ELLMTag::Logging); Registry::Instance().Shutdown(); TheDefaultLogger = {}; } bool EnableVTMode() { #if ZEN_PLATFORM_WINDOWS // Set output mode to handle virtual terminal sequences HANDLE hOut = GetStdHandle(STD_OUTPUT_HANDLE); if (hOut == INVALID_HANDLE_VALUE) { return false; } DWORD dwMode = 0; if (!GetConsoleMode(hOut, &dwMode)) { return false; } dwMode |= ENABLE_VIRTUAL_TERMINAL_PROCESSING; if (!SetConsoleMode(hOut, dwMode)) { return false; } #endif return true; } void FlushLogging() { Registry::Instance().FlushAll(); } } // namespace zen::logging namespace zen { LoggerRef::LoggerRef(logging::Logger& InLogger) : m_Logger(static_cast(&InLogger)) { } void LoggerRef::Flush() { (*this)->Flush(); } thread_local ScopedActivityBase* t_ScopeStack = nullptr; ScopedActivityBase* GetThreadActivity() { return t_ScopeStack; } ScopedActivityBase::ScopedActivityBase() : m_NextScope{t_ScopeStack} { t_ScopeStack = this; } ScopedActivityBase::~ScopedActivityBase() { if (t_ScopeStack != this) { ZEN_ERROR("invalid t_ScopeStack in ~ScopedActivityBase(). Expected {:#x}, found {:#x}", (uintptr_t)this, (uintptr_t)t_ScopeStack); return; } t_ScopeStack = m_NextScope; } std::string_view EmitActivitiesForLogging(StringBuilderBase& OutString) { OutString.Reset(); for (auto Bread = GetThreadActivity(); Bread; Bread = Bread->GetNext()) { OutString.Append("\n|>|>|> "); Bread->Emit(OutString); } return OutString.ToView(); } ////////////////////////////////////////////////////////////////////////// ScopedActivityString::~ScopedActivityString() { } void ScopedActivityString::Emit(StringBuilderBase& Target) { Target.Append(m_Text); } #if ZEN_WITH_TESTS void logging_forcelink() { } using namespace std::literals; TEST_SUITE_BEGIN("core.logging"); TEST_CASE("simple.bread") { ExtendableStringBuilder<256> Crumbs; auto EmitBreadcrumbs = [&] { Crumbs.Reset(); for (auto Bread = GetThreadActivity(); Bread; Bread = Bread->GetNext()) { Bread->Emit(Crumbs); } return Crumbs.ToView(); }; SUBCASE("single") { ScopedActivityString _{"hello"}; EmitBreadcrumbs(); CHECK_EQ(Crumbs.ToView(), "hello"sv); } SUBCASE("multi") { ScopedActivityString $1{"hello"}; ScopedActivityString $2{"world"}; ScopedActivityString $3{"amaze"}; CHECK_EQ(EmitBreadcrumbs(), "amazeworldhello"sv); } SUBCASE("multi_defer") { int n = 42; ScopedActivityString $1{"hello"}; ScopedActivityString $2{"world"}; ScopedActivityString $3{"amaze"}; ScopedLazyActivity $4{[&](StringBuilderBase& Out) { Out << "plant"; }}; { ScopedLazyActivity $5{[&](StringBuilderBase& Out) { Out << n; }}; ZEN_LOG_SCOPE("{}:{}", "abc", "def"); CHECK_EQ(EmitBreadcrumbs(), "abc:def42plantamazeworldhello"sv); } CHECK_EQ(EmitBreadcrumbs(), "plantamazeworldhello"sv); } } 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