perf(observed): benchmark emit paths with the production clock - #724
perf(observed): benchmark emit paths with the production clock#724Evgenii (Vaiz) wants to merge 2 commits into
Conversation
The benchmarks built every sink with `tick::SimpleClock::new_frozen()`, including the production-path emit benchmarks. A frozen clock is backed by `ClockControl`, which keeps its state in an `Arc<Mutex<State>>`, so every timestamp read paid mutex locking that production never pays, and the sink-construction benchmark additionally paid an `Arc<Mutex<..>>` allocation inside the measured closure. The numbers therefore described controlled-clock behaviour while being reported as production emit cost. Switch all twelve sink constructions to `tick::SimpleClock::new_system()`, the clock `Sink::new` documents for production, and hoist the clock out of the `construct_processor_free_sink` closure so it measures sink construction rather than clock construction. No benchmark here needs deterministic timestamps, so none stays frozen. Benchmark names, shapes and groups are unchanged. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Codecov Report✅ All modified and coverable lines are covered by tests. Additional details and impacted files@@ Coverage Diff @@
## main #724 +/- ##
========================================
Coverage 100.0% 100.0%
========================================
Files 587 587
Lines 63007 63131 +124
========================================
+ Hits 63007 63131 +124
Flags with carried forward coverage won't be shown. Click here to find out more. ☔ View full report in Codecov by Harness. 🚀 New features to boost your workflow:
|
|
There was a problem hiding this comment.
🟡 Changes recommended
One benchmark still includes avoidable per-iteration clock cloning overhead, which can skew the intended sink-construction measurement.
Once you've addressed the issues Copilot identified, you can request another Copilot review.
Pull request overview
This pull request updates the observed benchmark suite to measure event emission using the production clock implementation (tick::SimpleClock::new_system()) instead of the frozen test clock, so benchmark results better reflect real-world emit-path costs.
Changes:
- Switched multiple benchmark sinks from
SimpleClock::new_frozen()toSimpleClock::new_system(). - Adjusted the
construct_processor_free_sinkbenchmark to construct the clock once outside the measured closure and reuse it per iteration.
File summaries
| File | Description |
|---|---|
| crates/observed/benches/observed_benchmarks.rs | Updates benchmark sink construction to use the production clock and refines the sink-construction benchmark to avoid measuring clock creation. |
Review details
- Files reviewed: 1/1 changed files
- Comments generated: 1
- Review effort level: Lite
💡 Configure MCP servers for context-aware, tailored reviews. Learn more in the docs.
`Sink::new` takes `impl AsRef<SimpleClock>` and clones it internally, so `clock.clone()` at the call site made two clones per iteration inside the measured closure. Pass `&clock` instead. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
There was a problem hiding this comment.
🟢 Approval recommended
The changes are bench-only, align with Sink::new’s documented production clock usage, and introduce no evident correctness or design issues.
Review details
- Files reviewed: 1/1 changed files
- Comments generated: 0 new
- Review effort level: Lite
ok, but how about adding benchmark results to some readme.md file for future reference? |
🤖 Clawpilot here! Posted automatically by Clawpilot (an AI agent), not by a human. Please verify before acting.
What this changes
These benchmarks exist to answer one question: what does it cost to emit an event in production? They did not measure that. Every benchmark sink was built with
tick::SimpleClock::new_frozen(), the test clock. This change builds them withtick::SimpleClock::new_system(), the clock production uses. Refs AB#7757582.Why the clock matters
A sink stamps a timestamp on every event it dispatches. The clock therefore sits in the emit hot path, and its cost lands in every emit measurement.
The two clocks reach the time differently.
new_system()is a stateless enum variant that reads OS time directly.new_frozen()wraps aClockControl, which holds its state in anArc<Mutex<State>>(crates/tick/src/clock_control.rs). The frozen clock thus replaces a real OS time read with mutex locking. Neither cost resembles the other, so the published numbers described the test clock rather than the production emit path.One case was plainly wrong, not merely unrepresentative.
construct_processor_free_sinkbuilt a fresh frozen clock inside the measured closure. It allocated anArc<Mutex<..>>per iteration and counted that as sink-construction cost. Production never makes that allocation.Sink::newalready documents the split: pass the application clock in production, pass a frozen clock in tests for deterministic, Miri-safe timestamps (crates/observed/src/sink/core.rs). Benchmarks are not tests. None of these reads a timestamp value, so none belonged on the test side of that line.Details
SimpleClock::new_system():simple_log_2_fields,log_8_fields,log_with_body,log_of_metric_event,log_2_redacted_strings,emit_with_3_enrichments,emit_with_10_nested_enrichments,enrichment_vec_collect_3,emit_depth_0,emit_depth_5,construct_processor_free_sink, and the composite children ofpending_enriched_future_8_polls_composite_3.construct_processor_free_sinkbuilds the clock once outside the measured closure and clones it per iteration. A comment states why: an application owns one clock and hands it to every sink, so clock construction is not part of sink construction.Effects
construct_processor_free_sinkdrops by the per-iterationArc<Mutex<..>>.Cargo.tomlis unchanged. Theticktest-utildev-feature is still required, because unit tests undercrates/observed/srcstill use frozen clocks.Out of scope
log_4_fieldscontrol, no pooled-allocation alternative, no depth scaling model. The existingemit_alloccommentary is untouched.observedshould replaceall_the_timewith the workspacebenchmarkingcrate. That decision is open.crates/observed_macros*is untouched.Validation
cargo bench -p observed --features test-util --bench observed_benchmarks -- --testruns every benchmark once with the system clock. CI does not execute benchmarks, so this confirms the target still runs rather than only compiles.