Skip to content

feat(client): optional tracing spans (feature tracing, off by default) - #11

Merged
casibbald merged 1 commit into
integration/microscaler-forkfrom
feat/client-tracing
Oct 27, 2026
Merged

casibbald merged 1 commit into
integration/microscaler-forkfrom
feat/client-tracing

Conversation

@casibbald

Copy link
Copy Markdown

What

This adds an optional tracing feature (off by default) that instruments the pooled Client. With the feature off, nothing is compiled in and tracing is not a dependency: the macros expand to nothing and the span fields are zero-sized. There is no OpenTelemetry dependency in either case. A tracing-opentelemetry subscriber, or any other subscriber, turns these spans into whatever it exports.

With the feature on, each request is a span tree. The target is may_minihttp::client.

span level covers fields
http_client_request INFO the whole request, until the body is read (or the response dropped) http.request.method, server.address, server.port, url.scheme, http.response.status_code, error.type, http.request.resend_count, may_minihttp.connection_reused
http_client_connect INFO DNS, connect and TLS handshake of a new connection server.address, server.port, error.type
http_client_write DEBUG writing the request
http_client_wait DEBUG request written → response head (time to first byte) http.response.status_code
http_client_body DEBUG reading the body http.response.body.size (buffered)

It also emits DEBUG events: pool_checkout (result = hit / miss / wait) and pool_evict (reason = expired / closed, count). Paths, query strings and headers are never recorded.

Parenting, and why spans are never entered. A may coroutine can yield in the middle of a request and resume on another thread. An entered span would then be "current" for whatever else runs on the first thread. The client therefore creates every span with an explicit parent and closes it by dropping it, which is all an exporter needs for the tree and the timing. The parent is chosen as follows:

  • RequestBuilder::parent_span(&span) makes span the parent.
  • Otherwise the parent is Span::current() at send time. That lookup is skipped when nothing records INFO.
  • RequestBuilder::request_span(&span) hands the client a caller's span to use as the request span. The client records the fields that span declares and opens its phase spans under it. A caller with its own per-request client span (its own name, kind and route) then gets one span per request, not two nested ones.
  • When the request span is disabled, no phase spans or events are created. Otherwise they would be exported as orphan roots.

Also in this PR:

  • ClientErrorKind::as_str() returns stable snake_case names (a metric label or error.type).
  • HttpClient::send_request is split into the crate-private write_request and read_response, so the write and the wait are timed separately. send_request behaves as before.
  • bench_client honours BENCH_TRACING=info|debug when built with the feature.

Overhead

bench_client pool against bench_server on loopback, 16 coroutines × 4000 requests, ms02. Seven interleaved rounds, medians shown. The client's CPU time per request comes from /usr/bin/time and is quantised at 0.16 µs per request; it is steadier than req/s on this shared host (load 19–23).

configuration req/s client CPU µs/req allocs/req
before (integration head, no feature) 144.3k 12.50 24.1
this PR, feature off 146.3k 12.34 24.1
feature on, no subscriber 141.0k 12.81 24.1
feature on, tracing-subscriber registry at INFO (request span; connect only on a miss) 135.9k 12.97 24.1
feature on, registry at DEBUG (all spans and events) 133.8k 13.28 24.1
  • Feature off: no measurable change.
  • Feature on: at INFO it costs about 0.5 µs of client CPU per request. On this loopback microbenchmark, where a pooled request costs only ~12.5 µs, that is ~4%. Against a real call it is far smaller. The consumer that motivated this measures it end to end with an OpenTelemetry layer, on a proxied call, in its own PR.
  • Allocations: none per request in any configuration. The registry pools span data.

The "feature on, no subscriber" row was measured before Span::current() was skipped when nothing records INFO. This PR includes that skip.

Tests

tests/client_tracing.rs (required-features = ["tracing"]), using a recording tracing-subscriber layer:

  • the exact span tree and fields of a first request (miss → connect) and a second (hit, reuse), under an explicit parent; no path or query string anywhere;
  • Span::current() as the default parent;
  • a streaming request span ends when the body ends, not when the response is dropped;
  • a refused connect records error.type on the connect and request spans;
  • nothing is emitted when the target is disabled;
  • at INFO only the request and connect spans exist;
  • a caller span can be the request span (fields recorded on it, phase spans under it);
  • a disabled request span gets no orphan children.

cargo fmt --check, clippy (default -D warnings; all features, all targets), and the full suite with all features (320 passed) and with default features, on Rust 1.99.0.

🤖 Generated with Claude Code

https://claude.ai/code/session_01Y3TSRmEZAYU6RBUXhkn7WF

With the feature on, each request through the pooled Client is a span
tree, target `may_minihttp::client`:

- http_client_request (INFO), the whole request until the body is read or
  the response dropped: http.request.method, server.address, server.port,
  url.scheme, http.response.status_code, error.type,
  http.request.resend_count, may_minihttp.connection_reused;
- http_client_connect (INFO), DNS + connect + TLS of a new connection;
- http_client_write, http_client_wait (time to first byte) and
  http_client_body (DEBUG);
- DEBUG events pool_checkout (hit/miss/wait) and pool_evict
  (expired/closed).

No paths, query strings or headers are recorded. The parent is the span
given to RequestBuilder::parent_span, else Span::current() at send.
RequestBuilder::request_span hands the client a caller's span to use as
the request span instead: the client records the fields that span
declares and opens its phase spans under it, so a caller with its own
per-request client span gets one span, not two. When the request span is
disabled, no phase spans or events are created (they would be orphan
roots). The client never enters a span: a may coroutine can yield
mid-request and resume on another thread, so spans get an explicit parent
and close on drop.

With the feature off there is no tracing dependency, the macros expand to
nothing and the span fields are zero-sized.

Also: ClientErrorKind::as_str(); HttpClient::send_request split into
crate-private write_request/read_response so the write and the wait are
timed separately; bench_client honours BENCH_TRACING=info|debug when built
with the feature.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01Y3TSRmEZAYU6RBUXhkn7WF
@casibbald
casibbald merged commit e8d17ee into integration/microscaler-fork Oct 27, 2026
18 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant