diff options
| author | Stefan Boberg <[email protected]> | 2026-03-09 10:50:47 +0100 |
|---|---|---|
| committer | GitHub Enterprise <[email protected]> | 2026-03-09 10:50:47 +0100 |
| commit | 19a117889c2db6b817af9458c04c04f324162e75 (patch) | |
| tree | fbbd0d01c5bf40be90cec88e1d02c6a3c529a2f5 /src/zenutil/include | |
| parent | zenstore bug-fixes from static analysis pass (#815) (diff) | |
| download | zen-19a117889c2db6b817af9458c04c04f324162e75.tar.xz zen-19a117889c2db6b817af9458c04c04f324162e75.zip | |
Eliminate spdlog dependency (#773)
Removes the vendored spdlog library (~12,000 lines) and replaces it with a purpose-built logging system in zencore (~1,800 lines). The new implementation provides the same functionality with fewer abstractions, no shared_ptr overhead, and full control over the logging pipeline.
### What changed
**New logging core in zencore/logging/:**
- LogMessage, Formatter, Sink, Logger, Registry - core abstractions matching spdlog's model but simplified
- AnsiColorStdoutSink - ANSI color console output (replaces spdlog stdout_color_sink)
- MsvcSink - OutputDebugString on Windows (replaces spdlog msvc_sink)
- AsyncSink - async logging via BlockingQueue worker thread (replaces spdlog async_logger)
- NullSink, MessageOnlyFormatter - utility types
- Thread-safe timestamp caching in formatters using RwLock
**Moved to zenutil/logging/:**
- FullFormatter - full log formatting with timestamp, logger name, level, source location, multiline alignment
- JsonFormatter - structured JSON log output
- RotatingFileSink - rotating file sink with atomic size tracking
**API changes:**
- Log levels are now an enum (LogLevel) instead of int, eliminating the zen::logging::level namespace
- LoggerRef no longer wraps shared_ptr - it holds a raw pointer with the registry owning lifetime
- Logger error handler is wired through Registry and propagated to all loggers on registration
- Logger::Log() now populates ThreadId on every message
**Cleanup:**
- Deleted thirdparty/spdlog/ entirely (110+ files)
- Deleted full_test_formatter (was ~80% duplicate of FullFormatter)
- Renamed snake_case classes to PascalCase (full_formatter -> FullFormatter, json_formatter -> JsonFormatter, sentry_sink -> SentrySink)
- Removed spdlog from xmake dependency graph
### Build / test impact
- zencore no longer depends on spdlog
- zenutil and zenvfs xmake.lua updated to drop spdlog dep
- zentelemetry xmake.lua updated to drop spdlog dep
- All existing tests pass, no test changes required beyond formatter class renames
Diffstat (limited to 'src/zenutil/include')
| -rw-r--r-- | src/zenutil/include/zenutil/config/loggingconfig.h | 2 | ||||
| -rw-r--r-- | src/zenutil/include/zenutil/logging.h | 11 | ||||
| -rw-r--r-- | src/zenutil/include/zenutil/logging/fullformatter.h | 89 | ||||
| -rw-r--r-- | src/zenutil/include/zenutil/logging/jsonformatter.h | 168 | ||||
| -rw-r--r-- | src/zenutil/include/zenutil/logging/rotatingfilesink.h | 89 | ||||
| -rw-r--r-- | src/zenutil/include/zenutil/logging/testformatter.h | 160 |
6 files changed, 168 insertions, 351 deletions
diff --git a/src/zenutil/include/zenutil/config/loggingconfig.h b/src/zenutil/include/zenutil/config/loggingconfig.h index 6d6f64b30..b55b2d9f7 100644 --- a/src/zenutil/include/zenutil/config/loggingconfig.h +++ b/src/zenutil/include/zenutil/config/loggingconfig.h @@ -17,7 +17,7 @@ struct ZenLoggingConfig bool NoConsoleOutput = false; // Control default use of stdout for diagnostics bool QuietConsole = false; // Configure console logger output to level WARN std::filesystem::path AbsLogFile; // Absolute path to main log file - std::string Loggers[logging::level::LogLevelCount]; + std::string Loggers[logging::LogLevelCount]; std::string LogId; // Id for tagging log output std::string OtelEndpointUri; // OpenTelemetry endpoint URI }; diff --git a/src/zenutil/include/zenutil/logging.h b/src/zenutil/include/zenutil/logging.h index 85ddc86cd..95419c274 100644 --- a/src/zenutil/include/zenutil/logging.h +++ b/src/zenutil/include/zenutil/logging.h @@ -3,19 +3,12 @@ #pragma once #include <zencore/logging.h> +#include <zencore/logging/sink.h> #include <filesystem> #include <memory> #include <string> -namespace spdlog::sinks { -class sink; -} - -namespace spdlog { -using sink_ptr = std::shared_ptr<sinks::sink>; -} - ////////////////////////////////////////////////////////////////////////// // // Logging utilities @@ -45,6 +38,6 @@ void FinishInitializeLogging(const LoggingOptions& LoggingOptions); void InitializeLogging(const LoggingOptions& LoggingOptions); void ShutdownLogging(); -spdlog::sink_ptr GetFileSink(); +logging::SinkPtr GetFileSink(); } // namespace zen diff --git a/src/zenutil/include/zenutil/logging/fullformatter.h b/src/zenutil/include/zenutil/logging/fullformatter.h index 9f245becd..33cb94dae 100644 --- a/src/zenutil/include/zenutil/logging/fullformatter.h +++ b/src/zenutil/include/zenutil/logging/fullformatter.h @@ -2,21 +2,19 @@ #pragma once +#include <zencore/logging/formatter.h> +#include <zencore/logging/helpers.h> #include <zencore/memory/llm.h> #include <zencore/zencore.h> #include <string_view> -ZEN_THIRD_PARTY_INCLUDES_START -#include <spdlog/formatter.h> -ZEN_THIRD_PARTY_INCLUDES_END - namespace zen::logging { -class full_formatter final : public spdlog::formatter +class FullFormatter final : public Formatter { public: - full_formatter(std::string_view LogId, std::chrono::time_point<std::chrono::system_clock> Epoch) + FullFormatter(std::string_view LogId, std::chrono::time_point<std::chrono::system_clock> Epoch) : m_Epoch(Epoch) , m_LogId(LogId) , m_LinePrefix(128, ' ') @@ -24,16 +22,19 @@ public: { } - full_formatter(std::string_view LogId) : m_LogId(LogId), m_LinePrefix(128, ' '), m_UseFullDate(true) {} + FullFormatter(std::string_view LogId) : m_LogId(LogId), m_LinePrefix(128, ' '), m_UseFullDate(true) {} - virtual std::unique_ptr<formatter> clone() const override + virtual std::unique_ptr<Formatter> Clone() const override { ZEN_MEMSCOPE(ELLMTag::Logging); - // Note: this does not properly clone m_UseFullDate - return std::make_unique<full_formatter>(m_LogId, m_Epoch); + if (m_UseFullDate) + { + return std::make_unique<FullFormatter>(m_LogId); + } + return std::make_unique<FullFormatter>(m_LogId, m_Epoch); } - virtual void format(const spdlog::details::log_msg& msg, spdlog::memory_buf_t& OutBuffer) override + virtual void Format(const LogMessage& Msg, MemoryBuffer& OutBuffer) override { ZEN_MEMSCOPE(ELLMTag::Logging); @@ -44,38 +45,38 @@ public: std::chrono::seconds TimestampSeconds; - std::chrono::milliseconds millis; + std::chrono::milliseconds Millis; if (m_UseFullDate) { - TimestampSeconds = std::chrono::duration_cast<std::chrono::seconds>(msg.time.time_since_epoch()); + TimestampSeconds = std::chrono::duration_cast<std::chrono::seconds>(Msg.GetTime().time_since_epoch()); if (TimestampSeconds != m_LastLogSecs) { RwLock::ExclusiveLockScope _(m_TimestampLock); m_LastLogSecs = TimestampSeconds; - m_CachedLocalTm = spdlog::details::os::localtime(spdlog::log_clock::to_time_t(msg.time)); + m_CachedLocalTm = helpers::SafeLocaltime(LogClock::to_time_t(Msg.GetTime())); m_CachedDatetime.clear(); m_CachedDatetime.push_back('['); - spdlog::details::fmt_helper::pad2(m_CachedLocalTm.tm_year % 100, m_CachedDatetime); + helpers::Pad2(m_CachedLocalTm.tm_year % 100, m_CachedDatetime); m_CachedDatetime.push_back('-'); - spdlog::details::fmt_helper::pad2(m_CachedLocalTm.tm_mon + 1, m_CachedDatetime); + helpers::Pad2(m_CachedLocalTm.tm_mon + 1, m_CachedDatetime); m_CachedDatetime.push_back('-'); - spdlog::details::fmt_helper::pad2(m_CachedLocalTm.tm_mday, m_CachedDatetime); + helpers::Pad2(m_CachedLocalTm.tm_mday, m_CachedDatetime); m_CachedDatetime.push_back(' '); - spdlog::details::fmt_helper::pad2(m_CachedLocalTm.tm_hour, m_CachedDatetime); + helpers::Pad2(m_CachedLocalTm.tm_hour, m_CachedDatetime); m_CachedDatetime.push_back(':'); - spdlog::details::fmt_helper::pad2(m_CachedLocalTm.tm_min, m_CachedDatetime); + helpers::Pad2(m_CachedLocalTm.tm_min, m_CachedDatetime); m_CachedDatetime.push_back(':'); - spdlog::details::fmt_helper::pad2(m_CachedLocalTm.tm_sec, m_CachedDatetime); + helpers::Pad2(m_CachedLocalTm.tm_sec, m_CachedDatetime); m_CachedDatetime.push_back('.'); } - millis = spdlog::details::fmt_helper::time_fraction<std::chrono::milliseconds>(msg.time); + Millis = helpers::TimeFraction<std::chrono::milliseconds>(Msg.GetTime()); } else { - auto ElapsedTime = msg.time - m_Epoch; + auto ElapsedTime = Msg.GetTime() - m_Epoch; TimestampSeconds = std::chrono::duration_cast<std::chrono::seconds>(ElapsedTime); if (m_CacheTimestamp.load() != TimestampSeconds) @@ -93,15 +94,15 @@ public: m_CachedDatetime.clear(); m_CachedDatetime.push_back('['); - spdlog::details::fmt_helper::pad2(LogHours, m_CachedDatetime); + helpers::Pad2(LogHours, m_CachedDatetime); m_CachedDatetime.push_back(':'); - spdlog::details::fmt_helper::pad2(LogMins, m_CachedDatetime); + helpers::Pad2(LogMins, m_CachedDatetime); m_CachedDatetime.push_back(':'); - spdlog::details::fmt_helper::pad2(LogSecs, m_CachedDatetime); + helpers::Pad2(LogSecs, m_CachedDatetime); m_CachedDatetime.push_back('.'); } - millis = std::chrono::duration_cast<std::chrono::milliseconds>(ElapsedTime - TimestampSeconds); + Millis = std::chrono::duration_cast<std::chrono::milliseconds>(ElapsedTime - TimestampSeconds); } { @@ -109,44 +110,43 @@ public: OutBuffer.append(m_CachedDatetime.begin(), m_CachedDatetime.end()); } - spdlog::details::fmt_helper::pad3(static_cast<uint32_t>(millis.count()), OutBuffer); + helpers::Pad3(static_cast<uint32_t>(Millis.count()), OutBuffer); OutBuffer.push_back(']'); OutBuffer.push_back(' '); if (!m_LogId.empty()) { OutBuffer.push_back('['); - spdlog::details::fmt_helper::append_string_view(m_LogId, OutBuffer); + helpers::AppendStringView(m_LogId, OutBuffer); OutBuffer.push_back(']'); OutBuffer.push_back(' '); } // append logger name if exists - if (msg.logger_name.size() > 0) + if (Msg.GetLoggerName().size() > 0) { OutBuffer.push_back('['); - spdlog::details::fmt_helper::append_string_view(msg.logger_name, OutBuffer); + helpers::AppendStringView(Msg.GetLoggerName(), OutBuffer); OutBuffer.push_back(']'); OutBuffer.push_back(' '); } OutBuffer.push_back('['); // wrap the level name with color - msg.color_range_start = OutBuffer.size(); - spdlog::details::fmt_helper::append_string_view(spdlog::level::to_string_view(msg.level), OutBuffer); - msg.color_range_end = OutBuffer.size(); + Msg.ColorRangeStart = OutBuffer.size(); + helpers::AppendStringView(helpers::LevelToShortString(Msg.GetLevel()), OutBuffer); + Msg.ColorRangeEnd = OutBuffer.size(); OutBuffer.push_back(']'); OutBuffer.push_back(' '); // add source location if present - if (!msg.source.empty()) + if (Msg.GetSource()) { OutBuffer.push_back('['); - const char* filename = - spdlog::details::short_filename_formatter<spdlog::details::null_scoped_padder>::basename(msg.source.filename); - spdlog::details::fmt_helper::append_string_view(filename, OutBuffer); + const char* Filename = helpers::ShortFilename(Msg.GetSource().Filename); + helpers::AppendStringView(Filename, OutBuffer); OutBuffer.push_back(':'); - spdlog::details::fmt_helper::append_int(msg.source.line, OutBuffer); + helpers::AppendInt(Msg.GetSource().Line, OutBuffer); OutBuffer.push_back(']'); OutBuffer.push_back(' '); } @@ -156,8 +156,9 @@ public: const size_t LinePrefixCount = Min<size_t>(OutBuffer.size(), m_LinePrefix.size()); - auto ItLineBegin = msg.payload.begin(); - auto ItMessageEnd = msg.payload.end(); + auto MsgPayload = Msg.GetPayload(); + auto ItLineBegin = MsgPayload.begin(); + auto ItMessageEnd = MsgPayload.end(); bool IsFirstline = true; { @@ -170,9 +171,9 @@ public: } else { - spdlog::details::fmt_helper::append_string_view(std::string_view(m_LinePrefix.data(), LinePrefixCount), OutBuffer); + helpers::AppendStringView(std::string_view(m_LinePrefix.data(), LinePrefixCount), OutBuffer); } - spdlog::details::fmt_helper::append_string_view(spdlog::string_view_t(&*ItLineBegin, ItLineEnd - ItLineBegin), OutBuffer); + helpers::AppendStringView(std::string_view(&*ItLineBegin, ItLineEnd - ItLineBegin), OutBuffer); }; while (ItLineEnd != ItMessageEnd) @@ -187,7 +188,7 @@ public: if (ItLineBegin != ItMessageEnd) { EmitLine(); - spdlog::details::fmt_helper::append_string_view("\n"sv, OutBuffer); + helpers::AppendStringView("\n"sv, OutBuffer); } } } @@ -197,7 +198,7 @@ private: std::tm m_CachedLocalTm; std::chrono::seconds m_LastLogSecs{std::chrono::seconds(87654321)}; std::atomic<std::chrono::seconds> m_CacheTimestamp{std::chrono::seconds(87654321)}; - spdlog::memory_buf_t m_CachedDatetime; + MemoryBuffer m_CachedDatetime; std::string m_LogId; std::string m_LinePrefix; bool m_UseFullDate = true; diff --git a/src/zenutil/include/zenutil/logging/jsonformatter.h b/src/zenutil/include/zenutil/logging/jsonformatter.h index 3f660e421..216b1b5e5 100644 --- a/src/zenutil/include/zenutil/logging/jsonformatter.h +++ b/src/zenutil/include/zenutil/logging/jsonformatter.h @@ -2,27 +2,26 @@ #pragma once +#include <zencore/logging/formatter.h> +#include <zencore/logging/helpers.h> #include <zencore/memory/llm.h> #include <zencore/zencore.h> #include <string_view> - -ZEN_THIRD_PARTY_INCLUDES_START -#include <spdlog/formatter.h> -ZEN_THIRD_PARTY_INCLUDES_END +#include <unordered_map> namespace zen::logging { using namespace std::literals; -class json_formatter final : public spdlog::formatter +class JsonFormatter final : public Formatter { public: - json_formatter(std::string_view LogId) : m_LogId(LogId) {} + JsonFormatter(std::string_view LogId) : m_LogId(LogId) {} - virtual std::unique_ptr<formatter> clone() const override { return std::make_unique<json_formatter>(m_LogId); } + virtual std::unique_ptr<Formatter> Clone() const override { return std::make_unique<JsonFormatter>(m_LogId); } - virtual void format(const spdlog::details::log_msg& msg, spdlog::memory_buf_t& dest) override + virtual void Format(const LogMessage& Msg, MemoryBuffer& Dest) override { ZEN_MEMSCOPE(ELLMTag::Logging); @@ -30,141 +29,132 @@ public: using std::chrono::milliseconds; using std::chrono::seconds; - auto secs = std::chrono::duration_cast<seconds>(msg.time.time_since_epoch()); - if (secs != m_LastLogSecs) + auto Secs = std::chrono::duration_cast<seconds>(Msg.GetTime().time_since_epoch()); + if (Secs != m_LastLogSecs) { - m_CachedTm = spdlog::details::os::localtime(spdlog::log_clock::to_time_t(msg.time)); - m_LastLogSecs = secs; - } - - const auto& tm_time = m_CachedTm; + RwLock::ExclusiveLockScope _(m_TimestampLock); + m_CachedTm = helpers::SafeLocaltime(LogClock::to_time_t(Msg.GetTime())); + m_LastLogSecs = Secs; - // cache the date/time part for the next second. - - if (m_CacheTimestamp != secs || m_CachedDatetime.size() == 0) - { + // cache the date/time part for the next second. m_CachedDatetime.clear(); - spdlog::details::fmt_helper::append_int(tm_time.tm_year + 1900, m_CachedDatetime); + helpers::AppendInt(m_CachedTm.tm_year + 1900, m_CachedDatetime); m_CachedDatetime.push_back('-'); - spdlog::details::fmt_helper::pad2(tm_time.tm_mon + 1, m_CachedDatetime); + helpers::Pad2(m_CachedTm.tm_mon + 1, m_CachedDatetime); m_CachedDatetime.push_back('-'); - spdlog::details::fmt_helper::pad2(tm_time.tm_mday, m_CachedDatetime); + helpers::Pad2(m_CachedTm.tm_mday, m_CachedDatetime); m_CachedDatetime.push_back(' '); - spdlog::details::fmt_helper::pad2(tm_time.tm_hour, m_CachedDatetime); + helpers::Pad2(m_CachedTm.tm_hour, m_CachedDatetime); m_CachedDatetime.push_back(':'); - spdlog::details::fmt_helper::pad2(tm_time.tm_min, m_CachedDatetime); + helpers::Pad2(m_CachedTm.tm_min, m_CachedDatetime); m_CachedDatetime.push_back(':'); - spdlog::details::fmt_helper::pad2(tm_time.tm_sec, m_CachedDatetime); + helpers::Pad2(m_CachedTm.tm_sec, m_CachedDatetime); m_CachedDatetime.push_back('.'); - - m_CacheTimestamp = secs; } - dest.append("{"sv); - dest.append("\"time\": \""sv); - dest.append(m_CachedDatetime.begin(), m_CachedDatetime.end()); - auto millis = spdlog::details::fmt_helper::time_fraction<milliseconds>(msg.time); - spdlog::details::fmt_helper::pad3(static_cast<uint32_t>(millis.count()), dest); - dest.append("\", "sv); + helpers::AppendStringView("{"sv, Dest); + helpers::AppendStringView("\"time\": \""sv, Dest); + { + RwLock::SharedLockScope _(m_TimestampLock); + Dest.append(m_CachedDatetime.begin(), m_CachedDatetime.end()); + } + auto Millis = helpers::TimeFraction<milliseconds>(Msg.GetTime()); + helpers::Pad3(static_cast<uint32_t>(Millis.count()), Dest); + helpers::AppendStringView("\", "sv, Dest); - dest.append("\"status\": \""sv); - dest.append(spdlog::level::to_string_view(msg.level)); - dest.append("\", "sv); + helpers::AppendStringView("\"status\": \""sv, Dest); + helpers::AppendStringView(helpers::LevelToShortString(Msg.GetLevel()), Dest); + helpers::AppendStringView("\", "sv, Dest); - dest.append("\"source\": \""sv); - dest.append("zenserver"sv); - dest.append("\", "sv); + helpers::AppendStringView("\"source\": \""sv, Dest); + helpers::AppendStringView("zenserver"sv, Dest); + helpers::AppendStringView("\", "sv, Dest); - dest.append("\"service\": \""sv); - dest.append("zencache"sv); - dest.append("\", "sv); + helpers::AppendStringView("\"service\": \""sv, Dest); + helpers::AppendStringView("zencache"sv, Dest); + helpers::AppendStringView("\", "sv, Dest); if (!m_LogId.empty()) { - dest.append("\"id\": \""sv); - dest.append(m_LogId); - dest.append("\", "sv); + helpers::AppendStringView("\"id\": \""sv, Dest); + helpers::AppendStringView(m_LogId, Dest); + helpers::AppendStringView("\", "sv, Dest); } - if (msg.logger_name.size() > 0) + if (Msg.GetLoggerName().size() > 0) { - dest.append("\"logger.name\": \""sv); - dest.append(msg.logger_name); - dest.append("\", "sv); + helpers::AppendStringView("\"logger.name\": \""sv, Dest); + helpers::AppendStringView(Msg.GetLoggerName(), Dest); + helpers::AppendStringView("\", "sv, Dest); } - if (msg.thread_id != 0) + if (Msg.GetThreadId() != 0) { - dest.append("\"logger.thread_name\": \""sv); - spdlog::details::fmt_helper::pad_uint(msg.thread_id, 0, dest); - dest.append("\", "sv); + helpers::AppendStringView("\"logger.thread_name\": \""sv, Dest); + helpers::PadUint(Msg.GetThreadId(), 0, Dest); + helpers::AppendStringView("\", "sv, Dest); } - if (!msg.source.empty()) + if (Msg.GetSource()) { - dest.append("\"file\": \""sv); - WriteEscapedString( - dest, - spdlog::details::short_filename_formatter<spdlog::details::null_scoped_padder>::basename(msg.source.filename)); - dest.append("\","sv); - - dest.append("\"line\": \""sv); - dest.append(fmt::format("{}", msg.source.line)); - dest.append("\","sv); - - dest.append("\"logger.method_name\": \""sv); - WriteEscapedString(dest, msg.source.funcname); - dest.append("\", "sv); + helpers::AppendStringView("\"file\": \""sv, Dest); + WriteEscapedString(Dest, helpers::ShortFilename(Msg.GetSource().Filename)); + helpers::AppendStringView("\","sv, Dest); + + helpers::AppendStringView("\"line\": \""sv, Dest); + helpers::AppendInt(Msg.GetSource().Line, Dest); + helpers::AppendStringView("\","sv, Dest); } - dest.append("\"message\": \""sv); - WriteEscapedString(dest, msg.payload); - dest.append("\""sv); + helpers::AppendStringView("\"message\": \""sv, Dest); + WriteEscapedString(Dest, Msg.GetPayload()); + helpers::AppendStringView("\""sv, Dest); - dest.append("}\n"sv); + helpers::AppendStringView("}\n"sv, Dest); } private: - static inline const std::unordered_map<char, std::string_view> SpecialCharacterMap{{'\b', "\\b"sv}, - {'\f', "\\f"sv}, - {'\n', "\\n"sv}, - {'\r', "\\r"sv}, - {'\t', "\\t"sv}, - {'"', "\\\""sv}, - {'\\', "\\\\"sv}}; - - static void WriteEscapedString(spdlog::memory_buf_t& dest, const spdlog::string_view_t& payload) + static inline const std::unordered_map<char, std::string_view> s_SpecialCharacterMap{{'\b', "\\b"sv}, + {'\f', "\\f"sv}, + {'\n', "\\n"sv}, + {'\r', "\\r"sv}, + {'\t', "\\t"sv}, + {'"', "\\\""sv}, + {'\\', "\\\\"sv}}; + + static void WriteEscapedString(MemoryBuffer& Dest, const std::string_view& Text) { - const char* RangeStart = payload.begin(); - for (const char* It = RangeStart; It != payload.end(); ++It) + const char* RangeStart = Text.data(); + const char* End = Text.data() + Text.size(); + for (const char* It = RangeStart; It != End; ++It) { - if (auto SpecialIt = SpecialCharacterMap.find(*It); SpecialIt != SpecialCharacterMap.end()) + if (auto SpecialIt = s_SpecialCharacterMap.find(*It); SpecialIt != s_SpecialCharacterMap.end()) { if (RangeStart != It) { - dest.append(RangeStart, It); + Dest.append(RangeStart, It); } - dest.append(SpecialIt->second); + helpers::AppendStringView(SpecialIt->second, Dest); RangeStart = It + 1; } } - if (RangeStart != payload.end()) + if (RangeStart != End) { - dest.append(RangeStart, payload.end()); + Dest.append(RangeStart, End); } }; std::tm m_CachedTm{0, 0, 0, 0, 0, 0, 0, 0, 0}; std::chrono::seconds m_LastLogSecs{0}; - std::chrono::seconds m_CacheTimestamp{0}; - spdlog::memory_buf_t m_CachedDatetime; + MemoryBuffer m_CachedDatetime; std::string m_LogId; + RwLock m_TimestampLock; }; } // namespace zen::logging diff --git a/src/zenutil/include/zenutil/logging/rotatingfilesink.h b/src/zenutil/include/zenutil/logging/rotatingfilesink.h index 8901b7779..cebc5b110 100644 --- a/src/zenutil/include/zenutil/logging/rotatingfilesink.h +++ b/src/zenutil/include/zenutil/logging/rotatingfilesink.h @@ -3,14 +3,11 @@ #pragma once #include <zencore/basicfile.h> +#include <zencore/logging/formatter.h> +#include <zencore/logging/messageonlyformatter.h> +#include <zencore/logging/sink.h> #include <zencore/memory/llm.h> -ZEN_THIRD_PARTY_INCLUDES_START -#include <spdlog/details/log_msg.h> -#include <spdlog/pattern_formatter.h> -#include <spdlog/sinks/sink.h> -ZEN_THIRD_PARTY_INCLUDES_END - #include <atomic> #include <filesystem> @@ -19,13 +16,14 @@ namespace zen::logging { // Basically the same functionality as spdlog::sinks::rotating_file_sink with the biggest difference // being that it just ignores any errors when writing/rotating files and keeps chugging on. // It will keep trying to log, and if it starts to work it will continue to log. -class RotatingFileSink : public spdlog::sinks::sink +class RotatingFileSink : public Sink { public: RotatingFileSink(const std::filesystem::path& BaseFilename, std::size_t MaxSize, std::size_t MaxFiles, bool RotateOnOpen = false) : m_BaseFilename(BaseFilename) , m_MaxSize(MaxSize) , m_MaxFiles(MaxFiles) + , m_Formatter(std::make_unique<MessageOnlyFormatter>()) { ZEN_MEMSCOPE(ELLMTag::Logging); @@ -76,18 +74,21 @@ public: RotatingFileSink& operator=(const RotatingFileSink&) = delete; RotatingFileSink& operator=(RotatingFileSink&&) = delete; - virtual void log(const spdlog::details::log_msg& msg) override + virtual void Log(const LogMessage& Msg) override { ZEN_MEMSCOPE(ELLMTag::Logging); try { - spdlog::memory_buf_t Formatted; - if (TrySinkIt(msg, Formatted)) + MemoryBuffer Formatted; + if (TrySinkIt(Msg, Formatted)) { return; } - while (true) + + // This intentionally has no limit on the number of retries, see + // comment above. + for (;;) { { RwLock::ExclusiveLockScope RotateLock(m_Lock); @@ -113,7 +114,7 @@ public: // Silently eat errors } } - virtual void flush() override + virtual void Flush() override { if (!m_NeedFlush) { @@ -138,28 +139,14 @@ public: m_NeedFlush = false; } - virtual void set_pattern(const std::string& pattern) override + virtual void SetFormatter(std::unique_ptr<Formatter> InFormatter) override { ZEN_MEMSCOPE(ELLMTag::Logging); try { RwLock::ExclusiveLockScope _(m_Lock); - m_Formatter = spdlog::details::make_unique<spdlog::pattern_formatter>(pattern); - } - catch (const std::exception&) - { - // Silently eat errors - } - } - virtual void set_formatter(std::unique_ptr<spdlog::formatter> sink_formatter) override - { - ZEN_MEMSCOPE(ELLMTag::Logging); - - try - { - RwLock::ExclusiveLockScope _(m_Lock); - m_Formatter = std::move(sink_formatter); + m_Formatter = std::move(InFormatter); } catch (const std::exception&) { @@ -186,11 +173,17 @@ private: return; } - // If we fail to rotate, try extending the current log file m_CurrentSize = m_CurrentFile.FileSize(OutEc); + if (OutEc) + { + // FileSize failed but we have an open file — reset to 0 + // so we can at least attempt writes from the start + m_CurrentSize = 0; + OutEc.clear(); + } } - bool TrySinkIt(const spdlog::details::log_msg& msg, spdlog::memory_buf_t& OutFormatted) + bool TrySinkIt(const LogMessage& Msg, MemoryBuffer& OutFormatted) { ZEN_MEMSCOPE(ELLMTag::Logging); @@ -199,15 +192,15 @@ private: { return false; } - m_Formatter->format(msg, OutFormatted); - size_t add_size = OutFormatted.size(); - size_t write_pos = m_CurrentSize.fetch_add(add_size); - if (write_pos + add_size > m_MaxSize) + m_Formatter->Format(Msg, OutFormatted); + size_t AddSize = OutFormatted.size(); + size_t WritePos = m_CurrentSize.fetch_add(AddSize); + if (WritePos + AddSize > m_MaxSize) { return false; } std::error_code Ec; - m_CurrentFile.Write(OutFormatted.data(), OutFormatted.size(), write_pos, Ec); + m_CurrentFile.Write(OutFormatted.data(), OutFormatted.size(), WritePos, Ec); if (Ec) { return false; @@ -216,7 +209,7 @@ private: return true; } - bool TrySinkIt(const spdlog::memory_buf_t& Formatted) + bool TrySinkIt(const MemoryBuffer& Formatted) { ZEN_MEMSCOPE(ELLMTag::Logging); @@ -225,15 +218,15 @@ private: { return false; } - size_t add_size = Formatted.size(); - size_t write_pos = m_CurrentSize.fetch_add(add_size); - if (write_pos + add_size > m_MaxSize) + size_t AddSize = Formatted.size(); + size_t WritePos = m_CurrentSize.fetch_add(AddSize); + if (WritePos + AddSize > m_MaxSize) { return false; } std::error_code Ec; - m_CurrentFile.Write(Formatted.data(), Formatted.size(), write_pos, Ec); + m_CurrentFile.Write(Formatted.data(), Formatted.size(), WritePos, Ec); if (Ec) { return false; @@ -242,14 +235,14 @@ private: return true; } - RwLock m_Lock; - const std::filesystem::path m_BaseFilename; - std::unique_ptr<spdlog::formatter> m_Formatter; - std::atomic_size_t m_CurrentSize; - const std::size_t m_MaxSize; - const std::size_t m_MaxFiles; - BasicFile m_CurrentFile; - std::atomic<bool> m_NeedFlush = false; + RwLock m_Lock; + const std::filesystem::path m_BaseFilename; + const std::size_t m_MaxSize; + const std::size_t m_MaxFiles; + std::unique_ptr<Formatter> m_Formatter; + std::atomic_size_t m_CurrentSize; + BasicFile m_CurrentFile; + std::atomic<bool> m_NeedFlush = false; }; } // namespace zen::logging diff --git a/src/zenutil/include/zenutil/logging/testformatter.h b/src/zenutil/include/zenutil/logging/testformatter.h deleted file mode 100644 index 0b0c191fb..000000000 --- a/src/zenutil/include/zenutil/logging/testformatter.h +++ /dev/null @@ -1,160 +0,0 @@ -// Copyright Epic Games, Inc. All Rights Reserved. - -#pragma once - -#include <zencore/memory/llm.h> - -#include <spdlog/spdlog.h> - -namespace zen::logging { - -class full_test_formatter final : public spdlog::formatter -{ -public: - full_test_formatter(std::string_view LogId, std::chrono::time_point<std::chrono::system_clock> Epoch) : m_Epoch(Epoch), m_LogId(LogId) - { - } - - virtual std::unique_ptr<formatter> clone() const override - { - ZEN_MEMSCOPE(ELLMTag::Logging); - return std::make_unique<full_test_formatter>(m_LogId, m_Epoch); - } - - static constexpr bool UseDate = false; - - virtual void format(const spdlog::details::log_msg& msg, spdlog::memory_buf_t& dest) override - { - ZEN_MEMSCOPE(ELLMTag::Logging); - - using namespace std::literals; - - if constexpr (UseDate) - { - auto secs = std::chrono::duration_cast<std::chrono::seconds>(msg.time.time_since_epoch()); - if (secs != m_LastLogSecs) - { - m_CachedTm = spdlog::details::os::localtime(spdlog::log_clock::to_time_t(msg.time)); - m_LastLogSecs = secs; - } - } - - const auto& tm_time = m_CachedTm; - - // cache the date/time part for the next second. - auto duration = msg.time - m_Epoch; - auto secs = std::chrono::duration_cast<std::chrono::seconds>(duration); - - if (m_CacheTimestamp != secs) - { - RwLock::ExclusiveLockScope _(m_TimestampLock); - - m_CachedDatetime.clear(); - m_CachedDatetime.push_back('['); - - if constexpr (UseDate) - { - spdlog::details::fmt_helper::append_int(tm_time.tm_year + 1900, m_CachedDatetime); - m_CachedDatetime.push_back('-'); - - spdlog::details::fmt_helper::pad2(tm_time.tm_mon + 1, m_CachedDatetime); - m_CachedDatetime.push_back('-'); - - spdlog::details::fmt_helper::pad2(tm_time.tm_mday, m_CachedDatetime); - m_CachedDatetime.push_back(' '); - - spdlog::details::fmt_helper::pad2(tm_time.tm_hour, m_CachedDatetime); - m_CachedDatetime.push_back(':'); - - spdlog::details::fmt_helper::pad2(tm_time.tm_min, m_CachedDatetime); - m_CachedDatetime.push_back(':'); - - spdlog::details::fmt_helper::pad2(tm_time.tm_sec, m_CachedDatetime); - } - else - { - int Count = int(secs.count()); - - const int LogSecs = Count % 60; - Count /= 60; - - const int LogMins = Count % 60; - Count /= 60; - - const int LogHours = Count; - - spdlog::details::fmt_helper::pad2(LogHours, m_CachedDatetime); - m_CachedDatetime.push_back(':'); - spdlog::details::fmt_helper::pad2(LogMins, m_CachedDatetime); - m_CachedDatetime.push_back(':'); - spdlog::details::fmt_helper::pad2(LogSecs, m_CachedDatetime); - } - - m_CachedDatetime.push_back('.'); - - m_CacheTimestamp = secs; - } - - { - RwLock::SharedLockScope _(m_TimestampLock); - dest.append(m_CachedDatetime.begin(), m_CachedDatetime.end()); - } - - auto millis = spdlog::details::fmt_helper::time_fraction<std::chrono::milliseconds>(msg.time); - spdlog::details::fmt_helper::pad3(static_cast<uint32_t>(millis.count()), dest); - dest.push_back(']'); - dest.push_back(' '); - - if (!m_LogId.empty()) - { - dest.push_back('['); - spdlog::details::fmt_helper::append_string_view(m_LogId, dest); - dest.push_back(']'); - dest.push_back(' '); - } - - // append logger name if exists - if (msg.logger_name.size() > 0) - { - dest.push_back('['); - spdlog::details::fmt_helper::append_string_view(msg.logger_name, dest); - dest.push_back(']'); - dest.push_back(' '); - } - - dest.push_back('['); - // wrap the level name with color - msg.color_range_start = dest.size(); - spdlog::details::fmt_helper::append_string_view(spdlog::level::to_string_view(msg.level), dest); - msg.color_range_end = dest.size(); - dest.push_back(']'); - dest.push_back(' '); - - // add source location if present - if (!msg.source.empty()) - { - dest.push_back('['); - const char* filename = - spdlog::details::short_filename_formatter<spdlog::details::null_scoped_padder>::basename(msg.source.filename); - spdlog::details::fmt_helper::append_string_view(filename, dest); - dest.push_back(':'); - spdlog::details::fmt_helper::append_int(msg.source.line, dest); - dest.push_back(']'); - dest.push_back(' '); - } - - spdlog::details::fmt_helper::append_string_view(msg.payload, dest); - spdlog::details::fmt_helper::append_string_view("\n"sv, dest); - } - -private: - std::chrono::time_point<std::chrono::system_clock> m_Epoch; - std::tm m_CachedTm; - std::chrono::seconds m_LastLogSecs{std::chrono::seconds(87654321)}; - std::chrono::seconds m_CacheTimestamp{std::chrono::seconds(87654321)}; - spdlog::memory_buf_t m_CachedDatetime; - std::string m_LogId; - RwLock m_TimestampLock; -}; - -} // namespace zen::logging |