Repository navigation
Conversation
Merging this PR will regress 16 benchmarks4 warnings, 1 note
Warning Please fix the performance issues or acknowledge them on CodSpeed. Performance Changes
Tip Investigate this regression by commenting Comparing |
ce1df9a to
dfb0562
Compare
[Medium impact] The PR appears safe to merge; no new actionable issue was established. SummaryAdds a separate
The shared-span timestamp race is fixed by keeping the greatest exit time under the lock.
|
31f47a5 to
1e3f5f8
Compare
1e3f5f8 to
36e7664
Compare
…try feature Add an opt-in `telemetry` feature to `codspeed` and `codspeed-divan-compat`. When `CODSPEED_OTEL_ENDPOINT` is set, `divan::main()` installs a global `tracing` subscriber that exports the spans and events emitted by benchmarks over OTLP/HTTP, filtered by `CODSPEED_TELEMETRY_FILTER` (defaults to `info`), and flushes them when the run ends. Spans from the exporter's own HTTP stack are always filtered out to avoid an export loop. Benchmarks that already set a global subscriber are left untouched; they can compose `divan::telemetry::layer()` into their own subscriber instead. The telemetry dependencies stay within MSRV and minimal versions. `reqwest` pulls `idna_adapter` 1.2.2 and the `icu_*` 2.x crates, which require rustc 1.88: they are resolved with the MSRV-aware fallback resolver so the lockfile builds on rustc 1.85. `sharded-slab` declares `lazy_static = "1"` but fails to build with 1.0.x, which breaks the minimal-versions check: an optional direct `lazy_static = "1.1"` dependency, enabled by the `telemetry` feature, raises the floor. Closes COD-3862 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Events were only recorded as span events, so a receiver got no logs signal and events emitted outside any span were lost. Export them as log records to `/v1/logs` instead, through the SDK batch log processor, carrying the trace and span IDs of the span they are emitted in. Spans no longer carry the events, which would otherwise be exported twice. The log bridge sets the event name of every record to the name of its `tracing` callsite, which `tracing` generates as `event <file>:<line>` for an event given no `name:`, and `log event` for a record of the `log` crate. In the OpenTelemetry logs data model a record with an event name is an event, so a log processor clears these generated names: only the events named at their callsite keep one. It compares the name with the record's own location, leaving any other name as is. The bridge's `experimental_metadata_attributes` feature is enabled for that location: the `code.filepath`, `code.lineno` and `code.namespace` attributes, which keep it exported once the name is cleared. Refs COD-3862 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Spans and log records carry wall clock times, which cannot be lined up exactly with the benchmark markers taken on the monotonic clock: the wall clock can be adjusted while the benchmarks run. With instrument hooks, each span carries the times it started and ended at on the clock of the markers as its `codspeed.monotonic_start_ns` and `codspeed.monotonic_end_ns` attributes, and each log record the time it was emitted at as `codspeed.monotonic_time_ns`. Their timestamps stay the wall clock times of the SDK, as standard tools expect. The OpenTelemetry layer takes the start time of a span when the `tracing` span is created, but only starts the OpenTelemetry span when it is first entered or closed, e.g., on the first poll of an instrumented future. A layer placed after it starts the span on creation, through `get_otel_context`, to set the start then. The OpenTelemetry layer takes the end time when the span is last exited, or closed if it never was, and ends the span when it is closed. Since the SDK only adds attributes, a layer placed before it records the time of the last exit, and sets the end once, when the span is closed. The SDK batch processors are now built with a queue of 65536 rather than the default 2048, so that a benchmark emitting on every iteration doesn't overflow it. Refs COD-3862 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…elemetry mode `tracing` spans and events weigh on the measurements of the code they instrument. Every build for the simulation, walltime and memory modes now passes `--cfg=codspeed_tracing_off`, behind which the `codspeed` crate depends on `tracing` with `max_level_off`: features unification compiles every span and event of the build out, dependencies included. Unlike `--features tracing/max_level_off`, it doesn't require each selected package to depend on `tracing` directly. `--keep-tracing` opts out, e.g. to benchmark a `tracing` subscriber. The new `telemetry` measurement mode builds the benchmarks to collect the telemetry they emit instead of measuring them: they run once like in simulation mode (`--cfg=codspeed`), keep `tracing`, and land in `target/codspeed/telemetry`. It builds along other modes, each with its own flags, e.g. `-m walltime,telemetry`. `--keep-tracing` is rejected when telemetry is the only mode, since it implies it. The telemetry build also passes `--cfg=codspeed_telemetry`. The dependencies exporting the telemetry move to a target table on that cfg, so the other builds don't compile them, even with the `telemetry` feature: a benchmark enabling it builds 31 crates of `codspeed` instead of 157 in measured builds. They only appear in the lockfile of the projects enabling the feature, as before. Without the cfg, `telemetry::init` and `telemetry::layer` return `None`, which keeps the API of the feature. CI checks the MSRV and minimal versions, and runs the telemetry tests, with the cfg. `release_max_level_*` features still take precedence over `max_level_off` in measured builds, since debug assertions are off. Refs COD-3862 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
`init` installs its subscriber with `tracing::subscriber::set_global_default`, which, unlike `tracing-subscriber`'s `init`, doesn't forward the records of the `log` crate to it: benchmarks and dependencies logging with `log` exported nothing. `init` now also installs `tracing-log`'s `LogTracer`, unless a `log` logger is already set. The records go through the same `EnvFilter` as events, by their `log` target, and the bridge reads their location from their normalized metadata, so they get the right `code.*` attributes. The `log event` name they are given is already cleared. `LogTracer` takes the max level of the subscriber, which the `log` macros check before anything else. The `filter_fn` filters of the layer gave it no hint, which lifted it to `TRACE`: they now hint `TRACE`, so that the `EnvFilter` hint is kept. `layer` stays free of global side effects, and documents that a subscriber of your own needs a `LogTracer` to receive `log` records. A test runs `init`, in a binary of its own since it sets process-wide state, against an in-process OTLP/HTTP receiver, and checks the records it decodes. Like the export, it is only built with `--cfg codspeed_telemetry`. Refs COD-3862 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
The first span of the process takes 20 to 30 µs longer than the next ones to go through the subscriber, and the first event about 10 µs longer. The first benchmark emitting them took that time, which delayed its telemetry from the start of its run. `init` now emits a span and an event once the subscriber is installed. They carry a `codspeed_warmup` field, which the processors in front of the exporters drop, and a target the filter always lets through at the `error` level, which keeps the max level `log` takes from the filter. Refs COD-3862 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Compiling `tracing` out of every measured build applied to all the users
of cargo-codspeed, telemetry or not: their measured binaries no longer
matched what they ship, and features unification made it all or nothing
for a build, so a single benchmark couldn't keep it. Without a
subscriber, which only the telemetry build installs, a disabled callsite
costs a runtime level check, as it does in production.
Drop `--cfg=codspeed_tracing_off`, the `max_level_off` dependency of the
`codspeed` crate behind it, and `--keep-tracing`. Every build now passes
`--cfg=codspeed_build`, next to `--cfg=codspeed_telemetry` in the
telemetry build, so that a project can compile `tracing` and `log` out
of its measured builds from its own manifest:
[target.'cfg(all(codspeed_build, not(codspeed_telemetry)))'.dev-dependencies]
tracing = { version = "0.1", features = ["max_level_off"] }
log = { version = "0.4", features = ["max_level_off"] }
The tracing tests check both are kept by default in every mode, and
that such a table compiles them out of the simulation and walltime
builds but not the telemetry one.
The `telemetry` module of `codspeed` becomes a folder: `mod.rs` picks
the export or its stand-in on `codspeed_telemetry` and re-exports
`init`, `layer` and `TelemetryGuard` by name. The export is split into
the public API and its setup (`export.rs`), the times on the clock of
the benchmark markers (`monotonic.rs`), and the warmup of the
subscriber with the filter dropping it from the export (`warmup.rs`).
- A single `MonotonicTimestampLayer`, before the OpenTelemetry layer,
replaces the start and end layers: it keeps the creation time in the
span's extensions and sets both attributes when the span is closed.
The OpenTelemetry span is no longer started as soon as the `tracing`
span is created.
- The monotonic times are read from
`InstrumentHooks::current_timestamp` directly, and are 0 without
instrument hooks instead of being left out.
- The event names `tracing` generates (`event <file>:<line>`,
`log event`) are exported as is, as the OpenTelemetry setup of a
project exports them in production. Nothing reads them yet.
- The crates filtered out of the export are those of the upstream
`basic-otlp` example of `opentelemetry-otlp`. Directives match
targets by prefix, so `hyper` also covers `hyper_util`, the one crate
of the HTTP stack emitting `tracing` events in this build.
The telemetry section of the divan_compat README is dropped: it is too
advanced for a quickstart, and will be documented on the docs site.
Refs COD-3862
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
36e7664 to
32008a4
Compare
The export of the telemetry only compiles with `--cfg codspeed_telemetry`, which no clippy hook set, so its code was built and tested in CI but never linted. Add a clippy hook setting the cfg through `build.rustflags`, so that cargo also resolves the dependencies of the `cfg(codspeed_telemetry)` target table. Refs COD-3862 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Export the traces and logs that divan benchmarks emit with
tracingandlog, for the telemetry mode of the CodSpeed runner (CodSpeedHQ/codspeed#589) to collect.Using it takes the
telemetryfeature ofcodspeed-divan-compatand a telemetry build:cargo codspeed build -m telemetry # or with other modes, e.g. -m simulation,telemetry codspeed run -m telemetry -- cargo codspeed runWhen
CODSPEED_OTEL_ENDPOINTis set,divan::main()installs atracingsubscriber exporting over OTLP/HTTP:tracingevents andlogrecords as logs, carrying the trace and span IDs of the span they are emitted in.CODSPEED_TELEMETRY_FILTERtakesEnvFilterdirectives,infoby default. Benchmarks that install their own subscriber adddivan::telemetry::layer()to it.cargo-codspeedA new
telemetrymeasurement mode builds the benchmarks to run once, like simulation. It can be built along other modes.Measured builds keep
tracingandlogas they are: without a subscriber, which only the telemetry build installs, a disabled callsite costs a runtime level check, as in production.Every build passes
--cfg=codspeed_build, and the telemetry build--cfg=codspeed_telemetrytoo, so that a project can compiletracingandlogout of its measured builds from its own manifest:The OpenTelemetry dependencies sit in a
cfg(codspeed_telemetry)target table. With the feature on, measured builds only addtracingandtracing-subscriberto the dependencies ofcodspeed(5 crates, against about 100 in the telemetry build), and a project without the feature gets nothing new in its lockfile.Timing
Spans and log records keep the wall clock times of the SDK. They also carry their times on the monotonic clock of the benchmark markers, which wall clock adjustments don't move: spans as
codspeed.monotonic_start_nsandcodspeed.monotonic_end_ns, log records ascodspeed.monotonic_time_ns. These are 0 without instrument hooks.Worth a careful look
crates/codspeed/src/telemetry/monotonic.rs.MonotonicTimestampLayercomes before the OpenTelemetry layer and takes the same moments it does: the start when thetracingspan is created, the end when it is last exited, or when it is closed if it was never entered. It sets both attributes when the span closes, before the OpenTelemetry layer ends and exports it. A span exited on several threads keeps its latest exit.TRACEas their max level, so thatLogTracerkeeps the level of theEnvFilter: without it,filter_fnlifted it toTRACE.initwarms the subscriber up with a span and an event that are not exported: the first span of the process took 18 to 31 µs longer than the next ones.hyper,tonic,h2,reqwest, as in the upstreambasic-otlpexample) is always filtered out, or exporting would emit more spans in an endless loop. Telemetry of these crates emitted by the benchmarks is lost with it.reqwestpullsicu_*2.x crates, which require rustc 1.88: they are resolved with the MSRV-aware fallback resolver.sharded-slabfails to build with thelazy_static1.0 that minimal-versions picks, hence alazy_static = "1.1"floor.crates/divan_compat/examples/benches/telemetry.rsemits telemetry in each of these ways: nested spans with events, an event outside of any span, records of thelogcrate, and nothing at all. The telemetry tests only build with--cfg codspeed_telemetry; CI runs them, and checks the MSRV and minimal versions, with it. Thecargo-codspeedtracing tests check thattracingandlogare kept in every mode, and that the manifest table above compiles them out of the simulation and walltime builds but not the telemetry one.The feature will be documented on the docs site rather than in the README.
Closes COD-3862