diff --git a/Docs/LoggingSinks.md b/Docs/LoggingSinks.md new file mode 100644 index 0000000..b2692c6 --- /dev/null +++ b/Docs/LoggingSinks.md @@ -0,0 +1,20 @@ +# DraconicEngine Logging Sinks + +The logging module in DraconicEngine utilizes an asynchronous sink architecture. Sinks are responsible for formatting and routing `LogMessage` structs to their final destination. + +Currently, the engine provides three native sinks, all implementing the `ILogSink` interface: + +## 1. `ConsoleSink` +Outputs standard formatted logs directly to `stdout`. +* **Usage:** Best for local debugging and immediate developer feedback inside IDE terminals. +* **Performance:** Uses high-speed async queuing, but `stdout` blocking can occur depending on the OS terminal implementation. + +## 2. `FileSink` +Appends incoming log messages to a specified flat file path. +* **Usage:** Standard, long-running application logs where size constraints aren't an immediate concern. +* **Internal:** Implemented using the PIMPL idiom to avoid leaking `` into the module interface. + +## 3. `RollingFileSink` +Behaves like `FileSink`, but intelligently rolls the log to a new file when a predefined size limit (`m_max_file_size`) is hit. +* **Usage:** Production builds and dedicated servers where you need to prevent log files from infinitely ballooning and consuming disk space. +* **Formatting:** Appends a timestamp (`%Y%m%d_%H%M%S`) and an atomic sequence number to the new filename. diff --git a/Engine/cpp/runtime/CMakeLists.txt b/Engine/cpp/runtime/CMakeLists.txt index c9f083e..74b0ae9 100644 --- a/Engine/cpp/runtime/CMakeLists.txt +++ b/Engine/cpp/runtime/CMakeLists.txt @@ -5,7 +5,7 @@ add_modules_library(rendering) add_modules_library(scene) target_link_libraries(platform PUBLIC platform_impl) -target_link_libraries(core PUBLIC definitions math io memory) +target_link_libraries(core PUBLIC definitions math io memory logging) target_link_libraries(input PRIVATE SDL3::SDL3-static platform core) target_link_libraries(rendering PUBLIC rhi rendergraph mesh material quad_renderer renderer) target_link_libraries(scene PUBLIC renderable transform_component camera) diff --git a/Engine/cpp/runtime/core/CMakeLists.txt b/Engine/cpp/runtime/core/CMakeLists.txt index dd4dfb1..9925bc4 100644 --- a/Engine/cpp/runtime/core/CMakeLists.txt +++ b/Engine/cpp/runtime/core/CMakeLists.txt @@ -2,7 +2,9 @@ add_modules_library(definitions PIC) add_modules_library(math) add_modules_library(io) add_modules_library(memory) +add_modules_library(logging) target_link_libraries(math PUBLIC definitions bx) target_link_libraries(io PUBLIC definitions stb_image) target_link_libraries(memory PUBLIC definitions math) +target_link_libraries(logging PUBLIC definitions) \ No newline at end of file diff --git a/Engine/cpp/runtime/core/core.cppm b/Engine/cpp/runtime/core/core.cppm index 9de09a0..a8fe820 100644 --- a/Engine/cpp/runtime/core/core.cppm +++ b/Engine/cpp/runtime/core/core.cppm @@ -3,3 +3,4 @@ export import core.defs; export import core.math; export import core.memory; export import core.io; +export import core.logging; diff --git a/Engine/cpp/runtime/core/io/image_loader.cpp b/Engine/cpp/runtime/core/io/image_loader.cpp index 98ec0b4..93a9597 100644 --- a/Engine/cpp/runtime/core/io/image_loader.cpp +++ b/Engine/cpp/runtime/core/io/image_loader.cpp @@ -12,7 +12,7 @@ module core.io.image_loader; import core.stdtypes; -// TODO: I'm too lazy to write code so we need somethin' better +// TODO: I'm too lazy to write code so we need somethin' better (AR-DEV-1) namespace draco::core::io::image_loader { diff --git a/Engine/cpp/runtime/core/logging/logging.cpp b/Engine/cpp/runtime/core/logging/logging.cpp new file mode 100644 index 0000000..9077115 --- /dev/null +++ b/Engine/cpp/runtime/core/logging/logging.cpp @@ -0,0 +1,504 @@ +module; + +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include + +module core.logging; + +import core.stdtypes; + +namespace draco::core::logging +{ + static constexpr usize QUEUE_CAPACITY = 8192; + static constexpr usize QUEUE_MASK = QUEUE_CAPACITY - 1; + + struct Node + { + std::atomic sequence; + LogMessage msg; + }; + + alignas(64) static Node g_queue[QUEUE_CAPACITY]; + alignas(64) static std::atomic g_enqueue_pos{0}; + alignas(64) static std::atomic g_dequeue_pos{0}; + alignas(64) static std::atomic g_dispatched_pos{0}; + + static std::atomic g_dropped_count{0}; + static std::atomic g_written_count{0}; + + static std::atomic g_running{false}; + static std::atomic g_accepting_logs{false}; + static std::atomic g_active_producers{0}; + + static std::thread g_worker_thread; + static std::mutex g_worker_mutex; + static std::condition_variable g_worker_cv; + + static std::atomic g_global_verbosity{LogVerbosity::Info}; + + struct SinkList + { + std::vector> sinks; + }; + + static std::atomic> g_sink_list{ nullptr }; + static std::mutex g_sink_update_mutex; + static std::mutex g_sink_io_mutex; + static std::atomic g_roll_seq{0}; + + static std::chrono::steady_clock::time_point g_start_time; + + namespace internal + { + void (*fatal_hook)() = []() { std::abort(); }; + } + + static u32 get_thread_id() + { + return static_cast(std::hash{}(std::this_thread::get_id())); + } + + static u64 uptime_ns() + { + return std::chrono::duration_cast(std::chrono::steady_clock::now() - g_start_time).count(); + } + + static const char* verbosity_to_string(LogVerbosity v) + { + switch (v) + { + case LogVerbosity::Fatal: return "FATAL"; + case LogVerbosity::Error: return "ERROR"; + case LogVerbosity::Warning: return "WARNING"; + case LogVerbosity::Display: return "DISPLAY"; + case LogVerbosity::Info: return "INFO"; + case LogVerbosity::Verbose: return "VERBOSE"; + case LogVerbosity::VeryVerbose: return "VERYVERBOSE"; + } + return "UNKNOWN"; + } + + static void enqueue(const LogMessage& msg) + { + usize pos = g_enqueue_pos.load(std::memory_order_relaxed); + while (true) + { + Node* node = &g_queue[pos & QUEUE_MASK]; + usize seq = node->sequence.load(std::memory_order_acquire); + intptr_t diff = static_cast(seq) - static_cast(pos); + + if (diff == 0) + { + if (g_enqueue_pos.compare_exchange_weak(pos, pos + 1, std::memory_order_relaxed)) + { + node->msg = msg; + node->msg.sequence_id = pos; + + bool was_empty = (pos == g_dequeue_pos.load(std::memory_order_relaxed)); + + node->sequence.store(pos + 1, std::memory_order_release); + + if (was_empty) + { + std::lock_guard lock(g_worker_mutex); + g_worker_cv.notify_one(); + } + return; + } + } + else if (diff < 0) + { + g_dropped_count.fetch_add(1, std::memory_order_relaxed); + return; + } + else + { + pos = g_enqueue_pos.load(std::memory_order_relaxed); + } + } + } + + static bool dequeue(LogMessage& msg) + { + usize pos = g_dequeue_pos.load(std::memory_order_relaxed); + Node* node = &g_queue[pos & QUEUE_MASK]; + usize seq = node->sequence.load(std::memory_order_acquire); + intptr_t diff = static_cast(seq) - static_cast(pos + 1); + + if (diff == 0) + { + msg = node->msg; + g_dequeue_pos.store(pos + 1, std::memory_order_relaxed); + node->sequence.store(pos + QUEUE_CAPACITY, std::memory_order_release); + return true; + } + return false; + } + + static void worker_loop() + { + while (true) + { + bool running = g_running.load(std::memory_order_acquire); + std::shared_ptr current_sinks = g_sink_list.load(std::memory_order_acquire); + + LogMessage msg; + bool popped = false; + + while (dequeue(msg)) + { + if (current_sinks) + { + for (auto& sink : current_sinks->sinks) + { + if (sink) { + std::lock_guard io_lock(g_sink_io_mutex); + sink->write(msg); + } + } + } + g_written_count.fetch_add(1, std::memory_order_relaxed); + g_dispatched_pos.store(g_dequeue_pos.load(std::memory_order_relaxed), std::memory_order_release); + popped = true; + } + + if (!running && !popped) + { + if (g_dequeue_pos.load(std::memory_order_relaxed) == g_enqueue_pos.load(std::memory_order_acquire)) + { + break; + } + } + + if (!popped) + { + std::unique_lock lock(g_worker_mutex); + if (!g_running.load(std::memory_order_acquire)) continue; + if (g_dequeue_pos.load(std::memory_order_relaxed) != g_enqueue_pos.load(std::memory_order_acquire)) continue; + + g_worker_cv.wait_for(lock, std::chrono::milliseconds(2)); + } + } + } + + void init() + { + if (g_worker_thread.joinable()) { + return; + } + + g_start_time = std::chrono::steady_clock::now(); + g_global_verbosity.store(LogVerbosity::Info); + g_dropped_count.store(0); + g_written_count.store(0); + g_active_producers.store(0); + + for (usize i = 0; i < QUEUE_CAPACITY; i++) + { + g_queue[i].sequence.store(i, std::memory_order_relaxed); + } + g_enqueue_pos.store(0); + g_dequeue_pos.store(0); + g_dispatched_pos.store(0); + + { + std::lock_guard lock(g_sink_update_mutex); + g_sink_list.store(std::make_shared(), std::memory_order_release); + } + + g_accepting_logs.store(true, std::memory_order_release); + g_running.store(true, std::memory_order_release); + g_worker_thread = std::thread(worker_loop); + } + + void shutdown() + { + if (g_accepting_logs.exchange(false, std::memory_order_release)) + { + while (g_active_producers.load(std::memory_order_acquire) > 0) + { + std::this_thread::yield(); + } + + flush(); + + g_running.store(false, std::memory_order_release); + { + std::lock_guard lock(g_worker_mutex); + g_worker_cv.notify_all(); + } + if (g_worker_thread.joinable()) + { + g_worker_thread.join(); + } + + std::lock_guard lock(g_sink_update_mutex); + g_sink_list.store(nullptr, std::memory_order_release); + } + } + + void flush() + { + usize target = g_enqueue_pos.load(std::memory_order_acquire); + while (g_dispatched_pos.load(std::memory_order_acquire) < target) + { + std::this_thread::yield(); + } + + std::shared_ptr current_sinks = g_sink_list.load(std::memory_order_acquire); + if (current_sinks) + { + for (auto& sink : current_sinks->sinks) + { + if (sink) { + std::lock_guard io_lock(g_sink_io_mutex); + sink->flush(); + } + } + } + } + + void set_global_verbosity(LogVerbosity v) + { + g_global_verbosity.store(v); + } + + void add_sink(std::shared_ptr sink) + { + if (!sink) return; + std::lock_guard lock(g_sink_update_mutex); + auto current = g_sink_list.load(std::memory_order_acquire); + auto next = std::make_shared(); + if (current) + { + next->sinks = current->sinks; + } + if (std::find(next->sinks.begin(), next->sinks.end(), sink) == next->sinks.end()) + { + next->sinks.push_back(sink); + } + g_sink_list.store(next, std::memory_order_release); + } + + void remove_sink(std::shared_ptr sink) + { + if (!sink) return; + std::lock_guard lock(g_sink_update_mutex); + auto current = g_sink_list.load(std::memory_order_acquire); + auto next = std::make_shared(); + if (current) + { + next->sinks = current->sinks; + } + auto it = std::find(next->sinks.begin(), next->sinks.end(), sink); + if (it != next->sinks.end()) + { + next->sinks.erase(it); + } + g_sink_list.store(next, std::memory_order_release); + } + + namespace internal + { + void enqueue_log(LogVerbosity verbosity, const LogCategory& category, const std::source_location& loc, std::string_view text) noexcept + { + if (!g_accepting_logs.load(std::memory_order_acquire)) return; + + g_active_producers.fetch_add(1, std::memory_order_acquire); + if (!g_accepting_logs.load(std::memory_order_acquire)) + { + g_active_producers.fetch_sub(1, std::memory_order_release); + return; + } + + LogVerbosity target_verbosity = g_global_verbosity.load(std::memory_order_relaxed); + i32 category_override = category.override_verbosity.load(std::memory_order_relaxed); + if (category_override >= 0) + { + target_verbosity = static_cast(category_override); + } + + if (verbosity <= target_verbosity) + { + LogMessage msg{}; + msg.uptime_ns = uptime_ns(); + msg.thread_id = get_thread_id(); + msg.verbosity = verbosity; + msg.category = &category; + msg.location = loc; + + const usize len = std::min(text.size(), MaxLogMessageLength - 1); + std::memcpy(msg.text, text.data(), len); + msg.text[len] = '\0'; + + enqueue(msg); + } + + g_active_producers.fetch_sub(1, std::memory_order_release); + } + + [[noreturn]] void execute_fatal(const LogCategory& category, const std::source_location& loc, std::string_view text) + { + LogMessage msg{}; + msg.uptime_ns = uptime_ns(); + msg.thread_id = get_thread_id(); + msg.verbosity = LogVerbosity::Fatal; + msg.category = &category; + msg.location = loc; + + const usize len = std::min(text.size(), MaxLogMessageLength - 1); + std::memcpy(msg.text, text.data(), len); + msg.text[len] = '\0'; + + f64 uptime_s = static_cast(msg.uptime_ns) / 1'000'000'000.0; + std::println("[FATAL] [{:.6f}] [{}]: {}", uptime_s, category.name, msg.text); + + std::shared_ptr current_sinks = g_sink_list.load(std::memory_order_acquire); + if (current_sinks) + { + for (auto& sink : current_sinks->sinks) + { + if (sink) + { + std::lock_guard io_lock(g_sink_io_mutex); + sink->write(msg); + sink->flush(); + } + } + } + + internal::fatal_hook(); + std::abort(); + } + } + + LoggerMetrics get_metrics() + { + LoggerMetrics m{}; + m.messages_written = g_written_count.load(std::memory_order_relaxed); + m.messages_dropped = g_dropped_count.load(std::memory_order_relaxed); + + usize ep = g_enqueue_pos.load(std::memory_order_relaxed); + usize dp = g_dequeue_pos.load(std::memory_order_relaxed); + m.queue_depth = (ep >= dp) ? (ep - dp) : 0; + + auto current = g_sink_list.load(std::memory_order_acquire); + m.active_sinks = current ? static_cast(current->sinks.size()) : 0; + m.uptime_ns = uptime_ns(); + return m; + } + + void ConsoleSink::write(const LogMessage& msg) + { + f64 uptime_s = static_cast(msg.uptime_ns) / 1'000'000'000.0; + std::println("[{}] [{:.6f}] [{}] {}", verbosity_to_string(msg.verbosity), uptime_s, msg.category->name, msg.text); + } + + void ConsoleSink::flush() + { + std::fflush(stdout); + } + + struct FileSink::Impl { + std::ofstream stream; + }; + + FileSink::FileSink(const std::filesystem::path& path) : m_impl(std::make_unique()) + { + m_impl->stream.open(path, std::ios::out | std::ios::app); + } + + FileSink::~FileSink() = default; + + void FileSink::write(const LogMessage& msg) + { + if (m_impl->stream.is_open()) + { + m_impl->stream << "[" << verbosity_to_string(msg.verbosity) << "] [" << msg.category->name << "] " << msg.text << "\n"; + } + } + + void FileSink::flush() + { + if (m_impl->stream.is_open()) m_impl->stream.flush(); + } + + struct RollingFileSink::Impl { + std::filesystem::path base_path; + usize max_file_size; + usize current_size{0}; + std::ofstream stream; + + void roll_file() { + if (stream.is_open()) + stream.close(); + + auto now = std::chrono::system_clock::now(); + auto time = std::chrono::system_clock::to_time_t(now); + std::tm tm_buf{}; + +#if defined(_WIN32) + localtime_s(&tm_buf, &time); +#else + localtime_r(&time, &tm_buf); +#endif + std::stringstream ss; + ss << std::put_time(&tm_buf, "%Y%m%d_%H%M%S") << "_" << g_roll_seq.fetch_add(1, std::memory_order_relaxed); + + std::string ext = base_path.extension().string(); + std::string stem = base_path.stem().string(); + auto parent = base_path.parent_path(); + + std::filesystem::path new_path = parent / (stem + "_" + ss.str() + ext); + stream.open(new_path, std::ios::out | std::ios::trunc); + current_size = 0; + } + }; + + RollingFileSink::RollingFileSink(const std::filesystem::path& base_path, usize max_file_size) : m_impl(std::make_unique()) + { + m_impl->base_path = base_path; + m_impl->max_file_size = max_file_size; + m_impl->roll_file(); + } + RollingFileSink::~RollingFileSink() = default; + + void RollingFileSink::write(const LogMessage& msg) + { + if (!m_impl->stream.is_open()) + return; + + std::stringstream ss; + ss << "[" << verbosity_to_string(msg.verbosity) << "] [" << msg.category->name << "] " << msg.text << "\n"; + std::string str = ss.str(); + + if (m_impl->current_size + str.size() > m_impl->max_file_size) + { + m_impl->roll_file(); + } + + m_impl->stream << str; + m_impl->current_size += str.size(); + m_impl->stream.flush(); + } + + void RollingFileSink::flush() + { + if (m_impl->stream.is_open()) m_impl->stream.flush(); + } +} diff --git a/Engine/cpp/runtime/core/logging/logging.cppm b/Engine/cpp/runtime/core/logging/logging.cppm new file mode 100644 index 0000000..d96bb04 --- /dev/null +++ b/Engine/cpp/runtime/core/logging/logging.cppm @@ -0,0 +1,148 @@ +module; + +#include +#include +#include +#include +#include +#include +#include +#include +#include + +export module core.logging; + +import core.stdtypes; + +export namespace draco::core::logging +{ + inline constexpr usize MaxLogMessageLength = 512; + + enum class LogVerbosity : u8 + { + Fatal, + Error, + Warning, + Display, + Info, + Verbose, + VeryVerbose + }; + + struct LogCategory + { + const char* name; + mutable std::atomic override_verbosity{ -1 }; + }; + + struct LogMessage + { + u64 sequence_id; + u64 uptime_ns; + u32 thread_id; + + LogVerbosity verbosity; + const LogCategory* category; + + std::source_location location; + + char text[MaxLogMessageLength]; + }; + + struct ILogSink + { + virtual ~ILogSink() = default; + virtual void write(const LogMessage& msg) = 0; + virtual void flush() = 0; + }; + + class ConsoleSink final : public ILogSink + { + public: + void write(const LogMessage& msg) override; + void flush() override; + }; + + class FileSink final : public ILogSink + { + private: + struct Impl; + std::unique_ptr m_impl; + public: + FileSink(const std::filesystem::path& path); + ~FileSink() override; + + void write(const LogMessage& msg) override; + void flush() override; + }; + + class RollingFileSink final : public ILogSink + { + private: + struct Impl; + std::unique_ptr m_impl; + public: + RollingFileSink(const std::filesystem::path& base_path, usize max_file_size); + ~RollingFileSink() override; + + void write(const LogMessage& msg) override; + void flush() override; + }; + + struct LoggerMetrics + { + u64 messages_written; + u64 messages_dropped; + u64 queue_depth; + u32 active_sinks; + u64 uptime_ns; + }; + + namespace internal + { + extern void (*fatal_hook)(); + void enqueue_log(LogVerbosity verbosity, const LogCategory& category, const std::source_location& loc, std::string_view text) noexcept; + [[noreturn]] void execute_fatal(const LogCategory& category, const std::source_location& loc, std::string_view text); + } + + void init(); + void shutdown(); + void flush(); + + void set_global_verbosity(LogVerbosity verbosity); + + void add_sink(std::shared_ptr sink); + void remove_sink(std::shared_ptr sink); + + LoggerMetrics get_metrics(); + + template + struct LogFormatString + { + std::format_string fmt; + std::source_location loc; + + template + requires std::constructible_from, T> + consteval LogFormatString(const T& s, std::source_location l = std::source_location::current()) + : fmt(s), loc(l) {} + }; + + template + void log(LogVerbosity verbosity, const LogCategory& category, LogFormatString...> fmt, Args&&... args) noexcept + { + char buffer[MaxLogMessageLength]; + auto result = std::format_to_n(buffer, MaxLogMessageLength - 1, fmt.fmt, std::forward(args)...); + *result.out = '\0'; + internal::enqueue_log(verbosity, category, fmt.loc, buffer); + } + + template + [[noreturn]] void fatal(const LogCategory& category, LogFormatString...> fmt, Args&&... args) + { + char buffer[MaxLogMessageLength]; + auto result = std::format_to_n(buffer, MaxLogMessageLength - 1, fmt.fmt, std::forward(args)...); + *result.out = '\0'; + internal::execute_fatal(category, fmt.loc, buffer); + } +} diff --git a/Engine/cpp/runtime/core/logging/logging.test.cpp b/Engine/cpp/runtime/core/logging/logging.test.cpp new file mode 100644 index 0000000..021b378 --- /dev/null +++ b/Engine/cpp/runtime/core/logging/logging.test.cpp @@ -0,0 +1,374 @@ +#define DOCTEST_CONFIG_IMPLEMENT_WITH_MAIN +#include + +#include +#include +#include +#include +#include +#include +#include +#include + +import core.logging; +import core.stdtypes; + +inline const draco::core::logging::LogCategory LogTest{"Test"}; +inline const draco::core::logging::LogCategory LogRendering{"Rendering"}; +inline const draco::core::logging::LogCategory LogPhysics{"Physics"}; + +namespace draco::core::logging +{ + namespace + { + struct TestSink final : ILogSink + { + std::atomic write_count{0}; + std::atomic flush_count{0}; + std::mutex last_mutex; + LogMessage last{}; + draco::u64 expected_seq{0}; + + void write(const LogMessage& msg) override + { + std::lock_guard lock(last_mutex); + last = msg; + write_count.fetch_add(1); + + if (msg.verbosity != LogVerbosity::Fatal) + { + REQUIRE(msg.sequence_id == expected_seq); + expected_seq++; + } + } + + void flush() override + { + flush_count.fetch_add(1); + } + }; + + void wait_for_condition(auto&& fn, int timeout_ms = 2000) + { + using namespace std::chrono; + auto start = steady_clock::now(); + while (!fn()) + { + if (duration_cast(steady_clock::now() - start).count() > timeout_ms) + break; + std::this_thread::sleep_for(std::chrono::milliseconds(1)); + } + } + } +} + +TEST_CASE("Logger init and shutdown do not crash") +{ + using namespace draco::core::logging; + init(); + shutdown(); +} + +TEST_CASE("Logger dispatches messages to sinks (async)") +{ + using namespace draco::core::logging; + init(); + + auto sink = std::make_shared(); + add_sink(sink); + + log(LogVerbosity::Info, LogTest, "Hello Logging"); + + wait_for_condition([&] { return sink->write_count.load() >= 1; }); + + REQUIRE(sink->write_count.load() == 1); + REQUIRE(sink->last.category == &LogTest); + REQUIRE(sink->last.verbosity == LogVerbosity::Info); + REQUIRE(std::string_view(sink->last.text) == "Hello Logging"); + + shutdown(); +} + +TEST_CASE("Logger flush calls sink flush and acts as a safe barrier") +{ + using namespace draco::core::logging; + init(); + + auto sink = std::make_shared(); + add_sink(sink); + + log(LogVerbosity::Info, LogTest, "Barrier Test"); + flush(); + + REQUIRE(sink->write_count.load() == 1); + REQUIRE(sink->flush_count.load() == 1); + + shutdown(); +} + +TEST_CASE("Logger generates monotonically increasing sequence ids") +{ + using namespace draco::core::logging; + init(); + + auto sink = std::make_shared(); + add_sink(sink); + + log(LogVerbosity::Info, LogTest, "A"); + log(LogVerbosity::Info, LogTest, "B"); + log(LogVerbosity::Info, LogTest, "C"); + + flush(); + + REQUIRE(sink->write_count.load() == 3); + REQUIRE(sink->last.sequence_id == 2); + + shutdown(); +} + +TEST_CASE("Logger respects global verbosity filter") +{ + using namespace draco::core::logging; + init(); + + auto sink = std::make_shared(); + add_sink(sink); + + set_global_verbosity(LogVerbosity::Warning); + + log(LogVerbosity::Info, LogTest, "Hidden"); + log(LogVerbosity::Error, LogTest, "Visible"); + + flush(); + + REQUIRE(sink->write_count.load() == 1); + + shutdown(); +} + +TEST_CASE("Logger handles multiple sinks and removal") +{ + using namespace draco::core::logging; + init(); + + auto a = std::make_shared(); + auto b = std::make_shared(); + + add_sink(a); + add_sink(b); + + log(LogVerbosity::Info, LogTest, "Multi Sink"); + flush(); + + REQUIRE(a->write_count.load() == 1); + REQUIRE(b->write_count.load() == 1); + + remove_sink(b); + log(LogVerbosity::Info, LogTest, "Only A"); + flush(); + + REQUIRE(a->write_count.load() == 2); + REQUIRE(b->write_count.load() == 1); + + shutdown(); +} + +TEST_CASE("Async System Stress Test - Dropping Allowed") +{ + using namespace draco::core::logging; + init(); + + auto sink = std::make_shared(); + add_sink(sink); + + constexpr int NUM_THREADS = 16; + constexpr int MSG_PER_THREAD = 100000; + + std::vector threads; + threads.reserve(NUM_THREADS); + + for (int i = 0; i < NUM_THREADS; ++i) + { + threads.emplace_back([i]() { + for (int j = 0; j < MSG_PER_THREAD; ++j) + { + log(LogVerbosity::Info, LogTest, "Stress Test Message"); + } + }); + } + + for (auto& t : threads) + { + t.join(); + } + + flush(); + + LoggerMetrics m = get_metrics(); + REQUIRE(m.messages_written + m.messages_dropped == NUM_THREADS * MSG_PER_THREAD); + REQUIRE(sink->write_count.load() == m.messages_written); + + shutdown(); +} + +TEST_CASE("Logger handles Queue Overflow gracefully") +{ + using namespace draco::core::logging; + init(); + + auto sink = std::make_shared(); + add_sink(sink); + + for (int i = 0; i < 50000; ++i) + { + log(LogVerbosity::Info, LogTest, "Spam"); + } + + flush(); + + LoggerMetrics m = get_metrics(); + REQUIRE(m.messages_written + m.messages_dropped == 50000); + + shutdown(); +} + +struct FatalTestException {}; + +TEST_CASE("Fatal path writes directly and aborts") +{ + using namespace draco::core::logging; + init(); + + auto sink = std::make_shared(); + add_sink(sink); + + auto previous_fatal_hook = draco::core::logging::internal::fatal_hook; + + struct FatalHookRestore final { + void (**slot)(); + void (*old_value)(); + ~FatalHookRestore() { *slot = old_value; } + } fatal_hook_restore{&draco::core::logging::internal::fatal_hook, previous_fatal_hook}; + + draco::core::logging::internal::fatal_hook = [] { throw FatalTestException{}; }; + + bool caught = false; + try + { + fatal(LogTest, "Fatal crash {}!", 123); + } + catch (const FatalTestException&) + { + caught = true; + } + + CHECK(caught); + CHECK(sink->write_count.load() == 1); + CHECK(sink->flush_count.load() == 1); + CHECK(std::string_view(sink->last.text) == "Fatal crash 123!"); + + shutdown(); +} + +TEST_CASE("Logging drops silently after shutdown") +{ + using namespace draco::core::logging; + init(); + + auto sink = std::make_shared(); + add_sink(sink); + + shutdown(); + + log(LogVerbosity::Info, LogTest, "Post-shutdown ignored"); + + REQUIRE(sink->write_count.load() == 0); +} + +TEST_CASE("File Sinks Validation") +{ + using namespace draco::core::logging; + init(); + + std::filesystem::path test_path = "test_output.log"; + std::filesystem::remove(test_path); + + { + auto file_sink = std::make_shared(test_path); + add_sink(file_sink); + + log(LogVerbosity::Error, LogTest, "File Sink Data"); + flush(); + remove_sink(file_sink); + } + + REQUIRE(std::filesystem::exists(test_path)); + std::ifstream infile(test_path); + std::string line; + std::getline(infile, line); + REQUIRE(line.find("File Sink Data") != std::string::npos); + + std::filesystem::remove(test_path); + shutdown(); +} + +TEST_CASE("Formatting and Macro Validation") +{ + using namespace draco::core::logging; + init(); + + auto sink = std::make_shared(); + add_sink(sink); + + log(LogVerbosity::Info, LogTest, "Player {} joined", 42); + flush(); + REQUIRE(std::string_view(sink->last.text) == "Player 42 joined"); + + log(LogVerbosity::Warning, LogTest, "FPS dropped to {}", 59.5); + flush(); + REQUIRE(std::string_view(sink->last.text) == "FPS dropped to 59.5"); + + shutdown(); +} + +TEST_CASE("Category Overrides Validation") +{ + using namespace draco::core::logging; + init(); + + auto sink = std::make_shared(); + add_sink(sink); + + set_global_verbosity(LogVerbosity::Info); + LogRendering.override_verbosity.store(static_cast(LogVerbosity::Verbose), std::memory_order_relaxed); + LogPhysics.override_verbosity.store(static_cast(LogVerbosity::Error), std::memory_order_relaxed); + + log(LogVerbosity::Verbose, LogRendering, "Render Pass"); + log(LogVerbosity::Info, LogPhysics, "Physics Update"); + + flush(); + + REQUIRE(sink->write_count.load() == 1); + REQUIRE(std::string_view(sink->last.text) == "Render Pass"); + + shutdown(); +} + +TEST_CASE("Performance Metrics Operations") +{ + using namespace draco::core::logging; + init(); + + auto sink = std::make_shared(); + add_sink(sink); + + log(LogVerbosity::Info, LogTest, "Metrics Check"); + flush(); + + LoggerMetrics m = get_metrics(); + REQUIRE(m.messages_written == 1); + REQUIRE(m.active_sinks == 1); + REQUIRE(m.uptime_ns > 0); + + shutdown(); +}