perf: benchmark public macro and logger hot path

.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
@@ -293,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'
@@ -319,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

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")

bench/BenchmarkValidation.hpp

@@ -0,0 +1,32 @@
+#pragma once
+
+#include <cstddef>
+#include <stdexcept>
+#include <string>
+
+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

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)

bench/adapters/SpdlogAdapter.cpp

@@ -3,7 +3,9 @@
 #ifdef LOGIT_BENCH_HAVE_SPDLOG
 
 #include <algorithm>
+#include <chrono>
 #include <cstdint>
+#include <cstdlib>
 #include <filesystem>
 #include <fstream>
 #include <limits>
@@ -12,6 +14,7 @@
 #include <condition_variable>
 #include <string>
 #include <string_view>
+#include <thread>
 
 #include <spdlog/async.h>
 #include <spdlog/async_logger.h>
@@ -31,6 +34,14 @@ namespace logit_bench {
         void configure(const Scenario& scenario, std::shared_ptr<LatencyRecorder> 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::size_t>(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<LatencyRecorder> m_recorder;
+        std::size_t m_delay_ms = 0;
 
         std::ofstream m_file;
         mutable std::mutex m_mutex;

bench/benchmark_validation_test.cpp

@@ -0,0 +1,30 @@
+#include "BenchmarkValidation.hpp"
+
+#include <stdexcept>
+#include <string>
+
+int main() {
+    using namespace logit_bench;
+
+    bool rejected_capacity = false;
+    try {
+        validate_queue_capacity(0);
+    } catch (const std::invalid_argument&) {
+        rejected_capacity = true;
+    }
+    if (!rejected_capacity) return 1;
+    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;
+    }
+    if (!rejected_legacy_schema) return 2;
+
+    validate_latency_csv_header(std::string(latency_csv_header()) + "\r");
+    validate_latency_csv_header(latency_csv_header());
+    return 0;
+}

bench/logger_hotpath_bench.cpp

@@ -0,0 +1,84 @@
+#include <atomic>
+#include <chrono>
+#include <cstddef>
+#include <cstdint>
+#include <cstdlib>
+#include <iostream>
+#include <memory>
+#include <string>
+
+#include <logit.hpp>
+
+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<int>(level), std::memory_order_relaxed);
+    }
+    logit::LogLevel get_log_level() const override {
+        return static_cast<logit::LogLevel>(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<std::size_t> m_count{0};
+    std::atomic<int> m_level{static_cast<int>(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::size_t>(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<CountingLogger>();
+    auto* sink_ptr = sink.get();
+    logit::Logger::get_instance().add_logger(
+        std::move(sink), std::make_unique<PassthroughFormatter>());
+
+    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::nanoseconds>(
+        std::chrono::steady_clock::now() - start).count();
+
+    if (sink_ptr->count() != iterations) return 1;
+    const double ns_per_call = static_cast<double>(elapsed) / static_cast<double>(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;
+}

bench/logit_bench.cpp

@@ -20,6 +20,7 @@
 #include <sstream>
 
 #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<std::size_t>(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();