From d139534864843adc875bf9aebf288c59900f535c Mon Sep 17 00:00:00 2001 From: Aster Seker Date: Sun, 4 Oct 2026 00:39:09 +0300 Subject: [PATCH 1/2] test(bench): split async producer attribution probes Add focused probes for task construction, payload ownership, prebuilt queue admission, and dispatch without enqueueing. Keep the existing full-path measurements and document the new overlapping signals without changing production code. --- bench/producer_profile.cpp | 87 +++++++++++++++++++++++++++++++++++++- docs/benchmarks.md | 13 +++++- 2 files changed, 96 insertions(+), 4 deletions(-) diff --git a/bench/producer_profile.cpp b/bench/producer_profile.cpp index ee0abe3..3fdda7c 100644 --- a/bench/producer_profile.cpp +++ b/bench/producer_profile.cpp @@ -28,6 +28,7 @@ constexpr const char* kQueueBackend = "mutex_deque"; #endif std::uint64_t g_observer = 0; +std::atomic g_queue_completed{0}; std::size_t env_size(const char* name, std::size_t fallback) { if (const char* value = std::getenv(name)) { @@ -52,6 +53,7 @@ class ProfilingSink final : public logit::ILogger { public: enum class Mode { Synchronous, + ConstructTaskOnly, AsyncFullMessage, }; @@ -68,11 +70,16 @@ class ProfilingSink final : public logit::ILogger { } std::string payload = message; - logit::detail::TaskExecutor::get_instance().add_task( + std::function task = [this, payload = std::move(payload)]() mutable { g_observer += payload.size(); m_count.fetch_add(1, std::memory_order_relaxed); - }); + }; + if (m_mode == Mode::ConstructTaskOnly) { + task(); + return; + } + logit::detail::TaskExecutor::get_instance().add_task(std::move(task)); } std::string get_string_param(const logit::LoggerParam&) const override { return {}; } @@ -191,6 +198,67 @@ int main() { [](std::size_t) {}, warmup, total, repeats); std::cout << "case=logrecord_construct ns_per_call=" << record_ns << '\n'; + const double task_marker_ns = median_ns_per_call( + [](std::size_t count) { + for (std::size_t i = 0; i < count; ++i) { + std::function task = []() { ++g_observer; }; + task(); + } + }, + [](std::size_t) {}, warmup, total, repeats); + std::cout << "case=task_object_marker_only ns_per_call=" << task_marker_ns << '\n'; + + const double task_payload_ns = median_ns_per_call( + [](std::size_t count) { + for (std::size_t i = 0; i < count; ++i) { + std::string payload = kMessage; + std::function task = + [payload = std::move(payload)]() mutable { + g_observer += payload.size(); + }; + task(); + } + }, + [](std::size_t) {}, warmup, total, repeats); + std::cout << "case=task_object_full_message ns_per_call=" << task_payload_ns << '\n'; + + auto& task_executor = logit::detail::TaskExecutor::get_instance(); + const double queue_noop_ns = median_ns_per_call( + [&task_executor](std::size_t count) { + std::function task = []() { + g_queue_completed.fetch_add(1, std::memory_order_relaxed); + }; + for (std::size_t i = 0; i < count; ++i) { + task_executor.add_task(task); + } + }, + [&task_executor](std::size_t expected) { + task_executor.wait(); + const auto completed = g_queue_completed.load(std::memory_order_relaxed); + if (completed != expected) { + std::cerr << "prebuilt TaskExecutor completion mismatch\n"; + std::exit(7); + } + g_queue_completed.store(0, std::memory_order_relaxed); + }, warmup, total, repeats); + std::cout << "case=taskexecutor_enqueue_prebuilt_noop ns_per_call=" + << queue_noop_ns << '\n'; + + const double queue_payload_ns = median_ns_per_call( + [&task_executor](std::size_t count) { + for (std::size_t i = 0; i < count; ++i) { + std::string payload = kMessage; + task_executor.add_task( + [payload = std::move(payload)]() mutable { + g_observer += payload.size(); + }); + } + }, + [&task_executor](std::size_t) { task_executor.wait(); }, + warmup, total, repeats); + std::cout << "case=taskexecutor_enqueue_full_message ns_per_call=" + << queue_payload_ns << '\n'; + sink_ptr->set_mode(ProfilingSink::Mode::Synchronous); const double sync_ns = median_ns_per_call( log_prepared, @@ -205,6 +273,21 @@ int main() { warmup, total, repeats); std::cout << "case=logger_log_sync_null ns_per_call=" << sync_ns << '\n'; + sink_ptr->set_mode(ProfilingSink::Mode::ConstructTaskOnly); + const double dispatch_task_ns = median_ns_per_call( + log_prepared, + [&logger, sink_ptr](std::size_t expected) { + logger.wait(); + if (sink_ptr->count() != expected) { + std::cerr << "construct-only sink count mismatch\n"; + std::exit(8); + } + sink_ptr->reset_count(); + }, + warmup, total, repeats); + std::cout << "case=logger_log_construct_only_full ns_per_call=" + << dispatch_task_ns << '\n'; + sink_ptr->set_mode(ProfilingSink::Mode::AsyncFullMessage); auto task_completed = std::make_shared>(0); const double enqueue_ns = median_ns_per_call( diff --git a/docs/benchmarks.md b/docs/benchmarks.md index 811980f..ac6f884 100644 --- a/docs/benchmarks.md +++ b/docs/benchmarks.md @@ -257,10 +257,19 @@ overlap rather than form an additive decomposition: - `string_copy_only` measures copying the prepared 200-byte payload; - `logrecord_construct` measures construction of the same `LogRecord` shape used by `LogItAdapter`; +- `task_object_marker_only` measures local `std::function` construction and + invocation without a payload; +- `task_object_full_message` adds the 200-byte payload ownership and capture; +- `taskexecutor_enqueue_prebuilt_noop` measures admission of a prebuilt + no-op task, separating queue publication from task construction; +- `taskexecutor_enqueue_full_message` combines payload capture with queue + admission; +- `taskexecutor_enqueue_noop` retains the original shared-state capture probe; + it is intentionally not a pure queue-admission measurement; - `logger_log_sync_null` measures dispatch of a prepared record to a synchronous counting sink; -- `taskexecutor_enqueue_noop` measures direct `TaskExecutor` task admission with a no-op - completion task; +- `logger_log_construct_only_full` measures dispatch plus full task construction + while invoking the task inline instead of enqueueing it; - `logger_log_async_full_prepared` measures prepared-record dispatch plus full message task admission; - `prepared_record_plus_logger_async_full` adds per-call `LogRecord` From b9fee144d4d1cbeea840ab2c9b0c38c646ed61eb Mon Sep 17 00:00:00 2001 From: Aster Seker Date: Sun, 4 Oct 2026 16:48:50 +0300 Subject: [PATCH 2/2] docs(bench): clarify producer probe timing Rename the inline task probe to expose its invocation cost and document that prebuilt queue admission still includes by-value std::function ownership transfer. Keep the measurements explicit about what is inside the timed region. --- bench/producer_profile.cpp | 12 ++++++------ docs/benchmarks.md | 9 ++++++--- 2 files changed, 12 insertions(+), 9 deletions(-) diff --git a/bench/producer_profile.cpp b/bench/producer_profile.cpp index 3fdda7c..0bc8240 100644 --- a/bench/producer_profile.cpp +++ b/bench/producer_profile.cpp @@ -53,7 +53,7 @@ class ProfilingSink final : public logit::ILogger { public: enum class Mode { Synchronous, - ConstructTaskOnly, + ConstructAndInvokeTaskOnly, AsyncFullMessage, }; @@ -75,7 +75,7 @@ class ProfilingSink final : public logit::ILogger { g_observer += payload.size(); m_count.fetch_add(1, std::memory_order_relaxed); }; - if (m_mode == Mode::ConstructTaskOnly) { + if (m_mode == Mode::ConstructAndInvokeTaskOnly) { task(); return; } @@ -273,8 +273,8 @@ int main() { warmup, total, repeats); std::cout << "case=logger_log_sync_null ns_per_call=" << sync_ns << '\n'; - sink_ptr->set_mode(ProfilingSink::Mode::ConstructTaskOnly); - const double dispatch_task_ns = median_ns_per_call( + sink_ptr->set_mode(ProfilingSink::Mode::ConstructAndInvokeTaskOnly); + const double dispatch_construct_invoke_ns = median_ns_per_call( log_prepared, [&logger, sink_ptr](std::size_t expected) { logger.wait(); @@ -285,8 +285,8 @@ int main() { sink_ptr->reset_count(); }, warmup, total, repeats); - std::cout << "case=logger_log_construct_only_full ns_per_call=" - << dispatch_task_ns << '\n'; + std::cout << "case=logger_log_construct_and_invoke_full ns_per_call=" + << dispatch_construct_invoke_ns << '\n'; sink_ptr->set_mode(ProfilingSink::Mode::AsyncFullMessage); auto task_completed = std::make_shared>(0); diff --git a/docs/benchmarks.md b/docs/benchmarks.md index ac6f884..469cf7a 100644 --- a/docs/benchmarks.md +++ b/docs/benchmarks.md @@ -261,15 +261,18 @@ overlap rather than form an additive decomposition: invocation without a payload; - `task_object_full_message` adds the 200-byte payload ownership and capture; - `taskexecutor_enqueue_prebuilt_noop` measures admission of a prebuilt - no-op task, separating queue publication from task construction; + no-op task; the source callable is constructed once, but each `add_task` + call still includes by-value `std::function` copy/ownership transfer; - `taskexecutor_enqueue_full_message` combines payload capture with queue admission; - `taskexecutor_enqueue_noop` retains the original shared-state capture probe; it is intentionally not a pure queue-admission measurement; - `logger_log_sync_null` measures dispatch of a prepared record to a synchronous counting sink; -- `logger_log_construct_only_full` measures dispatch plus full task construction - while invoking the task inline instead of enqueueing it; +- `logger_log_construct_and_invoke_full` measures dispatch plus full task + construction and inline task-body invocation instead of enqueueing it; + the inline body is part of this timed producer-side probe and is not present + in the async producer timing region; - `logger_log_async_full_prepared` measures prepared-record dispatch plus full message task admission; - `prepared_record_plus_logger_async_full` adds per-call `LogRecord`