diff options
| author | Stefan Boberg <[email protected]> | 2023-05-02 10:01:47 +0200 |
|---|---|---|
| committer | GitHub <[email protected]> | 2023-05-02 10:01:47 +0200 |
| commit | 075d17f8ada47e990fe94606c3d21df409223465 (patch) | |
| tree | e50549b766a2f3c354798a54ff73404217b4c9af /zenserver/diag/logging.cpp | |
| parent | fix: bundle shouldn't append content zip to zen (diff) | |
| download | zen-075d17f8ada47e990fe94606c3d21df409223465.tar.xz zen-075d17f8ada47e990fe94606c3d21df409223465.zip | |
moved source directories into `/src` (#264)
* moved source directories into `/src`
* updated bundle.lua for new `src` path
* moved some docs, icon
* removed old test trees
Diffstat (limited to 'zenserver/diag/logging.cpp')
| -rw-r--r-- | zenserver/diag/logging.cpp | 467 |
1 files changed, 0 insertions, 467 deletions
diff --git a/zenserver/diag/logging.cpp b/zenserver/diag/logging.cpp deleted file mode 100644 index 24c7572f4..000000000 --- a/zenserver/diag/logging.cpp +++ /dev/null @@ -1,467 +0,0 @@ -// Copyright Epic Games, Inc. All Rights Reserved. - -#include "logging.h" - -#include "config.h" - -ZEN_THIRD_PARTY_INCLUDES_START -#include <spdlog/async.h> -#include <spdlog/async_logger.h> -#include <spdlog/pattern_formatter.h> -#include <spdlog/sinks/ansicolor_sink.h> -#include <spdlog/sinks/basic_file_sink.h> -#include <spdlog/sinks/daily_file_sink.h> -#include <spdlog/sinks/msvc_sink.h> -#include <spdlog/sinks/rotating_file_sink.h> -#include <spdlog/sinks/stdout_color_sinks.h> -ZEN_THIRD_PARTY_INCLUDES_END - -#include <zencore/compactbinary.h> -#include <zencore/filesystem.h> -#include <zencore/string.h> - -#include <chrono> -#include <memory> - -// Custom logging -- test code, this should be tweaked - -namespace logging { - -using namespace spdlog; -using namespace spdlog::details; -using namespace std::literals; - -class full_formatter final : public spdlog::formatter -{ -public: - full_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 { return std::make_unique<full_formatter>(m_LogId, m_Epoch); } - - static constexpr bool UseDate = false; - - virtual void format(const details::log_msg& msg, memory_buf_t& dest) override - { - using std::chrono::duration_cast; - using std::chrono::milliseconds; - using std::chrono::seconds; - - if constexpr (UseDate) - { - auto secs = std::chrono::duration_cast<seconds>(msg.time.time_since_epoch()); - if (secs != m_LastLogSecs) - { - m_CachedTm = os::localtime(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 = duration_cast<seconds>(duration); - - if (m_CacheTimestamp != secs || m_CachedDatetime.size() == 0) - { - m_CachedDatetime.clear(); - m_CachedDatetime.push_back('['); - - if constexpr (UseDate) - { - fmt_helper::append_int(tm_time.tm_year + 1900, m_CachedDatetime); - m_CachedDatetime.push_back('-'); - - fmt_helper::pad2(tm_time.tm_mon + 1, m_CachedDatetime); - m_CachedDatetime.push_back('-'); - - fmt_helper::pad2(tm_time.tm_mday, m_CachedDatetime); - m_CachedDatetime.push_back(' '); - - fmt_helper::pad2(tm_time.tm_hour, m_CachedDatetime); - m_CachedDatetime.push_back(':'); - - fmt_helper::pad2(tm_time.tm_min, m_CachedDatetime); - m_CachedDatetime.push_back(':'); - - 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; - - fmt_helper::pad2(LogHours, m_CachedDatetime); - m_CachedDatetime.push_back(':'); - fmt_helper::pad2(LogMins, m_CachedDatetime); - m_CachedDatetime.push_back(':'); - fmt_helper::pad2(LogSecs, m_CachedDatetime); - } - - m_CachedDatetime.push_back('.'); - - m_CacheTimestamp = secs; - } - - dest.append(m_CachedDatetime.begin(), m_CachedDatetime.end()); - - auto millis = fmt_helper::time_fraction<milliseconds>(msg.time); - fmt_helper::pad3(static_cast<uint32_t>(millis.count()), dest); - dest.push_back(']'); - dest.push_back(' '); - - if (!m_LogId.empty()) - { - dest.push_back('['); - 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('['); - 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(); - fmt_helper::append_string_view(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 = details::short_filename_formatter<details::null_scoped_padder>::basename(msg.source.filename); - fmt_helper::append_string_view(filename, dest); - dest.push_back(':'); - fmt_helper::append_int(msg.source.line, dest); - dest.push_back(']'); - dest.push_back(' '); - } - - fmt_helper::append_string_view(msg.payload, dest); - 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 m_CacheTimestamp{0}; - memory_buf_t m_CachedDatetime; - std::string m_LogId; -}; - -class json_formatter final : public spdlog::formatter -{ -public: - json_formatter(std::string_view LogId) : m_LogId(LogId) {} - - virtual std::unique_ptr<formatter> clone() const override { return std::make_unique<json_formatter>(m_LogId); } - - virtual void format(const details::log_msg& msg, memory_buf_t& dest) override - { - using std::chrono::duration_cast; - using std::chrono::milliseconds; - using std::chrono::seconds; - - auto secs = std::chrono::duration_cast<seconds>(msg.time.time_since_epoch()); - if (secs != m_LastLogSecs) - { - m_CachedTm = os::localtime(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. - - if (m_CacheTimestamp != secs || m_CachedDatetime.size() == 0) - { - m_CachedDatetime.clear(); - - fmt_helper::append_int(tm_time.tm_year + 1900, m_CachedDatetime); - m_CachedDatetime.push_back('-'); - - fmt_helper::pad2(tm_time.tm_mon + 1, m_CachedDatetime); - m_CachedDatetime.push_back('-'); - - fmt_helper::pad2(tm_time.tm_mday, m_CachedDatetime); - m_CachedDatetime.push_back(' '); - - fmt_helper::pad2(tm_time.tm_hour, m_CachedDatetime); - m_CachedDatetime.push_back(':'); - - fmt_helper::pad2(tm_time.tm_min, m_CachedDatetime); - m_CachedDatetime.push_back(':'); - - fmt_helper::pad2(tm_time.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 = fmt_helper::time_fraction<milliseconds>(msg.time); - fmt_helper::pad3(static_cast<uint32_t>(millis.count()), dest); - dest.append("\", "sv); - - dest.append("\"status\": \""sv); - dest.append(level::to_string_view(msg.level)); - dest.append("\", "sv); - - dest.append("\"source\": \""sv); - dest.append("zenserver"sv); - dest.append("\", "sv); - - dest.append("\"service\": \""sv); - dest.append("zencache"sv); - dest.append("\", "sv); - - if (!m_LogId.empty()) - { - dest.append("\"id\": \""sv); - dest.append(m_LogId); - dest.append("\", "sv); - } - - if (msg.logger_name.size() > 0) - { - dest.append("\"logger.name\": \""sv); - dest.append(msg.logger_name); - dest.append("\", "sv); - } - - if (msg.thread_id != 0) - { - dest.append("\"logger.thread_name\": \""sv); - fmt_helper::pad_uint(msg.thread_id, 0, dest); - dest.append("\", "sv); - } - - if (!msg.source.empty()) - { - dest.append("\"file\": \""sv); - WriteEscapedString(dest, details::short_filename_formatter<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); - } - - dest.append("\"message\": \""sv); - WriteEscapedString(dest, msg.payload); - dest.append("\""sv); - - dest.append("}\n"sv); - } - -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(memory_buf_t& dest, const spdlog::string_view_t& payload) - { - const char* RangeStart = payload.begin(); - for (const char* It = RangeStart; It != payload.end(); ++It) - { - if (auto SpecialIt = SpecialCharacterMap.find(*It); SpecialIt != SpecialCharacterMap.end()) - { - if (RangeStart != It) - { - dest.append(RangeStart, It); - } - dest.append(SpecialIt->second); - RangeStart = It + 1; - } - } - if (RangeStart != payload.end()) - { - dest.append(RangeStart, payload.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}; - memory_buf_t m_CachedDatetime; - std::string m_LogId; -}; - -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; -} - -} // namespace logging - -void -InitializeLogging(const ZenServerOptions& GlobalOptions) -{ - zen::logging::InitializeLogging(); - logging::EnableVTMode(); - - bool IsAsync = true; - spdlog::level::level_enum LogLevel = spdlog::level::info; - - if (GlobalOptions.IsDebug) - { - LogLevel = spdlog::level::debug; - IsAsync = false; - } - - if (GlobalOptions.IsTest) - { - LogLevel = spdlog::level::trace; - IsAsync = false; - } - - if (IsAsync) - { - const int QueueSize = 8192; - const int ThreadCount = 1; - spdlog::init_thread_pool(QueueSize, ThreadCount); - - auto AsyncLogger = spdlog::create_async<spdlog::sinks::ansicolor_stdout_sink_mt>("main"); - zen::logging::SetDefault(AsyncLogger); - } - - // Sinks - - auto ConsoleSink = std::make_shared<spdlog::sinks::ansicolor_stdout_sink_mt>(); - - // spdlog can't create directories that starts with `\\?\` so we make sure the folder exists before creating the logger instance - zen::CreateDirectories(GlobalOptions.AbsLogFile.parent_path()); - -#if 0 - auto FileSink = std::make_shared<spdlog::sinks::daily_file_sink_mt>(zen::PathToUtf8(GlobalOptions.AbsLogFile), - 0, - 0, - /* truncate */ false, - uint16_t(/* max files */ 14)); -#else - auto FileSink = std::make_shared<spdlog::sinks::rotating_file_sink_mt>(zen::PathToUtf8(GlobalOptions.AbsLogFile), - /* max size */ 128 * 1024 * 1024, - /* max files */ 16, - /* rotate on open */ true); -#endif - - std::set_terminate([]() { ZEN_CRITICAL("Program exited abnormally via std::terminate()"); }); - - // Default - - auto& DefaultLogger = zen::logging::Default(); - auto& Sinks = DefaultLogger.sinks(); - - Sinks.clear(); - Sinks.push_back(ConsoleSink); - Sinks.push_back(FileSink); - -#if ZEN_PLATFORM_WINDOWS - if (zen::IsDebuggerPresent() && GlobalOptions.IsDebug) - { - auto DebugSink = std::make_shared<spdlog::sinks::msvc_sink_mt>(); - DebugSink->set_level(spdlog::level::debug); - Sinks.push_back(DebugSink); - } -#endif - - // HTTP server request logging - - std::filesystem::path HttpLogPath = GlobalOptions.DataDir / "logs" / "http.log"; - - // spdlog can't create directories that starts with `\\?\` so we make sure the folder exists before creating the logger instance - zen::CreateDirectories(HttpLogPath.parent_path()); - - auto HttpSink = std::make_shared<spdlog::sinks::rotating_file_sink_mt>(zen::PathToUtf8(HttpLogPath), - /* max size */ 128 * 1024 * 1024, - /* max files */ 16, - /* rotate on open */ true); - - auto HttpLogger = std::make_shared<spdlog::logger>("http_requests", HttpSink); - spdlog::register_logger(HttpLogger); - - // Jupiter - only log upstream HTTP traffic to file - - auto JupiterLogger = std::make_shared<spdlog::logger>("jupiter", FileSink); - spdlog::register_logger(JupiterLogger); - - // Zen - only log upstream HTTP traffic to file - - auto ZenClientLogger = std::make_shared<spdlog::logger>("zenclient", FileSink); - spdlog::register_logger(ZenClientLogger); - - // Configure all registered loggers according to settings - - spdlog::set_level(LogLevel); - spdlog::flush_on(spdlog::level::err); - spdlog::flush_every(std::chrono::seconds{2}); - spdlog::set_formatter(std::make_unique<logging::full_formatter>(GlobalOptions.LogId, std::chrono::system_clock::now())); - - if (GlobalOptions.AbsLogFile.extension() == ".json") - { - FileSink->set_formatter(std::make_unique<logging::json_formatter>(GlobalOptions.LogId)); - } - else - { - FileSink->set_pattern("[%C-%m-%d.%e %T] [%n] [%l] %v"); - } - DefaultLogger.info("log starting at {}", zen::DateTime::Now().ToIso8601()); -} - -void -ShutdownLogging() -{ - auto& DefaultLogger = zen::logging::Default(); - DefaultLogger.info("log ending at {}", zen::DateTime::Now().ToIso8601()); - zen::logging::ShutdownLogging(); -} |