From 06dccc6c6ded9cd75800eca87a3fb57068e4b957 Mon Sep 17 00:00:00 2001 From: Aster Seker Date: Sat, 12 Sep 2026 20:00:48 +0300 Subject: [PATCH 1/5] perf(bench): add hot-path comparison and regression coverage Add a separate public LOGIT_INFO benchmark and a controlled legacy-versus-snapshot registry benchmark. Extract queue/CSV validation into testable helpers, add deterministic negative-path coverage, and strengthen the asynchronous flush test with a delayed sink. Run the new smoke targets in CI and document their measurement contracts. --- .github/workflows/ci.yml | 15 ++++- bench/BenchmarkValidation.hpp | 32 +++++++++++ bench/CMakeLists.txt | 23 ++++++++ bench/benchmark_validation_test.cpp | 31 ++++++++++ bench/logger_hotpath_bench.cpp | 84 ++++++++++++++++++++++++++++ bench/logit_bench.cpp | 20 ++----- bench/public_macro_bench.cpp | 87 +++++++++++++++++++++++++++++ bench/spdlog_flush_test.cpp | 71 ++++++++++++++++------- docs/benchmarks.md | 20 +++++++ include/logit_cpp/logit/Logger.hpp | 13 ++++- 10 files changed, 357 insertions(+), 39 deletions(-) create mode 100644 bench/BenchmarkValidation.hpp create mode 100644 bench/benchmark_validation_test.cpp create mode 100644 bench/logger_hotpath_bench.cpp create mode 100644 bench/public_macro_bench.cpp diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 08a266a..cec56ee 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -30,9 +30,22 @@ jobs: run: cmake -S . -B build-bench -DLOGIT_BENCH_ENABLE=ON -DLOGIT_BENCH_WITH_SPDLOG=ON -DCMAKE_BUILD_TYPE=Release -DCMAKE_CXX_STANDARD=${{ matrix.std }} -DLOGIT_WITH_SYSLOG=ON -DLOGIT_WITH_WIN_EVENT_LOG=OFF - name: Build benchmarks # if: ${{ github.event_name == 'pull_request' || (github.event_name == 'push' && github.ref == 'refs/heads/stable') }} - run: cmake --build build-bench --target logit_bench logit_bench_flush_test + run: cmake --build build-bench --target logit_bench logit_bench_flush_test logit_public_macro_bench logit_hotpath_bench logit_hotpath_bench_legacy benchmark_validation_test - name: Run spdlog async flush regression run: ./build-bench/logit_bench_flush_test + - name: Run public macro benchmark smoke + env: + LOGIT_PUBLIC_BENCH_TOTAL: 2000 + LOGIT_PUBLIC_BENCH_PRODUCERS: 4 + run: ./build-bench/logit_public_macro_bench + - name: Run benchmark validation tests + run: ./build-bench/benchmark_validation_test + - name: Run logger hot-path A/B smoke + env: + LOGIT_HOTPATH_BENCH_TOTAL: 20000 + run: | + ./build-bench/logit_hotpath_bench + ./build-bench/logit_hotpath_bench_legacy - name: Run latency benchmarks # if: ${{ github.event_name == 'pull_request' || (github.event_name == 'push' && github.ref == 'refs/heads/stable') }} timeout-minutes: 20 diff --git a/bench/BenchmarkValidation.hpp b/bench/BenchmarkValidation.hpp new file mode 100644 index 0000000..5fd739a --- /dev/null +++ b/bench/BenchmarkValidation.hpp @@ -0,0 +1,32 @@ +#pragma once + +#include +#include +#include + +namespace logit_bench { + +inline void validate_queue_capacity(std::size_t capacity) { + if (capacity == 0) { + throw std::invalid_argument( + "LOGIT_BENCH_QUEUE_CAPACITY must be greater than zero for a comparative benchmark"); + } +} + +inline const char* latency_csv_header() { + return "lib,async,sink,producers,msg_bytes,total,queue_capacity," + "p50_ns,p99_ns,p999_ns,throughput"; +} + +inline void validate_latency_csv_header(std::string header) { + if (!header.empty() && header.back() == '\r') { + header.pop_back(); + } + if (header != latency_csv_header()) { + throw std::runtime_error( + "Unsupported bench/results/latency.csv schema; rename or remove " + "the existing file before running this benchmark"); + } +} + +} // namespace logit_bench diff --git a/bench/CMakeLists.txt b/bench/CMakeLists.txt index a7e94f6..be08aa9 100644 --- a/bench/CMakeLists.txt +++ b/bench/CMakeLists.txt @@ -25,6 +25,29 @@ endforeach() target_link_libraries(logit_bench PRIVATE log-it-cpp::log-it-cpp) +add_executable(logit_public_macro_bench public_macro_bench.cpp) +target_compile_features(logit_public_macro_bench PRIVATE cxx_std_17) +target_link_libraries(logit_public_macro_bench PRIVATE log-it-cpp::log-it-cpp) +set_target_properties(logit_public_macro_bench PROPERTIES + RUNTIME_OUTPUT_DIRECTORY ${CMAKE_BINARY_DIR} +) + +add_executable(logit_hotpath_bench logger_hotpath_bench.cpp) +target_compile_features(logit_hotpath_bench PRIVATE cxx_std_17) +target_link_libraries(logit_hotpath_bench PRIVATE log-it-cpp::log-it-cpp) +set_target_properties(logit_hotpath_bench PROPERTIES RUNTIME_OUTPUT_DIRECTORY ${CMAKE_BINARY_DIR}) + +add_executable(logit_hotpath_bench_legacy logger_hotpath_bench.cpp) +target_compile_features(logit_hotpath_bench_legacy PRIVATE cxx_std_17) +target_compile_definitions(logit_hotpath_bench_legacy PRIVATE LOGIT_BENCH_LEGACY_REGISTRY=1) +target_link_libraries(logit_hotpath_bench_legacy PRIVATE log-it-cpp::log-it-cpp) +set_target_properties(logit_hotpath_bench_legacy PROPERTIES RUNTIME_OUTPUT_DIRECTORY ${CMAKE_BINARY_DIR}) + +add_executable(benchmark_validation_test benchmark_validation_test.cpp) +target_compile_features(benchmark_validation_test PRIVATE cxx_std_17) +set_target_properties(benchmark_validation_test PROPERTIES RUNTIME_OUTPUT_DIRECTORY ${CMAKE_BINARY_DIR}) +add_test(NAME benchmark_validation_test COMMAND benchmark_validation_test) + if(LOGIT_BENCH_WITH_SPDLOG) target_compile_definitions(logit_bench PRIVATE LOGIT_BENCH_HAVE_SPDLOG=1) if(NOT TARGET spdlog::spdlog) diff --git a/bench/benchmark_validation_test.cpp b/bench/benchmark_validation_test.cpp new file mode 100644 index 0000000..7559af9 --- /dev/null +++ b/bench/benchmark_validation_test.cpp @@ -0,0 +1,31 @@ +#include "BenchmarkValidation.hpp" + +#include +#include +#include + +int main() { + using namespace logit_bench; + + bool rejected_capacity = false; + try { + validate_queue_capacity(0); + } catch (const std::invalid_argument&) { + rejected_capacity = true; + } + assert(rejected_capacity); + validate_queue_capacity(1); + + bool rejected_legacy_schema = false; + try { + validate_latency_csv_header( + "lib,async,sink,producers,msg_bytes,total,p50_ns,p99_ns,p999_ns,throughput"); + } catch (const std::runtime_error&) { + rejected_legacy_schema = true; + } + assert(rejected_legacy_schema); + + validate_latency_csv_header(std::string(latency_csv_header()) + "\r"); + validate_latency_csv_header(latency_csv_header()); + return 0; +} diff --git a/bench/logger_hotpath_bench.cpp b/bench/logger_hotpath_bench.cpp new file mode 100644 index 0000000..d878344 --- /dev/null +++ b/bench/logger_hotpath_bench.cpp @@ -0,0 +1,84 @@ +#include +#include +#include +#include +#include +#include +#include +#include + +#include + +namespace { + +class CountingLogger final : public logit::ILogger { +public: + void log(const logit::LogRecord&, const std::string&) override { + m_count.fetch_add(1, std::memory_order_relaxed); + } + std::string get_string_param(const logit::LoggerParam&) const override { return {}; } + std::int64_t get_int_param(const logit::LoggerParam&) const override { return 0; } + double get_float_param(const logit::LoggerParam&) const override { return 0.0; } + void set_log_level(logit::LogLevel level) override { + m_level.store(static_cast(level), std::memory_order_relaxed); + } + logit::LogLevel get_log_level() const override { + return static_cast(m_level.load(std::memory_order_relaxed)); + } + void wait() override {} + std::size_t count() const { return m_count.load(std::memory_order_relaxed); } + +private: + std::atomic m_count{0}; + std::atomic m_level{static_cast(logit::LogLevel::LOG_LVL_TRACE)}; +}; + +class PassthroughFormatter final : public logit::ILogFormatter { +public: + void set_timestamp_offset(std::int64_t) override {} + std::string format(const logit::LogRecord& record) const override { return record.format; } + bool is_passthrough() const noexcept override { return true; } +}; + +std::size_t env_size(const char* name, std::size_t fallback) { + if (const char* value = std::getenv(name)) { + try { return static_cast(std::stoull(value)); } + catch (...) {} + } + return fallback; +} + +} // namespace + +int main() { + const std::size_t iterations = env_size("LOGIT_HOTPATH_BENCH_TOTAL", 200000); + auto sink = std::make_unique(); + auto* sink_ptr = sink.get(); + logit::Logger::get_instance().add_logger( + std::move(sink), std::make_unique()); + + logit::LogRecord record( + logit::LogLevel::LOG_LVL_INFO, 0, std::string(), -1, + std::string(), std::string("prepared message"), std::string(), -1, false, false); + + const auto start = std::chrono::steady_clock::now(); + for (std::size_t i = 0; i < iterations; ++i) { + logit::Logger::get_instance().log(record); + } + logit::Logger::get_instance().wait(); + const auto elapsed = std::chrono::duration_cast( + std::chrono::steady_clock::now() - start).count(); + + if (sink_ptr->count() != iterations) return 1; + const double ns_per_call = static_cast(elapsed) / static_cast(iterations); + std::cout << "logger-hotpath mode=" +#ifdef LOGIT_BENCH_LEGACY_REGISTRY + << "legacy"; +#else + << "snapshot"; +#endif + std::cout << " iterations=" << iterations + << " elapsed_ns=" << elapsed + << " ns_per_call=" << ns_per_call << '\n'; + return 0; +} diff --git a/bench/logit_bench.cpp b/bench/logit_bench.cpp index 390e75a..19e5bd9 100644 --- a/bench/logit_bench.cpp +++ b/bench/logit_bench.cpp @@ -20,6 +20,7 @@ #include #include "LatencyRecorder.hpp" +#include "BenchmarkValidation.hpp" #include "Scenario.hpp" #include "adapters/LogItAdapter.hpp" @@ -305,9 +306,7 @@ void append_csv( { namespace fs = std::filesystem; const fs::path csv_path{"bench/results/latency.csv"}; - const std::string expected_header = - "lib,async,sink,producers,msg_bytes,total,queue_capacity," - "p50_ns,p99_ns,p999_ns,throughput"; + const std::string expected_header = latency_csv_header(); fs::create_directories(csv_path.parent_path()); const bool write_header = !fs::exists(csv_path) || fs::file_size(csv_path) == 0; @@ -318,14 +317,7 @@ void append_csv( if (!in || !std::getline(in, header)) { throw std::runtime_error("Failed to read latency.csv schema header"); } - if (!header.empty() && header.back() == '\r') { - header.pop_back(); - } - if (header != expected_header) { - throw std::runtime_error( - "Unsupported bench/results/latency.csv schema; rename or remove " - "the existing file before running this benchmark"); - } + validate_latency_csv_header(header); } std::ofstream out(csv_path, std::ios::app); @@ -398,11 +390,7 @@ int main() { const std::size_t queue_capacity = get_env_size_t( "LOGIT_BENCH_QUEUE_CAPACITY", std::max(8192, total_messages * 2)); - if (queue_capacity == 0) { - throw std::invalid_argument( - "LOGIT_BENCH_QUEUE_CAPACITY must be greater than zero for " - "a comparative benchmark"); - } + validate_queue_capacity(queue_capacity); const BenchFilter filter = load_filter(); diff --git a/bench/public_macro_bench.cpp b/bench/public_macro_bench.cpp new file mode 100644 index 0000000..3c9b2b7 --- /dev/null +++ b/bench/public_macro_bench.cpp @@ -0,0 +1,87 @@ +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include + +#include + +namespace { + +class CountingLogger final : public logit::ILogger { +public: + void log(const logit::LogRecord&, const std::string&) override { + m_count.fetch_add(1, std::memory_order_relaxed); + } + std::string get_string_param(const logit::LoggerParam&) const override { return {}; } + std::int64_t get_int_param(const logit::LoggerParam&) const override { return 0; } + double get_float_param(const logit::LoggerParam&) const override { return 0.0; } + void set_log_level(logit::LogLevel level) override { m_level.store(static_cast(level)); } + logit::LogLevel get_log_level() const override { + return static_cast(m_level.load()); + } + void wait() override {} + std::size_t count() const { return m_count.load(std::memory_order_relaxed); } + +private: + std::atomic m_count{0}; + std::atomic m_level{static_cast(logit::LogLevel::LOG_LVL_TRACE)}; +}; + +class PassthroughFormatter final : public logit::ILogFormatter { +public: + void set_timestamp_offset(std::int64_t) override {} + std::string format(const logit::LogRecord& record) const override { return record.format; } + bool is_passthrough() const noexcept override { return true; } +}; + +std::size_t env_size(const char* name, std::size_t fallback) { + if (const char* value = std::getenv(name)) { + try { return static_cast(std::stoull(value)); } + catch (...) {} + } + return fallback; +} + +} // namespace + +int main() { + const std::size_t producers = env_size("LOGIT_PUBLIC_BENCH_PRODUCERS", 4); + const std::size_t total = env_size("LOGIT_PUBLIC_BENCH_TOTAL", 20000); + if (producers == 0 || total == 0) return 2; + + auto sink = std::make_unique(); + auto* sink_ptr = sink.get(); + logit::Logger::get_instance().add_logger( + std::move(sink), std::make_unique()); + + const auto start = std::chrono::steady_clock::now(); + std::vector workers; + workers.reserve(producers); + for (std::size_t producer = 0; producer < producers; ++producer) { + workers.emplace_back([producer, producers, total]() { + const std::size_t begin = (total * producer) / producers; + const std::size_t end = (total * (producer + 1)) / producers; + for (std::size_t i = begin; i < end; ++i) { + LOGIT_INFO("public macro message", i); + } + }); + } + for (auto& worker : workers) worker.join(); + logit::Logger::get_instance().wait(); + const auto elapsed = std::chrono::duration_cast( + std::chrono::steady_clock::now() - start).count(); + + if (sink_ptr->count() != total) return 1; + const double throughput = static_cast(total) * 1e9 / static_cast(elapsed); + std::cout << "public-macro producers=" << producers + << " total=" << total + << " elapsed_ns=" << elapsed + << " throughput=" << throughput << " msg/s\n"; + return 0; +} diff --git a/bench/spdlog_flush_test.cpp b/bench/spdlog_flush_test.cpp index 7def3fe..45f18d5 100644 --- a/bench/spdlog_flush_test.cpp +++ b/bench/spdlog_flush_test.cpp @@ -1,31 +1,60 @@ +#include +#include #include #include +#include +#include #include +#include -#include "LatencyRecorder.hpp" -#include "Scenario.hpp" -#include "adapters/SpdlogAdapter.hpp" +#include +#include +#include +#include int main() { - logit_bench::Scenario scenario; - scenario.async = true; - scenario.sink = logit_bench::SinkKind::Null; - scenario.producers = 1; - scenario.message_bytes = 1; - scenario.total_messages = 64; - scenario.queue_capacity = 8; + class DelayedSink final : public spdlog::sinks::sink { + public: + void log(const spdlog::details::log_msg&) override { + std::this_thread::sleep_for(std::chrono::milliseconds(2)); + m_seen.fetch_add(1, std::memory_order_release); + } + void set_pattern(const std::string&) override {} + void set_formatter(std::unique_ptr) override {} + void flush() override { + { + std::lock_guard lock(m_mutex); + ++m_flushes; + } + m_cv.notify_all(); + } + bool wait_for_flush(std::size_t expected, std::size_t count) { + std::unique_lock lock(m_mutex); + return m_cv.wait_for(lock, std::chrono::seconds(5), [&]() { + return m_flushes >= expected && m_seen.load(std::memory_order_acquire) == count; + }); + } + std::size_t seen() const { return m_seen.load(std::memory_order_acquire); } + private: + std::atomic m_seen{0}; + std::condition_variable m_cv; + std::mutex m_mutex; + std::size_t m_flushes = 0; + }; - logit_bench::SpdlogAdapter adapter; - auto recorder = std::make_shared( - scenario.total_messages); - adapter.set_recorder_handle(recorder); - adapter.prepare(scenario, *recorder); - - for (std::size_t i = 0; i < scenario.total_messages; ++i) { - const auto token = recorder->begin(true); - adapter.log(token, std::string_view("x", 1)); + constexpr std::size_t message_count = 32; + spdlog::init_thread_pool(8, 1); + auto sink = std::make_shared(); + auto logger = std::make_shared( + "flush-regression", sink, spdlog::thread_pool(), + spdlog::async_overflow_policy::block); + logger->set_level(spdlog::level::trace); + for (std::size_t i = 0; i < message_count; ++i) { + logger->info("delayed message {}", i); } - adapter.flush(); - return recorder->completed() == scenario.total_messages ? 0 : 1; + logger->flush(); + const bool complete = sink->wait_for_flush(1, message_count); + spdlog::shutdown(); + return complete ? 0 : 1; } diff --git a/docs/benchmarks.md b/docs/benchmarks.md index 9df75b8..a6fcfdc 100644 --- a/docs/benchmarks.md +++ b/docs/benchmarks.md @@ -85,6 +85,20 @@ The prepared-message/direct-dispatch pipeline and a true public macro benchmark calls `LOGIT_INFO(...)` are separate scenarios with different work contracts; their results must not be presented as one number. +`logit_public_macro_bench` is the focused public-API smoke benchmark. It invokes +`LOGIT_INFO(...)` from multiple producer threads and therefore includes argument +name parsing, `args_array` construction, formatting, and dispatch. Configure it +with `LOGIT_PUBLIC_BENCH_TOTAL` and `LOGIT_PUBLIC_BENCH_PRODUCERS`; its throughput +is reported separately from `latency.csv` and is intended for before/after +hot-path experiments on identical hardware. + +`logit_hotpath_bench` and `logit_hotpath_bench_legacy` provide a controlled A/B +measurement for the registry read path. Both run the same prepared `LogRecord` +workload; the legacy target is compiled with `LOGIT_BENCH_LEGACY_REGISTRY` and +uses the pre-optimization mutex-plus-copy path, while the default target uses +the immutable snapshot. Compare their `ns_per_call` output on the same run and +toolchain. This is a measurement harness, not a supported production option. + The prepared-message path is also the first target for the logger hot-path regression checks. Logger strategy lists are published as an immutable copy-on-write snapshot, so a normal dispatch no longer takes the registry lock @@ -94,3 +108,9 @@ existing formatter/backend execution mutex. That mutex remains intentional: custom formatters and backends are not assumed to be safe for concurrent invocation. Any future lock-elision experiment must advertise and test an explicit concurrency contract rather than infer one from a benchmark sink. + +The flush regression target uses an intentionally delayed asynchronous sink and +asserts that `flush()` does not return before every queued message has reached +that sink. `benchmark_validation_test` covers the comparative-protocol guardrails +(`queue_capacity=0` and legacy CSV schema rejection) without relying on packages +installed on the host. diff --git a/include/logit_cpp/logit/Logger.hpp b/include/logit_cpp/logit/Logger.hpp index f7dc3d7..8fb2a17 100644 --- a/include/logit_cpp/logit/Logger.hpp +++ b/include/logit_cpp/logit/Logger.hpp @@ -14,6 +14,7 @@ #include #include #include +#include #if __cplusplus >= 201703L #include @@ -41,6 +42,9 @@ namespace logit { /// Provides methods to log messages using these strategies and supports /// both synchronous and asynchronous logging. Class is thread-safe. class Logger { + struct LoggerStrategy; + using StrategyList = std::vector>; + public: /// \brief Retrieves singleton instance of Logger. @@ -163,8 +167,16 @@ namespace logit { if (m_shutdown.load(std::memory_order_acquire)) return; const bool targeted = record.logger_index >= 0; +#ifdef LOGIT_BENCH_LEGACY_REGISTRY + std::shared_ptr snapshot; + { + LoggerReadLock legacy_lock(m_loggers_mx); + snapshot.reset(new StrategyList(m_loggers)); + } +#else const auto snapshot = std::atomic_load_explicit( &m_loggers_snapshot, std::memory_order_acquire); +#endif if (!snapshot) return; if (targeted) { @@ -564,7 +576,6 @@ namespace logit { } std::vector> m_loggers; ///< Container for logger-formatter pairs. - using StrategyList = std::vector>; std::shared_ptr m_loggers_snapshot; ///< Immutable read-mostly strategy list. mutable LoggerMutex m_loggers_mx; ///< Protects access to logger strategies. std::atomic m_shutdown = ATOMIC_VAR_INIT(false); ///< Flag indicating if shutdown was requested. From 6567dfb6801f7700105bc91688ce7da7422f8565 Mon Sep 17 00:00:00 2001 From: Aster Seker Date: Sat, 12 Sep 2026 20:26:21 +0300 Subject: [PATCH 2/5] chore(deps): update TimeShield to v2 main Track the current TimeShield main commit and update LogIt++ includes to its canonical domain paths. Keep the existing TimeShield API usage and C++11 compatibility while consuming the reorganized formatter and parser headers. --- external/time-shield-cpp | 2 +- include/logit_cpp/logit/formatter/SimpleLogFormatter.hpp | 2 +- include/logit_cpp/logit/formatter/compiler/PatternCompiler.hpp | 2 +- include/logit_cpp/logit/loggers/FileLogger.hpp | 2 +- include/logit_cpp/logit/utils/VariableValue.hpp | 2 +- 5 files changed, 5 insertions(+), 5 deletions(-) diff --git a/external/time-shield-cpp b/external/time-shield-cpp index 21d6ca7..d5f1203 160000 --- a/external/time-shield-cpp +++ b/external/time-shield-cpp @@ -1 +1 @@ -Subproject commit 21d6ca767ca492aca14b883d16abe6066fe5267e +Subproject commit d5f1203f24341e4146af35d5bb36e762056d181f diff --git a/include/logit_cpp/logit/formatter/SimpleLogFormatter.hpp b/include/logit_cpp/logit/formatter/SimpleLogFormatter.hpp index df4b2c2..0b161aa 100644 --- a/include/logit_cpp/logit/formatter/SimpleLogFormatter.hpp +++ b/include/logit_cpp/logit/formatter/SimpleLogFormatter.hpp @@ -7,7 +7,7 @@ #include "ILogFormatter.hpp" #include "compiler/PatternCompiler.hpp" -#include +#include #include // for std::atomic namespace logit { diff --git a/include/logit_cpp/logit/formatter/compiler/PatternCompiler.hpp b/include/logit_cpp/logit/formatter/compiler/PatternCompiler.hpp index 706a27a..ec26756 100644 --- a/include/logit_cpp/logit/formatter/compiler/PatternCompiler.hpp +++ b/include/logit_cpp/logit/formatter/compiler/PatternCompiler.hpp @@ -5,7 +5,7 @@ /// \file PatternCompiler.hpp /// \brief Header file for the pattern compiler used in log formatting. -#include +#include #include #include #include diff --git a/include/logit_cpp/logit/loggers/FileLogger.hpp b/include/logit_cpp/logit/loggers/FileLogger.hpp index 1b4f7bf..c32a36e 100644 --- a/include/logit_cpp/logit/loggers/FileLogger.hpp +++ b/include/logit_cpp/logit/loggers/FileLogger.hpp @@ -21,7 +21,7 @@ #include #include #include -#include +#include namespace logit { diff --git a/include/logit_cpp/logit/utils/VariableValue.hpp b/include/logit_cpp/logit/utils/VariableValue.hpp index c13d23e..24e2569 100644 --- a/include/logit_cpp/logit/utils/VariableValue.hpp +++ b/include/logit_cpp/logit/utils/VariableValue.hpp @@ -5,7 +5,7 @@ /// \file VariableValue.hpp /// \brief Structure for storing variables of various types. -#include +#include #include #include #include From 1e058b39987442436b36d04a874de2614f34a84e Mon Sep 17 00:00:00 2001 From: Aster Seker Date: Sat, 12 Sep 2026 21:54:21 +0300 Subject: [PATCH 3/5] chore(deps): require TimeShield 2.0.0 Pin the minimum supported TimeShield version to the v2.0.0 release in build configuration, installed package metadata, and user documentation. The bundled submodule is already pinned to the matching v2.0.0 commit. --- CMakeLists.txt | 2 +- cmake/log-it-cppConfig.cmake.in | 2 +- docs/backends.md | 2 +- docs/installation.md | 2 +- 4 files changed, 4 insertions(+), 4 deletions(-) diff --git a/CMakeLists.txt b/CMakeLists.txt index 24dfd96..89aa029 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -38,7 +38,7 @@ endif() # Dependency: TimeShield if(NOT TARGET time_shield::time_shield) - find_package(TimeShield 1.0.6 QUIET CONFIG) + find_package(TimeShield 2.0.0 QUIET CONFIG) endif() if(NOT TARGET time_shield::time_shield) if(EXISTS "${CMAKE_CURRENT_SOURCE_DIR}/external/time-shield-cpp/CMakeLists.txt") diff --git a/cmake/log-it-cppConfig.cmake.in b/cmake/log-it-cppConfig.cmake.in index a832da1..ae969e1 100644 --- a/cmake/log-it-cppConfig.cmake.in +++ b/cmake/log-it-cppConfig.cmake.in @@ -2,7 +2,7 @@ include(CMakeFindDependencyMacro) if(NOT TARGET time_shield::time_shield) - find_dependency(TimeShield 1.0.6 CONFIG) + find_dependency(TimeShield 2.0.0 CONFIG) endif() if(@LOGIT_WITH_FMT@ AND NOT TARGET fmt::fmt) diff --git a/docs/backends.md b/docs/backends.md index 4fd8699..64bfa52 100644 --- a/docs/backends.md +++ b/docs/backends.md @@ -6,7 +6,7 @@ Choose a backend by delivery model, platform, and dependency requirements. Every backend implements `ILogger`; stored-log backends may additionally implement `ILogReader` and `ILogSubscriber`. -All LogIt++ builds require **TimeShield 1.0.6 or newer**. The dependency column +All LogIt++ builds require **TimeShield 2.0.0 or newer**. The dependency column below lists only feature-specific dependencies. | Backend | Enablement | Standard | Feature-specific dependency | Platform and packaging notes | diff --git a/docs/installation.md b/docs/installation.md index 028e658..4462a64 100644 --- a/docs/installation.md +++ b/docs/installation.md @@ -4,7 +4,7 @@ ## Requirements -LogIt++ requires CMake 3.18 or newer and **TimeShield 1.0.6 or newer**. The +LogIt++ requires CMake 3.18 or newer and **TimeShield 2.0.0 or newer**. The core library and most built-in backends use C++11. OTLP, the Prometheus HTTP server, and MDBX integrations require C++17. From a17befc5bd21694c24081864ec4135398efb6189 Mon Sep 17 00:00:00 2001 From: Aster Seker Date: Sun, 13 Sep 2026 00:41:13 +0300 Subject: [PATCH 4/5] fix(bench): address review regressions Keep the Logger benchmark compatibility path faithful to the pre-optimization stack-vector implementation and preserve white-box test access. Route the delayed flush regression through SpdlogAdapter, make validation checks active in Release, and document the public macro benchmark accurately. Run vcpkg validation against the current pull-request source with TimeShield 2.0.0 instead of combining a historical release port with the new dependency. --- .github/workflows/ci.yml | 23 ++++++-- bench/adapters/SpdlogAdapter.cpp | 15 +++++ bench/benchmark_validation_test.cpp | 5 +- bench/spdlog_flush_test.cpp | 88 +++++++++++++---------------- docs/backends.md | 2 +- docs/benchmarks.md | 5 +- docs/installation.md | 2 +- include/logit_cpp/logit/Logger.hpp | 21 +++++-- 8 files changed, 95 insertions(+), 66 deletions(-) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index cec56ee..17c9250 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -306,17 +306,32 @@ jobs: vcpkg vcpkg/downloads vcpkg/installed - key: ${{ runner.os }}-vcpkg-${{ env.VCPKG_TAG }}-${{ hashFiles('vcpkg-overlay/ports/**', 'external/time-shield-cpp/vcpkg-overlay/ports/**') }} + key: ${{ runner.os }}-vcpkg-${{ env.VCPKG_TAG }}-${{ github.sha }}-${{ hashFiles('vcpkg-overlay/ports/**', 'external/time-shield-cpp/vcpkg-overlay/ports/**') }} - name: Install vcpkg if: matrix.suite == 'vcpkg-install' && steps.cache-vcpkg.outputs.cache-hit != 'true' run: | git clone https://github.com/microsoft/vcpkg.git --branch $VCPKG_TAG --single-branch ./vcpkg/bootstrap-vcpkg.sh -disableMetrics - - name: Validate port + - name: Prepare current-source vcpkg port + if: matrix.suite == 'vcpkg-install' + env: + SOURCE_SHA: ${{ github.event.pull_request.head.sha || github.sha }} + run: | + set -euo pipefail + mkdir -p .ci/vcpkg-overlay/ports/log-it-cpp + cp vcpkg-overlay/ports/log-it-cpp/vcpkg.json .ci/vcpkg-overlay/ports/log-it-cpp/vcpkg.json + cp vcpkg-overlay/ports/log-it-cpp/portfile.cmake .ci/vcpkg-overlay/ports/log-it-cpp/portfile.cmake + archive_sha512=$(curl --fail --silent --show-error -L \ + "https://github.com/LimiNode/log-it-cpp/archive/${SOURCE_SHA}.tar.gz" | sha512sum | awk '{print $1}') + sed -i "s#REF .*#REF ${SOURCE_SHA}#; s#SHA512 .*#SHA512 ${archive_sha512}#" \ + .ci/vcpkg-overlay/ports/log-it-cpp/portfile.cmake + sed -i 's/"version-string": "1.0.1"/"version-string": "1.0.2-dev"/' \ + .ci/vcpkg-overlay/ports/log-it-cpp/vcpkg.json + - name: Validate current-source port if: matrix.suite == 'vcpkg-install' run: | ./vcpkg/vcpkg install log-it-cpp \ - --overlay-ports=vcpkg-overlay/ports \ + --overlay-ports=.ci/vcpkg-overlay/ports \ --overlay-ports=external/time-shield-cpp/vcpkg-overlay/ports - name: Configure consumer project if: matrix.suite == 'vcpkg-install' @@ -332,7 +347,7 @@ jobs: vcpkg vcpkg/downloads vcpkg/installed - key: ${{ runner.os }}-vcpkg-${{ env.VCPKG_TAG }}-${{ hashFiles('vcpkg-overlay/ports/**', 'external/time-shield-cpp/vcpkg-overlay/ports/**') }} + key: ${{ runner.os }}-vcpkg-${{ env.VCPKG_TAG }}-${{ github.sha }}-${{ hashFiles('vcpkg-overlay/ports/**', 'external/time-shield-cpp/vcpkg-overlay/ports/**') }} - name: Upload logs if: failure() uses: actions/upload-artifact@v4 diff --git a/bench/adapters/SpdlogAdapter.cpp b/bench/adapters/SpdlogAdapter.cpp index 2d282e9..b6170a6 100644 --- a/bench/adapters/SpdlogAdapter.cpp +++ b/bench/adapters/SpdlogAdapter.cpp @@ -3,7 +3,9 @@ #ifdef LOGIT_BENCH_HAVE_SPDLOG #include +#include #include +#include #include #include #include @@ -12,6 +14,7 @@ #include #include #include +#include #include #include @@ -31,6 +34,14 @@ namespace logit_bench { void configure(const Scenario& scenario, std::shared_ptr recorder) { m_sink = scenario.sink; m_recorder = std::move(recorder); + m_delay_ms = 0; + if (const char* delay = std::getenv("LOGIT_BENCH_SPDLOG_SINK_DELAY_MS")) { + try { + m_delay_ms = static_cast(std::stoull(delay)); + } catch (...) { + m_delay_ms = 0; + } + } if (m_sink == SinkKind::File) { std::filesystem::create_directories("bench/results"); @@ -44,6 +55,9 @@ namespace logit_bench { } void log(const spdlog::details::log_msg& msg) override { + if (m_delay_ms > 0) { + std::this_thread::sleep_for(std::chrono::milliseconds(m_delay_ms)); + } // Record sink-entry latency; file I/O happens below and is not // part of this completion marker. The slot is stored in // msg.source.line. @@ -92,6 +106,7 @@ namespace logit_bench { SinkKind m_sink = SinkKind::Null; std::shared_ptr m_recorder; + std::size_t m_delay_ms = 0; std::ofstream m_file; mutable std::mutex m_mutex; diff --git a/bench/benchmark_validation_test.cpp b/bench/benchmark_validation_test.cpp index 7559af9..2d19642 100644 --- a/bench/benchmark_validation_test.cpp +++ b/bench/benchmark_validation_test.cpp @@ -1,6 +1,5 @@ #include "BenchmarkValidation.hpp" -#include #include #include @@ -13,7 +12,7 @@ int main() { } catch (const std::invalid_argument&) { rejected_capacity = true; } - assert(rejected_capacity); + if (!rejected_capacity) return 1; validate_queue_capacity(1); bool rejected_legacy_schema = false; @@ -23,7 +22,7 @@ int main() { } catch (const std::runtime_error&) { rejected_legacy_schema = true; } - assert(rejected_legacy_schema); + if (!rejected_legacy_schema) return 2; validate_latency_csv_header(std::string(latency_csv_header()) + "\r"); validate_latency_csv_header(latency_csv_header()); diff --git a/bench/spdlog_flush_test.cpp b/bench/spdlog_flush_test.cpp index 45f18d5..ad54531 100644 --- a/bench/spdlog_flush_test.cpp +++ b/bench/spdlog_flush_test.cpp @@ -1,60 +1,48 @@ -#include -#include #include +#include #include -#include -#include -#include -#include +#include -#include -#include -#include -#include +#include "LatencyRecorder.hpp" +#include "Scenario.hpp" +#include "adapters/SpdlogAdapter.hpp" int main() { - class DelayedSink final : public spdlog::sinks::sink { - public: - void log(const spdlog::details::log_msg&) override { - std::this_thread::sleep_for(std::chrono::milliseconds(2)); - m_seen.fetch_add(1, std::memory_order_release); - } - void set_pattern(const std::string&) override {} - void set_formatter(std::unique_ptr) override {} - void flush() override { - { - std::lock_guard lock(m_mutex); - ++m_flushes; - } - m_cv.notify_all(); - } - bool wait_for_flush(std::size_t expected, std::size_t count) { - std::unique_lock lock(m_mutex); - return m_cv.wait_for(lock, std::chrono::seconds(5), [&]() { - return m_flushes >= expected && m_seen.load(std::memory_order_acquire) == count; - }); - } - std::size_t seen() const { return m_seen.load(std::memory_order_acquire); } - private: - std::atomic m_seen{0}; - std::condition_variable m_cv; - std::mutex m_mutex; - std::size_t m_flushes = 0; - }; +#ifdef _WIN32 + _putenv_s("LOGIT_BENCH_SPDLOG_SINK_DELAY_MS", "2"); +#else + setenv("LOGIT_BENCH_SPDLOG_SINK_DELAY_MS", "2", 1); +#endif - constexpr std::size_t message_count = 32; - spdlog::init_thread_pool(8, 1); - auto sink = std::make_shared(); - auto logger = std::make_shared( - "flush-regression", sink, spdlog::thread_pool(), - spdlog::async_overflow_policy::block); - logger->set_level(spdlog::level::trace); - for (std::size_t i = 0; i < message_count; ++i) { - logger->info("delayed message {}", i); + logit_bench::Scenario scenario; + scenario.async = true; + scenario.sink = logit_bench::SinkKind::Null; + scenario.producers = 1; + scenario.message_bytes = 1; + scenario.total_messages = 32; + scenario.queue_capacity = 8; + + auto recorder = std::make_shared( + scenario.total_messages); + logit_bench::SpdlogAdapter adapter; + adapter.set_recorder_handle(recorder); + adapter.prepare(scenario, *recorder); + + for (std::size_t i = 0; i < scenario.total_messages; ++i) { + const auto token = recorder->begin(true); + adapter.log(token, std::string_view("x", 1)); } - logger->flush(); - const bool complete = sink->wait_for_flush(1, message_count); - spdlog::shutdown(); + // SpdlogAdapter::flush() must wait for the worker-side flush marker. No + // additional wait is allowed here: completion is the adapter contract. + adapter.flush(); + const bool complete = recorder->completed() == scenario.total_messages; + adapter.set_recorder_handle(nullptr); + +#ifdef _WIN32 + _putenv_s("LOGIT_BENCH_SPDLOG_SINK_DELAY_MS", ""); +#else + unsetenv("LOGIT_BENCH_SPDLOG_SINK_DELAY_MS"); +#endif return complete ? 0 : 1; } diff --git a/docs/backends.md b/docs/backends.md index 64bfa52..66b4ea8 100644 --- a/docs/backends.md +++ b/docs/backends.md @@ -6,7 +6,7 @@ Choose a backend by delivery model, platform, and dependency requirements. Every backend implements `ILogger`; stored-log backends may additionally implement `ILogReader` and `ILogSubscriber`. -All LogIt++ builds require **TimeShield 2.0.0 or newer**. The dependency column +All LogIt++ builds require **TimeShield 2.0.x (minimum 2.0.0)**. The dependency column below lists only feature-specific dependencies. | Backend | Enablement | Standard | Feature-specific dependency | Platform and packaging notes | diff --git a/docs/benchmarks.md b/docs/benchmarks.md index a6fcfdc..7053d86 100644 --- a/docs/benchmarks.md +++ b/docs/benchmarks.md @@ -87,7 +87,10 @@ their results must not be presented as one number. `logit_public_macro_bench` is the focused public-API smoke benchmark. It invokes `LOGIT_INFO(...)` from multiple producer threads and therefore includes argument -name parsing, `args_array` construction, formatting, and dispatch. Configure it +name parsing, `args_array` construction, and dispatch. Its passthrough formatter +intentionally bypasses formatter work, so this is a public macro +record-construction + dispatch benchmark rather than a formatting benchmark. +Configure it with `LOGIT_PUBLIC_BENCH_TOTAL` and `LOGIT_PUBLIC_BENCH_PRODUCERS`; its throughput is reported separately from `latency.csv` and is intended for before/after hot-path experiments on identical hardware. diff --git a/docs/installation.md b/docs/installation.md index 4462a64..f965ae3 100644 --- a/docs/installation.md +++ b/docs/installation.md @@ -4,7 +4,7 @@ ## Requirements -LogIt++ requires CMake 3.18 or newer and **TimeShield 2.0.0 or newer**. The +LogIt++ requires CMake 3.18 or newer and **TimeShield 2.0.x (minimum 2.0.0)**. The core library and most built-in backends use C++11. OTLP, the Prometheus HTTP server, and MDBX integrations require C++17. diff --git a/include/logit_cpp/logit/Logger.hpp b/include/logit_cpp/logit/Logger.hpp index 8fb2a17..64b265f 100644 --- a/include/logit_cpp/logit/Logger.hpp +++ b/include/logit_cpp/logit/Logger.hpp @@ -42,6 +42,7 @@ namespace logit { /// Provides methods to log messages using these strategies and supports /// both synchronous and asynchronous logging. Class is thread-safe. class Logger { + private: struct LoggerStrategy; using StrategyList = std::vector>; @@ -168,20 +169,28 @@ namespace logit { const bool targeted = record.logger_index >= 0; #ifdef LOGIT_BENCH_LEGACY_REGISTRY - std::shared_ptr snapshot; + StrategyList legacy_snapshot; { LoggerReadLock legacy_lock(m_loggers_mx); - snapshot.reset(new StrategyList(m_loggers)); + if (targeted) { + if (record.logger_index < static_cast(m_loggers.size())) { + legacy_snapshot.push_back(m_loggers[record.logger_index]); + } + } else { + legacy_snapshot = m_loggers; + } } + const StrategyList* strategies = &legacy_snapshot; #else const auto snapshot = std::atomic_load_explicit( &m_loggers_snapshot, std::memory_order_acquire); + const StrategyList* strategies = snapshot ? snapshot.get() : nullptr; #endif - if (!snapshot) return; + if (!strategies) return; if (targeted) { - if (record.logger_index >= static_cast(snapshot->size())) return; - const auto& strategy = (*snapshot)[record.logger_index]; + if (record.logger_index >= static_cast(strategies->size())) return; + const auto& strategy = (*strategies)[record.logger_index]; if (!strategy) return; std::lock_guard exec_lock(strategy->exec_mx); @@ -193,7 +202,7 @@ namespace logit { return; } - for (const auto& strategy : *snapshot) { + for (const auto& strategy : *strategies) { if (!strategy) continue; std::lock_guard exec_lock(strategy->exec_mx); From 194f4cf6b63737d2e696b5451dfa532edc0e0e14 Mon Sep 17 00:00:00 2001 From: Aster Seker Date: Sun, 13 Sep 2026 14:18:33 +0300 Subject: [PATCH 5/5] test(bench): cover targeted legacy registry dispatch Use the compact legacy snapshot correctly when a targeted record selects a non-zero logger index. Add a dedicated two-logger regression test compiled with the legacy benchmark path, and keep the production immutable snapshot indexing unchanged. --- include/logit_cpp/logit/Logger.hpp | 11 +++- tests/CMakeLists.txt | 4 ++ tests/logger_legacy_targeted_path_test.cpp | 58 ++++++++++++++++++++++ 3 files changed, 71 insertions(+), 2 deletions(-) create mode 100644 tests/logger_legacy_targeted_path_test.cpp diff --git a/include/logit_cpp/logit/Logger.hpp b/include/logit_cpp/logit/Logger.hpp index 64b265f..6d180a6 100644 --- a/include/logit_cpp/logit/Logger.hpp +++ b/include/logit_cpp/logit/Logger.hpp @@ -181,16 +181,23 @@ namespace logit { } } const StrategyList* strategies = &legacy_snapshot; + // The targeted legacy snapshot contains only the selected strategy, + // so dispatch must address its sole element rather than the original + // registry index. The production snapshot retains the full registry + // and continues to use record.logger_index below. + const int strategy_index = targeted ? 0 : record.logger_index; #else const auto snapshot = std::atomic_load_explicit( &m_loggers_snapshot, std::memory_order_acquire); const StrategyList* strategies = snapshot ? snapshot.get() : nullptr; + const int strategy_index = record.logger_index; #endif if (!strategies) return; if (targeted) { - if (record.logger_index >= static_cast(strategies->size())) return; - const auto& strategy = (*strategies)[record.logger_index]; + if (strategy_index < 0 || + strategy_index >= static_cast(strategies->size())) return; + const auto& strategy = (*strategies)[strategy_index]; if (!strategy) return; std::lock_guard exec_lock(strategy->exec_mx); diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index 35d082f..045abf3 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -46,6 +46,7 @@ else() log_filters_tags_test.cpp logger_shutdown_race_test.cpp logger_hot_path_state_test.cpp + logger_legacy_targeted_path_test.cpp logger_snapshot_read_path_test.cpp logger_clear_api_test.cpp memory_logger_backend_test.cpp @@ -129,6 +130,9 @@ else() if(test_name STREQUAL "file_logger_external_cmd_compression_test") set_tests_properties(${test_name} PROPERTIES SKIP_RETURN_CODE 77) endif() + if(test_name STREQUAL "logger_legacy_targeted_path_test") + target_compile_definitions(${test_name} PRIVATE LOGIT_BENCH_LEGACY_REGISTRY=1) + endif() if(LOGIT_WITH_OTLP AND test_name MATCHES "^otlp_http_logger_(integration|callback|gzip|zstd)_test$") target_include_directories(${test_name} PRIVATE "${CMAKE_CURRENT_SOURCE_DIR}/../external/kurlyk/external/Simple-Web-Server") diff --git a/tests/logger_legacy_targeted_path_test.cpp b/tests/logger_legacy_targeted_path_test.cpp new file mode 100644 index 0000000..3bb7a36 --- /dev/null +++ b/tests/logger_legacy_targeted_path_test.cpp @@ -0,0 +1,58 @@ +#include +#include +#include +#include +#include + +#include + +namespace { + +class CountingLogger final : public logit::ILogger { +public: + void log(const logit::LogRecord&, const std::string&) override { + count.fetch_add(1, std::memory_order_relaxed); + } + + std::string get_string_param(const logit::LoggerParam&) const override { return {}; } + std::int64_t get_int_param(const logit::LoggerParam&) const override { return 0; } + double get_float_param(const logit::LoggerParam&) const override { return 0.0; } + void set_log_level(logit::LogLevel level) override { + m_level.store(static_cast(level), std::memory_order_relaxed); + } + logit::LogLevel get_log_level() const override { + return static_cast(m_level.load(std::memory_order_relaxed)); + } + void wait() override {} + + std::atomic count{0}; + +private: + std::atomic m_level{static_cast(logit::LogLevel::LOG_LVL_TRACE)}; +}; + +} // namespace + +int main() { + auto first = std::unique_ptr(new CountingLogger()); + auto second = std::unique_ptr(new CountingLogger()); + CountingLogger* first_ptr = first.get(); + CountingLogger* second_ptr = second.get(); + + logit::Logger& logger = logit::Logger::get_instance(); + logger.add_logger( + std::move(first), + std::unique_ptr(new logit::SimpleLogFormatter("%v"))); + logger.add_logger( + std::move(second), + std::unique_ptr(new logit::SimpleLogFormatter("%v"))); + + const logit::LogRecord targeted( + logit::LogLevel::LOG_LVL_INFO, 0, std::string(), 0, std::string(), + std::string("targeted"), std::string(), 1, false, false); + logger.log(targeted); + + if (first_ptr->count.load(std::memory_order_relaxed) != 0) return 1; + if (second_ptr->count.load(std::memory_order_relaxed) != 1) return 2; + return 0; +}