Skip to content

Add request phase timing: Server-Timing subtimings and access telemetry - #1074

Open
jevansnyc wants to merge 29 commits into
mainfrom
feat/request-phase-timing
Open

Add request phase timing: Server-Timing subtimings and access telemetry#1074
jevansnyc wants to merge 29 commits into
mainfrom
feat/request-phase-timing

Conversation

@jevansnyc

@jevansnyc jevansnyc commented Aug 26, 2026

Copy link
Copy Markdown
Collaborator

Closes #1068. Implements the design in #1069 (docs/superpowers/specs/2026-08-24-request-phase-timing-design.md); the implementation plan and the spec ride in the branch.

What this adds

  • RequestTimings (core): always-on per-request phase collection; try_lock-only, saturating, infallible by construction.
  • Server-Timing header (ts-total, ts-appbuild, ts-filter, ts-geo, ts-kv, ts-origin, ts-template-cache) emitted at the send freeze point immediately before into_parts(), gated by observability.server_timing_enabled and restricted to conclusively private (private/no-store) responses so no shared cache can replay timings.
  • Phase spans: app build, pre-route filters (vendor-masked), geo, origin fetch, template-cache lookup, and EC KV via a TimedKvStore decorator implementing both PlatformKvStore and EcKvStore (latency-only; reads no payloads). Pull-sync stores are explicitly untimed.
  • Geo dedupe rider: one hostcall per request instead of two, via a GeoLookupState response extension (NotAttempted / Attempted / Resolved), 401 rule preserved.
  • Body-phase capture: stream duration via a counting writer (DeliveryResult::{Complete, Partial, Error}), auction-wait with explicit placement (in_stream at the seam, pre_header on buffered paths), response bytes, and a post-body request_elapsed_ms that excludes pull-sync and telemetry.
  • Access telemetry: an AccessTelemetrySnapshot built unconditionally at the freeze point, coarse PII-safe route templates (allowlist-reject; adversarially tested with EC ids, emails, search terms), and a confirmed-delivery Tinybird sink (bounded await, 2xx-validated, sampled by tinybird.access_sample_rate) that runs after client delivery and after pull-sync.
  • access_logs_raw schema aligned column-for-column with the row producer; sorting key (toDate(event_ts), service_id, publisher_domain, env, route_class, pop, status); there is no event_date column (Tinybird's Events API requires a JSONPath on every column, which a derived-default column cannot carry).
  • Axum adapter emits the header via an outer service wrapper (router-generated 404/405 covered); operator docs in docs/guide/configuration.md.

Review process

Eleven plan tasks, each implemented and passed an independent task-scoped review; two task-level fix rounds (settings validation coverage; a schema/producer nullability mismatch caught before it could quarantine rows at ingestion); a final whole-branch review on the full 13-commit diff followed by one fix wave (method-token normalization, a zero-sample-rate guard, geo write-back symmetry) and a clean scoped re-review.

Known limitations and rollout preconditions (disclosures)

  • The Tinybird schema was validated by inspection (no local tb CLI). Rollout must verify whether access_logs_raw was ever deployed remotely: the sorting key changed incompatibly from the reserved schema, so a deployed datasource means a versioned replacement with cutover, not an in-place edit. Panel queries need EXPLAIN validation against the new key.
  • Deploy ordering: binary first, config second; rollback config first, binary second. An older binary rejects a config carrying the [observability] table.
  • Adapter scope: Axum emits the header only (no telemetry rows, no ts-appbuild); Cloudflare and Spin collect but do not emit in v1. An earlier revision of this branch used std::time::Instant, which panics on wasm32-unknown-unknown and trapped every Cloudflare publisher request (the failing integration tests runs on this branch); the timing paths now use web_time::Instant, verified against the real workerd runtime locally.
  • The fronting delivery layer's Server-Timing pass-through is unverified until the first staging deploy (spec section 15 step 2, together with a MISS-then-HIT replay check).
  • DeliveryResult is collected but not yet emitted on any surface (intentional groundwork). Partial semantics are error-based only, per an explicit owner ruling: clean-but-early source truncation is out of scope permanently.
  • On the buffered Fastly path, request_elapsed_ms is stamped before send_to_client (no drive to time); streaming responses, the case that matters for stall diagnosis, include the full drive.
  • access_sample_rate = 1.0 is a diagnosis setting, not a steady state.

Generated with Claude Code

* Add request phase timing design spec (Server-Timing subtimings + access telemetry)

* Address review round 1: freeze point, template-cache naming, snapshot semantics, KV scope, geo carry, route template, sink confirmation, sampling and query model, config rollback

* Address review round 2: auction-wait placement modes, conservative private-only header emission, non-null sorting key with service identity, coarse publisher route template, telemetry snapshot and outage behavior, tinybird flag decoupling, adapter phase semantics

* Add request phase timing implementation plan

* Address engineer review: KV timing decorator, try_lock sampling, route metadata extension, adapter-derived env, typed template-cache state, adapter-owned emission context, per-mode delivery semantics, Axum outer wrapper
…ite-back in middleware

Three final-review fixes for access telemetry correctness:

- Normalize the HTTP method to an allowlist (GET/HEAD/POST/PUT/DELETE/
  PATCH/OPTIONS, else "other") inside access_event_row, so a client-
  controlled extension-method token can never inflate the LowCardinality
  method column, regardless of which adapter builds the row.
- Guard emit_access_telemetry_after_send against snapshots carrying a
  degraded sample_rate of 0.0 (captured on the app-state-build-failure
  fallback path), which could otherwise be sampled in by freshly reloaded
  settings and corrupt the sum(1.0/sample_rate) volume estimator.
- Mirror the geo lookup write-back from apply_entry_point_finalize_headers
  into FinalizeResponseMiddleware::handle, so a middleware-finalized
  response that resolved geo via fallback carries the resolved
  GeoLookupState for the access-telemetry snapshot instead of showing
  country "unknown".
@jevansnyc

Copy link
Copy Markdown
Collaborator Author

Post-review addition from the first live full-stack test (stackpop.com staging property): commit 7cf7d86 adds JSONPaths to every access_logs_raw column and replaces the event_date DEFAULT column with a toDate(event_ts) sorting-key expression. The Events API rejects NDJSON ingestion into a datasource without JSONPaths (400, discovered live; the confirmed-delivery check surfaced it via the drop warning), and once any column has a path every column needs one, which a DEFAULT column the producer never sends cannot satisfy. Spec section 9 updated in the same commit. Verified end to end: rows now flowing guest -> Events API -> ClickHouse with correct phase attribution and route-template normalization.

@prk-Jr prk-Jr left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Review summary

Verdict: Request changes.

The timing core is careful, well-reasoned work, and the Tinybird schema discipline is actually better than the PR body claims (verified below). The blocker is that this ships a reproducible crash-on-every-request regression on the Cloudflare adapter — with a one-line fix — plus a second instance of the same bug that CI structurally cannot catch, and a route normalizer that lets UUIDs, reset tokens and article slugs into a 30-day dataset.

Verification performed

Reviewed at head 7cf7d867 in a scratch worktree. Local gates, all run there:

Gate Result
cargo fmt --all -- --check PASS
cargo clippy-fastly / clippy-axum / clippy-cloudflare-wasm PASS
cargo test-fastly PASS (2235 + 186 + 21 + 4 + 2)
cargo test-axum PASS (25 + 14 + 1)
npx vitest run PASS — 45 files, 871 tests, 0 failures

gh pr checks 1074: 19 checks, 1 failingintegration tests. It is not in the branch-protection required set, so it will not block the merge button, but it is a genuine regression (root-caused inline).

Blocking

  1. CRITICALstd::time::Instant panics on wasm32-unknown-unknown; every publisher request on Cloudflare traps. Confirmed by reproducing the failing integration test locally, capturing the workerd stack trace, applying the fix, and re-running green (15.34s fail → 1.16s pass).
  2. HIGH — Two more Instant::now() calls on the auction path in publisher.rs. The integration fixture has [auction] enabled = false, so CI stays green even after finding 1 is fixed, while Cloudflare does dispatch auctions in production.
  3. HIGHpublisher_route_template admits UUIDs, opaque tokens and full article slugs into a 30-day dataset, contradicting the module's own doc comment.

Verified praise

  • Schema alignment is exactly right. Parsed all four artifacts: 26 datasource columns, 26 producer keys, 26 fixture keys, 26 FORWARD_QUERY columns — identical names and identical order, zero set difference.
  • try_lock-only is real. 7 lock acquisitions in request_timing.rs, all try_lock, zero .lock(). No method calls another while holding its guard, so no re-entrant self-deadlock.
  • Saturating arithmetic is completesaturating_add in record/record_auction_wait/CountingWriter::write, try_from(..).unwrap_or(MAX) in both duration_ms and record_buffered_delivery.
  • The Server-Timing cache-control gate holds on every emit path. Both emitters funnel through append_server_timing_if_private, and cache_control_value_has_directive is exact-name and quote-aware (not-private / no-storey correctly do not match). On Fastly the call sits after apply_terminal_response_effects and both finalize passes, so Cache-Control is settled and nothing mutates it afterwards.
  • [observability] back-compat is sound. Settings carries deny_unknown_fields and the pushed blob is a serde serialization of Settings, so skip_serializing_if = "ObservabilitySettings::is_default" genuinely keeps a default table out of the blob. TinybirdSettings has no deny_unknown_fields on either side, so the new auction_enabled key does not break rollback either.
  • The hand-rolled Axum serve is behaviourally equivalent to the upstream helper it replaces (Stores::default() makes every store-attach branch a no-op; the rest is mirrored exactly).

Audit of the PR body's stated limitations

Most disclosures check out. Four do not:

Disclosure Verdict
"The 27 vitest failures ... will block the JS CI gate" Stale. vitest is green on CI; locally 871 tests, 0 failures.
"Cloudflare and Spin collect but do not emit in v1" Badly understated. Spin is fine (wasm32-wasip1, std Instant works). Cloudflare does not collect — it traps on every publisher request.
"sorting key (event_date, service_id, ...)" Inaccurate. Actual key is toDate(event_ts), service_id, ...; event_date is not a column at all.
Failing Cloudflare integration job Unmentioned, and failing on all three runs of the branch.

Accurate as written: deploy/rollback ordering and the older-binary rejection mechanism (verified end to end), column-for-column schema alignment, the inspection-only Tinybird caveat and incompatible sorting-key change, Axum header-only semantics, DeliveryResult collected-but-unemitted, and the buffered-path request_elapsed_ms placement.

One nuance: "infallible by construction ... no panics" is accurate on locking and arithmetic, but slightly overstated given the unchecked phases[index] array access (noted inline, non-blocking).

Comment thread crates/trusted-server-core/src/request_timing.rs Outdated
Comment thread crates/trusted-server-core/src/publisher.rs Outdated
Comment thread crates/trusted-server-core/src/publisher.rs Outdated
Comment thread crates/trusted-server-core/src/access_telemetry.rs Outdated
Comment thread crates/trusted-server-core/src/access_telemetry.rs Outdated
Comment thread crates/trusted-server-adapter-fastly/src/main.rs Outdated
Comment thread crates/trusted-server-adapter-fastly/src/app.rs
Comment thread crates/trusted-server-core/src/request_timing.rs
Comment thread crates/trusted-server-adapter-fastly/src/tinybird.rs Outdated
Comment thread crates/trusted-server-core/examples/local_dev_config.rs Outdated
std::time::Instant::now() panics on wasm32-unknown-unknown, so every
publisher request on the Cloudflare adapter trapped when the timing
collector was constructed, and the two auction-wait sites would trap
once an auction dispatched. web_time re-exports std's Instant on every
other target, so Fastly, Axum, and Spin behavior is unchanged.

The publisher.rs sites are qualified locally because that module's
std Instant import still serves the pre-existing template-cache sites,
which are out of scope here.
The character allowlist alone does not bound identity: [a-z0-9_-] is
exactly the alphabet UUIDs, hex ids, reset tokens, and article slugs
are built from, and truncating to 32 characters still leaves a
globally unique prefix. A first segment now rejects whole to /other/*
when it exceeds 32 characters or carries more than 7 ASCII digits,
alongside the existing charset rejection. Year archives and
hyphenated section names still pass.

Extends the adversarial tests to the publisher-fallback path with
UUID, hex-id, token, and slug shapes, and fixes the stale event_date
reference in the row-builder doc.
- Gate building the access snapshot on tinybird.enabled and
  access_enabled, threaded through SendContext: a disabled deployment
  (the default) no longer pays env reads and String allocations on
  the pre-send path. DeliveryOutcome.snapshot becomes Option and the
  emitter treats None as nothing to send.
- Classify asset-fallback responses as route_class asset with the
  operator-configured route prefix as the template, instead of
  landing in the other/unknown bucket alongside 404s.
- Pin Phase::index() to PHASE_COUNT with a uniqueness-and-bounds
  test so a future variant fails the suite instead of panicking at
  runtime.
- Drop the tautological sampled-out emission test; the 0.0-rate
  behavior is covered by sampled_in_boundary_rates_are_unconditional.
- Clarify that the local dev config env var name genuinely triples
  trusted_server_config (prefix, store, key) rather than reading as
  a find/replace mistake.

@ChristianPavilonis ChristianPavilonis left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Summary

👍 Reviewed the exact head revision 38043d7464362d44519153a09fe850bacc256b58. The overall implementation direction is solid and all reported CI checks pass. I left seven actionable inline findings: three P2 telemetry-correctness issues and four P3 design/test-cleanup issues. There are no P0 or P1 findings.

Comment thread crates/trusted-server-adapter-fastly/src/tinybird.rs Outdated
Comment thread crates/trusted-server-core/src/publisher.rs
Comment thread docs/superpowers/specs/2026-08-24-request-phase-timing-design.md Outdated
Comment thread crates/trusted-server-adapter-axum/src/app.rs
Comment thread crates/trusted-server-adapter-fastly/src/main.rs
Comment thread crates/trusted-server-adapter-fastly/src/main.rs Outdated
Comment thread crates/trusted-server-adapter-fastly/src/main.rs

@ChristianPavilonis ChristianPavilonis left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Summary

🔧 Superseding my prior approval for 38043d7464362d44519153a09fe850bacc256b58: please address the seven inline findings already posted in the preceding review, particularly the three P2 telemetry-correctness issues, before merge. The existing inline threads remain the actionable review details and are not duplicated here.

@prk-Jr prk-Jr left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Summary

Substantial, carefully-built observability layer: 27 files, ~6.5k insertions, with a
freeze-point design that reads typed response extensions rather than the headers they
back, symmetric geo write-back on both finalize sites, and adversarial route-template
tests. All 19 GitHub checks pass and I reproduced every CI gate locally (2450 Fastly +
40 Axum + 39 Cloudflare + 79 Spin + 13 parity Rust tests, 871 JS tests).

One blocking finding, and it is a spec-conformance question rather than a crash risk:
publisher_route_template does not meet section 9 of
docs/superpowers/specs/2026-08-24-request-phase-timing-design.md for single-segment
paths. Everything else below is non-blocking.

I also checked the access sampler for modulo bias and it came back clean — see the
note in the cross-cutting section, since it is the kind of thing worth recording as
verified rather than leaving as an open question.

4 of the inline comments below carry a one-click GitHub suggestion. I applied all
four together in a scratch worktree at this head and verified them:
cargo fmt --all -- --check PASS, cargo clippy-fastly PASS (0 warnings),
trusted-server-core lib 2238 passed / 0 failed, trusted-server-adapter-fastly
185 passed / 0 failed.

Blocking

🔧 wrench

  • publisher_route_template keeps single-segment article slugs verbatim, against spec section 9 — inline at crates/trusted-server-core/src/access_telemetry.rs:189

Non-blocking

🤔 thinking

  • Server-Timing is an unrestricted client-visible latency oracle when enabled — inline at crates/trusted-server-core/src/request_timing.rs:285

♻️ refactor

  • HEADER_PHASES is a second hand-synced list with no test — inline at crates/trusted-server-core/src/request_timing.rs:419
  • #[allow(dead_code)] on the whole DeliveryOutcome masks two live fields — inline at crates/trusted-server-adapter-fastly/src/main.rs:571

🏕 camp site

  • route_class_renders_snake_case omits the new Asset variant — inline at crates/trusted-server-core/src/access_telemetry.rs:526

⛏ nitpick

  • Test name asserts the opposite of what it tests — inline at crates/trusted-server-core/src/access_telemetry.rs:439

👍 praise

  • Freeze point reads extensions, not headers — inline at crates/trusted-server-adapter-fastly/src/main.rs:797

Cross-cutting

  • Checked and clean: the access sampler is not modulo-biased. entropy = since_epoch.as_nanos() as u64 ^ outcome.bytes then entropy % 1_000_000 < rate * 1e6 looks like it could starve whole response-size classes, because the guest wall clock is microsecond-resolution and nanos is therefore always a multiple of 1000. It does not: as_nanos() since epoch is a ~61-bit monotonically advancing value, and % 1_000_000 folds the high bits back in, so residues walk the whole bucket range across requests. Measured at n=200,000 per size against the binomial 3σ band, with the clock spread over a realistic arrival window: fixed sizes of 200 B, 4 KB, 64 KB, 100 KB, ~1 MB and 1.5 MB all land inside the band at both access_sample_rate = 0.05 and 0.01; 0/400 random sizes are ever starved. Freezing the clock inside a single millisecond does produce an apparent bias, but that is an artifact of collapsing the reachable residue set, not a property of the sampler. No change wanted here — sampled_in's "approximately even, not provably unbiased" doc comment is accurate as written.

  • 📌 std::time::Instant::now() still traps on wasm32-unknown-unknown in ~15 pre-existing core sites. This PR correctly moved its own timing paths to web_time, and #1075 tracks two of the neighbours — but the set is wider than that issue records: crates/trusted-server-core/src/auction/orchestrator.rs (lines 101, 295, 332, 375, 509, 581, 978, 1045, 1348), crates/trusted-server-core/src/auction/telemetry.rs:178,202, crates/trusted-server-core/src/integrations/datadome/protection_scope.rs:405,435, and crates/trusted-server-core/src/publisher.rs:2259,4734 (the template-cache TTL sites the new comments explicitly point at). Out of scope to change here; worth widening #1075's scope so the Cloudflare auction, DataDome-scope and template-cache-TTL paths are not left believed-covered.

  • 📝 The Axum adapter now hand-rolls AxumDevServer's serve loop. crates/trusted-server-adapter-axum/src/main.rs replaces AxumDevServer::with_config(router, config).run() with a local run/serve pair. Diffed against the pinned rev (edgezero tag v0.0.4, 9e661ae, crates/edgezero-adapter-axum/src/dev_server.rs:274-321) and it is faithful: AxumDevServerConfig has exactly addr and enable_ctrl_c and both are honoured, serve_with_stores with Stores::default() inserts nothing extra, and the Router::new().fallback_service(service_fn(...)) + into_make_service_with_connect_info::<SocketAddr>() shape matches line for line. Only deviation is tokio::net::TcpListener::bind where upstream binds a std listener and calls from_std — behaviourally equivalent here. No finding against the code as written; the note is drift risk, since this copy will silently diverge at the next edgezero repin. Upstreaming a service-layer hook (AxumDevServer::with_service_layer) would let the fork go away.

  • 📝 Phase spans are not disjoint, so header subtimings do not partition ts-total. Phase::Stream deliberately encloses the in-stream auction wait — stream_drive_records_stream_ms_covering_the_in_stream_auction_wait asserts stream_ms >= auction_wait_ms — and every span is RAII across .await, so it measures wall clock including suspension rather than work. Both are the right choices for stall diagnosis, but docs/guide/configuration.md's new "Observability" section reads as if the entries were a breakdown. One sentence saying the entries may overlap and do not sum to ts-total would stop an operator drawing the wrong conclusion from the header.

  • 📝 ObservabilitySettings' rollback doc attributes the protection to the wrong attribute. crates/trusted-server-core/src/settings.rs says of ObservabilitySettings: "this struct denies unknown fields, so an older binary loading a config blob carrying an [observability] table it does not know would reject it, breaking rollback." The mechanism that actually makes rollback unsafe is #[serde(deny_unknown_fields)] on Settings itself (settings.rs:2653) in the older binary; ObservabilitySettings' own attribute only rejects unknown keys inside the table in the new binary. The conclusion and the skip_serializing_if = "ObservabilitySettings::is_default" guard are both correct — only the stated reason is off, and it would mislead the next reader who tries to relax either attribute.

Verification performed

Scratch worktree at PR head 38043d74:

Gate Result
gh pr checks 1074 19/19 PASS, 0 failing, 0 pending
cargo fmt --all -- --check PASS
cargo clippy-fastly / -axum / -cloudflare / -cloudflare-wasm / -spin-native / -spin-wasm PASS (all six)
cargo test-fastly PASS — 2450 passed, 0 failed, 10 ignored
cargo test-axum PASS — 40 passed, 0 failed
cargo test-cloudflare PASS — 39 passed, 0 failed
cargo test-spin PASS — 79 passed, 0 failed
parity suite PASS — 13 passed, 0 failed
npx vitest run PASS — 45 files, 871 tests, 0 failed

Could not verify

  1. Fastly Compute production wall-clock granularity — the microsecond resolution behind the sampler check was measured under Viceroy on wasm32-wasip1, not on Fastly Compute. The clean result holds for any granularity finer than a millisecond, so this does not change the conclusion.
  2. Cloudflare web_time::Instant behaviour on workerd — no workerd here; taking the description's word that it was verified. Worth noting Workers deliberately freezes clocks between I/O, so CPU-only phases will likely read 0 there. Harmless while Cloudflare does not emit, but the collected values are not usable as-is if emission is turned on later.
  3. Tinybird schema deployment stateENGINE_SORTING_KEY changed incompatibly from the reserved schema; whether access_logs_raw was ever deployed remotely (and so whether this needs a versioned replacement plus cutover rather than an in-place edit) is a live-account question. Already disclosed as a rollout precondition; no tb CLI here.
  4. Fronting delivery layer Server-Timing pass-through — needs a staging deploy; already disclosed.
  5. emit_access_event against real Tinybird — exercised only through the recording double, so the live ingest contract is unverified.

Comment thread crates/trusted-server-core/src/access_telemetry.rs Outdated
Comment thread crates/trusted-server-core/src/request_timing.rs
Comment thread crates/trusted-server-core/src/request_timing.rs
Comment thread crates/trusted-server-adapter-fastly/src/main.rs Outdated
Comment thread crates/trusted-server-core/src/access_telemetry.rs
Comment thread crates/trusted-server-core/src/access_telemetry.rs Outdated
Comment thread crates/trusted-server-adapter-fastly/src/main.rs
@aram356
aram356 self-requested a review August 28, 2026 20:59
@aram356 aram356 added this to the 202608 milestone Aug 28, 2026
The first path segment is only a section name when the path has depth:
under a /%postname%/ permalink structure every article is a
single-segment path, so keeping those segments verbatim put full
article slugs into the 30-day dataset, against spec section 9. Depth
is now required for a named template; single-segment paths, root
landing pages included, bucket to /other/*. Route slicing keeps
route_class and multi-segment templates like /news/*.
The bucket-quantized sampler truncated rates below one in a million to
a zero threshold (silently emitting nothing) and quantized other low
rates downward while rows still carried the configured rate, biasing
the sum(1.0 / sample_rate) volume estimator. Its no-rand premise was
also wrong: rand::thread_rng() is WASI-backed on this target and the
EC generation path already relies on it. The sampler is now a direct
uniform-roll comparison, and the roll gates on the rate stored in the
snapshot itself, so emission probability and the row's sample_rate
column cannot diverge; the divergence guard and its tests are removed.

Also per review: the settings-reload fallback in the post-send path
could never emit (no snapshot exists when settings were absent) and is
removed; the dead_code allow on DeliveryOutcome narrows to the one
collected-but-unemitted field; and the post-send ordering test is
narrowed to the leg it actually proves, that request_elapsed is
stamped when send returns.
On origin failure with a dispatched auction, the origin span guard
stayed alive through the emit_abandoned_auction await, so ts-origin
and origin_ms absorbed Tinybird emission time. The span now closes
when the send resolves, before either branch, with an error-path
regression test.
- Pin HEADER_PHASES against Phase::header_name() in the phase-index
  test, closing the second hand-synced list.
- Add RouteClass::Asset to the snake_case rendering test; rename the
  lowercasing test to say what it does.
- Give the Axum adapter a named, fully configured construction path
  (TrustedServerApp::dev_server_service) so server_timing_enabled is
  never silently discarded; the tuple API is private now.
- Document that Server-Timing is client-visible when enabled, in the
  configuration guide's observability section.
- Replace stale event_date references in the spec, plan, and dashboard
  guidance with the toDate(event_ts) sorting-key expression, and state
  the single-segment rejection rule in spec section 9.
@aram356
aram356 removed their request for review August 31, 2026 15:22
…ming

# Conflicts:
#	crates/trusted-server-adapter-fastly/src/app.rs
#	crates/trusted-server-adapter-fastly/src/main.rs
#	crates/trusted-server-adapter-fastly/src/middleware.rs
#	crates/trusted-server-core/src/publisher.rs
#	crates/trusted-server-core/src/settings.rs
#	docs/guide/configuration.md
#	trusted-server.example.toml
The access emitter carried the configured body limit without enforcing it, allowing oversized rows to bypass the intended transport safeguard.

@ChristianPavilonis ChristianPavilonis left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Summary

Approved at c6235b91fcd247a57d27fa8703734340d85d0c22. The timing, terminal header, and Tinybird transport controls passed focused validation. One medium-severity route-normalization finding is noted inline.

Comment thread crates/trusted-server-core/src/access_telemetry.rs Outdated

@prk-Jr prk-Jr left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Summary

The timing model is thoughtfully structured: phase accumulation is saturating, response extensions keep adapter/core boundaries typed, and origin timing closes before abandonment telemetry. The telemetry schema, producer, fixture, and forwarding query are also broadly aligned.

I found five blocking issues and four non-blocking follow-ups. Two one-click suggestions were scratch-tested; only the Fastly streaming and fixture suggestions remained byte-for-byte unchanged after their checks. The rollback replacement was rewritten by the docs formatter, so I am leaving that finding as prose instead of posting an unverified patch.

Blocking findings

  • 🔧 Publisher route telemetry retains attacker-controlled path content. For publisher fallbacks at depth two or greater, publisher_route_template preserves any short allowlisted first segment. Requests such as /alice/orders or sensitive-looking arbitrary prefixes can therefore become 30-day Tinybird dimension values. Please collapse non-root publisher fallbacks to a fixed template such as /other/*, or gate preserved segments behind an explicit operator-controlled allowlist. This is the same issue already tracked in the unresolved current-head thread: #1074 (comment)
  • 🔧 The documented rollback sequence can fail startup or unexpectedly enable auction telemetry. The [tinybird] access fields are not all new and the nested Tinybird schema does not reject every unknown field. Older binaries reject access_enabled = true, ignore auction_enabled, and interpret enabled = true as auction telemetry. Please document a compatibility config pushed before rollback: remove [observability], set access_enabled = false, and set enabled = false for access-only deployments before rolling back the binary.
  • 🔧 The max_body_bytes contract is inconsistent. The guide, settings docs, design spec, and implementation plan describe a positive value, while runtime validation rejects values below 1024. Please make every published contract say >= 1024 (or change validation and tests if the intended contract is actually > 0).
  • 🔧 The required CodeQL check is failing. The current head reports 11 high-severity rust/cleartext-logging alerts. The inspected paths suggest the analyzer may be following the Tinybird secret-key-name validation rather than an actual token value, but the merge gate remains red. Please fix/suppress the flow or dismiss the alerts with a documented rationale before merge.

The remaining blocking issue, buffering the unused Tinybird response body, has an inline verified suggestion.

Non-blocking findings

  • 🤔 The Axum timing test only proves that the outer wrapper emits ts-total; it does not prove that request extensions survive the adapter boundary and phase timings recorded in the core handler return to the wrapper.
  • 🏕 The complete Fastly post-send order—elapsed snapshot, pull sync, then access telemetry—does not have the instrumented sequence regression test called for by the implementation plan.
  • 📝 Snapshot lifecycle documentation is stale. The implementation now constructs the snapshot only when access telemetry is enabled, while the core comment, design spec, implementation plan, and PR description still say it is unconditional.
  • ⛏ The Tinybird fixture uses a reserved-for-testing-style publisher hostname rather than this repository's example-domain convention; an inline suggestion updates it.

Checks

  • GitHub: 18 checks pass; CodeQL fails on head c6235b91fcd247a57d27fa8703734340d85d0c22.
  • Scratch verification for the Fastly streaming suggestion: cargo fmt --all -- --check; all Fastly, Axum, Cloudflare, Cloudflare WASM, Spin native, and Spin WASM clippy aliases; cargo test-fastly, cargo test-axum, cargo test-cloudflare, cargo test-spin, and cross-adapter parity all passed.
  • Scratch verification for the rollback text: docs formatting and the same Rust test/clippy matrix passed, but docs formatting changed the proposed bytes, so no GitHub suggestion is attached.
  • Scratch verification for the fixture suggestion: JSON parsing, the expected domain assertion, and git diff --check passed without changing the proposed bytes.

Comment thread crates/trusted-server-adapter-fastly/src/tinybird.rs Outdated
Comment thread docs/guide/configuration.md Outdated
Comment thread crates/trusted-server-adapter-axum/src/timing.rs
Comment thread crates/trusted-server-adapter-fastly/src/main.rs Outdated
Comment thread tinybird/fixtures/access_logs_raw.ndjson Outdated

@aram356 aram356 left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Summary

Adds always-on per-request phase timing with a Server-Timing header and a sampled access-telemetry sink to Tinybird. The engineering is careful — a single shared emission gate across adapters, sampling that cannot diverge from the row's own sample_rate, a body limit that rejects rather than truncates, exact schema/producer alignment, and 123 new tests.

Three blocking items: a PII leak in the publisher route classifier, a config doc that states a constraint the code rejects, and a failing CodeQL gate.

2 of the inline comments below carry a one-click GitHub suggestion — use Commit suggestion (or Add suggestion to batch) to apply them. The remaining comments describe the fix in prose because the change spans multiple files, needs new config plumbing, or is a question.

I verified the cache-safety gate separately and it is sound: an isolated probe showed Cache-Control: private plus Surrogate-Control: max-age=600 passing append_server_timing_if_private, but on the real path enforce_uncacheable_cache_privacy strips every edge-cache header immediately before the freeze point, and enforce_uncacheable_cache_privacy_handles_late_filter_headers already pins that exact combination. Not a finding.

Blocking

🔧 wrench

  • publisher_route_template emits user data verbatim at depth >= 2 — see inline at crates/trusted-server-core/src/access_telemetry.rs:194
  • Docs state a max_body_bytes floor the code rejects — see inline at docs/guide/configuration.md:2010
  • CodeQL is failing with 11 new high-severity alerts — see Cross-cutting below

Non-blocking

♻️ refactor / 🤔 thinking / 📝 note / ⛏ nitpick

  • TimedKvStore does not forward exists — see inline at crates/trusted-server-core/src/platform/timed_kv.rs:45
  • 401 write-back clobbers a resolved geo state — see inline at crates/trusted-server-adapter-fastly/src/middleware.rs:109
  • Poisoned mutex is indistinguishable from WouldBlock — see inline at crates/trusted-server-core/src/request_timing.rs:139
  • Integration-proxy branch degrades an already-bounded route — see inline at crates/trusted-server-adapter-fastly/src/app.rs:876
  • auction_enabled lacks skip_serializing_if, so rollback silently re-enables auction telemetry — see inline at crates/trusted-server-core/src/settings.rs:1794
  • Access sink omits the trailing newline the auction sink appends — see inline at crates/trusted-server-adapter-fastly/src/tinybird.rs:348
  • Axum reads server_timing_enabled once at startup — see inline at crates/trusted-server-adapter-axum/src/app.rs:625
  • The outer-wrapper rationale does not hold in this application — see inline at crates/trusted-server-adapter-axum/src/timing.rs:14
  • ts-total starts after init_logger() and the JA4 short-circuit — see inline at crates/trusted-server-adapter-fastly/src/main.rs:126
  • Fixture uses a real registrable domain — see inline at tinybird/fixtures/access_logs_raw.ndjson:1

Cross-cutting / body-level findings

  • 🔧 CodeQL is failing with 11 new high-severity alerts. CodeQL reports "11 new alerts including 11 high severity security vulnerabilities", all Cleartext logging of sensitive information. Branch protection does not require this check, but CLAUDE.md treats it as a PR gate. Reading the alerts, they look like false positives: they name validate_tinybird_secret(...) as a taint source, but that function takes a Secret Store key name (not a secret value), never returns it, and only formats the setting name into an error message. The flagged sinks are almost all in files this PR does not touch (adapter-axum/src/platform.rs, adapter-fastly/src/management_api.rs, auction/orchestrator.rs, response_privacy.rs, storage/kv_store.rs) — the new validator appears to have introduced a source that lights up pre-existing log sites. Please either dismiss the alerts with that rationale recorded, or rename the parameter to make the key-name-vs-secret-value distinction legible to the analysis. Leaving a red gate red without a recorded rationale is the part worth avoiding.

  • 📝 Test-coverage gaps worth closing alongside the findings above. (1) No Axum-layer test that server_timing_enabled = false suppresses the header — all three tests in timing.rs construct TimingService::new(..., true), so a refactor that drops the flag read would ship silently. (2) No test that a response with no Cache-Control header at all is excluded; that is the fail-closed case and the single most security-relevant assertion in the feature. (3) No classifier test for a short user-data first segment at depth >= 2 (the case in the first finding) — every existing rejection case is depth-1 or caught by the 32-char cap.

  • 📝 DeliveryResult::Partial / Error is collected but never emitted, behind #[allow(dead_code)] at main.rs:533-538. The PR description discloses this as intentional groundwork, which is fine — worth confirming a follow-up issue exists so it does not settle in as permanently dead code.

CI Status

  • integration tests (Fastly EC lifecycle): PASS
  • browser integration tests: PASS
  • integration tests: PASS
  • CodeQL: FAIL (not required by branch protection)
  • Analyze (actions): PASS
  • Analyze (rust): PASS
  • Analyze (javascript-typescript): PASS
  • prepare integration artifacts: PASS
  • format-typescript: PASS (required)
  • format-docs: PASS (required)
  • cargo test: PASS (required)
  • cargo fmt: PASS (required)
  • cargo test (axum native): PASS
  • cargo check (cloudflare native + wasm32-unknown-unknown): PASS
  • cargo check/build/test (spin native + wasm32-wasip1): PASS
  • cargo test (cross-adapter parity): PASS
  • cargo test (ts CLI, native): PASS
  • vitest: PASS

Comment thread crates/trusted-server-core/src/access_telemetry.rs Outdated
Comment thread docs/guide/configuration.md Outdated
Comment thread docs/guide/configuration.md Outdated
Comment thread crates/trusted-server-core/src/platform/timed_kv.rs
Comment thread crates/trusted-server-adapter-fastly/src/middleware.rs Outdated
Comment thread crates/trusted-server-adapter-fastly/src/tinybird.rs
Comment thread crates/trusted-server-adapter-axum/src/app.rs
Comment thread crates/trusted-server-adapter-axum/src/timing.rs Outdated
Comment thread crates/trusted-server-adapter-fastly/src/main.rs
Comment thread tinybird/fixtures/access_logs_raw.ndjson Outdated
jevansnyc and others added 3 commits September 8, 2026 11:29
Conflicts: publisher.rs (origin span now wraps the early-dispatch
pending-origin wait as well as the direct send, still dropping before
the abandonment-telemetry branch), main.rs (EdgeZero env parameter
threaded through the AppBuild span block and the finalize signature
gaining both mut ec_state and timings), app.rs (both sides' test-module
additions kept).

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
…rface

Review round 3, the blocking route finding plus the config items:

- Publisher route templates now come from an operator allowlist
  (observability.route_sections, default empty): a first segment that
  matches an entry and has further depth emits the lowercased allowlist
  entry as /{section}/*; everything else emits /other/*. The shape
  heuristics (charset, length, digit bounds) are gone because they
  could not bound identity: depth-2 first segments are usernames under
  /{username}/posts shapes and single-segment paths are documents. The
  emitted value set is now fixed by configuration, so no
  request-derived byte reaches the row.
- Integration-proxy responses carry the registered route pattern
  verbatim (bounded, integration-defined) instead of a classifier
  output; the registry stores the pattern at registration.
- auction_enabled serializes only when false, so a pushed config
  cannot silently re-enable auction telemetry on rollback; with a
  serialization test alongside the observability one.
- The secret-store validator is renamed to validate_secret_store_key_name
  with a key_name parameter: it validates an identifier, never a
  credential, and the old name tainted the key name as a secret value
  in CodeQL, lighting up eleven pre-existing log sites.
- Docs: the tinybird table gains its three missing rows,
  max_body_bytes states the 1024 floor the code enforces, the rollback
  guidance now describes the real compatibility boundary (push a
  compat config first: drop [observability], access_enabled = false,
  and enabled = false for access-only deployments), and the fixture
  uses the example-domain convention.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
- The access sink streams the Tinybird response (the body is never
  consumed; buffered conversion materializes chunked bodies before the
  limit check) and newline-terminates rows to match the auction sink's
  NDJSON framing, with the recording client now asserting both.
- Poisoned RequestTimings locks recover via into_inner instead of
  silently dropping every subsequent sample: the guarded data are
  plain counters, so one panic cannot blank the header and row for the
  rest of the request. Module and spec docs updated to stop conflating
  poisoning with contention.
- The geo write-back skips 401 responses through a shared helper:
  resolve_geo_for_response short-circuits on 401 before consulting the
  carried state, so the old unconditional write downgraded a carried
  Resolved to Attempted and cost the row its country.
- TimedKvStore forwards exists, so decorating a store with a cheap
  metadata probe (Spin) no longer downgrades it to the get-and-discard
  default body; with a contradiction-stub delegation test.
- Post-send ordering is owned by run_post_send_steps, which both
  production sites route through, and the instrumented sequence test
  drives the real seam: elapsed stamped by send, then pull-sync, then
  telemetry.
- Axum: dev_server_service remains the standard path; new tests pin
  flag-off suppression and the extension round trip (a phase recorded
  in the handler must surface as ts-filter in the header); the
  outer-wrapper rationale is reworded to the terminal-freeze-point
  argument; the configuration guide notes the flag is read once at
  startup.
- The no-Cache-Control fail-closed case is pinned by a test, and t0's
  boundary (constructed after the adapter prologue) is documented.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>

@aram356 aram356 left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Summary

Round-3 pass on head a1523675a. All 13 findings from the previous review are addressed, several exactly as proposed, and CI is green across all 19 checks.

I re-ran the route-classifier attack cases from the last pass against the new allowlist implementation: /jane-doe/posts, /johnsmith1985/settings, /how-to-treat-my-hiv-today/comments, a 32-char all-letter hex id, and an 8-hex-char session id all now collapse to /other/*. The emitted value comes from the operator's configured section string rather than the request, so the column is bounded in cardinality as well as content-free. That finding is fully closed.

The merge of main was verified mechanically rather than by eye: for the files both sides touched without conflict, a reconstructed three-way merge is byte-identical to git's automatic result; for the four hand-resolved conflicts, primitive counts (?;, change_context, .await, expect() reconcile as ours+theirs-base exactly, and unwrap() remains at zero. EC KV stays timed while pull-sync stays untimed, and the new JS asset proxy from #742 is attributed from operator config rather than the request path.

What follows is all non-blocking. Requesting changes for three of them: the Server-Timing cache gate now depends on one adapter's call ordering rather than on the gate itself, and two doc-correctness regressions were introduced by the fix commits — one of which is the same max_body_bytes defect as last round, in a second location.

4 of the inline comments carry a one-click suggestion. The rest describe the fix in prose because it spans files or needs a design decision.

Blocking

🔧 wrench

  • Server-Timing cache gate is adapter-dependent, and Axum has no guard — see inline at crates/trusted-server-core/src/request_timing.rs:335
  • resolve_geo_for_response lost its doc comment to an insertion artifact — see inline at crates/trusted-server-adapter-fastly/src/middleware.rs:188
  • The max_body_bytes correction missed the rustdoc — see inline at crates/trusted-server-core/src/settings.rs:1820

Non-blocking

🤔 thinking / ♻️ refactor / 📝 note / ⛏ nitpick

  • Example config contradicts its own validation — see inline at trusted-server.example.toml:386
  • Generated build artifact committed — see Cross-cutting below
  • Two unconditional allocations on the disabled-by-default hot path — see inline at crates/trusted-server-adapter-fastly/src/main.rs:160
  • route_sections accepts unvalidated entries — see inline at crates/trusted-server-core/src/settings.rs:2747
  • Poisoning docs contradict the new recovery behavior — see inline at crates/trusted-server-core/src/request_timing.rs:198
  • Tautological assertion in the pull-sync test — see inline at crates/trusted-server-adapter-fastly/src/app.rs:3659
  • Triple router lookup with an unreachable fallback — see inline at crates/trusted-server-adapter-fastly/src/app.rs:880
  • -- used as an em-dash substitute — see inline at crates/trusted-server-adapter-axum/src/timing.rs:13

Cross-cutting / body-level findings

  • ♻️ A generated build artifact was committed. crates/trusted-server-adapter-cloudflare/wrangler.integration.generated.toml is written at test time by write_generated_ci_config (crates/trusted-server-integration-tests/tests/environments/cloudflare.rs:30), which substitutes the TRUSTED_SERVER_CONFIG = "{}" placeholder in wrangler.ci.toml. I confirmed the committed copy has that placeholder already substituted, so it is an output rather than a fixture, and git check-ignore reports it is not ignored. Two consequences: every CI run that exercises the Cloudflare environment leaves a dirty working tree, and the committed copy embeds a frozen config snapshot with a baked sha256 that will drift from the template silently. The embedded values are all fictional (integration-test-token-*, example.com, localhost), so there is no credential exposure. It is also unrelated to request-phase timing. Suggest deleting it and adding it to .gitignore.

  • 📝 Coverage the round-3 fixes did not bring with them. There is no test for the mutex poison-recovery path added in this round. That is genuinely awkward rather than an oversight: wasm32-wasip1 has no threads, so a poisoning test cannot run under cargo test-fastly — a #[cfg(not(target_arch = "wasm32"))] test would cover it on the native adapters. Separately, matched_route_pattern (crates/trusted-server-core/src/integrations/registry.rs:917) is public and exercised only indirectly through the adapter; a registry-level test pinning that it returns the integration-authored literal (/*) rather than the matchit-converted form ({*rest}) would lock that invariant in the module that owns it.

  • 📝 Not covered by this pass. The Tinybird access_logs_raw datasource drops the path and event_date columns and changes ENGINE_SORTING_KEY, which is a destructive migration against an already-deployed datasource. The schema matches the row producer field-for-field, but the migration path for an existing deployment was not assessed here and remains a rollout precondition, consistent with the disclosure in the PR description. cargo test-cloudflare, cargo test-spin, and the parity integration suite were not run locally; GitHub reports all three green.

CI Status

All 19 checks pass at a1523675a, including CodeQL, which was the failing gate in the previous round.

  • integration tests: PASS
  • integration tests (Fastly EC lifecycle): PASS
  • browser integration tests: PASS
  • prepare integration artifacts: PASS
  • CodeQL: PASS
  • Analyze (actions): PASS
  • Analyze (rust): PASS
  • Analyze (javascript-typescript): PASS
  • cargo fmt: PASS (required)
  • cargo test: PASS (required)
  • format-docs: PASS (required)
  • format-typescript: PASS (required)
  • cargo test (axum native): PASS
  • cargo test (cloudflare native + wasm32-unknown-unknown): PASS
  • cargo check/build/test (spin native + wasm32-wasip1): PASS
  • cargo test (cross-adapter parity): PASS
  • cargo test (ts CLI, native): PASS
  • vitest: PASS

) {
timings.mark_headers_ready();

let conclusively_private = cache_control_headers_are_private_or_no_store(response.headers());

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🔧 wrench — This gate reads only Cache-Control, which makes the cache-safety property depend on each adapter's call ordering rather than on the gate itself.

On Fastly it holds. apply_terminal_response_effects runs enforce_uncacheable_cache_privacy at main.rs:872, stripping every edge-cache header on a private response, and it is invoked at main.rs:700 — one line before apply_server_timing_header at main.rs:701. I re-verified that ordering survived the merge.

The Axum adapter has no equivalent. enforce_uncacheable_cache_privacy and remove_edge_cache_headers appear nowhere under crates/trusted-server-adapter-axum/src/, and timing.rs:93 calls this function at the bare tower boundary. A response carrying Cache-Control: private alongside CDN-Cache-Control: max-age=300 or Surrogate-Control: max-age=300 therefore passes the gate and gets stamped — I confirmed that by running the predicate against exactly those headers. A shared cache honouring the CDN header would store and replay one user's ts-kv and ts-origin timings for the object's lifetime.

Severity is held down by Axum being the dev server, which normally sits behind no shared cache. Raising it as blocking because the safety of a privacy property currently rests on a convention that one of the two wired adapters does not follow, and the next adapter to call this function inherits the same trap. The design spec's claim that emission happens only when the response is "conclusively non-storable by any shared cache" is true of the Fastly pipeline, not of this predicate.

Proposed fix (apply manually — changes shared core behaviour and needs a matching test, so it does not fit a single-hunk suggestion): make the invariant local to the gate. Either require the absence of edge-cache headers alongside the Cache-Control check:

let conclusively_private = cache_control_headers_are_private_or_no_store(response.headers())
    && !response
        .headers()
        .keys()
        .any(|name| is_edge_cache_header_name(name.as_str()));

or have the gate call remove_edge_cache_headers itself when it decides a response is private. Either way every present and future adapter is safe by construction rather than by call-site discipline. is_edge_cache_header_name and EDGE_CACHE_HEADER_NAMES already exist in cache_policy.rs and cover surrogate-control, fastly-surrogate-control, cdn-cache-control, and cloudflare-cdn-cache-control.

Comment on lines 188 to +198
/// server or the upstream origin.
/// Writes the resolved geo outcome back onto the response as a
/// [`GeoLookupState`] extension, so a downstream access-telemetry snapshot
/// sees what was actually looked up rather than the stale carried-in state.
///
/// Skips the write on a 401: [`resolve_geo_for_response`] returns `None`
/// for unauthorized responses before consulting the carried state, so
/// writing `Attempted` there would overwrite a carried `Resolved` with a
/// value that was never looked up, and the row would lose a country it
/// legitimately had.
pub(crate) fn write_back_geo_lookup_state(response: &mut Response, geo_info: Option<&GeoInfo>) {

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🔧 wrench — The new write_back_geo_lookup_state was inserted between resolve_geo_for_response's doc comment and the function it documented, with no blank line and no item separating them:

/// server or the upstream origin.
/// Writes the resolved geo outcome back onto the response as a

Rustdoc therefore attaches the entire preceding block — the 401-skip contract, the Resolved/Attempted/NotAttempted dedupe rules, and a # Parity note about legacy Fastly behaviour — to write_back_geo_lookup_state, a function none of it describes. resolve_geo_for_response at line 209 is left with no doc comment at all, which is both a misattributed behavioural contract and a violation of the repo's "each public item must have a doc comment" rule.

This is a mechanical artifact of the insertion rather than a design choice, and both of my review passes flagged it independently.

Proposed fix (apply manually — the fix moves a block across the two functions, which spans more than one contiguous range): move lines 166-187 back to sit directly above resolve_geo_for_response at line 209, leaving lines 188-197 attached to write_back_geo_lookup_state. The write-back's own doc is correct and well written; it just needs to be the only thing above it.

Comment on lines +1819 to +1820
/// `true` requires `enabled`, non-empty `api_host`/`secret_store`/
/// `access_dataset`/`access_token_secret`, `max_body_bytes > 0`, and

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🔧 wrench — The round-2 finding about this constraint was fixed in docs/guide/configuration.md, but this rustdoc still carries the wrong bound. The code enforces a floor of 1024 at settings.rs:1912:

if self.max_body_bytes < 1024 {
    return Err(Report::new(TrustedServerError::Configuration {
        message: "tinybird.max_body_bytes must be at least 1024".to_owned(),
    }));
}

Same failure as last round, in a second location: an operator or agent reading cargo doc sets max_body_bytes = 512, and config load fails with a message contradicting the documentation they just read.

Suggested change
/// `true` requires `enabled`, non-empty `api_host`/`secret_store`/
/// `access_dataset`/`access_token_secret`, `max_body_bytes > 0`, and
/// `true` requires `enabled`, non-empty `api_host`/`secret_store`/
/// `access_dataset`/`access_token_secret`, `max_body_bytes` of at least

The following line already reads /// `access_sample_rate > 0.0`. This prevents..., so the sentence needs 1024, and prepended to it as well. Applying this suggestion alone leaves the sentence reading "of at least access_sample_rate > 0.0" — please apply both halves, or edit the two lines together manually.

(Verified: applied in a scratch worktree, cargo fmt --all -- --check passes.)

# access_enabled = false # emit sampled access telemetry
# access_dataset = "access_logs_raw" # access Events API datasource
# access_token_secret = "tinybird_access_append_token"
# access_sample_rate = 0.0 # fraction from 0.0 through 1.0

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🤔 thinking — This example pairs access_sample_rate = 0.0 with access_enabled three lines above it, but TinybirdSettings::prepare_runtime rejects that combination at settings.rs:1942:

if self.access_sample_rate <= 0.0 {
    return Err(Report::new(TrustedServerError::Configuration {
        message: "tinybird.access_sample_rate must be > 0 when tinybird.access_enabled is true".to_owned(),
    }));
}

An operator uncommenting this block and flipping access_enabled = true — the obvious next step — gets an immediate config rejection. Both lines are commented out, so this is a footgun rather than a broken default, but the example is the first thing an operator copies.

Suggested change
# access_sample_rate = 0.0 # fraction from 0.0 through 1.0
# access_sample_rate = 0.01 # must be > 0 when access_enabled

(Verified: applied in a scratch worktree.)

Comment on lines +160 to +163
let publisher_domain = settings_snapshot.as_deref().map_or_else(
|| "unknown".to_owned(),
|settings| settings.publisher.domain.clone(),
);

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🤔 thinkingpublisher_domain here and request_method at line 185 are both allocated unconditionally on every request, then discarded whenever access telemetry is off, which is the default.

I traced the consumers: both are read only by build_access_telemetry_snapshot (main.rs:814, :818), and send_edgezero_response gates that call behind context.access_telemetry_enabled at main.rs:707. Each value is additionally cloned into SendContext at main.rs:287-288 and :327-328. So a disabled deployment pays two short-string allocations plus two clones per edge request for data nothing reads.

Small in absolute terms, but this is the always-on path on an edge runtime, and the rest of the feature is careful about exactly this: access_telemetry_enabled already short-circuits the snapshot build, and server_timing_value() is never reached when the flag is off.

Proposed fix (apply manually — touches the capture sites and SendContext together): carry publisher_domain as Arc<str> (it already sits behind an Arc<Settings>, so this becomes a refcount bump), and defer request_method by capturing the cheap Method or a &'static str and materialising the String inside the .then(...) at main.rs:707 where it is actually needed.

/// `/other/*`. Matching is ASCII case-insensitive on the first path
/// segment, and a match requires at least one further segment. Defaults
/// to empty, which collapses every publisher path.
#[serde(default, skip_serializing_if = "Vec::is_empty")]

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🤔 thinkingroute_sections is never validated. I grepped for every reference to the field, and no prepare_runtime hook or validator touches it.

I compiled the classifier standalone against malformed entries and confirmed they reach the emitted row as-is:

section "x\"y"   -> "/x\"y/*"
section "x\ny"   -> "/x\ny/*"
section ""        -> "//*"      (from path "//z")

Not a security issue: serde_json::json! escapes the value, so NDJSON framing survives, and the values are operator-supplied rather than request-derived. But an empty entry yields the malformed template "//*", and there is no cap on entry count or length feeding a LowCardinality column.

Worth pairing with a documentation note: route_sections is only safe when each entry is genuinely a section name. Configuring route_sections = ["u"] on a site whose paths are /u/{username} re-opens the exact leak this allowlist was introduced to close, because /u/alice then emits /u/* — correct — but the operator may not realise the sibling /{username}/posts shape is what the mechanism protects against.

Proposed fix (apply manually — needs a new validator function and a call site in prepare_runtime): reject empty entries and entries containing / or control characters, and cap both entry length and list length. Then add a line to the [observability] docs stating that a section name must identify a section rather than a user-scoped prefix.

Comment on lines +196 to +198
///
/// Subsequent calls are no-ops (first call wins). Drops the sample
/// silently on lock contention or poisoning.

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

📝 note — The poisoning fix from the last round updated the docs on record, record_auction_wait, and set_resp_bytes, but four doc comments still describe the old behaviour and now assert the opposite of the code:

  • line 198 (mark_headers_ready): "silently on lock contention or poisoning"
  • line 218 (mark_request_elapsed): same
  • line 258 (server_timing_value): "silently (returning None) on lock contention or poisoning"
  • line 281 (snapshot): "Returns an all-None snapshot on lock contention or poisoning"

All four now recover via Err(TryLockError::Poisoned(poisoned)) => poisoned.into_inner(). The behaviour is right — I verified all seven lock sites handle poisoning and that into_inner() recovery persists across repeated calls — only the docs are stale.

Separately, there is no test for poison recovery. That is genuinely awkward rather than an oversight: wasm32-wasip1 has no threads, so a poisoning test cannot run under cargo test-fastly. A #[cfg(not(target_arch = "wasm32"))] test would cover it on the native adapters and pin a behaviour that is otherwise only asserted in prose.

Comment on lines +3659 to +3664
let pull_sync_timings = RequestTimings::new();
pull_sync_timings.mark_headers_ready();
assert!(
pull_sync_timings.snapshot().kv_ms.is_none(),
"pull-sync's untimed graph construction has no timings handle to record into"
);

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

nitpick — This assertion cannot fail. pull_sync_timings is constructed on the line above and nothing ever records into it, so kv_ms.is_none() holds for any freshly built collector — including one where require_identity_graph were timed. The test's name promises "pull_sync_is_not [timed]", but this half proves nothing.

The fix is to assert against the handle that was actually in play: capture the EC KV total after the consent read, then confirm the pull-sync read did not move it.

Suggested change
let pull_sync_timings = RequestTimings::new();
pull_sync_timings.mark_headers_ready();
assert!(
pull_sync_timings.snapshot().kv_ms.is_none(),
"pull-sync's untimed graph construction has no timings handle to record into"
);
let consent_kv_ms = timings.snapshot().kv_ms;
assert!(
consent_kv_ms.is_some(),
"a consent-store read through the decorated RuntimeServices store should record Phase::EcKv"
);
// Pull-sync's identity graph is built by `require_identity_graph`,
// which takes no `timings` parameter at all, so the untimed store it
// constructs cannot record into the handle the consent read used.
let graph = crate::require_identity_graph(&settings)
.expect("should construct the pull-sync identity graph");
let ec_id = "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.test01";
let _ = graph.get(ec_id);
assert_eq!(
timings.snapshot().kv_ms,
consent_kv_ms,
"the pull-sync graph is untimed, so its read must not add to the EC KV phase"
);

This replacement spans from the existing let consent_kv_ms binding through the end of the assertion, so it also folds the timings.snapshot().kv_ms capture into the earlier assert. Note the suggestion assumes the preceding line reads timings.mark_headers_ready(); — it does.

(Verified: applied in a scratch worktree; cargo fmt --all -- --check passes and cargo test-fastly --package trusted-server-adapter-fastly consent_store_reads reports 1 passed.)

Comment on lines 880 to +886
} else if state.registry.has_route(&method, &path) {
// Integration-proxy responses are not bounded by
// publisher.max_buffered_body_bytes. Publisher fallback below uses the
// publisher-specific streaming finalizer instead.
// The matched route pattern is an integration-defined literal
// (bounded and content-free by construction), so telemetry keeps it
// verbatim instead of running the request path through the lossy

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

nitpick — This arm now performs three router lookups where it previously did two: has_route here, matched_route_pattern for the template, and a third inside handle_proxy. These are matchit radix-tree lookups, so the cost is not the concern.

The dead fallback is. has_route at line 880 has already proved find_route returns Some, so the || "/other/*".to_owned() arm in map_or_else is unreachable. A later reader may reasonably take its presence as evidence that a registry-matched path can miss, which would be a misleading signal about the privacy invariant this branch is upholding.

Proposed fix (apply manually — restructuring the else if chain reaches beyond this hunk): collapse the guard and the lookup into one:

} else if let Some(pattern) = state.registry.matched_route_pattern(&method, &path) {
    route_metadata = Some(RouteMetadata {
        route_class: RouteClass::IntegrationProxy,
        route_template: pattern.to_owned(),
    });

That removes one lookup and the unreachable branch together.

Related, and worth a follow-up rather than a change here: matched_route_pattern (crates/trusted-server-core/src/integrations/registry.rs:917) is public but exercised only indirectly through this adapter. A registry-level test pinning that it returns the integration-authored literal (/*) rather than the matchit-converted form ({*rest}) would lock that invariant in the module that owns it.

Comment on lines +13 to +14
//! freeze point: by the time a response reaches this layer -- after
//! `RouterService::oneshot` inside `EdgeZeroAxumService::call` has

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

nitpick — These two lines use -- as an em-dash substitute, which CLAUDE.md disallows in comments. Only one other instance exists across trusted-server-core/src/*.rs, so this is not established house style.

Suggested change
//! freeze point: by the time a response reaches this layer -- after
//! `RouterService::oneshot` inside `EdgeZeroAxumService::call` has
//! freeze point: by the time a response reaches this layer, after
//! `RouterService::oneshot` inside `EdgeZeroAxumService::call` has

Line 16 closes the same clause with a second -- ("into a plain response -- every response is"); that one needs the same treatment, and a single suggestion cannot span both non-contiguous edits. Recasting with commas as above reads cleanly without either dash.

(Verified: applied in a scratch worktree, cargo fmt --all -- --check passes.)

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.

Create eng spec for better server side timing metrics and observability

4 participants