Add request phase timing: Server-Timing subtimings and access telemetry - #1074
Add request phase timing: Server-Timing subtimings and access telemetry#1074jevansnyc wants to merge 29 commits into
Conversation
* 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".
|
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
left a comment
prk-Jr
left a comment
There was a problem hiding this comment.
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 failing — integration 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
- CRITICAL —
std::time::Instantpanics onwasm32-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). - HIGH — Two more
Instant::now()calls on the auction path inpublisher.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. - HIGH —
publisher_route_templateadmits 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_QUERYcolumns — identical names and identical order, zero set difference. try_lock-only is real. 7 lock acquisitions inrequest_timing.rs, alltry_lock, zero.lock(). No method calls another while holding its guard, so no re-entrant self-deadlock.- Saturating arithmetic is complete —
saturating_addinrecord/record_auction_wait/CountingWriter::write,try_from(..).unwrap_or(MAX)in bothduration_msandrecord_buffered_delivery. - The Server-Timing cache-control gate holds on every emit path. Both emitters funnel through
append_server_timing_if_private, andcache_control_value_has_directiveis exact-name and quote-aware (not-private/no-storeycorrectly do not match). On Fastly the call sits afterapply_terminal_response_effectsand both finalize passes, soCache-Controlis settled and nothing mutates it afterwards. [observability]back-compat is sound.Settingscarriesdeny_unknown_fieldsand the pushed blob is a serde serialization ofSettings, soskip_serializing_if = "ObservabilitySettings::is_default"genuinely keeps a default table out of the blob.TinybirdSettingshas nodeny_unknown_fieldson either side, so the newauction_enabledkey does not break rollback either.- The hand-rolled Axum
serveis 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).
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
left a comment
ChristianPavilonis
left a comment
There was a problem hiding this comment.
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.
ChristianPavilonis
left a comment
ChristianPavilonis
left a comment
There was a problem hiding this comment.
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
left a comment
prk-Jr
left a comment
There was a problem hiding this comment.
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 -- --checkPASS,cargo clippy-fastlyPASS (0 warnings),
trusted-server-corelib 2238 passed / 0 failed,trusted-server-adapter-fastly
185 passed / 0 failed.
Blocking
🔧 wrench
publisher_route_templatekeeps single-segment article slugs verbatim, against spec section 9 — inline atcrates/trusted-server-core/src/access_telemetry.rs:189
Non-blocking
🤔 thinking
Server-Timingis an unrestricted client-visible latency oracle when enabled — inline atcrates/trusted-server-core/src/request_timing.rs:285
♻️ refactor
HEADER_PHASESis a second hand-synced list with no test — inline atcrates/trusted-server-core/src/request_timing.rs:419#[allow(dead_code)]on the wholeDeliveryOutcomemasks two live fields — inline atcrates/trusted-server-adapter-fastly/src/main.rs:571
🏕 camp site
route_class_renders_snake_caseomits the newAssetvariant — inline atcrates/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.bytesthenentropy % 1_000_000 < rate * 1e6looks like it could starve whole response-size classes, because the guest wall clock is microsecond-resolution andnanosis therefore always a multiple of 1000. It does not:as_nanos()since epoch is a ~61-bit monotonically advancing value, and% 1_000_000folds 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 bothaccess_sample_rate = 0.05and0.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 onwasm32-unknown-unknownin ~15 pre-existing core sites. This PR correctly moved its own timing paths toweb_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, andcrates/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.rsreplacesAxumDevServer::with_config(router, config).run()with a localrun/servepair. Diffed against the pinned rev (edgezerotagv0.0.4,9e661ae,crates/edgezero-adapter-axum/src/dev_server.rs:274-321) and it is faithful:AxumDevServerConfighas exactlyaddrandenable_ctrl_cand both are honoured,serve_with_storeswithStores::default()inserts nothing extra, and theRouter::new().fallback_service(service_fn(...))+into_make_service_with_connect_info::<SocketAddr>()shape matches line for line. Only deviation istokio::net::TcpListener::bindwhere upstream binds astdlistener and callsfrom_std— behaviourally equivalent here. No finding against the code as written; the note is drift risk, since this copy will silently diverge at the nextedgezerorepin. 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::Streamdeliberately encloses the in-stream auction wait —stream_drive_records_stream_ms_covering_the_in_stream_auction_waitassertsstream_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, butdocs/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 tots-totalwould 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.rssays ofObservabilitySettings: "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)]onSettingsitself (settings.rs:2653) in the older binary;ObservabilitySettings' own attribute only rejects unknown keys inside the table in the new binary. The conclusion and theskip_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
- 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. - Cloudflare
web_time::Instantbehaviour 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 read0there. Harmless while Cloudflare does not emit, but the collected values are not usable as-is if emission is turned on later. - Tinybird schema deployment state —
ENGINE_SORTING_KEYchanged incompatibly from the reserved schema; whetheraccess_logs_rawwas 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; notbCLI here. - Fronting delivery layer
Server-Timingpass-through — needs a staging deploy; already disclosed. emit_access_eventagainst real Tinybird — exercised only through the recording double, so the live ingest contract is unverified.
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.
…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
left a comment
ChristianPavilonis
left a comment
There was a problem hiding this comment.
Summary
Approved at c6235b91fcd247a57d27fa8703734340d85d0c22. The timing, terminal header, and Tinybird transport controls passed focused validation. One medium-severity route-normalization finding is noted inline.
prk-Jr
left a comment
prk-Jr
left a comment
There was a problem hiding this comment.
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_templatepreserves any short allowlisted first segment. Requests such as/alice/ordersor 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 rejectaccess_enabled = true, ignoreauction_enabled, and interpretenabled = trueas auction telemetry. Please document a compatibility config pushed before rollback: remove[observability], setaccess_enabled = false, and setenabled = falsefor access-only deployments before rolling back the binary. - 🔧 The
max_body_bytescontract 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-loggingalerts. 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;
CodeQLfails on headc6235b91fcd247a57d27fa8703734340d85d0c22. - 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 --checkpassed without changing the proposed bytes.
aram356
left a comment
aram356
left a comment
There was a problem hiding this comment.
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_templateemits user data verbatim at depth >= 2 — see inline atcrates/trusted-server-core/src/access_telemetry.rs:194- Docs state a
max_body_bytesfloor the code rejects — see inline atdocs/guide/configuration.md:2010 - CodeQL is failing with 11 new high-severity alerts — see Cross-cutting below
Non-blocking
♻️ refactor / 🤔 thinking / 📝 note / ⛏ nitpick
TimedKvStoredoes not forwardexists— see inline atcrates/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 atcrates/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_enabledlacksskip_serializing_if, so rollback silently re-enables auction telemetry — see inline atcrates/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_enabledonce at startup — see inline atcrates/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-totalstarts afterinit_logger()and the JA4 short-circuit — see inline atcrates/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.
CodeQLreports "11 new alerts including 11 high severity security vulnerabilities", allCleartext 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 namevalidate_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 = falsesuppresses the header — all three tests intiming.rsconstructTimingService::new(..., true), so a refactor that drops the flag read would ship silently. (2) No test that a response with noCache-Controlheader 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/Erroris collected but never emitted, behind#[allow(dead_code)]atmain.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
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
left a comment
aram356
left a comment
There was a problem hiding this comment.
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-Timingcache gate is adapter-dependent, and Axum has no guard — see inline atcrates/trusted-server-core/src/request_timing.rs:335resolve_geo_for_responselost its doc comment to an insertion artifact — see inline atcrates/trusted-server-adapter-fastly/src/middleware.rs:188- The
max_body_bytescorrection missed the rustdoc — see inline atcrates/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_sectionsaccepts unvalidated entries — see inline atcrates/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 atcrates/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.tomlis written at test time bywrite_generated_ci_config(crates/trusted-server-integration-tests/tests/environments/cloudflare.rs:30), which substitutes theTRUSTED_SERVER_CONFIG = "{}"placeholder inwrangler.ci.toml. I confirmed the committed copy has that placeholder already substituted, so it is an output rather than a fixture, andgit check-ignorereports 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 bakedsha256that 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-wasip1has no threads, so a poisoning test cannot run undercargo 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_rawdatasource drops thepathandevent_datecolumns and changesENGINE_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
|
Round 3 addressed in two commits (bcc1475, a152367) on top of a fresh merge of main (6f133cc). Every inline thread has a reply naming its fixing commit and is resolved; the body-level findings without threads: CodeQL (blocking, both reviews). Took the rename option with the rationale recorded here: Coverage gaps (aram356). All three closed in a152367: an Axum test pins DeliveryResult groundwork. Follow-up issue exists now: #1155 (emit a Snapshot lifecycle docs (prk-Jr). The core doc comment, spec sections 4 and 10, and the implementation plan all now say the snapshot is built only when One deliberate divergence from a one-click suggestion: the fixture domain uses |
4 participants
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-Timingheader (ts-total,ts-appbuild,ts-filter,ts-geo,ts-kv,ts-origin,ts-template-cache) emitted at the send freeze point immediately beforeinto_parts(), gated byobservability.server_timing_enabledand restricted to conclusively private (private/no-store) responses so no shared cache can replay timings.TimedKvStoredecorator implementing bothPlatformKvStoreandEcKvStore(latency-only; reads no payloads). Pull-sync stores are explicitly untimed.GeoLookupStateresponse extension (NotAttempted/Attempted/Resolved), 401 rule preserved.DeliveryResult::{Complete, Partial, Error}), auction-wait with explicit placement (in_streamat the seam,pre_headeron buffered paths), response bytes, and a post-bodyrequest_elapsed_msthat excludes pull-sync and telemetry.AccessTelemetrySnapshotbuilt at the freeze point whentinybird.access_enabledis set, route templates emitted only from an operator-configured section allowlist (observability.route_sections, default empty, so no request-derived byte reaches the row; adversarially tested with usernames, slugs, tokens, EC ids, emails, and search terms), and a confirmed-delivery Tinybird sink (bounded await, streamed response, 2xx-validated, sampled bytinybird.access_sample_rate) that runs after client delivery and after pull-sync.access_logs_rawschema aligned column-for-column with the row producer; sorting key(toDate(event_ts), service_id, publisher_domain, env, route_class, pop, status); there is noevent_datecolumn (Tinybird's Events API requires a JSONPath on every column, which a derived-default column cannot carry).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)
access_logs_rawwas 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 needEXPLAINvalidation against the new key.[observability]table.ts-appbuild); Cloudflare and Spin collect but do not emit in v1. An earlier revision of this branch usedstd::time::Instant, which panics onwasm32-unknown-unknownand trapped every Cloudflare publisher request (the failingintegration testsruns on this branch); the timing paths now useweb_time::Instant, verified against the real workerd runtime locally.DeliveryResultis collected but not yet emitted on any surface (intentional groundwork).Partialsemantics are error-based only, per an explicit owner ruling: clean-but-early source truncation is out of scope permanently.request_elapsed_msis stamped beforesend_to_client(no drive to time); streaming responses, the case that matters for stall diagnosis, include the full drive.access_sample_rate = 1.0is a diagnosis setting, not a steady state.Generated with Claude Code