diff --git a/.gitignore b/.gitignore
index 24b9e06aa1..4340873735 100644
--- a/.gitignore
+++ b/.gitignore
@@ -63,3 +63,7 @@ src/*.html
# leftover local build artifacts (node_modules, target, dist) that remain on disk.
/crates/js/
/crates/integration-tests/
+
+# Wrangler config rendered by the Cloudflare integration-test harness from
+# wrangler.ci.toml for CI or test-specific configuration overrides.
+wrangler.integration.generated.toml
diff --git a/CHANGELOG.md b/CHANGELOG.md
index c7a0eb1ecd..eb3def6744 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -9,6 +9,15 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
### Changed
+- Access telemetry v2 now uses `auction_collected_ms` for collection return, sets `ts_version` to the TS build identifier matching `x-ts-version`, and adds `delivery_result` for local complete/partial/error transport handoff. It does not establish client receipt. Coordinate any deployed preview v2 schema before updating the producer.
+- Access ingestion now dispatches without waiting for Tinybird's reply. Start failures are reported; later transport errors, non-2xx responses and remote ingestion acceptance are unobserved, with no retry.
+- `/auction`, page-bids and HTML collectors share measured collection waits and outcome mapping. Real mediator-only work can have collection/wait/commit timing without a provider dispatch offset; routing and admission still decide whether any request is sent.
+- Prebid diagnostics listener, targeting and correlation code now lives in the optional diagnostics bundle. Badge evidence passes clicks through, its small control sits outside observed creative bounds, and selecting the latest request no longer opens history.
+
+- Auction telemetry failure batches for `/auction` and page-bids now include provider launch-failure rows alongside the summary, so a failed dispatch can emit more than one row. `/auction` summary `elapsed_ms` now uses the orchestrator's elapsed time.
+- GPT diagnostics JSON exports now include bounded server winner and Prebid candidate/win bidder codes and bucketed `hb_pb` values. These observations do not establish which creative GAM ultimately served; raw CPM and creative markup remain excluded.
+- The Axum dev server now runs its own serve loop to apply terminal request-timing handling.
+- The default `tinybird.access_dataset` is now `access_logs_v2`. Since this field is serialized, an upgrade from TOML that omits it may produce a one-time config-envelope diff; review and push once to settle it. Explicit legacy dataset values must be changed before enabling access telemetry.
- **Breaking:** `x-ts-version` now reports the deployed git version — the release tag, else the branch, else the first 6 characters of the commit — compiled in from the build-time `TRUSTED_SERVER__GIT_VERSION` (set by the deploy pipeline) or local git, and is sent by every adapter, including on the Fastly `GET /health` probe. The Fastly service version it previously carried is now `x-ts-fastly-version`; update dashboards, monitors, and scripts that read `x-ts-version` as the Fastly version number. Builds with neither the override nor git omit the header.
- **Breaking:** `ts prebid bundle` is now `ts prebid client`, alongside the new `ts prebid server` namespace. Update scripts and runbooks to use `ts prebid client` with the same arguments. The old `bundle` spelling is no longer accepted and has no compatibility alias.
- The S2S `/_ts/api/v1/batch-sync` endpoint now validates the full batch and calls the CAS-protected update path once per distinct normalized EC ID. The last valid UID wins within a group, and infrastructure failures reject the failing and each unprocessed group, so accepted and `kv_unavailable` input indexes may interleave.
@@ -43,6 +52,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
### Added
+- Added opt-in request-phase `Server-Timing` on private Fastly/Axum responses and sampled post-delivery Fastly access telemetry. Deploy the new `access_logs_v2` datasource and its scoped APPEND token before enabling access emission; the legacy `access_logs_raw` schema and data remain unchanged. Access rows retain bounded route templates and coarse operational dimensions for 30 days, with random UUID joins for active auction observations and null UUIDs for disabled auctions. Each row stores its sampling rate. Access ingestion waits after delivery and can delay the next request in a reused Fastly sandbox. Before rolling back to an older binary, disable access emission, remove non-default `[observability]` config, and re-push; access-only deployments must also disable the Tinybird master switch. See the telemetry guide and Tinybird cutover runbook.
- Added the `[auction].rewrite_creatives` (default `true`) and `[auction].sanitize_creatives` (default `false`) options. `rewrite_creatives` rewrites winning-bid adm to first-party endpoints across `POST /auction` and publisher SSAT/page-bids delivery (proxy/click URL conversion, bidder `` removal; creative TSJS injection on `POST /auction` only). Enabling `sanitize_creatives` strips executable markup from winning-bid adm before delivery.
- `creative_opportunities.slot.gam_unit_path` is now a template supporting `{network_id}`, `{slot_id}`, and `{section}`, so a publisher whose ad unit varies by site section expresses it in one slot rule instead of one per (slot × section). `{section}` derives from the request path: `[creative_opportunities].section_segment` selects which path segment names the section (0-based, default `0`; set `1` for locale-prefixed URLs), and `section_root` supplies the value for paths with no such segment. `section_root` is required when a template uses `{section}`. Existing static and absent `gam_unit_path` configs are unchanged. Startup rejects a blank `gam_network_id` only when an absent/default path or `{network_id}` template consumes it. Trusted Server conservatively caps whole rendered dynamic paths at 100 UTF-8 bytes, informed by Google's 100-character per-ad-unit-code limit; an over-limit request-specific path omits that slot without failing the response. During typed/startup finalization, every placeholder-bearing template that omits `section_segment` materializes `section_segment = 0`, so an older binary rejects the blob loudly. Static and absent paths remain legacy-schema compatible only when both `section_root` and `section_segment` are omitted. Before rolling back below this feature, replace or remove dynamic paths, remove both keys, re-push and finalize the config, then roll back the binary.
- Added opt-in APS HTTP debug metadata for controlled test sites, exposing the direct request and response under `/auction` provider metadata using the Prebid Server `debug.httpcalls` shape.
diff --git a/Cargo.lock b/Cargo.lock
index e915a0ea8b..a60f1d4eca 100644
--- a/Cargo.lock
+++ b/Cargo.lock
@@ -832,7 +832,7 @@ version = "3.1.1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "faf9468729b8cbcea668e36183cb69d317348c2e08e994829fb56ebfdfbaac34"
dependencies = [
- "windows-sys 0.61.2",
+ "windows-sys 0.48.0",
]
[[package]]
@@ -1498,7 +1498,7 @@ dependencies = [
[[package]]
name = "edgezero-adapter"
version = "0.1.0"
-source = "git+https://github.com/stackpop/edgezero?rev=683202c66948146ec360f490126f1d60f920288b#683202c66948146ec360f490126f1d60f920288b"
+source = "git+https://github.com/stackpop/edgezero?rev=ab444946fcacb1d44c020c6079abb6ba29231402#ab444946fcacb1d44c020c6079abb6ba29231402"
dependencies = [
"toml",
]
@@ -1506,7 +1506,7 @@ dependencies = [
[[package]]
name = "edgezero-adapter-axum"
version = "0.1.0"
-source = "git+https://github.com/stackpop/edgezero?rev=683202c66948146ec360f490126f1d60f920288b#683202c66948146ec360f490126f1d60f920288b"
+source = "git+https://github.com/stackpop/edgezero?rev=ab444946fcacb1d44c020c6079abb6ba29231402#ab444946fcacb1d44c020c6079abb6ba29231402"
dependencies = [
"anyhow",
"async-trait",
@@ -1534,7 +1534,7 @@ dependencies = [
[[package]]
name = "edgezero-adapter-cloudflare"
version = "0.1.0"
-source = "git+https://github.com/stackpop/edgezero?rev=683202c66948146ec360f490126f1d60f920288b#683202c66948146ec360f490126f1d60f920288b"
+source = "git+https://github.com/stackpop/edgezero?rev=ab444946fcacb1d44c020c6079abb6ba29231402#ab444946fcacb1d44c020c6079abb6ba29231402"
dependencies = [
"anyhow",
"async-trait",
@@ -1557,7 +1557,7 @@ dependencies = [
[[package]]
name = "edgezero-adapter-fastly"
version = "0.1.0"
-source = "git+https://github.com/stackpop/edgezero?rev=683202c66948146ec360f490126f1d60f920288b#683202c66948146ec360f490126f1d60f920288b"
+source = "git+https://github.com/stackpop/edgezero?rev=ab444946fcacb1d44c020c6079abb6ba29231402#ab444946fcacb1d44c020c6079abb6ba29231402"
dependencies = [
"anyhow",
"async-stream",
@@ -1586,7 +1586,7 @@ dependencies = [
[[package]]
name = "edgezero-adapter-spin"
version = "0.1.0"
-source = "git+https://github.com/stackpop/edgezero?rev=683202c66948146ec360f490126f1d60f920288b#683202c66948146ec360f490126f1d60f920288b"
+source = "git+https://github.com/stackpop/edgezero?rev=ab444946fcacb1d44c020c6079abb6ba29231402#ab444946fcacb1d44c020c6079abb6ba29231402"
dependencies = [
"anyhow",
"async-trait",
@@ -1613,7 +1613,7 @@ dependencies = [
[[package]]
name = "edgezero-cli"
version = "0.1.0"
-source = "git+https://github.com/stackpop/edgezero?rev=683202c66948146ec360f490126f1d60f920288b#683202c66948146ec360f490126f1d60f920288b"
+source = "git+https://github.com/stackpop/edgezero?rev=ab444946fcacb1d44c020c6079abb6ba29231402#ab444946fcacb1d44c020c6079abb6ba29231402"
dependencies = [
"chrono",
"clap",
@@ -1638,7 +1638,7 @@ dependencies = [
[[package]]
name = "edgezero-core"
version = "0.1.0"
-source = "git+https://github.com/stackpop/edgezero?rev=683202c66948146ec360f490126f1d60f920288b#683202c66948146ec360f490126f1d60f920288b"
+source = "git+https://github.com/stackpop/edgezero?rev=ab444946fcacb1d44c020c6079abb6ba29231402#ab444946fcacb1d44c020c6079abb6ba29231402"
dependencies = [
"anyhow",
"async-compression",
@@ -1669,7 +1669,7 @@ dependencies = [
[[package]]
name = "edgezero-macros"
version = "0.1.0"
-source = "git+https://github.com/stackpop/edgezero?rev=683202c66948146ec360f490126f1d60f920288b#683202c66948146ec360f490126f1d60f920288b"
+source = "git+https://github.com/stackpop/edgezero?rev=ab444946fcacb1d44c020c6079abb6ba29231402#ab444946fcacb1d44c020c6079abb6ba29231402"
dependencies = [
"log",
"proc-macro2",
@@ -2557,7 +2557,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "1c91d8cffac8849493a82233811bd02b2b183b8cf39bf704de0fa0841b737595"
dependencies = [
"bstr",
- "hashbrown 0.17.1",
+ "hashbrown 0.16.1",
]
[[package]]
@@ -6546,6 +6546,7 @@ dependencies = [
"futures",
"log",
"log-fastly",
+ "rand 0.8.6",
"serde",
"serde_json",
"toml",
@@ -7210,7 +7211,7 @@ version = "0.1.11"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "c2a7b1c03c876122aa43f3020e6c3c3ee5c05081c9a00739faf7503aeba10d22"
dependencies = [
- "windows-sys 0.61.2",
+ "windows-sys 0.48.0",
]
[[package]]
diff --git a/Cargo.toml b/Cargo.toml
index f5c81ecf4b..c00b3a2659 100644
--- a/Cargo.toml
+++ b/Cargo.toml
@@ -56,12 +56,14 @@ cssparser = "0.36"
derive_more = { version = "2.0", features = ["display", "error"] }
directories = "5"
ed25519-dalek = { version = "2.2", features = ["rand_core"] }
-edgezero-adapter-axum = { git = "https://github.com/stackpop/edgezero", rev = "683202c66948146ec360f490126f1d60f920288b", default-features = false }
-edgezero-adapter-cloudflare = { git = "https://github.com/stackpop/edgezero", rev = "683202c66948146ec360f490126f1d60f920288b", default-features = false }
-edgezero-adapter-fastly = { git = "https://github.com/stackpop/edgezero", rev = "683202c66948146ec360f490126f1d60f920288b", default-features = false }
-edgezero-adapter-spin = { git = "https://github.com/stackpop/edgezero", rev = "683202c66948146ec360f490126f1d60f920288b", default-features = false }
-edgezero-cli = { git = "https://github.com/stackpop/edgezero", rev = "683202c66948146ec360f490126f1d60f920288b" }
-edgezero-core = { git = "https://github.com/stackpop/edgezero", rev = "683202c66948146ec360f490126f1d60f920288b", default-features = false }
+# Temporary integration pin for EdgeZero PR #389. Before merging TS into main,
+# replace all six pins with the approved EdgeZero release tag and revalidate.
+edgezero-adapter-axum = { git = "https://github.com/stackpop/edgezero", rev = "ab444946fcacb1d44c020c6079abb6ba29231402", default-features = false }
+edgezero-adapter-cloudflare = { git = "https://github.com/stackpop/edgezero", rev = "ab444946fcacb1d44c020c6079abb6ba29231402", default-features = false }
+edgezero-adapter-fastly = { git = "https://github.com/stackpop/edgezero", rev = "ab444946fcacb1d44c020c6079abb6ba29231402", default-features = false }
+edgezero-adapter-spin = { git = "https://github.com/stackpop/edgezero", rev = "ab444946fcacb1d44c020c6079abb6ba29231402", default-features = false }
+edgezero-cli = { git = "https://github.com/stackpop/edgezero", rev = "ab444946fcacb1d44c020c6079abb6ba29231402" }
+edgezero-core = { git = "https://github.com/stackpop/edgezero", rev = "ab444946fcacb1d44c020c6079abb6ba29231402", default-features = false }
env_logger = "0.11"
error-stack = "0.6"
esi = "0.7.2"
diff --git a/crates/trusted-server-adapter-axum/Cargo.toml b/crates/trusted-server-adapter-axum/Cargo.toml
index 94ad02170c..1c0158e6fd 100644
--- a/crates/trusted-server-adapter-axum/Cargo.toml
+++ b/crates/trusted-server-adapter-axum/Cargo.toml
@@ -20,6 +20,7 @@ path = "src/main.rs"
[dependencies]
async-trait = { workspace = true }
+axum = { workspace = true }
edgezero-adapter-axum = { workspace = true, features = ["axum"] }
edgezero-core = { workspace = true }
error-stack = { workspace = true }
@@ -27,7 +28,8 @@ futures = { workspace = true }
log = { workspace = true }
reqwest = { workspace = true }
simple_logger = { workspace = true }
-tokio = { workspace = true, features = ["rt-multi-thread", "macros", "sync", "time"] }
+tokio = { workspace = true, features = ["rt-multi-thread", "macros", "net", "signal", "sync", "time"] }
+tower = { workspace = true, features = ["util"] }
trusted-server-core = { workspace = true }
[dev-dependencies]
@@ -36,4 +38,3 @@ axum = { workspace = true }
base64 = { workspace = true }
temp-env = { workspace = true }
tokio = { workspace = true, features = ["rt-multi-thread", "macros"] }
-tower = { workspace = true, features = ["util"] }
diff --git a/crates/trusted-server-adapter-axum/src/app.rs b/crates/trusted-server-adapter-axum/src/app.rs
index caba714d68..7bd46b12e4 100644
--- a/crates/trusted-server-adapter-axum/src/app.rs
+++ b/crates/trusted-server-adapter-axum/src/app.rs
@@ -1,6 +1,7 @@
use core::future::Future;
use std::sync::Arc;
+use edgezero_adapter_axum::service::EdgeZeroAxumService;
use edgezero_core::app::Hooks;
use edgezero_core::context::RequestContext;
use edgezero_core::error::EdgeError;
@@ -615,16 +616,10 @@ impl Hooks for TrustedServerApp {
"TrustedServer"
}
+ /// Returns the bare router without terminal timing; serve with
+ /// [`Self::dev_server_service`] to preserve `Server-Timing` emission.
fn routes() -> RouterService {
- let state = match build_state() {
- Ok(s) => s,
- Err(ref e) => {
- log::error!("failed to build application state: {:?}", e);
- return startup_error_router(e);
- }
- };
-
- build_router(&state)
+ Self::routes_with_server_timing_flag().0
}
}
@@ -646,6 +641,43 @@ impl TrustedServerApp {
Ok(build_router(&state))
}
+ /// The dev server's fully configured tower service: the application
+ /// router wrapped in the terminal timing layer
+ /// ([`crate::timing::TimingService`]), with `server_timing_enabled`
+ /// read from the same settings snapshot that built the router.
+ ///
+ /// This is the standard construction path for serving this adapter.
+ /// [`Hooks::routes`] satisfies the `Hooks` trait contract and returns
+ /// the bare router without the timing layer; callers who serve traffic
+ /// should use this instead so `server_timing_enabled` is never
+ /// silently discarded.
+ #[must_use]
+ pub fn dev_server_service() -> crate::timing::TimingService {
+ let (router, server_timing_enabled) = Self::routes_with_server_timing_flag();
+ crate::timing::TimingService::new(EdgeZeroAxumService::new(router), server_timing_enabled)
+ }
+
+ /// Build the router alongside whether `Server-Timing` emission is
+ /// enabled, read from the same settings snapshot used to build the
+ /// router.
+ ///
+ /// The Axum dev server's terminal timing layer ([`crate::timing`]) needs
+ /// this flag once at startup. The Axum dev server builds its application
+ /// state once and reuses the same [`RouterService`] for every request.
+ #[must_use]
+ fn routes_with_server_timing_flag() -> (RouterService, bool) {
+ let state = match build_state() {
+ Ok(s) => s,
+ Err(ref e) => {
+ log::error!("failed to build application state: {:?}", e);
+ return (startup_error_router(e), false);
+ }
+ };
+
+ let server_timing_enabled = state.settings.observability.server_timing_enabled;
+ (build_router(&state), server_timing_enabled)
+ }
+
/// Build the full router with explicit settings and runtime services.
///
/// Each request receives a clone of the supplied services, allowing callers
diff --git a/crates/trusted-server-adapter-axum/src/lib.rs b/crates/trusted-server-adapter-axum/src/lib.rs
index 2f15e566d2..b1d4c3dd8f 100644
--- a/crates/trusted-server-adapter-axum/src/lib.rs
+++ b/crates/trusted-server-adapter-axum/src/lib.rs
@@ -10,3 +10,6 @@ pub mod app;
pub mod middleware;
/// Platform-trait implementations backed by env vars and `reqwest`.
pub mod platform;
+/// Terminal timing layer wrapping the Axum dev server's tower `Service`
+/// boundary with the request-phase `Server-Timing` freeze point.
+pub mod timing;
diff --git a/crates/trusted-server-adapter-axum/src/main.rs b/crates/trusted-server-adapter-axum/src/main.rs
index 66d592e0b7..db21ab3d86 100644
--- a/crates/trusted-server-adapter-axum/src/main.rs
+++ b/crates/trusted-server-adapter-axum/src/main.rs
@@ -1,7 +1,18 @@
-use edgezero_adapter_axum::dev_server::{AxumDevServer, AxumDevServerConfig};
-use edgezero_core::app::Hooks as _;
+use std::convert::Infallible;
+use std::net::SocketAddr;
+
+use axum::Router;
+use axum::body::Body;
+use axum::http::{Request, Response};
+use edgezero_adapter_axum::dev_server::AxumDevServerConfig;
+use edgezero_adapter_axum::service::EdgeZeroAxumService;
use log::LevelFilter;
+use tokio::net::TcpListener;
+use tokio::runtime::Builder as RuntimeBuilder;
+use tokio::signal;
+use tower::{Service, ServiceExt as _, service_fn};
use trusted_server_adapter_axum::app::TrustedServerApp;
+use trusted_server_adapter_axum::timing::TimingService;
/// Environment variable that sets the maximum log level.
const LOG_LEVEL_ENV: &str = "RUST_LOG";
@@ -37,14 +48,88 @@ fn main() {
None => AxumDevServerConfig::default(),
};
- log::info!("Listening on http://{}", config.addr);
- let router = TrustedServerApp::routes();
- if let Err(err) = AxumDevServer::with_config(router, config).run() {
+ let service = TrustedServerApp::dev_server_service();
+ if let Err(err) = run(service, config) {
log::error!("trusted-server-adapter-axum failed: {err}");
std::process::exit(1);
}
}
+/// Runs the Axum dev server with the request-phase timing terminal layer
+/// ([`trusted_server_adapter_axum::timing::TimingService`]) wrapped around
+/// `EdgeZeroAxumService`, ahead of `axum::serve`.
+///
+/// This does not use `edgezero_adapter_axum::dev_server::AxumDevServer::run`:
+/// that helper only accepts a bare [`RouterService`](edgezero_core::router::RouterService) and builds its own
+/// `EdgeZeroAxumService` and `axum::Router` internally, with no seam for an
+/// outer service wrapper. Router-generated 404/405 responses bypass
+/// `RouterBuilder::middleware` (see `trusted_server_adapter_axum::timing`),
+/// so the freeze point has to wrap the tower `Service` boundary itself.
+/// Driving `axum::serve` directly here mirrors that helper's own internal
+/// bind/wrap/serve/shutdown sequence closely enough to keep behavior
+/// identical for callers (`PORT` env var, ctrl-c graceful shutdown).
+///
+/// # Errors
+///
+/// Returns an error if the Tokio runtime fails to start, the listener fails
+/// to bind, or the underlying serve loop errors.
+fn run(
+ service: TimingService,
+ config: AxumDevServerConfig,
+) -> std::io::Result<()> {
+ let runtime = RuntimeBuilder::new_multi_thread()
+ .enable_all()
+ .build()
+ .map_err(|error| {
+ std::io::Error::new(
+ error.kind(),
+ format!("failed to build tokio runtime: {error}"),
+ )
+ })?;
+ runtime.block_on(serve(service, config))
+}
+
+async fn serve(
+ service: TimingService,
+ config: AxumDevServerConfig,
+) -> std::io::Result<()> {
+ let listener = TcpListener::bind(config.addr).await.map_err(|error| {
+ std::io::Error::new(
+ error.kind(),
+ format!("failed to bind dev server to {}: {error}", config.addr),
+ )
+ })?;
+
+ log::info!("Listening on http://{}", listener.local_addr()?);
+
+ let make_service =
+ dev_server_router(service).into_make_service_with_connect_info::();
+
+ let server = axum::serve(listener, make_service);
+ if config.enable_ctrl_c {
+ server
+ .with_graceful_shutdown(async {
+ let _ctrl_c = signal::ctrl_c().await;
+ })
+ .await
+ } else {
+ server.await
+ }
+ .map_err(|error| std::io::Error::new(error.kind(), format!("axum server error: {error}")))
+}
+
+fn dev_server_router(service: S) -> Router
+where
+ S: Service, Response = Response, Error = Infallible>
+ + Clone
+ + Send
+ + Sync
+ + 'static,
+ S::Future: Send + 'static,
+{
+ Router::new().fallback_service(service_fn(move |req| service.clone().oneshot(req)))
+}
+
/// Parses an optional `RUST_LOG` value into the logger's maximum level.
///
/// Absent and blank values resolve to [`DEFAULT_LOG_LEVEL`]. Any other value
@@ -84,10 +169,100 @@ fn port_from_env() -> Option {
#[cfg(test)]
mod tests {
+ use std::future::{Ready, ready};
+ use std::sync::Arc;
+ use std::sync::atomic::{AtomicUsize, Ordering};
+ use std::task::{Context, Poll};
+
use super::*;
- #[test]
- fn crate_compiles() {}
+ struct ReadinessSensitiveService {
+ polled: bool,
+ readied: bool,
+ pending_polls: Arc,
+ calls: Arc,
+ }
+
+ impl Clone for ReadinessSensitiveService {
+ fn clone(&self) -> Self {
+ Self {
+ polled: false,
+ readied: false,
+ pending_polls: Arc::clone(&self.pending_polls),
+ calls: Arc::clone(&self.calls),
+ }
+ }
+ }
+
+ impl Service> for ReadinessSensitiveService {
+ type Response = Response;
+ type Error = Infallible;
+ type Future = Ready>;
+
+ fn poll_ready(&mut self, cx: &mut Context<'_>) -> Poll> {
+ if !self.polled {
+ self.polled = true;
+ self.pending_polls.fetch_add(1, Ordering::Relaxed);
+ cx.waker().wake_by_ref();
+ return Poll::Pending;
+ }
+ self.readied = true;
+ Poll::Ready(Ok(()))
+ }
+
+ fn call(&mut self, _request: Request) -> Self::Future {
+ assert!(
+ self.readied,
+ "should wait for this instance to become ready"
+ );
+ self.readied = false;
+ self.calls.fetch_add(1, Ordering::Relaxed);
+ ready(Ok(Response::builder()
+ .header("cache-control", "private")
+ .body(Body::empty())
+ .expect("should build a private response")))
+ }
+ }
+
+ #[tokio::test]
+ async fn dev_server_bridge_waits_for_readiness_on_timed_and_health_paths() {
+ for path in ["/private", "/health"] {
+ for enabled in [true, false] {
+ let pending_polls = Arc::new(AtomicUsize::new(0));
+ let calls = Arc::new(AtomicUsize::new(0));
+ let router = dev_server_router(TimingService::new(
+ ReadinessSensitiveService {
+ polled: false,
+ readied: false,
+ pending_polls: Arc::clone(&pending_polls),
+ calls: Arc::clone(&calls),
+ },
+ enabled,
+ ));
+
+ for expected_calls in 1..=2 {
+ let response = router
+ .clone()
+ .oneshot(
+ Request::builder()
+ .uri(path)
+ .body(Body::empty())
+ .expect("should build a bridge request"),
+ )
+ .await
+ .expect("should serve the request after readiness");
+
+ assert_eq!(calls.load(Ordering::Relaxed), expected_calls);
+ assert_eq!(pending_polls.load(Ordering::Relaxed), expected_calls);
+ assert_eq!(
+ response.headers().contains_key("server-timing"),
+ enabled && path != "/health",
+ "should preserve timing configuration and health exclusion"
+ );
+ }
+ }
+ }
+ }
#[test]
fn parse_log_level_defaults_to_info_when_unset_or_blank() {
diff --git a/crates/trusted-server-adapter-axum/src/timing.rs b/crates/trusted-server-adapter-axum/src/timing.rs
new file mode 100644
index 0000000000..16da24d126
--- /dev/null
+++ b/crates/trusted-server-adapter-axum/src/timing.rs
@@ -0,0 +1,518 @@
+//! Terminal timing layer for the Axum dev server.
+//!
+//! [`TimingService`](crate::timing::TimingService) wraps the tower `Service`
+//! boundary the Axum dev server's router sits behind: it reuses the generic
+//! handle in request extensions or creates one, exposing it through the
+//! [`RequestTimings`](trusted_server_core::request_timing::RequestTimings)
+//! facade. Downstream core handlers can record into it. The wrapper stamps
+//! `mark_headers_ready` on the way back and appends the `Server-Timing` header via
+//! [`append_server_timing_if_private`](trusted_server_core::request_timing::append_server_timing_if_private).
+//!
+//! This wraps *outside* `RouterService` rather than registering as
+//! `RouterBuilder::middleware` because the tower boundary is the terminal
+//! freeze point. Before a response reaches this layer,
+//! `RouterService::oneshot` inside `EdgeZeroAxumService::call` has
+//! converted any dispatch error into a plain response. Every response is
+//! covered uniformly regardless of how routing produced it, and the
+//! position survives future routing changes. (In this application's router
+//! a catch-all fallback spans every path and publisher method, so
+//! router-generated 404/405s that bypass middleware are close to
+//! unreachable today; the outer position does not depend on them.)
+//!
+//! `/health` is excluded by path match before a
+//! [`RequestTimings`](trusted_server_core::request_timing::RequestTimings)
+//! collector is even created: this wrapper bypasses timing for every method
+//! on that path, leaving any preinstalled handle unchanged.
+//!
+//! The Axum dev server builds its application state once at startup, so
+//! `ts-appbuild` never appears in its per-request header. Fastly records
+//! per-request setup and, on cold requests, application construction in
+//! `Phase::AppBuild`.
+
+use std::convert::Infallible;
+use std::future::Future;
+use std::pin::Pin;
+use std::task::{Context, Poll};
+
+use axum::body::Body as AxumBody;
+use axum::http::{Request, Response};
+use tower::Service;
+use trusted_server_core::request_timing::{RequestTimings, append_server_timing_if_private};
+
+/// Path excluded from timing collection and `Server-Timing` emission: health
+/// checks bypass this wrapper for every method.
+const HEALTH_PATH: &str = "/health";
+
+/// Wraps an inner Axum tower service with the request-phase timing freeze
+/// point described in the module docs.
+#[derive(Clone)]
+pub struct TimingService {
+ inner: S,
+ server_timing_enabled: bool,
+}
+
+impl TimingService {
+ /// Wraps `inner`, appending `Server-Timing` when `server_timing_enabled`
+ /// is set and the response is conclusively private.
+ #[must_use]
+ pub fn new(inner: S, server_timing_enabled: bool) -> Self {
+ Self {
+ inner,
+ server_timing_enabled,
+ }
+ }
+}
+
+impl Service> for TimingService
+where
+ S: Service, Response = Response, Error = Infallible>
+ + Clone
+ + Send
+ + 'static,
+ S::Future: Send + 'static,
+{
+ type Error = Infallible;
+ type Future = Pin> + Send>>;
+ type Response = Response;
+
+ fn call(&mut self, mut req: Request) -> Self::Future {
+ // Readiness belongs to the polled instance, not necessarily its clone.
+ let replacement = self.inner.clone();
+ let mut inner = std::mem::replace(&mut self.inner, replacement);
+
+ // Bypass installation and finalization for `/health`, regardless of method.
+ // A preinstalled collector remains available to the inner service.
+ if req.uri().path() == HEALTH_PATH {
+ return Box::pin(async move { inner.call(req).await });
+ }
+
+ let server_timing_enabled = self.server_timing_enabled;
+ let timings = RequestTimings::from_extensions(req.extensions()).unwrap_or_else(|| {
+ let timings = RequestTimings::new();
+ req.extensions_mut().insert(timings.handle().clone());
+ timings
+ });
+
+ Box::pin(async move {
+ let mut response = inner.call(req).await?;
+ append_server_timing_if_private(&mut response, &timings, server_timing_enabled);
+ Ok(response)
+ })
+ }
+
+ fn poll_ready(&mut self, cx: &mut Context<'_>) -> Poll> {
+ self.inner.poll_ready(cx)
+ }
+}
+
+#[cfg(test)]
+mod tests {
+ use std::future::{Ready, ready};
+ use std::sync::Arc;
+ use std::sync::atomic::{AtomicUsize, Ordering};
+
+ use super::*;
+ use axum::http::header::CACHE_CONTROL;
+ use axum::http::{HeaderValue, StatusCode};
+ use edgezero_adapter_axum::service::EdgeZeroAxumService;
+ use edgezero_core::body::Body as EdgeBody;
+ use edgezero_core::context::RequestContext;
+ use edgezero_core::error::EdgeError;
+ use edgezero_core::http::response_builder;
+ use edgezero_core::router::RouterService;
+ use tower::{ServiceExt as _, service_fn};
+
+ struct ReadinessSensitiveService {
+ readied: bool,
+ calls: Arc,
+ }
+
+ impl Clone for ReadinessSensitiveService {
+ fn clone(&self) -> Self {
+ Self {
+ readied: false,
+ calls: Arc::clone(&self.calls),
+ }
+ }
+ }
+
+ impl Service> for ReadinessSensitiveService {
+ type Response = Response;
+ type Error = Infallible;
+ type Future = Ready>;
+
+ fn poll_ready(&mut self, _cx: &mut Context<'_>) -> Poll> {
+ self.readied = true;
+ Poll::Ready(Ok(()))
+ }
+
+ fn call(&mut self, _req: Request) -> Self::Future {
+ assert!(
+ self.readied,
+ "should call the instance whose readiness permit was reserved"
+ );
+ self.readied = false;
+ self.calls.fetch_add(1, Ordering::Relaxed);
+ ready(Ok(Response::builder()
+ .header(CACHE_CONTROL, "private")
+ .body(AxumBody::empty())
+ .expect("should build a private fixture response")))
+ }
+ }
+
+ #[tokio::test]
+ async fn axum_calls_the_readied_instance_on_timed_and_health_paths() {
+ for path in ["/private", "/health"] {
+ for enabled in [true, false] {
+ let calls = Arc::new(AtomicUsize::new(0));
+ let inner = ReadinessSensitiveService {
+ readied: false,
+ calls: Arc::clone(&calls),
+ };
+ let mut service = TimingService::new(inner, enabled);
+
+ for expected_calls in 1..=2 {
+ let request = Request::builder()
+ .uri(path)
+ .body(AxumBody::empty())
+ .expect("should build a request for readiness testing");
+ let response = service
+ .ready()
+ .await
+ .expect("should reserve readiness")
+ .call(request)
+ .await
+ .expect("should call the readied service");
+
+ assert_eq!(
+ calls.load(Ordering::Relaxed),
+ expected_calls,
+ "should forward each request exactly once"
+ );
+ assert_eq!(
+ header(&response, "server-timing").is_some(),
+ enabled && path != HEALTH_PATH,
+ "should preserve the timing flag and health bypass"
+ );
+ }
+ }
+ }
+ }
+
+ /// Builds a private (`cache-control: private, no-store`) response for a
+ /// handler under test.
+ fn private_ok_response() -> Result {
+ Ok(response_builder()
+ .status(StatusCode::OK)
+ .header("cache-control", "private, no-store")
+ .body(EdgeBody::from("ok"))
+ .expect("should build a private response fixture"))
+ }
+
+ /// Reads a response header as a UTF-8 string, or `None` if absent.
+ fn header(response: &Response, name: &str) -> Option {
+ response
+ .headers()
+ .get(name)
+ .and_then(|value| value.to_str().ok())
+ .map(ToOwned::to_owned)
+ }
+
+ #[tokio::test(flavor = "multi_thread", worker_threads = 2)]
+ async fn axum_preserves_preinstalled_collector_and_origin() {
+ let timings = RequestTimings::new();
+ timings.record(
+ trusted_server_core::request_timing::Phase::Filter,
+ std::time::Duration::from_millis(7),
+ );
+ tokio::time::sleep(std::time::Duration::from_millis(20)).await;
+ let router = RouterService::builder()
+ .get("/private", |ctx: RequestContext| async move {
+ let timings = RequestTimings::from_extensions(ctx.request().extensions())
+ .expect("should receive preinstalled collector");
+ assert_eq!(
+ timings.snapshot().filter_ms,
+ Some(7),
+ "should preserve upstream phase"
+ );
+ timings.mark_auction_dispatched();
+ assert!(
+ timings
+ .snapshot()
+ .auction_dispatched_ms
+ .expect("should mark dispatch")
+ >= 20,
+ "should preserve the pre-aged origin"
+ );
+ private_ok_response()
+ })
+ .build();
+ let terminal = TimingService::new(EdgeZeroAxumService::new(router), true);
+ let upstream_timings = timings.clone();
+ let mut upstream = service_fn(move |mut req: Request| {
+ req.extensions_mut()
+ .insert(upstream_timings.handle().clone());
+ let mut service = terminal.clone();
+ async move { service.call(req).await }
+ });
+ let request = Request::builder()
+ .uri("/private")
+ .body(AxumBody::empty())
+ .expect("should build request");
+ let response = upstream
+ .ready()
+ .await
+ .expect("should be ready")
+ .call(request)
+ .await
+ .expect("should handle request");
+ let value = header(&response, "server-timing").expect("should render private timing");
+ assert!(
+ value.contains("ts-filter;dur=7.0"),
+ "should render upstream phase: {value}"
+ );
+ assert!(
+ timings
+ .snapshot()
+ .time_elapsed_ms
+ .expect("should stamp original handle")
+ >= 20,
+ "terminal rendering should use the original clock"
+ );
+ }
+
+ #[tokio::test(flavor = "multi_thread", worker_threads = 2)]
+ async fn axum_emits_header_on_private_response() {
+ let router = RouterService::builder()
+ .get("/private", |_ctx: RequestContext| async {
+ private_ok_response()
+ })
+ .build();
+ let mut service = TimingService::new(EdgeZeroAxumService::new(router), true);
+
+ let request = Request::builder()
+ .uri("/private")
+ .body(AxumBody::empty())
+ .expect("should build request");
+ let response = service
+ .ready()
+ .await
+ .expect("should be ready")
+ .call(request)
+ .await
+ .expect("should not fail");
+
+ let server_timing = header(&response, "server-timing").expect("should emit header");
+ assert!(
+ server_timing.contains("ts-total;dur="),
+ "should carry the collected total: {server_timing}"
+ );
+ assert!(
+ !server_timing.contains("ts-appbuild"),
+ "the Axum dev server builds state once at startup, so there is no \
+ per-request app-build interval to render: {server_timing}"
+ );
+ }
+
+ #[tokio::test(flavor = "multi_thread", worker_threads = 2)]
+ async fn axum_suppresses_timing_when_edge_cache_header_collides_with_private_cache_control() {
+ let router = RouterService::builder()
+ .get("/collision", |_ctx: RequestContext| async {
+ Ok(response_builder()
+ .status(StatusCode::OK)
+ .header("cache-control", "private, no-store")
+ .header("cdn-cache-control", "max-age=60")
+ .body(EdgeBody::from("ok"))
+ .expect("should build a response with conflicting cache directives"))
+ })
+ .build();
+ let mut service = TimingService::new(EdgeZeroAxumService::new(router), true);
+
+ let request = Request::builder()
+ .uri("/collision")
+ .body(AxumBody::empty())
+ .expect("should build request");
+ let response = service
+ .ready()
+ .await
+ .expect("should be ready")
+ .call(request)
+ .await
+ .expect("should not fail");
+
+ assert_eq!(response.status(), StatusCode::OK);
+ assert_eq!(
+ header(&response, "cdn-cache-control").as_deref(),
+ Some("max-age=60")
+ );
+ assert!(
+ header(&response, "server-timing").is_none(),
+ "must not expose timing when a CDN header can make the private response cacheable"
+ );
+ }
+
+ #[tokio::test(flavor = "multi_thread", worker_threads = 2)]
+ async fn axum_suppresses_header_when_flag_is_off() {
+ let router = RouterService::builder()
+ .get("/private", |_ctx: RequestContext| async {
+ private_ok_response()
+ })
+ .build();
+ let mut service = TimingService::new(EdgeZeroAxumService::new(router), false);
+
+ let request = Request::builder()
+ .uri("/private")
+ .body(AxumBody::empty())
+ .expect("should build request");
+ let response = service
+ .ready()
+ .await
+ .expect("should be ready")
+ .call(request)
+ .await
+ .expect("should not fail");
+
+ assert!(
+ header(&response, "server-timing").is_none(),
+ "should not emit server-timing when server_timing_enabled is false"
+ );
+ }
+
+ #[tokio::test(flavor = "multi_thread", worker_threads = 2)]
+ async fn axum_round_trips_phase_timings_recorded_in_the_handler() {
+ // The collector crosses the adapter boundary as a request extension;
+ // this pins the round trip end to end: a phase recorded inside a
+ // core-style handler must come back out in the rendered header, so
+ // a future adapter conversion that drops request extensions fails
+ // here instead of silently losing every phase.
+ let router = RouterService::builder()
+ .get("/private", |ctx: RequestContext| async move {
+ if let Some(timings) = RequestTimings::from_extensions(ctx.request().extensions()) {
+ timings.record(
+ trusted_server_core::request_timing::Phase::Filter,
+ std::time::Duration::from_millis(7),
+ );
+ }
+ private_ok_response()
+ })
+ .build();
+ let mut service = TimingService::new(EdgeZeroAxumService::new(router), true);
+
+ let request = Request::builder()
+ .uri("/private")
+ .body(AxumBody::empty())
+ .expect("should build request");
+ let response = service
+ .ready()
+ .await
+ .expect("should be ready")
+ .call(request)
+ .await
+ .expect("should not fail");
+
+ let server_timing = header(&response, "server-timing").expect("should emit header");
+ assert!(
+ server_timing.contains("ts-filter;dur=7.0"),
+ "a phase recorded in the handler should survive the adapter round trip: {server_timing}"
+ );
+ }
+
+ #[tokio::test(flavor = "multi_thread", worker_threads = 2)]
+ async fn axum_404_carries_header_when_private() {
+ // An empty router has no routes at all, so any path dispatches
+ // through `RouterInner::dispatch`'s `NotFound` branch, exactly the
+ // path that bypasses `RouterBuilder::middleware`. The router's own
+ // `EdgeError::into_response` does not attach `Cache-Control`, so a
+ // small wrapping service forces the response private here, standing
+ // in for whatever upstream layer would normally mark a genuinely
+ // private 404. This proves the freeze point still runs for a
+ // router-generated response without weakening
+ // `append_server_timing_if_private`'s real gating logic.
+ let empty_router = RouterService::builder().build();
+ let inner = EdgeZeroAxumService::new(empty_router);
+ let force_private = service_fn(move |req: Request| {
+ let mut svc = inner.clone();
+ async move {
+ let mut response = svc.call(req).await?;
+ response
+ .headers_mut()
+ .insert(CACHE_CONTROL, HeaderValue::from_static("private, no-store"));
+ Ok::<_, Infallible>(response)
+ }
+ });
+ let mut service = TimingService::new(force_private, true);
+
+ let request = Request::builder()
+ .uri("/does-not-exist")
+ .body(AxumBody::empty())
+ .expect("should build request");
+ let response = service
+ .ready()
+ .await
+ .expect("should be ready")
+ .call(request)
+ .await
+ .expect("should not fail");
+
+ assert_eq!(
+ response.status(),
+ StatusCode::NOT_FOUND,
+ "should still be the router's own not-found response"
+ );
+ let server_timing = header(&response, "server-timing")
+ .expect("a router-generated 404 must still carry the header when private");
+ assert!(
+ server_timing.contains("ts-total;dur="),
+ "should carry the collected total: {server_timing}"
+ );
+ }
+
+ #[tokio::test(flavor = "multi_thread", worker_threads = 2)]
+ async fn axum_health_is_excluded() {
+ for method in [axum::http::Method::GET, axum::http::Method::POST] {
+ for path in ["/health", "/health?probe=1"] {
+ for preinstalled in [false, true] {
+ let timings = RequestTimings::new();
+ let inner = service_fn(move |req: Request| async move {
+ assert_eq!(
+ RequestTimings::from_extensions(req.extensions()).is_some(),
+ preinstalled,
+ "health bypass should not install or remove a handle"
+ );
+ Ok::<_, Infallible>(
+ Response::builder()
+ .header("cache-control", "private")
+ .body(AxumBody::empty())
+ .expect("should build private response"),
+ )
+ });
+ let mut service = TimingService::new(inner, true);
+ let mut request = Request::builder()
+ .method(method.clone())
+ .uri(path)
+ .body(AxumBody::empty())
+ .expect("should build request");
+ if preinstalled {
+ request.extensions_mut().insert(timings.handle().clone());
+ }
+ let response = service
+ .ready()
+ .await
+ .expect("should be ready")
+ .call(request)
+ .await
+ .expect("should not fail");
+ assert!(
+ header(&response, "server-timing").is_none(),
+ "health should not emit timing"
+ );
+ assert_eq!(
+ timings.snapshot().time_elapsed_ms,
+ None,
+ "health bypass should not finalize timing"
+ );
+ }
+ }
+ }
+ }
+}
diff --git a/crates/trusted-server-adapter-cloudflare/src/app.rs b/crates/trusted-server-adapter-cloudflare/src/app.rs
index 87b9567e7f..3a7445e059 100644
--- a/crates/trusted-server-adapter-cloudflare/src/app.rs
+++ b/crates/trusted-server-adapter-cloudflare/src/app.rs
@@ -40,6 +40,7 @@ use trusted_server_core::publisher::{
use trusted_server_core::request_signing::{
handle_trusted_server_discovery, handle_verify_signature,
};
+use trusted_server_core::request_timing::RequestTimingMiddleware;
use trusted_server_core::settings::Settings;
use crate::middleware::{AuthMiddleware, FinalizeResponseMiddleware, SanitizeRequestMiddleware};
@@ -602,6 +603,7 @@ fn build_router(state: &Arc) -> RouterService {
// any middleware registered ahead of it would observe the
// shared-secret authentication header.
.middleware(SanitizeRequestMiddleware::new(Arc::clone(&state.settings)))
+ .middleware(RequestTimingMiddleware::default().with_excluded_paths(&["/health"]))
.middleware(FinalizeResponseMiddleware::new(Arc::clone(&state.settings)))
.middleware(AuthMiddleware::new(Arc::clone(&state.settings)))
.get(
diff --git a/crates/trusted-server-adapter-cloudflare/src/middleware.rs b/crates/trusted-server-adapter-cloudflare/src/middleware.rs
index a22b51982e..b6f049bd50 100644
--- a/crates/trusted-server-adapter-cloudflare/src/middleware.rs
+++ b/crates/trusted-server-adapter-cloudflare/src/middleware.rs
@@ -56,9 +56,9 @@ impl Middleware for SanitizeRequestMiddleware {
/// (injected by the Cloudflare Workers runtime). On the native host target the
/// header is absent, so `X-Geo-Info-Available: false` is emitted.
///
-/// Registered directly inside [`SanitizeRequestMiddleware`] and ahead of
-/// [`AuthMiddleware`] so that every outgoing response — including auth-rejected
-/// ones — carries a consistent set of headers.
+/// Registered inside [`RequestTimingMiddleware`](trusted_server_core::request_timing::RequestTimingMiddleware) and ahead of [`AuthMiddleware`]
+/// so that every outgoing response — including auth-rejected ones — carries a
+/// consistent set of headers.
pub struct FinalizeResponseMiddleware {
settings: Arc,
}
@@ -163,6 +163,8 @@ pub(crate) fn apply_finalize_headers(
#[cfg(test)]
mod tests {
use super::*;
+ use edgezero_core::router::RouterService;
+ use trusted_server_core::request_timing::{RequestTimingMiddleware, RequestTimings};
use std::collections::HashMap;
use std::sync::Mutex;
@@ -182,10 +184,10 @@ mod tests {
.expect("should build empty test response")
}
- fn empty_ctx() -> RequestContext {
+ fn ctx_for_path(path: &str) -> RequestContext {
let req = request_builder()
.method(Method::GET)
- .uri("/test")
+ .uri(path)
.header("x-reader-ip", "198.51.100.7")
.header("x-reader-ip-auth", "fictional-shared-secret-0123456789")
.body(Body::empty())
@@ -193,6 +195,10 @@ mod tests {
RequestContext::new(req, PathParams::new(HashMap::new()))
}
+ fn empty_ctx() -> RequestContext {
+ ctx_for_path("/test")
+ }
+
fn settings_with_response_headers(headers: Vec<(&str, &str)>) -> Settings {
// Build from explicit test settings: the settings baked into the
// binary contain placeholder secrets that `get_settings()` rejects
@@ -291,6 +297,77 @@ mod tests {
);
}
+ #[test]
+ fn request_timing_middleware_preserves_shared_handle_and_health_policy() {
+ for method in [Method::GET, Method::POST] {
+ for path in ["/test", "/health", "/health?probe=1", "/health/child"] {
+ for preinstalled in [false, true] {
+ let route_path = path.split('?').next().expect("should have path");
+ let expected = preinstalled || route_path != "/health";
+ let timings = RequestTimings::new();
+ timings.record(
+ trusted_server_core::request_timing::Phase::Filter,
+ std::time::Duration::from_millis(7),
+ );
+ std::thread::sleep(std::time::Duration::from_millis(2));
+ let router = RouterService::builder()
+ .middleware(
+ RequestTimingMiddleware::default().with_excluded_paths(&["/health"]),
+ )
+ .middleware(
+ RequestTimingMiddleware::default().with_excluded_paths(&["/health"]),
+ )
+ .route(route_path, method.clone(), move |ctx: RequestContext| async move {
+ let installed = RequestTimings::from_extensions(ctx.request().extensions());
+ assert_eq!(installed.is_some(), expected, "should preserve exact health policy");
+ if let Some(installed) = installed {
+ if preinstalled {
+ assert_eq!(installed.snapshot().filter_ms, Some(7), "should retain upstream facts");
+ installed.mark_auction_dispatched();
+ assert!(installed.snapshot().auction_dispatched_ms.expect("should mark dispatch") >= 2,
+ "should retain upstream origin");
+ } else {
+ assert_eq!(installed.snapshot(), trusted_server_core::request_timing::TimingSnapshot::default(),
+ "should install independent empty facts");
+ }
+ installed.record_auction_wait(
+ trusted_server_core::request_timing::AuctionWaitPlacement::PreHeader,
+ std::time::Duration::from_millis(3));
+ }
+ Ok::(empty_response())
+ })
+ .build();
+ let mut request = request_builder()
+ .method(method.clone())
+ .uri(path)
+ .body(Body::empty())
+ .expect("should build request");
+ if preinstalled {
+ request.extensions_mut().insert(timings.handle().clone());
+ }
+ let response =
+ block_on(router.oneshot(request)).expect("should dispatch request");
+ assert!(
+ response.headers().get("server-timing").is_none(),
+ "attachment should not expose timing"
+ );
+ if preinstalled {
+ assert_eq!(
+ timings.snapshot().auction_wait_ms,
+ Some(3),
+ "should share handler updates"
+ );
+ assert_eq!(
+ timings.snapshot().request_elapsed_ms,
+ None,
+ "should not fabricate completion"
+ );
+ }
+ }
+ }
+ }
+ }
+
#[test]
fn sanitize_middleware_strips_configured_trust_headers_before_routing() {
let mut settings = settings_with_response_headers(vec![]);
diff --git a/crates/trusted-server-adapter-fastly/Cargo.toml b/crates/trusted-server-adapter-fastly/Cargo.toml
index 710523766e..ed66130f72 100644
--- a/crates/trusted-server-adapter-fastly/Cargo.toml
+++ b/crates/trusted-server-adapter-fastly/Cargo.toml
@@ -32,6 +32,7 @@ fern = { workspace = true }
futures = { workspace = true }
log = { workspace = true }
log-fastly = { workspace = true }
+rand = { workspace = true }
serde = { workspace = true }
serde_json = { workspace = true }
trusted-server-core = { workspace = true }
diff --git a/crates/trusted-server-adapter-fastly/src/app.rs b/crates/trusted-server-adapter-fastly/src/app.rs
index d1da9b61fb..b87bdb38e3 100644
--- a/crates/trusted-server-adapter-fastly/src/app.rs
+++ b/crates/trusted-server-adapter-fastly/src/app.rs
@@ -100,6 +100,7 @@ use edgezero_core::http::{
};
use edgezero_core::router::RouterService;
use error_stack::Report;
+use trusted_server_core::access_telemetry::{RouteClass, RouteMetadata, publisher_route_template};
use trusted_server_core::auction::AuctionTelemetrySink;
use trusted_server_core::auction::endpoints::handle_auction;
use trusted_server_core::auction::{
@@ -119,6 +120,7 @@ use trusted_server_core::ec::kv::KvIdentityGraph;
use trusted_server_core::ec::registry::PartnerRegistry;
use trusted_server_core::ec::{EcContext, EidSyncSource};
use trusted_server_core::error::{IntoHttpResponse as _, TrustedServerError};
+use trusted_server_core::geo::GeoLookupState;
use trusted_server_core::http_util::is_navigation_request;
use trusted_server_core::integrations::{
IntegrationRegistry, ProxyDispatchInput, RequestFilterEffects, RequestFilterRegistryInput,
@@ -140,6 +142,7 @@ use trusted_server_core::request_signing::{
handle_deactivate_key, handle_rotate_key, handle_trusted_server_discovery,
handle_verify_signature,
};
+use trusted_server_core::request_timing::{Phase, RequestTimings};
use trusted_server_core::settings::{ProxyAssetRoute, Settings};
use trusted_server_core::settings_data::{DEFAULT_CONFIG_STORE_ID, get_settings_from_config_store};
use trusted_server_core::tester_cookie::{handle_clear_tester, handle_set_tester};
@@ -298,6 +301,12 @@ fn uses_dynamic_tsjs_fallback(method: &Method, path: &str) -> bool {
*method == Method::GET && path.starts_with("/static/tsjs=")
}
+/// Coarse route template for every `tsjs` bundle request, used as the
+/// `route_template` in the [`RouteMetadata`] attached by the tsjs branch of
+/// [`dispatch_fallback`]. Actual filenames vary by module/hash; the prefix
+/// alone is the route identity that matters for access telemetry.
+const TSJS_ROUTE_TEMPLATE: &str = "/static/tsjs=*";
+
// ---------------------------------------------------------------------------
// EC request state
// ---------------------------------------------------------------------------
@@ -359,6 +368,17 @@ impl EcRequestState {
services: self.services,
}
}
+
+ /// Derives the carried [`GeoLookupState`] from this request's geo lookup
+ /// outcome, so response-phase finalize can reuse it instead of repeating
+ /// the lookup. `build_ec_request_state` always attempts the lookup, so
+ /// `None` here means the lookup ran and failed, not that it was skipped.
+ fn geo_lookup_state(&self) -> GeoLookupState {
+ match &self.geo_info {
+ Some(info) => GeoLookupState::Resolved(info.clone()),
+ None => GeoLookupState::Attempted,
+ }
+ }
}
/// Derives device signals from the request's `User-Agent` header.
@@ -414,13 +434,17 @@ fn build_ec_request_state(
let eids_cookie = crate::extract_cookie_value(req, COOKIE_TS_EIDS);
let sharedid_cookie = crate::extract_cookie_value(req, COOKIE_SHAREDID);
- let geo_info = services
- .geo()
- .lookup(services.client_info().client_ip)
- .unwrap_or_else(|e| {
- log::warn!("geo lookup failed during EC setup: {e}");
- None
- });
+ let timings = RequestTimings::from_extensions(req.extensions()).unwrap_or_default();
+ let geo_info = {
+ let _span = timings.span(Phase::Geo);
+ services
+ .geo()
+ .lookup(services.client_info().client_ip)
+ .unwrap_or_else(|e| {
+ log::warn!("geo lookup failed during EC setup: {e}");
+ None
+ })
+ };
let (ec_context, setup_error) =
match EcContext::read_from_request_with_geo(settings, req, services, geo_info.as_ref()) {
@@ -441,7 +465,7 @@ fn build_ec_request_state(
// Bot gate: suppress KV-backed EC writes for unrecognized clients, except
// consent withdrawals. Revocations keep the write path so tombstones stay
// authoritative even for privacy-extension-heavy clients.
- let kv_graph = crate::maybe_identity_graph(settings);
+ let kv_graph = crate::identity_graph_with_timing(settings, &timings);
let finalize_kv_graph = if setup_error.is_none()
&& (is_real_browser || ec_consent_withdrawn(ec_context.consent()))
{
@@ -493,6 +517,14 @@ async fn run_pre_route_filters(
req: &mut Request,
geo_info: Option<&GeoInfo>,
) -> PreRoute {
+ // Only recorded when a filter is actually registered, so unconfigured
+ // deployments omit ts-filter from the Server-Timing header entirely.
+ let timings = RequestTimings::from_extensions(req.extensions()).unwrap_or_default();
+ let _span = state
+ .registry
+ .has_request_filters()
+ .then(|| timings.span(Phase::Filter));
+
match state
.registry
.filter_request(RequestFilterRegistryInput {
@@ -526,6 +558,7 @@ fn attach_dispatch_extensions(
ec: EcRequestState,
effects: RequestFilterEffects,
) -> Response {
+ response.extensions_mut().insert(ec.geo_lookup_state());
response.extensions_mut().insert(ec.into_finalize_state());
if !effects.response_headers.is_empty() {
response.extensions_mut().insert(effects);
@@ -576,7 +609,9 @@ async fn execute_named(
// Deliberately do not use an EC request-state graph: that
// copy is bot-gated, while operators use curl for this
// authenticated diagnostic.
- let kv = crate::maybe_identity_graph(&state.settings);
+ let timings =
+ RequestTimings::from_extensions(req.extensions()).unwrap_or_default();
+ let kv = crate::identity_graph_with_timing(&state.settings, &timings);
handle_admin_ec_lookup(kv.as_ref(), ®istry, &req)
}
NamedRouteHandler::AdminEidsLookup => handle_admin_eids_lookup(®istry, &req),
@@ -650,7 +685,8 @@ async fn run_named_route(
if req.method() == Method::OPTIONS {
cors_preflight_identify(&state.settings, &req)
} else {
- let kv = crate::require_identity_graph(&state.settings)?;
+ let timings = RequestTimings::from_extensions(req.extensions()).unwrap_or_default();
+ let kv = crate::require_identity_graph_with_timing(&state.settings, &timings)?;
let partner_registry = PartnerRegistry::from_config(&state.settings.ec.partners)?;
handle_identify(
&state.settings,
@@ -733,12 +769,14 @@ fn run_batch_sync(state: &AppState, services: &RuntimeServices, req: Request) ->
let is_real_browser = device_signals.looks_like_browser();
let eids_cookie = crate::extract_cookie_value(&req, COOKIE_TS_EIDS);
let sharedid_cookie = crate::extract_cookie_value(&req, COOKIE_SHAREDID);
+ let timings = RequestTimings::from_extensions(req.extensions()).unwrap_or_default();
- let result = crate::require_identity_graph(&state.settings).and_then(|kv| {
- let partner_registry = PartnerRegistry::from_config(&state.settings.ec.partners)?;
- let limiter = FastlyRateLimiter::new(RATE_COUNTER_NAME);
- handle_batch_sync(&kv, &partner_registry, &limiter, req)
- });
+ let result =
+ crate::require_identity_graph_with_timing(&state.settings, &timings).and_then(|kv| {
+ let partner_registry = PartnerRegistry::from_config(&state.settings.ec.partners)?;
+ let limiter = FastlyRateLimiter::new(RATE_COUNTER_NAME);
+ handle_batch_sync(&kv, &partner_registry, &limiter, req)
+ });
let mut response = result.unwrap_or_else(|e| http_error(&e));
// Legacy parity: batch-sync responses still pass through
@@ -798,12 +836,32 @@ async fn dispatch_fallback(
PreRoute::Continue { effects } => effects,
};
+ // Assigned exactly once, per branch below, alongside the routing
+ // decision itself, so the access-telemetry route identity always
+ // reflects which branch actually dispatched the request — including
+ // when that branch's handler errors. The asset-route sub-branch is an
+ // early return handled separately by `dispatch_asset_fallback`, so it
+ // never reaches (or needs to assign) this binding.
+ let route_metadata: Option;
+
let result = if uses_dynamic_tsjs_fallback(&method, &path) {
+ route_metadata = Some(RouteMetadata {
+ route_class: RouteClass::Tsjs,
+ route_template: TSJS_ROUTE_TEMPLATE.to_owned(),
+ });
handle_tsjs_dynamic(&req, &state.registry, EdgeCacheHeader::SurrogateControl)
- } else if state.registry.has_route(&method, &path) {
+ } else if let Some(pattern) = state.registry.matched_route_pattern(&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
+ // publisher classifier.
+ route_metadata = Some(RouteMetadata {
+ route_class: RouteClass::IntegrationProxy,
+ route_template: pattern.to_owned(),
+ });
state
.registry
.handle_proxy(ProxyDispatchInput {
@@ -831,9 +889,34 @@ async fn dispatch_fallback(
.then(|| state.settings.asset_route_for_path(&path))
.flatten();
if let Some(asset_route) = matched_asset_route {
- return dispatch_asset_fallback(state, services, req, asset_route, &effects).await;
+ // The template is the operator-configured route prefix, so it
+ // is bounded and content-free by construction (unlike request
+ // paths, which need `publisher_route_template`).
+ let asset_metadata = RouteMetadata {
+ route_class: RouteClass::Asset,
+ route_template: format!("{}/*", asset_route.prefix.trim_end_matches('/')),
+ };
+ let mut response = dispatch_asset_fallback(
+ state,
+ services,
+ req,
+ asset_route,
+ &effects,
+ ec.geo_lookup_state(),
+ )
+ .await;
+ response.extensions_mut().insert(asset_metadata);
+ return response;
}
+ route_metadata = Some(RouteMetadata {
+ route_class: RouteClass::PublisherHtml,
+ route_template: publisher_route_template(
+ &path,
+ &state.settings.observability.route_sections,
+ ),
+ });
+
// Generate an EC ID if needed — mirrors the legacy catch-all arm.
// Only for document navigations by recognised browsers; subresource
// requests may lack consent signals such as Sec-GPC.
@@ -899,7 +982,10 @@ async fn dispatch_fallback(
}
};
- let response = result.unwrap_or_else(|e| http_error(&e));
+ let mut response = result.unwrap_or_else(|e| http_error(&e));
+ if let Some(metadata) = route_metadata {
+ response.extensions_mut().insert(metadata);
+ }
attach_dispatch_extensions(response, ec, effects)
}
@@ -923,7 +1009,10 @@ fn asset_response_carries_body(method: &Method, status: StatusCode) -> bool {
/// [`AssetProxyCachePolicy`] out via response extensions so `edgezero_main`
/// can reapply protected cache directives after finalization. EC finalization
/// is intentionally skipped: no [`EcFinalizeState`] is attached, matching the
-/// legacy `should_finalize_ec = false` behavior for asset responses.
+/// legacy `should_finalize_ec = false` behavior for asset responses. The
+/// caller's [`GeoLookupState`] is still attached, since `build_ec_request_state`
+/// already attempted the lookup before the asset route was matched — this is
+/// the one exit path that carries geo state without an `EcFinalizeState`.
///
/// Like legacy `route_request`, asset bodies are streamed straight to the client
/// with no cap: the origin stream is attached to the response and `edgezero_main`
@@ -938,6 +1027,7 @@ async fn dispatch_asset_fallback(
req: Request,
asset_route: &ProxyAssetRoute,
effects: &RequestFilterEffects,
+ geo_state: GeoLookupState,
) -> Response {
log::info!("No explicit route matched; proxying via configured asset route");
@@ -959,6 +1049,7 @@ async fn dispatch_asset_fallback(
}
response.extensions_mut().insert(cache_policy);
+ response.extensions_mut().insert(geo_state);
attach_request_filter_effects(&mut response, effects);
response
}
@@ -967,6 +1058,7 @@ async fn dispatch_asset_fallback(
response
.extensions_mut()
.insert(AssetProxyCachePolicy::NoStorePrivate);
+ response.extensions_mut().insert(geo_state);
attach_request_filter_effects(&mut response, effects);
response
}
@@ -1090,6 +1182,10 @@ struct NamedRoute {
path: &'static str,
primary_methods: &'static [Method],
handler: NamedRouteHandler,
+ /// Access-telemetry traffic category for this row. Attached verbatim
+ /// alongside `path` (the route-table pattern) to every response this
+ /// route produces — see [`named_route_handler`].
+ route_class: RouteClass,
}
/// Every method an admin route must claim to keep non-primary methods from falling
@@ -1112,21 +1208,25 @@ const NAMED_ROUTES: &[NamedRoute] = &[
path: "/.well-known/trusted-server.json",
primary_methods: &[Method::GET],
handler: NamedRouteHandler::TrustedServerDiscovery,
+ route_class: RouteClass::Other,
},
NamedRoute {
path: "/verify-signature",
primary_methods: &[Method::POST],
handler: NamedRouteHandler::VerifySignature,
+ route_class: RouteClass::Ec,
},
NamedRoute {
path: "/_ts/admin/keys/rotate",
primary_methods: &[Method::POST],
handler: NamedRouteHandler::RotateKey,
+ route_class: RouteClass::Ec,
},
NamedRoute {
path: "/_ts/admin/keys/deactivate",
primary_methods: &[Method::POST],
handler: NamedRouteHandler::DeactivateKey,
+ route_class: RouteClass::Ec,
},
// Every method is claimed, not just POST. A method this route did not claim would
// fall through to the publisher, and `enforce_basic_auth` leaves the `Authorization`
@@ -1136,6 +1236,7 @@ const NAMED_ROUTES: &[NamedRoute] = &[
path: "/_ts/admin/cache/purge",
primary_methods: LEGACY_ADMIN_DENY_METHODS,
handler: NamedRouteHandler::AdminCachePurge,
+ route_class: RouteClass::Other,
},
// Admin EC lookup: the bare route reads the EC ID from the caller's
// `ts-ec` cookie; the parameterized route takes an explicit EC ID.
@@ -1143,11 +1244,13 @@ const NAMED_ROUTES: &[NamedRoute] = &[
path: "/_ts/admin/ec",
primary_methods: &[Method::GET],
handler: NamedRouteHandler::AdminEcLookup,
+ route_class: RouteClass::Ec,
},
NamedRoute {
path: "/_ts/admin/ec/{id}",
primary_methods: &[Method::GET],
handler: NamedRouteHandler::AdminEcLookup,
+ route_class: RouteClass::Ec,
},
// Admin EIDs echo: decodes the request's ts-eids/sharedId cookies with
// an ingestion preview. Pure request inspection — no KV access.
@@ -1155,6 +1258,7 @@ const NAMED_ROUTES: &[NamedRoute] = &[
path: "/_ts/admin/eids",
primary_methods: &[Method::GET],
handler: NamedRouteHandler::AdminEidsLookup,
+ route_class: RouteClass::Ec,
},
// The legacy non-`/_ts` aliases (`/admin/keys/*`) are denied locally with a
// 404 instead of executing key operations: the production basic-auth handler
@@ -1166,36 +1270,43 @@ const NAMED_ROUTES: &[NamedRoute] = &[
path: "/admin/keys/rotate",
primary_methods: LEGACY_ADMIN_DENY_METHODS,
handler: NamedRouteHandler::LegacyAdminDenied,
+ route_class: RouteClass::Other,
},
NamedRoute {
path: "/admin/keys/deactivate",
primary_methods: LEGACY_ADMIN_DENY_METHODS,
handler: NamedRouteHandler::LegacyAdminDenied,
+ route_class: RouteClass::Other,
},
NamedRoute {
path: "/_ts/api/v1/batch-sync",
primary_methods: &[Method::POST],
handler: NamedRouteHandler::BatchSync,
+ route_class: RouteClass::Ec,
},
NamedRoute {
path: "/_ts/api/v1/identify",
primary_methods: &[Method::GET, Method::OPTIONS],
handler: NamedRouteHandler::Identify,
+ route_class: RouteClass::Ec,
},
NamedRoute {
path: "/_ts/set-tester",
primary_methods: &[Method::GET],
handler: NamedRouteHandler::SetTester,
+ route_class: RouteClass::Other,
},
NamedRoute {
path: "/_ts/clear-tester",
primary_methods: &[Method::GET],
handler: NamedRouteHandler::ClearTester,
+ route_class: RouteClass::Other,
},
NamedRoute {
path: "/auction",
primary_methods: &[Method::POST],
handler: NamedRouteHandler::Auction,
+ route_class: RouteClass::AuctionApi,
},
// GET runs the SPA re-auction; OPTIONS is denied in-handler as a CORS
// preflight guard for this side-effecting endpoint.
@@ -1203,6 +1314,7 @@ const NAMED_ROUTES: &[NamedRoute] = &[
path: PAGE_BIDS_PATH,
primary_methods: &[Method::GET, Method::OPTIONS],
handler: NamedRouteHandler::PageBids,
+ route_class: RouteClass::AuctionApi,
},
// Deprecated double-underscore alias. tsjs bundles served before the
// `/_ts/page-bids` rename keep requesting this path from already-loaded
@@ -1213,21 +1325,29 @@ const NAMED_ROUTES: &[NamedRoute] = &[
path: PAGE_BIDS_LEGACY_PATH,
primary_methods: &[Method::GET, Method::OPTIONS],
handler: NamedRouteHandler::PageBids,
+ route_class: RouteClass::AuctionApi,
},
+ // Classified `Other` rather than `IntegrationProxy`: that class is
+ // reserved for `state.registry.handle_proxy` (the js-integration proxy
+ // dispatch in `dispatch_fallback`), which these first-party proxy routes
+ // do not go through.
NamedRoute {
path: "/first-party/proxy",
primary_methods: &[Method::GET],
handler: NamedRouteHandler::FirstPartyProxy,
+ route_class: RouteClass::Other,
},
NamedRoute {
path: "/first-party/click",
primary_methods: &[Method::GET],
handler: NamedRouteHandler::FirstPartyClick,
+ route_class: RouteClass::Other,
},
NamedRoute {
path: "/first-party/sign",
primary_methods: &[Method::GET, Method::POST],
handler: NamedRouteHandler::FirstPartySign,
+ route_class: RouteClass::Other,
},
NamedRoute {
path: "/first-party/proxy-rebuild",
@@ -1236,16 +1356,35 @@ const NAMED_ROUTES: &[NamedRoute] = &[
// POST is blocked by CORS and the guard navigates here for a 302 instead.
primary_methods: &[Method::GET, Method::POST],
handler: NamedRouteHandler::FirstPartyProxyRebuild,
+ route_class: RouteClass::Other,
},
];
+/// Wraps [`execute_named`], attaching a [`RouteMetadata`] extension carrying
+/// `route_class` and the route-table pattern (`route_template`, verbatim,
+/// with parameters left as placeholders) to every response the handler
+/// produces — including its early-return diagnostic and setup-error arms,
+/// since the attachment happens once around the whole future rather than in
+/// each branch.
fn named_route_handler(
state: Arc,
handler: NamedRouteHandler,
+ route_class: RouteClass,
+ route_template: &'static str,
) -> impl Fn(RequestContext) -> HandlerFuture + Clone + Send + Sync + 'static {
move |ctx: RequestContext| {
let state = Arc::clone(&state);
- Box::pin(execute_named(state, ctx, handler))
+ Box::pin(async move {
+ execute_named(state, ctx, handler)
+ .await
+ .map(|mut response| {
+ response.extensions_mut().insert(RouteMetadata {
+ route_class,
+ route_template: route_template.to_owned(),
+ });
+ response
+ })
+ })
}
}
@@ -1306,7 +1445,12 @@ impl TrustedServerApp {
router = router.route(
route.path,
method.clone(),
- named_route_handler(Arc::clone(state), route.handler),
+ named_route_handler(
+ Arc::clone(state),
+ route.handler,
+ route.route_class,
+ route.path,
+ ),
);
}
@@ -1366,10 +1510,11 @@ mod tests {
use super::{
AppState, AuctionDispatch, EcContext, EdgeCacheHeader, EidSyncSource, HandlerFuture,
- NAMED_ROUTES, NamedRouteHandler, PAGE_BIDS_LEGACY_PATH, PAGE_BIDS_PATH, RuntimeStoreConfig,
- TrustedServerApp, build_orchestrator_with_plan, build_per_request_services,
- build_state_from_settings, compile_auction_plan, handle_publisher_request,
- publisher_response_into_streaming_response, startup_error_router,
+ NAMED_ROUTES, NamedRouteHandler, PAGE_BIDS_LEGACY_PATH, PAGE_BIDS_PATH, RouteClass,
+ RouteMetadata, RuntimeStoreConfig, TSJS_ROUTE_TEMPLATE, TrustedServerApp,
+ build_orchestrator_with_plan, build_per_request_services, build_state_from_settings,
+ compile_auction_plan, handle_publisher_request, publisher_response_into_streaming_response,
+ startup_error_router,
};
use base64::Engine as _;
use bytes::Bytes;
@@ -1379,6 +1524,7 @@ mod tests {
use edgezero_core::env_config::EnvConfig;
use edgezero_core::http::{
HeaderValue, Method, Request, Response, StatusCode, header, request_builder,
+ response_builder,
};
use edgezero_core::key_value_store::NoopKvStore;
use edgezero_core::params::PathParams;
@@ -1387,20 +1533,23 @@ mod tests {
use error_stack::Report;
use futures::executor::block_on;
- use trusted_server_core::constants::HEADER_X_GEO_INFO_AVAILABLE;
+ use trusted_server_core::constants::{HEADER_X_GEO_COUNTRY, HEADER_X_GEO_INFO_AVAILABLE};
use trusted_server_core::ec::device::DeviceSignals;
use trusted_server_core::error::TrustedServerError;
+ use trusted_server_core::geo::GeoLookupState;
use trusted_server_core::integrations::{
HeaderMutation, IntegrationRegistry, IntegrationRequestFilter, RequestFilterDecision,
RequestFilterEffects, RequestFilterInput,
};
use trusted_server_core::platform::{
- ClientInfo, PlatformBackend, PlatformBackendSpec, PlatformError, PlatformHttpClient,
- PlatformHttpRequest, PlatformKvStore, PlatformPendingRequest, PlatformResponse,
- PlatformSelectResult, PlatformTemplateCache, PlatformTemplateCacheReservation,
- RuntimeServices, TemplateCacheError, TemplateCacheKey, TemplateCacheLookup,
- TemplateCacheMiss, TemplateCacheReservation, TemplateEntry, TemplateMetadata,
+ ClientInfo, GeoInfo, PlatformBackend, PlatformBackendSpec, PlatformError, PlatformGeo,
+ PlatformHttpClient, PlatformHttpRequest, PlatformKvStore, PlatformPendingRequest,
+ PlatformResponse, PlatformSelectResult, PlatformTemplateCache,
+ PlatformTemplateCacheReservation, RuntimeServices, TemplateCacheError, TemplateCacheKey,
+ TemplateCacheLookup, TemplateCacheMiss, TemplateCacheReservation, TemplateEntry,
+ TemplateMetadata,
};
+ use trusted_server_core::request_timing::RequestTimings;
use trusted_server_core::settings::Settings;
#[test]
@@ -1579,12 +1728,12 @@ mod tests {
);
}
- /// Builds a router whose `AppState` uses a registry containing the given
- /// request filters (and no routes), so dispatch-level request-filter
- /// behavior can be exercised without a real integration.
- fn router_with_request_filters(
+ /// Builds an `AppState` whose registry contains the given request
+ /// filters (and no routes), so dispatch-level request-filter behavior can
+ /// be exercised without a real integration.
+ fn state_with_request_filters(
filters: Vec>,
- ) -> RouterService {
+ ) -> Arc {
let settings = test_settings();
let plan = Arc::new(
trusted_server_core::auction::compile_auction_plan(&settings)
@@ -1596,7 +1745,7 @@ mod tests {
let registry = IntegrationRegistry::from_request_filters(filters);
let default_kv_store =
Arc::new(crate::platform::UnavailableKvStore) as Arc;
- let state = Arc::new(super::AppState {
+ Arc::new(super::AppState {
auction_telemetry_sink: Arc::new(
trusted_server_core::auction::NoopAuctionTelemetrySink,
),
@@ -1604,8 +1753,15 @@ mod tests {
orchestrator: Arc::new(orchestrator),
registry: Arc::new(registry),
default_kv_store,
- });
- TrustedServerApp::routes_for_state(&state)
+ })
+ }
+
+ /// Builds a router on top of [`state_with_request_filters`] so
+ /// dispatch-level request-filter behavior can be exercised end-to-end.
+ fn router_with_request_filters(
+ filters: Vec>,
+ ) -> RouterService {
+ TrustedServerApp::routes_for_state(&state_with_request_filters(filters))
}
/// Continues routing while mutating the request and emitting a response
@@ -2292,6 +2448,114 @@ mod tests {
);
}
+ /// `Authorization: Basic` header value for `test_settings()`'s
+ /// `^/_ts/admin` handler (`admin` / `admin-pass`).
+ fn admin_basic_auth_header() -> edgezero_core::http::HeaderValue {
+ let credentials = base64::engine::general_purpose::STANDARD.encode("admin:admin-pass");
+ format!("Basic {credentials}")
+ .parse()
+ .expect("should parse basic-auth header value")
+ }
+
+ #[test]
+ fn named_route_attaches_the_table_pattern_verbatim_even_with_a_real_id_in_the_path() {
+ // A named-route response must carry the route-TABLE pattern
+ // (`{id}` left as a placeholder), never the caller's actual matched
+ // path segment — this is what keeps a real EC identifier out of
+ // access telemetry, independent of anything the row-serialization
+ // layer does.
+ let router = test_router();
+ let ec_id = "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.test01";
+ let mut req = empty_request(Method::GET, &format!("/_ts/admin/ec/{ec_id}"));
+ req.headers_mut()
+ .insert(header::AUTHORIZATION, admin_basic_auth_header());
+ let response = route(&router, req);
+
+ let metadata = response
+ .extensions()
+ .get::()
+ .expect("named-route responses should carry RouteMetadata");
+ assert_eq!(metadata.route_class, RouteClass::Ec);
+ assert_eq!(metadata.route_template, "/_ts/admin/ec/{id}");
+ assert!(
+ !metadata.route_template.contains(ec_id),
+ "the attached template must never contain the matched id"
+ );
+ }
+
+ #[test]
+ fn named_route_attaches_metadata_even_on_a_read_only_diagnostic_early_return() {
+ // AdminEidsLookup is handled by an early-return arm inside
+ // execute_named, before the normal EC lifecycle runs (see the
+ // "read-only diagnostics" comment there). named_route_handler wraps
+ // the whole future, so the attachment must still happen here too.
+ let router = test_router();
+ let mut req = empty_request(Method::GET, "/_ts/admin/eids");
+ req.headers_mut()
+ .insert(header::AUTHORIZATION, admin_basic_auth_header());
+ let response = route(&router, req);
+
+ let metadata = response
+ .extensions()
+ .get::()
+ .expect("even a read-only diagnostic early-return response should carry RouteMetadata");
+ assert_eq!(metadata.route_class, RouteClass::Ec);
+ assert_eq!(metadata.route_template, "/_ts/admin/eids");
+ }
+
+ #[test]
+ fn tsjs_fallback_attaches_tsjs_route_metadata() {
+ let router = test_router();
+ let response = route(
+ &router,
+ empty_request(Method::GET, "/static/tsjs=tsjs-unified.min.js"),
+ );
+
+ let metadata = response
+ .extensions()
+ .get::()
+ .expect("tsjs fallback responses should carry RouteMetadata");
+ assert_eq!(metadata.route_class, RouteClass::Tsjs);
+ assert_eq!(metadata.route_template, TSJS_ROUTE_TEMPLATE);
+ }
+
+ #[test]
+ fn integration_proxy_fallback_attaches_integration_proxy_route_metadata() {
+ // test_settings() enables the prebid integration, which registers a
+ // proxy route at /integrations/prebid/bundle.js.
+ let router = test_router();
+ let response = route(
+ &router,
+ empty_request(Method::GET, "/integrations/prebid/bundle.js"),
+ );
+
+ let metadata = response
+ .extensions()
+ .get::()
+ .expect("integration-proxy fallback responses should carry RouteMetadata");
+ assert_eq!(metadata.route_class, RouteClass::IntegrationProxy);
+ assert_eq!(
+ metadata.route_template, "/integrations/prebid/bundle.js",
+ "should carry the registered route pattern verbatim, not a classifier output"
+ );
+ }
+
+ #[test]
+ fn publisher_fallback_attaches_publisher_html_route_metadata() {
+ let router = test_router();
+ let response = route(&router, empty_request(Method::GET, "/news/some-article"));
+
+ let metadata = response
+ .extensions()
+ .get::()
+ .expect("publisher fallback responses should carry RouteMetadata");
+ assert_eq!(metadata.route_class, RouteClass::PublisherHtml);
+ assert_eq!(
+ metadata.route_template, "/other/*",
+ "the default empty section allowlist should collapse publisher paths"
+ );
+ }
+
fn browser_request(method: Method, path: &str, fetch_destination: &str) -> Request {
let mut request = empty_request(method, path);
request.headers_mut().insert(
@@ -2732,6 +2996,61 @@ mod tests {
);
}
+ #[test]
+ fn asset_fallback_carries_geo_state_without_ec_finalize_state() {
+ // The asset-route fallback is the one exit path that skips
+ // EcFinalizeState but must still carry GeoLookupState, since
+ // build_ec_request_state (and its geo lookup) already ran before the
+ // asset route was matched. Without this, the finalize step would
+ // silently repeat the lookup for every asset request.
+ let settings = Settings::from_toml(
+ r#"
+ [[handlers]]
+ path = "^/_ts/admin"
+ username = "admin"
+ password = "admin-pass"
+
+ [publisher]
+ domain = "test-publisher.com"
+ cookie_domain = ".test-publisher.com"
+ origin_url = "https://origin.test-publisher.com"
+ proxy_secret = "unit-test-proxy-secret"
+
+ [ec]
+ passphrase = "test-secret-key-32-bytes-minimum"
+
+ [request_signing]
+ enabled = false
+ config_store_id = "test-config-store-id"
+ secret_store_id = "test-secret-store-id"
+
+ [proxy]
+
+ [[proxy.asset_routes]]
+ prefix = "/.image/"
+ origin_url = "https://assets.example.com"
+ "#,
+ )
+ .expect("should parse asset-route settings");
+ let state = build_state_from_settings(settings).expect("should build state");
+ let router = TrustedServerApp::routes_for_state(&state);
+
+ let response = route(&router, empty_request(Method::GET, "/.image/banner.png"));
+
+ assert!(
+ response.extensions().get::().is_some(),
+ "asset-route responses should still carry GeoLookupState even though \
+ EC finalization is skipped"
+ );
+ assert!(
+ response
+ .extensions()
+ .get::()
+ .is_none(),
+ "asset-route responses must skip EC finalization (no EcFinalizeState)"
+ );
+ }
+
struct FixedBackend;
impl PlatformBackend for FixedBackend {
@@ -3154,6 +3473,7 @@ mod tests {
req,
asset_route,
&effects,
+ trusted_server_core::geo::GeoLookupState::NotAttempted,
));
assert_eq!(
@@ -3197,6 +3517,193 @@ mod tests {
);
}
+ /// A [`PlatformGeo`] stub that counts every `lookup` call and always
+ /// returns the same canned result, used to prove the request-phase geo
+ /// lookup is never repeated during finalize.
+ struct CountingGeo {
+ calls: Arc,
+ result: Option,
+ }
+
+ impl PlatformGeo for CountingGeo {
+ fn lookup(&self, _: Option) -> Result, Report> {
+ self.calls.fetch_add(1, Ordering::SeqCst);
+ Ok(self.result.clone())
+ }
+ }
+
+ fn sample_geo_info() -> GeoInfo {
+ GeoInfo {
+ city: "Testville".to_string(),
+ country: "US".to_string(),
+ continent: "NorthAmerica".to_string(),
+ latitude: 0.0,
+ longitude: 0.0,
+ metro_code: 0,
+ region: None,
+ asn: None,
+ }
+ }
+
+ fn runtime_services_with_geo(geo: Arc) -> RuntimeServices {
+ RuntimeServices::builder()
+ .config_store(Arc::new(crate::platform::FastlyPlatformConfigStore))
+ .secret_store(Arc::new(crate::platform::FastlyPlatformSecretStore))
+ .kv_store(Arc::new(NoopKvStore) as Arc)
+ .backend(Arc::new(FixedBackend))
+ .http_client(Arc::new(StreamingHttpClient))
+ .geo(geo)
+ .client_info(ClientInfo::default())
+ .build()
+ }
+
+ #[test]
+ fn finalize_reuses_request_phase_geo_without_second_lookup() {
+ // Dispatching a publisher route runs build_ec_request_state, which
+ // attempts the geo lookup once and carries the result via
+ // GeoLookupState. The finalize step (resolve_geo_for_response) must
+ // reuse that carried value instead of calling the geo backend again.
+ let calls = Arc::new(AtomicUsize::new(0));
+ let geo = Arc::new(CountingGeo {
+ calls: Arc::clone(&calls),
+ result: Some(sample_geo_info()),
+ });
+ let state = app_state_for_settings(test_settings());
+ let services = runtime_services_with_geo(geo);
+ let req = empty_request(Method::GET, "/some-page");
+
+ let response = block_on(super::dispatch_fallback(&state, &services, req));
+
+ let carried = response
+ .extensions()
+ .get::()
+ .cloned()
+ .expect("dispatch should attach GeoLookupState");
+ assert!(
+ matches!(carried, GeoLookupState::Resolved(_)),
+ "a successful lookup should carry Resolved"
+ );
+
+ let geo_info =
+ crate::middleware::resolve_geo_for_response(&response, &carried, None, |_| {
+ panic!("finalize must not repeat a resolved geo lookup");
+ });
+
+ assert_eq!(
+ calls.load(Ordering::SeqCst),
+ 1,
+ "only the request-phase lookup should have run"
+ );
+
+ let mut response = response;
+ geo_info
+ .expect("geo info should have resolved")
+ .set_response_headers(&mut response);
+ assert!(
+ response.headers().get(HEADER_X_GEO_COUNTRY).is_some(),
+ "x-geo-country should still be set on the response after reusing the carried geo"
+ );
+ }
+
+ #[test]
+ fn failed_lookup_is_not_retried() {
+ // When the request-phase lookup fails (returns None), dispatch must
+ // carry GeoLookupState::Attempted rather than NotAttempted, and
+ // finalize must not retry it.
+ let calls = Arc::new(AtomicUsize::new(0));
+ let geo = Arc::new(CountingGeo {
+ calls: Arc::clone(&calls),
+ result: None,
+ });
+ let state = app_state_for_settings(test_settings());
+ let services = runtime_services_with_geo(geo);
+ let req = empty_request(Method::GET, "/some-page");
+
+ let response = block_on(super::dispatch_fallback(&state, &services, req));
+
+ let carried = response
+ .extensions()
+ .get::()
+ .cloned()
+ .expect("dispatch should attach GeoLookupState even for a failed lookup");
+ assert!(
+ matches!(carried, GeoLookupState::Attempted),
+ "a failed lookup should carry Attempted, not Resolved or NotAttempted"
+ );
+
+ let geo_info =
+ crate::middleware::resolve_geo_for_response(&response, &carried, None, |_| {
+ panic!("finalize must not retry a failed geo lookup");
+ });
+
+ assert_eq!(
+ calls.load(Ordering::SeqCst),
+ 1,
+ "only the request-phase lookup should have run"
+ );
+ assert!(
+ geo_info.is_none(),
+ "no geo info should be available after a failed lookup"
+ );
+ }
+
+ #[test]
+ fn filter_span_recorded_when_request_filter_runs() {
+ // The Filter phase span should only be recorded when the registry
+ // actually has a request filter registered, so unconfigured
+ // deployments omit ts-filter from the Server-Timing header entirely.
+ let state = state_with_request_filters(vec![Arc::new(RecordingRequestFilter)]);
+ let services = RuntimeServices::builder()
+ .config_store(Arc::new(crate::platform::FastlyPlatformConfigStore))
+ .secret_store(Arc::new(crate::platform::FastlyPlatformSecretStore))
+ .kv_store(Arc::new(NoopKvStore) as Arc)
+ .backend(Arc::new(FixedBackend))
+ .http_client(Arc::new(StreamingHttpClient))
+ .geo(Arc::new(crate::platform::FastlyPlatformGeo))
+ .client_info(ClientInfo::default())
+ .build();
+ let mut req = empty_request(Method::GET, "/some-page");
+ let timings = RequestTimings::new();
+ req.extensions_mut().insert(timings.handle().clone());
+
+ let _ = block_on(super::run_pre_route_filters(
+ &state, &services, &mut req, None,
+ ));
+
+ assert!(
+ timings.snapshot().filter_ms.is_some(),
+ "should record the Filter phase span when a request filter is registered and runs"
+ );
+ }
+
+ #[test]
+ fn filter_span_not_recorded_when_no_request_filters_registered() {
+ // Mirror test: an empty registry must never record the Filter span,
+ // even though run_pre_route_filters still runs (as a no-op loop).
+ let state = state_with_request_filters(Vec::new());
+ let services = RuntimeServices::builder()
+ .config_store(Arc::new(crate::platform::FastlyPlatformConfigStore))
+ .secret_store(Arc::new(crate::platform::FastlyPlatformSecretStore))
+ .kv_store(Arc::new(NoopKvStore) as Arc)
+ .backend(Arc::new(FixedBackend))
+ .http_client(Arc::new(StreamingHttpClient))
+ .geo(Arc::new(crate::platform::FastlyPlatformGeo))
+ .client_info(ClientInfo::default())
+ .build();
+ let mut req = empty_request(Method::GET, "/some-page");
+ let timings = RequestTimings::new();
+ req.extensions_mut().insert(timings.handle().clone());
+
+ let _ = block_on(super::run_pre_route_filters(
+ &state, &services, &mut req, None,
+ ));
+
+ assert!(
+ timings.snapshot().filter_ms.is_none(),
+ "should omit the Filter phase span when no request filters are registered"
+ );
+ }
+
#[test]
fn dispatch_runs_request_filter_and_threads_response_effects() {
// Regression guard for the EdgeZero request-filter bypass: the publisher
@@ -3256,6 +3763,61 @@ mod tests {
);
}
+ /// Joins every instance of a response header into one comma-separated
+ /// string (mirroring how a client sees repeated header fields), or
+ /// `None` if the header is absent.
+ fn response_header(response: &Response, name: &str) -> Option {
+ let values: Vec<&str> = response
+ .headers()
+ .get_all(name)
+ .iter()
+ .filter_map(|value| value.to_str().ok())
+ .collect();
+ if values.is_empty() {
+ None
+ } else {
+ Some(values.join(", "))
+ }
+ }
+
+ #[test]
+ fn server_timing_emitted_on_private_response_when_enabled() {
+ let mut response = response_builder()
+ .header("cache-control", "private, no-store")
+ .body(Body::empty())
+ .expect("should build a private response fixture");
+ let timings = RequestTimings::new();
+
+ crate::apply_server_timing_header(&mut response, &timings, true);
+
+ let header = response_header(&response, "server-timing").expect("should emit header");
+ assert!(
+ header.contains("ts-total;dur="),
+ "should carry the stored total: {header}"
+ );
+ assert_eq!(
+ header.matches("ts-total").count(),
+ 1,
+ "should emit exactly one TS-owned metric set"
+ );
+ }
+
+ #[test]
+ fn server_timing_absent_when_flag_off() {
+ let mut response = response_builder()
+ .header("cache-control", "private, no-store")
+ .body(Body::empty())
+ .expect("should build a private response fixture");
+ let timings = RequestTimings::new();
+
+ crate::apply_server_timing_header(&mut response, &timings, false);
+
+ assert!(
+ response_header(&response, "server-timing").is_none(),
+ "should not emit server-timing when the flag is off"
+ );
+ }
+
fn recovery_eligible_of(response: &Response) -> bool {
response
.extensions()
@@ -3299,6 +3861,32 @@ mod tests {
);
}
+ #[test]
+ fn server_timing_absent_on_cacheable_responses() {
+ // tsjs route policy: public, long max-age, immutable.
+ let mut tsjs_response = response_builder()
+ .header("cache-control", "public, max-age=31536000, immutable")
+ .body(Body::empty())
+ .expect("should build a tsjs-style response fixture");
+ // A bare shared-cacheable response with no private/no-store directive.
+ let mut public_response = response_builder()
+ .header("cache-control", "max-age=60")
+ .body(Body::empty())
+ .expect("should build a bare max-age response fixture");
+
+ crate::apply_server_timing_header(&mut tsjs_response, &RequestTimings::new(), true);
+ crate::apply_server_timing_header(&mut public_response, &RequestTimings::new(), true);
+
+ assert!(
+ response_header(&tsjs_response, "server-timing").is_none(),
+ "should not emit on the public immutable tsjs cache policy"
+ );
+ assert!(
+ response_header(&public_response, "server-timing").is_none(),
+ "should not emit on a bare shared-cacheable max-age response"
+ );
+ }
+
#[test]
fn filter_short_circuit_response_is_not_eligible_for_eid_persistence() {
// A request-filter short circuit (e.g. a DataDome challenge/block) must
@@ -3336,6 +3924,45 @@ mod tests {
);
}
+ #[test]
+ fn server_timing_absent_when_no_cache_control_header_exists() {
+ // The fail-closed case: absence of Cache-Control is not evidence of
+ // privacy, so emission must be suppressed rather than defaulted on.
+ let mut response = response_builder()
+ .body(Body::empty())
+ .expect("should build a response with no cache-control header");
+
+ crate::apply_server_timing_header(&mut response, &RequestTimings::new(), true);
+
+ assert!(
+ response_header(&response, "server-timing").is_none(),
+ "should not emit when the response carries no Cache-Control at all"
+ );
+ }
+
+ #[test]
+ fn preexisting_server_timing_values_survive() {
+ let mut response = response_builder()
+ .header("cache-control", "private, no-store")
+ .header("server-timing", "upstream;dur=1")
+ .body(Body::empty())
+ .expect("should build a private response fixture carrying an upstream Server-Timing");
+ let timings = RequestTimings::new();
+
+ crate::apply_server_timing_header(&mut response, &timings, true);
+
+ let header =
+ response_header(&response, "server-timing").expect("should still carry a header");
+ assert!(
+ header.contains("upstream;dur=1"),
+ "should preserve the pre-existing entry: {header}"
+ );
+ assert!(
+ header.contains("ts-total"),
+ "should append the TS-owned set: {header}"
+ );
+ }
+
#[test]
fn publisher_navigation_origin_start_failure_is_not_recovery_eligible() {
// Recovery is authorized only after a successful origin start. With no
diff --git a/crates/trusted-server-adapter-fastly/src/main.rs b/crates/trusted-server-adapter-fastly/src/main.rs
index 1f2668b0a6..596b696293 100644
--- a/crates/trusted-server-adapter-fastly/src/main.rs
+++ b/crates/trusted-server-adapter-fastly/src/main.rs
@@ -1,4 +1,5 @@
use std::sync::Arc;
+use std::time::{Instant, SystemTime, UNIX_EPOCH};
use edgezero_adapter_fastly::config_store::FastlyConfigStore as EdgeZeroFastlyConfigStore;
use edgezero_adapter_fastly::request::into_core_request;
@@ -12,9 +13,15 @@ use edgezero_core::response::IntoResponse;
use error_stack::Report;
use fastly::http::Method as FastlyMethod;
use fastly::{Request as FastlyRequest, Response as FastlyResponse};
+use rand::Rng as _;
+use trusted_server_core::access_telemetry::{
+ AccessTelemetrySnapshot, DeliveryResult, RouteClass, RouteMetadata, access_event_row,
+};
use trusted_server_core::cache_policy::{EdgeCacheHeader, cache_control_headers_have_directive};
-use trusted_server_core::constants::HEADER_X_TS_VERSION;
+use trusted_server_core::constants::{
+ ENV_FASTLY_IS_STAGING, ENV_FASTLY_POP, ENV_FASTLY_SERVICE_ID, HEADER_X_TS_VERSION,
+};
use trusted_server_core::ec::device::DeviceSignals;
use trusted_server_core::ec::finalize::ec_finalize_response;
use trusted_server_core::ec::kv::KvIdentityGraph;
@@ -23,9 +30,13 @@ use trusted_server_core::ec::pull_sync::{
};
use trusted_server_core::ec::registry::PartnerRegistry;
use trusted_server_core::error::TrustedServerError;
+use trusted_server_core::geo::GeoLookupState;
use trusted_server_core::integrations::RequestFilterEffects;
use trusted_server_core::platform::PlatformGeo as _;
+use trusted_server_core::platform::{PlatformHttpClient, TimedKvStore};
use trusted_server_core::proxy::{AssetProxyCachePolicy, stream_asset_body};
+use trusted_server_core::publisher::TemplateCacheResponseState;
+use trusted_server_core::request_timing::{Phase, RequestTimings, append_server_timing_if_private};
use trusted_server_core::response_privacy::TerminalPrivateResponse;
use trusted_server_core::settings::Settings;
use trusted_server_core::version_header::{apply_git_version_header, git_version_header_value};
@@ -371,7 +382,10 @@ fn edgezero_main(mut req: FastlyRequest, sandbox: &mut Sandbox, ordinal: u64, re
return;
}
- let config_store =
+ let timings = RequestTimings::new();
+
+ let config_store = {
+ let _appbuild = timings.span(Phase::AppBuild);
match open_trusted_server_config_store(runtime_stores.config_store_name.as_ref()) {
Ok(cs) => cs,
Err(e) => {
@@ -381,8 +395,8 @@ fn edgezero_main(mut req: FastlyRequest, sandbox: &mut Sandbox, ordinal: u64, re
.send_to_client();
return;
}
- };
-
+ }
+ };
// Build lazily, once per sandbox. Reached only past the health, JA4, and
// counters short-circuits, so none of those pays for construction.
//
@@ -393,6 +407,7 @@ fn edgezero_main(mut req: FastlyRequest, sandbox: &mut Sandbox, ordinal: u64, re
// permanent error mode, and the next callback retries construction.
let failed_build = sandbox
.initialize(|| {
+ let _appbuild = timings.span(Phase::AppBuild);
let (app, state) = TrustedServerApp::build_app_with_state(&runtime_stores);
match state {
Some(state) => Ok(RetainedApp { app, state }),
@@ -417,6 +432,18 @@ fn edgezero_main(mut req: FastlyRequest, sandbox: &mut Sandbox, ordinal: u64, re
let settings_snapshot = app_state.as_ref().map(|state| Arc::clone(&state.settings));
let counters =
SandboxCounters::capture(sandbox, ordinal, request_id, settings_snapshot.as_deref());
+ let server_timing_enabled = settings_snapshot
+ .as_deref()
+ .is_some_and(|settings| settings.observability.server_timing_enabled);
+ let access_sample_rate = settings_snapshot
+ .as_deref()
+ .map_or(0.0, |settings| settings.tinybird.access_sample_rate);
+ let access_telemetry_enabled = settings_snapshot
+ .as_deref()
+ .is_some_and(|settings| settings.tinybird.enabled && settings.tinybird.access_enabled);
+ let publisher_domain = settings_snapshot
+ .as_deref()
+ .map_or("unknown", |settings| settings.publisher.domain.as_str());
let trusted_client_ip = settings_snapshot
.as_deref()
.and_then(|settings| settings.trusted_client_ip.as_ref());
@@ -436,6 +463,10 @@ fn edgezero_main(mut req: FastlyRequest, sandbox: &mut Sandbox, ordinal: u64, re
req.set_header("fastly-ssl", "1");
}
+ // Capture the method before dispatch consumes the request. The resolved
+ // client IP is retained below in `ClientInfo`.
+ let request_method = req.get_method().clone();
+
// Strip any client-supplied x-ts-tls-* headers before injecting the trusted
// values from the Fastly SDK. Must run after sanitize_fastly_forwarded_headers.
req.remove_header("x-ts-tls-protocol");
@@ -467,6 +498,7 @@ fn edgezero_main(mut req: FastlyRequest, sandbox: &mut Sandbox, ordinal: u64, re
core_req.extensions_mut().insert(config_store);
core_req.extensions_mut().insert(device_signals);
core_req.extensions_mut().insert(client_info);
+ core_req.extensions_mut().insert(timings.handle().clone());
match futures::executor::block_on(app.router().oneshot(core_req)) {
Ok(response) => response,
Err(error) => edge_error_response(error),
@@ -485,14 +517,34 @@ fn edgezero_main(mut req: FastlyRequest, sandbox: &mut Sandbox, ordinal: u64, re
let ec_state = response.extensions_mut().remove::();
let asset_cache_policy = response.extensions_mut().remove::();
let request_filter_effects = response.extensions_mut().remove::();
+ // Read rather than pop: the access-telemetry snapshot built later in
+ // `send_edgezero_response` reads this same extension, so it must still
+ // be attached to `response` at that point.
+ let geo_lookup_state = response
+ .extensions()
+ .get::()
+ .cloned()
+ .unwrap_or(GeoLookupState::NotAttempted);
if !take_finalize_sentinel(&mut response) {
if let Some(settings) = settings_snapshot.as_deref() {
- apply_entry_point_finalize_headers(settings, &mut response, client_ip);
+ apply_entry_point_finalize_headers(
+ settings,
+ &mut response,
+ client_ip,
+ &geo_lookup_state,
+ &timings,
+ );
} else {
match load_settings_from_config_store(&runtime_stores) {
Ok(settings) => {
- apply_entry_point_finalize_headers(&settings, &mut response, client_ip);
+ apply_entry_point_finalize_headers(
+ &settings,
+ &mut response,
+ client_ip,
+ &geo_lookup_state,
+ &timings,
+ );
}
Err(e) => {
log::warn!("entry-point finalize skipped: failed to reload settings: {e:?}");
@@ -508,16 +560,43 @@ fn edgezero_main(mut req: FastlyRequest, sandbox: &mut Sandbox, ordinal: u64, re
policy.apply_after_route_finalization(&mut response, EdgeCacheHeader::SurrogateControl);
}
+ let send_context = SendContext {
+ timings: timings.clone(),
+ server_timing_enabled,
+ method: request_method.as_str(),
+ publisher_domain,
+ access_sample_rate,
+ access_telemetry_enabled,
+ };
+ let access_http_client = platform::FastlyPlatformHttpClient;
+
if let Some(mut ec_state) = ec_state {
if let Some(settings) = settings_snapshot.as_deref() {
- match apply_edgezero_ec_finalize(settings, &mut ec_state, &mut response) {
+ match apply_edgezero_ec_finalize(settings, &mut ec_state, &mut response, &timings) {
Ok(partner_registry) => {
- send_edgezero_response(
+ let outcome = send_edgezero_response(
response,
request_filter_effects.as_ref(),
+ &send_context,
counters.as_ref(),
);
- run_edgezero_pull_sync_after_send(settings, &partner_registry, &ec_state);
+ run_post_send_steps(
+ || {
+ run_edgezero_pull_sync_after_send(
+ settings,
+ &partner_registry,
+ &ec_state,
+ )
+ },
+ || {
+ emit_access_telemetry_after_send(
+ &access_http_client,
+ settings,
+ &outcome,
+ &timings,
+ )
+ },
+ );
return;
}
Err(e) => {
@@ -529,17 +608,35 @@ fn edgezero_main(mut req: FastlyRequest, sandbox: &mut Sandbox, ordinal: u64, re
} else {
match load_settings_from_config_store(&runtime_stores) {
Ok(settings) => {
- match apply_edgezero_ec_finalize(&settings, &mut ec_state, &mut response) {
+ match apply_edgezero_ec_finalize(
+ &settings,
+ &mut ec_state,
+ &mut response,
+ &timings,
+ ) {
Ok(partner_registry) => {
- send_edgezero_response(
+ let outcome = send_edgezero_response(
response,
request_filter_effects.as_ref(),
+ &send_context,
counters.as_ref(),
);
- run_edgezero_pull_sync_after_send(
- &settings,
- &partner_registry,
- &ec_state,
+ run_post_send_steps(
+ || {
+ run_edgezero_pull_sync_after_send(
+ &settings,
+ &partner_registry,
+ &ec_state,
+ );
+ },
+ || {
+ emit_access_telemetry_after_send(
+ &access_http_client,
+ &settings,
+ &outcome,
+ &timings,
+ )
+ },
);
return;
}
@@ -557,7 +654,21 @@ fn edgezero_main(mut req: FastlyRequest, sandbox: &mut Sandbox, ordinal: u64, re
}
}
- send_edgezero_response(response, request_filter_effects.as_ref(), counters.as_ref());
+ let outcome = send_edgezero_response(
+ response,
+ request_filter_effects.as_ref(),
+ &send_context,
+ counters.as_ref(),
+ );
+ // The asset/admin/error fallback path: no `EcFinalizeState` (or the ec
+ // finalize branch above failed), so there is no pull-sync dispatch here
+ // at all — telemetry is the only post-send step. When `app_state` never
+ // built there is nothing to emit either: `access_telemetry_enabled` was
+ // necessarily false without a settings snapshot, so the outcome carries
+ // no access snapshot, and reloading settings here could not change that.
+ if let Some(settings) = settings_snapshot.as_deref() {
+ emit_access_telemetry_after_send(&access_http_client, settings, &outcome, &timings);
+ }
}
fn edge_error_response(error: EdgeError) -> HttpResponse {
@@ -585,24 +696,36 @@ fn apply_entry_point_finalize_headers(
settings: &Settings,
response: &mut HttpResponse,
client_ip: Option,
+ geo_state: &GeoLookupState,
+ timings: &RequestTimings,
) {
- let geo_info = resolve_geo_for_response(response, client_ip, |client_ip| {
+ let geo_info = resolve_geo_for_response(response, geo_state, client_ip, |client_ip| {
+ let _span = timings.span(Phase::Geo);
FastlyPlatformGeo.lookup(client_ip).unwrap_or_else(|e| {
log::warn!("entry-point geo lookup failed: {e}");
None
})
});
apply_finalize_headers(settings, geo_info.as_ref(), response);
+
+ // This path runs only when the middleware chain was bypassed (e.g. a
+ // router-level 404/405 for an unregistered method), so `geo_state` may
+ // still be `NotAttempted` even after a fresh lookup just ran above.
+ // Write the resolved outcome back so the access-telemetry snapshot built
+ // later in `send_edgezero_response` sees what was actually looked up;
+ // 401 handling lives in the shared helper.
+ middleware::write_back_geo_lookup_state(response, geo_info.as_ref());
}
fn apply_edgezero_ec_finalize(
settings: &Settings,
ec_state: &mut EcFinalizeState,
response: &mut HttpResponse,
+ timings: &RequestTimings,
) -> Result> {
let partner_registry = PartnerRegistry::from_config(&settings.ec.partners)?;
let finalize_kv_graph = if ec_state.use_finalize_kv {
- maybe_identity_graph(settings)
+ identity_graph_with_timing(settings, timings)
} else {
None
};
@@ -663,6 +786,218 @@ where
Some((context, kv))
}
+/// Runs the post-send steps in their contract order: EC identity pull-sync
+/// first, then access-telemetry emission.
+///
+/// Every `edgezero_main` site that has both steps routes through this
+/// function, so the ordering is owned in exactly one place and the
+/// sequence test can instrument it; `request_elapsed` is already stamped
+/// before either step because `send_edgezero_response` stamps it before
+/// returning.
+fn run_post_send_steps(pull_sync: impl FnOnce(), emit_access_telemetry: impl FnOnce()) {
+ pull_sync();
+ emit_access_telemetry();
+}
+
+/// Builds and dispatches the access row after a response's transport attempt,
+/// when access telemetry is enabled and this request is sampled in.
+///
+/// Called last at every `send_edgezero_response` call site in
+/// [`edgezero_main`] — after `run_edgezero_pull_sync_after_send` on the two
+/// EC-finalized paths, and directly after send on the asset/admin/error
+/// fallback path, which never builds an [`EcFinalizeState`] or route-scoped
+/// `RuntimeServices` at all. The Tinybird transport context is therefore
+/// constructed fresh from `settings` here rather than threaded through
+/// either of those per-route types, so every response class can emit.
+///
+/// Sampling happens before snapshot construction, using the same configured
+/// rate stored in the row. Disabled and sampled-out requests have no snapshot
+/// and return silently. Row construction, setup and request-start failures log
+/// one warning. The host-owned ingest request continues after this callback;
+/// later transport errors, HTTP status and remote acceptance are unobserved.
+/// Credentials were resolved during settings load.
+fn emit_access_telemetry_after_send(
+ http_client: &dyn PlatformHttpClient,
+ settings: &Settings,
+ outcome: &DeliveryOutcome,
+ timings: &RequestTimings,
+) {
+ if !settings.tinybird.enabled || !settings.tinybird.access_enabled {
+ return;
+ }
+
+ // No snapshot means access telemetry was disabled or sampled out before
+ // the response was sent; there is nothing to emit.
+ let Some(snapshot) = &outcome.snapshot else {
+ return;
+ };
+
+ let since_epoch = SystemTime::now()
+ .duration_since(UNIX_EPOCH)
+ .unwrap_or_default();
+ let epoch_ms = u64::try_from(since_epoch.as_millis()).unwrap_or(u64::MAX);
+ let row = access_event_row(snapshot, &timings.snapshot(), outcome.result, epoch_ms);
+ let result = futures::executor::block_on(async {
+ let target = tinybird::TinybirdEventsTarget::from_access_config(&settings.tinybird)?;
+ tinybird::emit_access_event(http_client, &target, row).await
+ });
+ if let Err(error) = result {
+ log::warn!("access telemetry emission dropped: {error:?}");
+ }
+}
+
+/// Per-response context threaded into [`send_edgezero_response`] so the
+/// function stays at or under seven parameters.
+struct SendContext<'a> {
+ /// The request's phase-timing collector.
+ timings: RequestTimings,
+ /// Whether `observability.server_timing_enabled` is set.
+ server_timing_enabled: bool,
+ /// The request's HTTP method, captured before the request was consumed
+ /// by dispatch.
+ method: &'a str,
+ /// The configured publisher domain, borrowed from the settings snapshot.
+ publisher_domain: &'a str,
+ /// The configured access-telemetry sample rate.
+ access_sample_rate: f64,
+ /// Whether `tinybird.enabled` and `tinybird.access_enabled` were both
+ /// set when settings were first read. Gates building the
+ /// [`AccessTelemetrySnapshot`] at all: the snapshot costs env reads and
+ /// `String` allocations on the pre-send path, which a disabled
+ /// deployment (the default) should not pay.
+ access_telemetry_enabled: bool,
+}
+
+/// Outcome of handing a finalized response to the client.
+pub(crate) struct DeliveryOutcome {
+ /// Outcome of the local body handoff, emitted as `delivery_result`.
+ /// This does not establish confirmed client receipt.
+ pub result: DeliveryResult,
+ /// Access-telemetry dimensions captured for this response at the
+ /// freeze point. `None` when access telemetry was disabled or sampled out;
+ /// the emitter treats that as nothing to send.
+ pub snapshot: Option,
+}
+
+/// Thin Fastly-adapter wrapper around
+/// [`append_server_timing_if_private`], the freeze point shared with the
+/// Axum adapter's terminal timing layer. See that function's doc for the
+/// emission rules (always stamps `mark_headers_ready`; appends rather than
+/// overwrites; never promotes a response to shared-cacheable).
+pub(crate) fn apply_server_timing_header(
+ response: &mut HttpResponse,
+ timings: &RequestTimings,
+ server_timing_enabled: bool,
+) {
+ append_server_timing_if_private(response, timings, server_timing_enabled);
+}
+
+/// A [`Write`](std::io::Write) wrapper that tallies bytes successfully written
+/// to the inner writer.
+///
+/// Wraps the client transport during a streaming drive so a truncated or
+/// failed drive still reports how many bytes actually reached it, instead of
+/// the placeholder `0` a failed/aborted drive would otherwise report.
+struct CountingWriter {
+ inner: W,
+ bytes: u64,
+}
+
+impl CountingWriter {
+ fn new(inner: W) -> Self {
+ Self { inner, bytes: 0 }
+ }
+
+ /// Bytes successfully written to the inner writer so far.
+ fn bytes(&self) -> u64 {
+ self.bytes
+ }
+
+ fn into_inner(self) -> W {
+ self.inner
+ }
+}
+
+impl std::io::Write for CountingWriter {
+ fn write(&mut self, buf: &[u8]) -> std::io::Result {
+ let written = self.inner.write(buf)?;
+ self.bytes = self.bytes.saturating_add(written as u64);
+ Ok(written)
+ }
+
+ fn flush(&mut self) -> std::io::Result<()> {
+ self.inner.flush()
+ }
+}
+
+/// Drives a streaming `EdgeZero` body through `output`, tallying bytes written
+/// and timing the drive into `timings`.
+///
+/// Stamps `resp_bytes` and `request_elapsed` immediately once the drive
+/// returns — before the caller does anything transport-specific (finishing
+/// the streaming body, logging) — so `request_elapsed` never includes that
+/// work. Returns the counting writer (so the caller can recover both the
+/// tallied byte count and the wrapped transport) alongside the drive's
+/// result.
+fn drive_streaming_body(
+ body: EdgeBody,
+ output: W,
+ timings: &RequestTimings,
+) -> (CountingWriter, Result<(), Report>) {
+ let mut counting = CountingWriter::new(output);
+ let drive_started = Instant::now();
+ let result = futures::executor::block_on(stream_asset_body(body, &mut counting));
+ timings.record(Phase::Stream, drive_started.elapsed());
+ timings.set_resp_bytes(counting.bytes());
+ timings.mark_request_elapsed();
+ (counting, result)
+}
+
+/// Classifies a completed streaming drive into a [`DeliveryResult`].
+///
+/// A drive that failed after writing at least one byte delivered a truncated
+/// response rather than nothing at all, so it is [`DeliveryResult::Partial`],
+/// not [`DeliveryResult::Error`].
+///
+/// The `Ok(())` arm exists for the classifier's totality, not for the
+/// production caller: `send_edgezero_response` consumes this value only in
+/// its `Err` branch and re-derives the success outcome from
+/// `streaming_body.finish()`.
+fn classify_stream_delivery(
+ drive_result: &Result<(), Report>,
+ bytes: u64,
+) -> DeliveryResult {
+ match drive_result {
+ Ok(()) => DeliveryResult::Complete,
+ Err(_) if bytes > 0 => DeliveryResult::Partial,
+ Err(_) => DeliveryResult::Error,
+ }
+}
+
+/// Classifies the transport's finish result after a successful body drive.
+fn classify_stream_finish(
+ finish_result: std::io::Result<()>,
+ counter_context: &str,
+) -> DeliveryResult {
+ match finish_result {
+ Ok(()) => DeliveryResult::Complete,
+ Err(error) => {
+ log::error!("failed to finish EdgeZero streaming body{counter_context}: {error}");
+ DeliveryResult::Partial
+ }
+ }
+}
+
+/// Stamps `resp_bytes`/`request_elapsed` for an already-materialized body,
+/// immediately before it is handed to the Fastly client transport, and
+/// returns its byte length.
+fn record_buffered_delivery(body: &EdgeBody, timings: &RequestTimings) -> u64 {
+ let bytes = u64::try_from(body.as_bytes().map(<[u8]>::len).unwrap_or(0)).unwrap_or(u64::MAX);
+ timings.set_resp_bytes(bytes);
+ timings.mark_request_elapsed();
+ bytes
+}
+
/// Sends a finalized `EdgeZero` response to the client.
///
/// Streaming `EdgeZero` bodies commit headers first, then pipe chunks to Fastly's
@@ -671,9 +1006,27 @@ where
fn send_edgezero_response(
mut response: HttpResponse,
request_filter_effects: Option<&RequestFilterEffects>,
+ context: &SendContext,
counters: Option<&SandboxCounters>,
-) {
- apply_terminal_response_effects(&mut response, request_filter_effects);
+) -> DeliveryOutcome {
+ finalize_send_response_headers(
+ &mut response,
+ request_filter_effects,
+ &context.timings,
+ context.server_timing_enabled,
+ );
+
+ // Built right after the freeze point and before `into_parts()`
+ // consumes `response`: nothing else survives to post-send on every
+ // path (the request was consumed by dispatch, and `EcFinalizeState`
+ // is absent on asset, admin, and error paths). Skipped entirely when
+ // access telemetry is disabled, so the default configuration pays no
+ // env reads or allocations here.
+ let snapshot = sampled_access_snapshot(
+ context,
+ || rand::thread_rng().r#gen::(),
+ || build_access_telemetry_snapshot(&response, context),
+ );
// Captured before the body is consumed so post-commitment failures can be
// matched back to the response that carried these counters.
@@ -699,17 +1052,18 @@ fn send_edgezero_response(
parts,
EdgeBody::empty(),
));
- let mut streaming_body = skeleton.stream_to_client();
- match futures::executor::block_on(stream_asset_body(body, &mut streaming_body)) {
- Ok(()) => {
- if let Err(e) = streaming_body.finish() {
- // Also post-commitment: same attribution as the
- // streaming failure below.
- log::error!(
- "failed to finish EdgeZero streaming body{counter_context}: {e}"
- );
- }
- }
+ let (counting, drive_result) =
+ drive_streaming_body(body, skeleton.stream_to_client(), &context.timings);
+ let bytes = counting.bytes();
+ let streaming_body = counting.into_inner();
+ // Computed before `drive_result` is matched by value below, since
+ // the `Err` arm there moves its `Report` out.
+ let result = classify_stream_delivery(&drive_result, bytes);
+ match drive_result {
+ Ok(()) => DeliveryOutcome {
+ result: classify_stream_finish(streaming_body.finish(), &counter_context),
+ snapshot,
+ },
Err(e) => {
// After commitment: log and stop. Returning an error here
// would let the SDK attempt a second response. Counters
@@ -717,16 +1071,124 @@ fn send_edgezero_response(
// tagged with the same identity for reconciliation.
log::error!("EdgeZero streaming failed{counter_context}: {e:?}");
drop(streaming_body);
+ DeliveryOutcome { result, snapshot }
}
}
}
once => {
+ record_buffered_delivery(&once, &context.timings);
compat::to_fastly_response(HttpResponse::from_parts(parts, once)).send_to_client();
+ DeliveryOutcome {
+ result: DeliveryResult::Complete,
+ snapshot,
+ }
}
}
}
-/// Apply every late response mutation, then restore privacy invariants before headers commit.
+/// Samples once before doing snapshot work. Neither closure runs when disabled,
+/// and sampled-out requests never build dimensions or read environment values.
+fn sampled_access_snapshot(
+ context: &SendContext<'_>,
+ roll: impl FnOnce() -> f64,
+ build: impl FnOnce() -> AccessTelemetrySnapshot,
+) -> Option {
+ if !context.access_telemetry_enabled
+ || !tinybird::sampled_in(context.access_sample_rate, roll())
+ {
+ return None;
+ }
+ Some(build())
+}
+
+/// Builds the [`AccessTelemetrySnapshot`] for `response` at the
+/// `Server-Timing` freeze point.
+///
+/// Reads route identity, geo country, and template-cache state from typed
+/// response extensions rather than the headers those extensions back —
+/// operator-configured response headers can override a managed header, so
+/// reading a header here could silently drift from what actually happened.
+/// Falls back to `"unknown"`/[`RouteClass::Other`] sentinels when an
+/// extension was never attached (router-generated, asset, and other
+/// responses that never passed through a `RouteMetadata`-attaching
+/// wrapper).
+fn build_access_telemetry_snapshot(
+ response: &HttpResponse,
+ context: &SendContext,
+) -> AccessTelemetrySnapshot {
+ let (route_class, route_template) = match response.extensions().get::() {
+ Some(metadata) => (metadata.route_class, metadata.route_template.clone()),
+ None => (RouteClass::Other, "unknown".to_owned()),
+ };
+
+ let country = match response.extensions().get::() {
+ Some(GeoLookupState::Resolved(info)) => info.country.clone(),
+ Some(GeoLookupState::Attempted | GeoLookupState::NotAttempted) | None => {
+ "unknown".to_owned()
+ }
+ };
+
+ let template_cache_state = response
+ .extensions()
+ .get::()
+ .map_or_else(|| "unknown".to_owned(), |state| state.as_str().to_owned());
+
+ let body_mode = if matches!(response.body(), EdgeBody::Stream(_)) {
+ "streamed"
+ } else {
+ "buffered"
+ };
+
+ AccessTelemetrySnapshot {
+ method: context.method.to_owned(),
+ status: response.status().as_u16(),
+ route_class,
+ route_template,
+ publisher_domain: context.publisher_domain.to_owned(),
+ env: resolve_env_dimension(),
+ service_id: env_var_or_unknown(ENV_FASTLY_SERVICE_ID),
+ pop: env_var_or_unknown(ENV_FASTLY_POP),
+ country,
+ template_cache_state,
+ body_mode,
+ sample_rate: context.access_sample_rate,
+ }
+}
+
+/// Derives the `env` access-telemetry dimension from the same
+/// `FASTLY_IS_STAGING` input that drives the `x-ts-env` response header
+/// (see [`apply_finalize_headers`]), never from [`Settings`] — `Settings`
+/// has no environment field and does not gain one for this.
+///
+/// `"unknown"` covers contexts where the variable is entirely absent (for
+/// example native unit tests run outside Fastly Compute); on the Fastly
+/// platform the variable is always present, as either `"1"` or not.
+fn resolve_env_dimension() -> String {
+ match std::env::var(ENV_FASTLY_IS_STAGING) {
+ Ok(value) if value == "1" => "staging".to_owned(),
+ Ok(_) => "production".to_owned(),
+ Err(_) => "unknown".to_owned(),
+ }
+}
+
+/// Reads a Fastly-provided environment variable, defaulting to `"unknown"`
+/// when unset.
+fn env_var_or_unknown(name: &str) -> String {
+ std::env::var(name).unwrap_or_else(|_| "unknown".to_owned())
+}
+
+/// Apply terminal response effects before evaluating Server-Timing at the send freeze point.
+fn finalize_send_response_headers(
+ response: &mut HttpResponse,
+ request_filter_effects: Option<&RequestFilterEffects>,
+ timings: &RequestTimings,
+ server_timing_enabled: bool,
+) {
+ apply_terminal_response_effects(response, request_filter_effects);
+ apply_server_timing_header(response, timings, server_timing_enabled);
+}
+
+/// Apply late response effects and restore cache-privacy invariants before headers commit.
fn apply_terminal_response_effects(
response: &mut HttpResponse,
request_filter_effects: Option<&RequestFilterEffects>,
@@ -797,16 +1259,31 @@ fn build_ja4_debug_response(req: &FastlyRequest) -> FastlyResponse {
.with_body(body)
}
-pub(crate) fn maybe_identity_graph(settings: &Settings) -> Option {
- settings
- .ec
- .ec_store
- .as_ref()
- .map(|store_name| KvIdentityGraph::new(FastlyEcKvStore::new(store_name)))
+/// Constructs a `KvIdentityGraph` wrapped in the [`Phase::EcKv`] timing
+/// decorator, for request-path callers with a `RequestTimings` handle.
+///
+/// Returns `None` when `ec.ec_store` is not configured, matching
+/// [`require_identity_graph_with_timing`]'s contract on every other axis.
+pub(crate) fn identity_graph_with_timing(
+ settings: &Settings,
+ timings: &RequestTimings,
+) -> Option {
+ settings.ec.ec_store.as_ref().map(|store_name| {
+ KvIdentityGraph::new(TimedKvStore::new(
+ FastlyEcKvStore::new(store_name),
+ timings.clone(),
+ ))
+ })
}
/// Constructs a `KvIdentityGraph` from settings, or returns an error if the
/// `ec_store` config is not set.
+///
+/// Deliberately untimed: pull-sync (this function's only caller) runs after
+/// `send_edgezero_response`'s Server-Timing freeze point, so a decorated
+/// store here would record into a handle nothing ever renders.
+/// Request-path callers with a `RequestTimings` handle use
+/// [`require_identity_graph_with_timing`] instead.
pub(crate) fn require_identity_graph(
settings: &Settings,
) -> Result> {
@@ -819,6 +1296,27 @@ pub(crate) fn require_identity_graph(
Ok(KvIdentityGraph::new(FastlyEcKvStore::new(store_name)))
}
+/// Constructs a `KvIdentityGraph` wrapped in the [`Phase::EcKv`] timing
+/// decorator, or returns an error if the `ec_store` config is not set.
+///
+/// Request-path sibling of [`require_identity_graph`], which pull-sync uses
+/// unwrapped because pull-sync runs after the Server-Timing freeze point.
+pub(crate) fn require_identity_graph_with_timing(
+ settings: &Settings,
+ timings: &RequestTimings,
+) -> Result> {
+ let store_name = settings.ec.ec_store.as_deref().ok_or_else(|| {
+ Report::new(TrustedServerError::KvStore {
+ store_name: "ec.ec_store".to_owned(),
+ message: "ec.ec_store is not configured".to_owned(),
+ })
+ })?;
+ Ok(KvIdentityGraph::new(TimedKvStore::new(
+ FastlyEcKvStore::new(store_name),
+ timings.clone(),
+ )))
+}
+
/// Extracts a named cookie value from the request's `Cookie` header.
pub(crate) fn extract_cookie_value(req: &HttpRequest, name: &str) -> Option {
let cookie_header = req.headers().get("cookie").and_then(|v| v.to_str().ok())?;
@@ -847,12 +1345,58 @@ pub(crate) fn derive_device_signals(req: &FastlyRequest) -> DeviceSignals {
#[cfg(test)]
mod tests {
+ use std::sync::Mutex;
+
use super::*;
+ use base64::Engine as _;
use edgezero_core::body::Body as EdgeBody;
use edgezero_core::http::HeaderValue;
use edgezero_core::http::response_builder;
use fastly::mime;
+ use std::time::Duration;
use trusted_server_core::integrations::HeaderMutation;
+ use trusted_server_core::platform::{
+ PlatformError, PlatformHttpRequest, PlatformPendingRequest, PlatformResponse,
+ PlatformSelectResult, RuntimeServices,
+ };
+ use trusted_server_core::request_timing::AuctionWaitPlacement;
+
+ #[derive(Default)]
+ struct RecordingAccessHttpClient {
+ requests: Mutex>,
+ }
+
+ #[async_trait::async_trait(?Send)]
+ impl PlatformHttpClient for RecordingAccessHttpClient {
+ async fn send(
+ &self,
+ request: PlatformHttpRequest,
+ ) -> Result> {
+ self.requests
+ .lock()
+ .expect("should lock recorded requests")
+ .push(request.request.uri().to_string());
+ Err(Report::new(PlatformError::Unsupported))
+ }
+
+ async fn send_async(
+ &self,
+ request: PlatformHttpRequest,
+ ) -> Result> {
+ self.requests
+ .lock()
+ .expect("should lock recorded requests")
+ .push(request.request.uri().to_string());
+ Err(Report::new(PlatformError::Unsupported))
+ }
+
+ async fn select(
+ &self,
+ _pending_requests: Vec,
+ ) -> Result> {
+ Err(Report::new(PlatformError::Unsupported))
+ }
+ }
fn test_settings() -> Settings {
Settings::from_toml(
@@ -880,6 +1424,25 @@ mod tests {
.expect("should parse test settings")
}
+ /// A minimal [`AccessTelemetrySnapshot`] fixture for tests that only
+ /// need a `DeliveryOutcome` to exist, not its telemetry content.
+ fn sample_access_snapshot() -> AccessTelemetrySnapshot {
+ AccessTelemetrySnapshot {
+ method: "GET".to_owned(),
+ status: 200,
+ route_class: RouteClass::Other,
+ route_template: "/other/*".to_owned(),
+ publisher_domain: "unknown".to_owned(),
+ env: "unknown".to_owned(),
+ service_id: "unknown".to_owned(),
+ pop: "unknown".to_owned(),
+ country: "unknown".to_owned(),
+ template_cache_state: "unknown".to_owned(),
+ body_mode: "buffered",
+ sample_rate: 0.0,
+ }
+ }
+
#[test]
fn pull_sync_noop_states_skip_post_send_graph_factory() {
let calls = std::cell::Cell::new(0);
@@ -915,6 +1478,21 @@ mod tests {
);
}
+ #[test]
+ fn health_short_circuit_is_get_only_and_ignores_query() {
+ for path in ["/health", "/health?probe=1"] {
+ let url = format!("https://example.com{path}");
+ assert!(
+ health_response(&FastlyRequest::get(&url)).is_some(),
+ "should bypass GET health"
+ );
+ assert!(
+ health_response(&FastlyRequest::post(&url)).is_none(),
+ "should time non-GET health normally"
+ );
+ }
+ }
+
#[test]
fn health_response_reports_git_version_only() {
let req = FastlyRequest::get("https://example.com/health");
@@ -1057,6 +1635,31 @@ mod tests {
assert!(response.headers().get("etag").is_none());
}
+ #[test]
+ fn send_freeze_applies_filter_effects_before_server_timing_privacy_gate() {
+ let mut response = response_builder()
+ .header("cache-control", "private, no-store")
+ .body(EdgeBody::empty())
+ .expect("should build response");
+ let effects = RequestFilterEffects {
+ request_headers: Vec::new(),
+ response_headers: vec![HeaderMutation::set(
+ "cache-control",
+ "public, s-maxage=3600",
+ )],
+ };
+ let context = send_context_fixture();
+ drop(context.timings.span(Phase::Origin));
+
+ finalize_send_response_headers(&mut response, Some(&effects), &context.timings, true);
+
+ assert_eq!(response.headers()["cache-control"], "public, s-maxage=3600");
+ assert!(
+ response.headers().get("server-timing").is_none(),
+ "late public cache policy must be visible to the Server-Timing privacy gate"
+ );
+ }
+
#[test]
fn late_filter_effects_cannot_make_a_page_bids_response_public() {
let mut response = trusted_server_core::publisher::page_bids_preflight_denied();
@@ -1216,9 +1819,10 @@ mod tests {
.body(EdgeBody::empty())
.expect("should build response");
- let geo_info = resolve_geo_for_response(&response, None, |_| {
- panic!("should skip entry-point geo lookup for 401 responses");
- });
+ let geo_info =
+ resolve_geo_for_response(&response, &GeoLookupState::NotAttempted, None, |_| {
+ panic!("should skip entry-point geo lookup for 401 responses");
+ });
apply_finalize_headers(&settings, geo_info.as_ref(), &mut response);
assert_eq!(
@@ -1284,4 +1888,686 @@ mod tests {
"should include sec-ch-ua-platform fallback"
);
}
+
+ fn ec_finalize_settings() -> Settings {
+ Settings::from_toml(
+ r#"
+ [[handlers]]
+ path = "^/_ts/admin"
+ username = "admin"
+ password = "admin-pass"
+
+ [publisher]
+ domain = "test-publisher.com"
+ cookie_domain = ".test-publisher.com"
+ origin_url = "https://origin.test-publisher.com"
+ proxy_secret = "unit-test-proxy-secret"
+
+ [ec]
+ passphrase = "test-secret-key-32-bytes-minimum"
+ ec_store = "ec_identity_store"
+
+ [[ec.partners]]
+ name = "Example Partner"
+ source_domain = "example.com"
+ api_token = "test-vendor-token-32-bytes-minimum"
+
+ [request_signing]
+ enabled = false
+ config_store_id = "test-config-store-id"
+ secret_store_id = "test-secret-store-id"
+ "#,
+ )
+ .expect("should parse EC finalize test settings")
+ }
+
+ /// Minimal `RuntimeServices` for `EcFinalizeState.services`. Real
+ /// `FastlyPlatform*` handles are used as inert placeholders: EC
+ /// finalization never calls through them, it only satisfies the field.
+ fn inert_runtime_services() -> RuntimeServices {
+ RuntimeServices::builder()
+ .config_store(Arc::new(crate::platform::FastlyPlatformConfigStore))
+ .secret_store(Arc::new(crate::platform::FastlyPlatformSecretStore))
+ .kv_store(Arc::new(edgezero_core::key_value_store::NoopKvStore)
+ as Arc)
+ .backend(Arc::new(crate::platform::FastlyPlatformBackend))
+ .http_client(Arc::new(crate::platform::FastlyPlatformHttpClient))
+ .geo(Arc::new(crate::platform::FastlyPlatformGeo))
+ .client_info(trusted_server_core::platform::ClientInfo::default())
+ .build()
+ }
+
+ #[test]
+ fn ec_finalize_kv_lands_before_freeze() {
+ // A pre-seeded EC entry (see fastly.toml's ec_identity_store fixture)
+ // for a returning user carrying an eids cookie that matches the
+ // configured partner. This drives ec_finalize_response into
+ // ingest_eid_cookies, which reads and writes the KV identity graph.
+ let settings = ec_finalize_settings();
+ let ec_id = "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.test01";
+ let eids = serde_json::json!([{
+ "source": "example.com",
+ "uids": [{ "id": "example-uid", "atype": 1 }]
+ }]);
+ let eids_cookie = base64::engine::general_purpose::STANDARD.encode(eids.to_string());
+ let request = edgezero_core::http::request_builder()
+ .method(fastly::http::Method::GET)
+ .uri("https://test-publisher.com/article")
+ .header("cookie", format!("ts-ec={ec_id}; ts-eids={eids_cookie}"))
+ .body(EdgeBody::empty())
+ .expect("should build EC finalize test request");
+
+ let services = inert_runtime_services();
+ let geo_info = trusted_server_core::platform::GeoInfo {
+ city: String::new(),
+ country: "US".to_owned(),
+ continent: "NorthAmerica".to_owned(),
+ latitude: 0.0,
+ longitude: 0.0,
+ metro_code: 0,
+ region: None,
+ asn: None,
+ };
+ let mut ec_context = trusted_server_core::ec::EcContext::read_from_request_with_geo(
+ &settings,
+ &request,
+ &services,
+ Some(&geo_info),
+ )
+ .expect("should read EC context from a non-regulated request");
+ assert!(
+ ec_context.ec_was_present(),
+ "the pre-seeded ts-ec cookie should be recognized"
+ );
+ // Returning-user EID persistence is gated on the request source; the
+ // dispatcher marks document navigations this way before finalization.
+ ec_context.set_eid_sync_source(trusted_server_core::ec::EidSyncSource::Navigation);
+
+ let mut ec_state = EcFinalizeState {
+ ec_context,
+ use_finalize_kv: true,
+ eids_cookie: Some(eids_cookie),
+ sharedid_cookie: None,
+ is_real_browser: true,
+ services,
+ };
+ let mut response = response_builder()
+ .header("cache-control", "private, no-store")
+ .body(EdgeBody::empty())
+ .expect("should build EC finalize response fixture");
+ let timings = RequestTimings::new();
+
+ // Mirrors edgezero_main's ordering: EC finalize runs, then the freeze
+ // point (apply_server_timing_header, called just before
+ // response.into_parts() inside send_edgezero_response) renders the
+ // header. Calling both directly exercises exactly this order without
+ // requiring a live Fastly client connection.
+ apply_edgezero_ec_finalize(&settings, &mut ec_state, &mut response, &timings)
+ .expect("should finalize EC response");
+ apply_server_timing_header(&mut response, &timings, true);
+
+ let header = response
+ .headers()
+ .get("server-timing")
+ .and_then(|v| v.to_str().ok())
+ .expect("should emit a Server-Timing header");
+ assert!(
+ header.contains("ts-kv"),
+ "the freeze point must run after EC finalization recorded KV time: {header}"
+ );
+ }
+
+ #[test]
+ fn streamed_delivery_row_reports_bytes_and_request_elapsed() {
+ let timings = RequestTimings::new();
+ let body = EdgeBody::stream(futures::stream::iter(vec![
+ bytes::Bytes::from_static(b"hello "),
+ bytes::Bytes::from_static(b"world"),
+ ]));
+
+ let (counting, drive_result) = drive_streaming_body(body, Vec::new(), &timings);
+ drive_result.expect("streaming a well-formed body should not fail");
+ let bytes = counting.bytes();
+ let outcome = DeliveryOutcome {
+ result: DeliveryResult::Complete,
+ snapshot: Some(AccessTelemetrySnapshot {
+ body_mode: "streamed",
+ ..sample_access_snapshot()
+ }),
+ };
+
+ assert_eq!(
+ counting.into_inner(),
+ b"hello world",
+ "should write every byte to the underlying transport"
+ );
+ assert_eq!(
+ bytes,
+ "hello world".len() as u64,
+ "should count bytes accepted by the underlying transport"
+ );
+
+ let snapshot = timings.snapshot();
+ let row: serde_json::Value = serde_json::from_str(&access_event_row(
+ outcome
+ .snapshot
+ .as_ref()
+ .expect("should capture access dimensions"),
+ &snapshot,
+ outcome.result,
+ 0,
+ ))
+ .expect("should parse the emitted delivery row");
+ assert_eq!(row["delivery_result"], "complete");
+ assert_eq!(row["resp_bytes"], bytes);
+ assert_eq!(
+ snapshot.resp_bytes,
+ Some("hello world".len() as u64),
+ "should stamp resp_bytes to the tallied byte count"
+ );
+ assert!(
+ snapshot.request_elapsed_ms.is_some(),
+ "should stamp request_elapsed once the drive returns"
+ );
+ }
+
+ #[test]
+ fn buffered_delivery_stamps_bytes_and_request_elapsed() {
+ let timings = RequestTimings::new();
+ let body = EdgeBody::from(b"a buffered body".to_vec());
+
+ let bytes = record_buffered_delivery(&body, &timings);
+
+ assert_eq!(
+ bytes,
+ "a buffered body".len() as u64,
+ "should report the buffered body length"
+ );
+ let snapshot = timings.snapshot();
+ assert_eq!(
+ snapshot.resp_bytes,
+ Some("a buffered body".len() as u64),
+ "should stamp resp_bytes for the buffered path too"
+ );
+ assert!(
+ snapshot.request_elapsed_ms.is_some(),
+ "should stamp request_elapsed for the buffered path too"
+ );
+ }
+
+ fn send_context_fixture() -> SendContext<'static> {
+ SendContext {
+ timings: RequestTimings::new(),
+ server_timing_enabled: false,
+ method: "GET",
+ publisher_domain: "publisher.example.com",
+ access_sample_rate: 0.25,
+ access_telemetry_enabled: true,
+ }
+ }
+
+ #[test]
+ fn disabled_access_telemetry_skips_entropy_and_snapshot_work() {
+ let mut context = send_context_fixture();
+ context.access_telemetry_enabled = false;
+
+ let snapshot = sampled_access_snapshot(
+ &context,
+ || panic!("disabled telemetry should not draw entropy"),
+ || panic!("disabled telemetry should not construct dimensions"),
+ );
+
+ assert!(snapshot.is_none(), "should not build a disabled snapshot");
+ }
+
+ #[test]
+ fn sampled_out_access_telemetry_skips_snapshot_and_transport() {
+ let context = send_context_fixture();
+ let snapshot = sampled_access_snapshot(
+ &context,
+ || context.access_sample_rate,
+ || panic!("sampled-out telemetry should not construct dimensions"),
+ );
+ assert!(snapshot.is_none(), "should exclude the sampling boundary");
+ let mut settings = test_settings();
+ settings.tinybird.api_host = "ingest.example.com".to_owned();
+ settings.tinybird.enabled = true;
+ settings.tinybird.access_enabled = true;
+ settings.tinybird.access_token_secret = Some(trusted_server_core::redacted::Redacted::new(
+ "access-append-token".to_owned(),
+ ));
+ let http_client = RecordingAccessHttpClient::default();
+ emit_access_telemetry_after_send(
+ &http_client,
+ &settings,
+ &DeliveryOutcome {
+ result: DeliveryResult::Complete,
+ snapshot,
+ },
+ &context.timings,
+ );
+
+ assert!(
+ http_client
+ .requests
+ .lock()
+ .expect("should lock recorded requests")
+ .is_empty(),
+ "should not dispatch access telemetry for a sampled-out response"
+ );
+ }
+
+ #[test]
+ fn access_telemetry_setup_error_skips_transport_without_panicking() {
+ let mut settings = test_settings();
+ settings.tinybird.api_host = "ingest.example.com".to_owned();
+ settings.tinybird.enabled = true;
+ settings.tinybird.access_enabled = true;
+ settings.tinybird.access_token_secret = None;
+ let http_client = RecordingAccessHttpClient::default();
+
+ emit_access_telemetry_after_send(
+ &http_client,
+ &settings,
+ &DeliveryOutcome {
+ result: DeliveryResult::Complete,
+ snapshot: Some(sample_access_snapshot()),
+ },
+ &RequestTimings::new(),
+ );
+
+ assert!(
+ http_client
+ .requests
+ .lock()
+ .expect("should lock recorded requests")
+ .is_empty(),
+ "should not dispatch access telemetry without a resolved token"
+ );
+ }
+
+ #[test]
+ fn access_telemetry_dispatch_is_gated_and_best_effort() {
+ for (enabled, access_enabled) in [(false, true), (true, false), (true, true)] {
+ let mut settings = test_settings();
+ settings.tinybird.api_host = "ingest.example.com".to_owned();
+ settings.tinybird.enabled = enabled;
+ settings.tinybird.access_enabled = access_enabled;
+ settings.tinybird.access_token_secret = Some(
+ trusted_server_core::redacted::Redacted::new("access-append-token".to_owned()),
+ );
+ let http_client = RecordingAccessHttpClient::default();
+
+ emit_access_telemetry_after_send(
+ &http_client,
+ &settings,
+ &DeliveryOutcome {
+ result: DeliveryResult::Complete,
+ snapshot: Some(sample_access_snapshot()),
+ },
+ &RequestTimings::new(),
+ );
+
+ assert_eq!(
+ http_client
+ .requests
+ .lock()
+ .expect("should lock recorded requests")
+ .len(),
+ usize::from(enabled && access_enabled),
+ "should dispatch once only when both toggles are enabled, without retrying errors"
+ );
+ }
+ }
+
+ #[test]
+ fn sampled_in_snapshot_records_the_exact_rate_and_draws_once() {
+ let context = send_context_fixture();
+ let response = response_builder()
+ .body(EdgeBody::empty())
+ .expect("should build response");
+ let draws = std::cell::Cell::new(0);
+ let builds = std::cell::Cell::new(0);
+
+ let snapshot = sampled_access_snapshot(
+ &context,
+ || {
+ draws.set(draws.get() + 1);
+ 0.0
+ },
+ || {
+ builds.set(builds.get() + 1);
+ build_access_telemetry_snapshot(&response, &context)
+ },
+ )
+ .expect("should include zero entropy at a positive rate");
+
+ assert_eq!(draws.get(), 1, "should sample exactly once");
+ assert_eq!(builds.get(), 1, "should build one sampled snapshot");
+ assert_eq!(snapshot.sample_rate, context.access_sample_rate);
+ }
+
+ #[test]
+ fn access_snapshot_defaults_when_no_extensions_are_attached() {
+ // Router-generated 404/405 responses and other paths that never pass
+ // through a RouteMetadata-attaching wrapper must still produce a
+ // usable snapshot: RouteClass::Other and "unknown" sentinels, never
+ // a missing/panicking build.
+ let response = response_builder()
+ .status(404)
+ .body(EdgeBody::empty())
+ .expect("should build response");
+ let context = send_context_fixture();
+
+ let snapshot = build_access_telemetry_snapshot(&response, &context);
+
+ assert_eq!(snapshot.status, 404);
+ assert_eq!(snapshot.method, "GET");
+ assert!(matches!(snapshot.route_class, RouteClass::Other));
+ assert_eq!(snapshot.route_template, "unknown");
+ assert_eq!(snapshot.country, "unknown");
+ assert_eq!(snapshot.template_cache_state, "unknown");
+ assert_eq!(snapshot.body_mode, "buffered");
+ assert_eq!(snapshot.publisher_domain, "publisher.example.com");
+ assert_eq!(snapshot.sample_rate, 0.25);
+ }
+
+ #[test]
+ fn access_snapshot_reads_route_geo_and_template_cache_extensions() {
+ let mut response = response_builder()
+ .status(200)
+ .body(EdgeBody::empty())
+ .expect("should build response");
+ response.extensions_mut().insert(RouteMetadata {
+ route_class: RouteClass::AuctionApi,
+ route_template: "/auction".to_owned(),
+ });
+ response.extensions_mut().insert(GeoLookupState::Resolved(
+ trusted_server_core::platform::GeoInfo {
+ city: String::new(),
+ country: "US".to_owned(),
+ continent: "NorthAmerica".to_owned(),
+ latitude: 0.0,
+ longitude: 0.0,
+ metro_code: 0,
+ region: None,
+ asn: None,
+ },
+ ));
+ response
+ .extensions_mut()
+ .insert(TemplateCacheResponseState::Hit);
+ let context = send_context_fixture();
+
+ let snapshot = build_access_telemetry_snapshot(&response, &context);
+
+ assert!(matches!(snapshot.route_class, RouteClass::AuctionApi));
+ assert_eq!(snapshot.route_template, "/auction");
+ assert_eq!(snapshot.country, "US");
+ assert_eq!(snapshot.template_cache_state, "hit");
+ }
+
+ #[test]
+ fn entry_point_404_finalization_writes_geo_state_before_access_snapshot() {
+ let settings = Settings::default();
+ let timings = RequestTimings::new();
+ let resolved_geo = trusted_server_core::platform::GeoInfo {
+ city: String::new(),
+ country: "US".to_owned(),
+ continent: "NorthAmerica".to_owned(),
+ latitude: 0.0,
+ longitude: 0.0,
+ metro_code: 0,
+ region: None,
+ asn: None,
+ };
+
+ for (geo_state, expected_country) in [
+ (GeoLookupState::NotAttempted, "unknown"),
+ (GeoLookupState::Resolved(resolved_geo), "US"),
+ ] {
+ let mut response = response_builder()
+ .status(404)
+ .body(EdgeBody::empty())
+ .expect("should build router 404");
+
+ apply_entry_point_finalize_headers(
+ &settings,
+ &mut response,
+ None,
+ &geo_state,
+ &timings,
+ );
+
+ match (geo_state, response.extensions().get::()) {
+ (GeoLookupState::NotAttempted, Some(GeoLookupState::Attempted)) => {}
+ (GeoLookupState::Resolved(expected), Some(GeoLookupState::Resolved(actual))) => {
+ assert_eq!(actual.country, expected.country)
+ }
+ (_, actual) => {
+ panic!("should write back the entry-point geo result, got {actual:?}")
+ }
+ }
+ let snapshot = build_access_telemetry_snapshot(&response, &send_context_fixture());
+ assert_eq!(
+ snapshot.status, 404,
+ "should preserve the router 404 status"
+ );
+ assert_eq!(snapshot.country, expected_country);
+ }
+ }
+
+ #[test]
+ fn access_snapshot_treats_attempted_geo_lookup_as_unknown_country() {
+ let mut response = response_builder()
+ .status(200)
+ .body(EdgeBody::empty())
+ .expect("should build response");
+ response.extensions_mut().insert(GeoLookupState::Attempted);
+ let context = send_context_fixture();
+
+ let snapshot = build_access_telemetry_snapshot(&response, &context);
+
+ assert_eq!(
+ snapshot.country, "unknown",
+ "an attempted-but-unresolved lookup must not surface a stale country"
+ );
+ }
+
+ #[test]
+ fn access_snapshot_body_mode_reflects_the_response_body_variant() {
+ let streamed = response_builder()
+ .status(200)
+ .body(EdgeBody::stream(futures::stream::empty()))
+ .expect("should build streaming response");
+ let buffered = response_builder()
+ .status(200)
+ .body(EdgeBody::from(b"hi".to_vec()))
+ .expect("should build buffered response");
+ let context = send_context_fixture();
+
+ assert_eq!(
+ build_access_telemetry_snapshot(&streamed, &context).body_mode,
+ "streamed"
+ );
+ assert_eq!(
+ build_access_telemetry_snapshot(&buffered, &context).body_mode,
+ "buffered"
+ );
+ }
+
+ #[test]
+ fn stream_drive_records_stream_ms_covering_the_in_stream_auction_wait() {
+ // A streaming seam wait (Task 6, publisher.rs) records into the same
+ // `RequestTimings` handle the adapter drives with. `Phase::Stream`
+ // wraps the entire drive, so it must cover — and therefore be at
+ // least as large as — any `AuctionWait` recorded while the body was
+ // being polled.
+ let timings = RequestTimings::new();
+ let wait_timings = timings.clone();
+ let stream = futures::stream::once(async move {
+ let waited = Duration::from_millis(5);
+ std::thread::sleep(waited);
+ wait_timings.record_auction_wait(AuctionWaitPlacement::InStream, waited);
+ bytes::Bytes::from_static(b"")
+ });
+ let body = EdgeBody::stream(stream);
+
+ let (_counting, drive_result) = drive_streaming_body(body, Vec::new(), &timings);
+ drive_result.expect("streaming a well-formed body should not fail");
+
+ let snapshot = timings.snapshot();
+ assert_eq!(
+ snapshot.auction_wait_placement,
+ Some(AuctionWaitPlacement::InStream),
+ "should preserve the placement recorded from inside the polled body"
+ );
+ let auction_wait_ms = snapshot
+ .auction_wait_ms
+ .expect("should record the auction wait");
+ let stream_ms = snapshot.stream_ms.expect("should record the stream drive");
+ assert!(
+ stream_ms >= auction_wait_ms,
+ "the drive's Phase::Stream span must cover the in-stream auction wait: \
+ stream_ms={stream_ms} auction_wait_ms={auction_wait_ms}"
+ );
+ }
+
+ #[test]
+ fn failed_stream_drives_emit_partial_or_error_rows_with_actual_bytes() {
+ for (prefix, expected) in [(&b"example"[..], "partial"), (&b""[..], "error")] {
+ let mut chunks = Vec::new();
+ if !prefix.is_empty() {
+ chunks.push(Ok(bytes::Bytes::copy_from_slice(prefix)));
+ }
+ chunks.push(Err(std::io::Error::other("example stream failure")));
+ let body = EdgeBody::from_stream(futures::stream::iter(chunks));
+ let timings = RequestTimings::new();
+ let (writer, drive_result) = drive_streaming_body(body, Vec::new(), &timings);
+ assert!(drive_result.is_err(), "should observe the stream failure");
+ let result = classify_stream_delivery(&drive_result, writer.bytes());
+ let snapshot = AccessTelemetrySnapshot {
+ body_mode: "streamed",
+ ..sample_access_snapshot()
+ };
+ let row: serde_json::Value =
+ serde_json::from_str(&access_event_row(&snapshot, &timings.snapshot(), result, 0))
+ .expect("should parse the failed delivery row");
+ assert_eq!(row["delivery_result"], expected);
+ assert_eq!(row["resp_bytes"], prefix.len());
+ assert_eq!(row["status"], 200, "should retain the already-sent status");
+ }
+ }
+
+ #[test]
+ fn stream_finish_results_reach_the_access_row() {
+ for (finish_result, expected) in [
+ (Ok(()), "complete"),
+ (
+ Err(std::io::Error::other("example finish failure")),
+ "partial",
+ ),
+ ] {
+ let result = classify_stream_finish(finish_result, "");
+ let row: serde_json::Value = serde_json::from_str(&access_event_row(
+ &sample_access_snapshot(),
+ &Default::default(),
+ result,
+ 0,
+ ))
+ .expect("should parse the transport finish row");
+ assert_eq!(row["delivery_result"], expected);
+ }
+ }
+
+ #[test]
+ fn classify_stream_delivery_treats_bytes_written_before_an_error_as_partial() {
+ let err = Report::new(TrustedServerError::Proxy {
+ message: "boom".to_string(),
+ });
+ assert_eq!(
+ classify_stream_delivery(&Err(err), 42),
+ DeliveryResult::Partial,
+ "bytes already on the wire before a stream error is a truncated delivery"
+ );
+ }
+
+ #[test]
+ fn classify_stream_delivery_treats_an_error_with_no_bytes_as_error() {
+ let err = Report::new(TrustedServerError::Proxy {
+ message: "boom".to_string(),
+ });
+ assert_eq!(
+ classify_stream_delivery(&Err(err), 0),
+ DeliveryResult::Error,
+ "a failure before any byte reached the client is a clean failure, not a truncation"
+ );
+ }
+
+ #[test]
+ fn classify_stream_delivery_treats_ok_as_complete() {
+ assert_eq!(
+ classify_stream_delivery(&Ok(()), 123),
+ DeliveryResult::Complete
+ );
+ }
+
+ #[test]
+ fn post_send_order_is_elapsed_then_pull_sync_then_telemetry() {
+ // The full contract sequence, instrumented through the real seams:
+ // `send_edgezero_response` stamps `request_elapsed` before
+ // returning, and `run_post_send_steps` (which every production
+ // site with both steps routes through) owns pull-sync-then-
+ // telemetry ordering.
+ let log: Arc>> = Arc::new(Mutex::new(Vec::new()));
+ let timings = RequestTimings::new();
+ let response = response_builder()
+ .body(EdgeBody::from("ok"))
+ .expect("should build response");
+
+ let outcome = send_edgezero_response(
+ response,
+ None,
+ &SendContext {
+ timings: timings.clone(),
+ server_timing_enabled: false,
+ method: "GET",
+ publisher_domain: "publisher.example.com",
+ access_sample_rate: 1.0,
+ access_telemetry_enabled: true,
+ },
+ None,
+ );
+ assert!(
+ timings.snapshot().request_elapsed_ms.is_some(),
+ "request_elapsed should be stamped before any post-send step runs"
+ );
+ assert!(
+ outcome.snapshot.is_some(),
+ "the access snapshot should exist for the enabled context"
+ );
+
+ let pull_log = Arc::clone(&log);
+ let emit_log = Arc::clone(&log);
+ run_post_send_steps(
+ move || {
+ pull_log
+ .lock()
+ .expect("should lock order log")
+ .push("pull_sync")
+ },
+ move || {
+ emit_log
+ .lock()
+ .expect("should lock order log")
+ .push("telemetry")
+ },
+ );
+
+ assert_eq!(
+ *log.lock().expect("should lock order log"),
+ vec!["pull_sync", "telemetry"],
+ "pull-sync must dispatch before telemetry emits"
+ );
+ }
}
diff --git a/crates/trusted-server-adapter-fastly/src/middleware.rs b/crates/trusted-server-adapter-fastly/src/middleware.rs
index 9bbc25d7ba..4188d01e73 100644
--- a/crates/trusted-server-adapter-fastly/src/middleware.rs
+++ b/crates/trusted-server-adapter-fastly/src/middleware.rs
@@ -24,8 +24,9 @@ use trusted_server_core::constants::{
ENV_FASTLY_IS_STAGING, ENV_FASTLY_SERVICE_VERSION, HEADER_X_GEO_INFO_AVAILABLE,
HEADER_X_TS_ENV, HEADER_X_TS_FASTLY_VERSION,
};
-use trusted_server_core::geo::GeoInfo;
+use trusted_server_core::geo::{GeoInfo, GeoLookupState};
use trusted_server_core::platform::{ClientInfo, PlatformGeo};
+use trusted_server_core::request_timing::{Phase, RequestTimings};
use trusted_server_core::settings::Settings;
use trusted_server_core::version_header::apply_git_version_header;
@@ -74,6 +75,8 @@ impl Middleware for FinalizeResponseMiddleware {
|| FastlyRequestContext::get(ctx.request()).and_then(|c| c.client_ip),
|info| info.client_ip,
);
+ let timings =
+ RequestTimings::from_extensions(ctx.request().extensions()).unwrap_or_default();
let mut response = match next.run(ctx).await {
Ok(r) => r,
@@ -83,13 +86,24 @@ impl Middleware for FinalizeResponseMiddleware {
}
};
- let geo_info = resolve_geo_for_response(&response, client_ip, |ip| {
+ let carried = response
+ .extensions()
+ .get::()
+ .cloned()
+ .unwrap_or(GeoLookupState::NotAttempted);
+ let geo_info = resolve_geo_for_response(&response, &carried, client_ip, |ip| {
+ let _span = timings.span(Phase::Geo);
self.geo.lookup(ip).unwrap_or_else(|e| {
log::warn!("geo lookup failed: {e}");
None
})
});
+ // Mirrors the entry-point finalize site in `main.rs`
+ // (`apply_entry_point_finalize_headers`); 401 handling lives in the
+ // shared helper.
+ write_back_geo_lookup_state(&mut response, geo_info.as_ref());
+
apply_finalize_headers(&self.settings, geo_info.as_ref(), &mut response);
response
.headers_mut()
@@ -148,14 +162,40 @@ impl Middleware for AuthMiddleware {
// Shared geo resolution helper
// ---------------------------------------------------------------------------
-/// Resolves geo for a response, skipping the lookup for 401 responses.
+/// 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>) {
+ if response.status() == StatusCode::UNAUTHORIZED {
+ return;
+ }
+ let resolved_state = match geo_info {
+ Some(geo) => GeoLookupState::Resolved(geo.clone()),
+ None => GeoLookupState::Attempted,
+ };
+ response.extensions_mut().insert(resolved_state);
+}
+
+/// Resolves geo for a response, skipping the lookup for 401 responses and
+/// reusing a request-phase lookup when one was already carried.
///
-/// Returns `None` for authentication rejections (401) without calling `lookup_geo`
-/// to avoid unnecessary work and exposing geo data to unauthenticated callers.
-/// All other responses call `lookup_geo` and return its result.
+/// Returns `None` for authentication rejections (401) without consulting
+/// `carried` or calling `lookup_geo`, to avoid unnecessary work and exposing
+/// geo data to unauthenticated callers. Otherwise dispatches on `carried`:
+/// a [`GeoLookupState::Resolved`] value is reused as-is, a
+/// [`GeoLookupState::Attempted`] value is treated as no geo info without
+/// retrying the lookup, and [`GeoLookupState::NotAttempted`] falls back to
+/// calling `lookup_geo`.
///
/// Used by both [`FinalizeResponseMiddleware`] and the entry-point finalization
-/// in `main.rs` so the 401-skip rule is defined in one place.
+/// in `main.rs` so the 401-skip rule and the dedupe rule are each defined in
+/// one place.
///
/// # Parity note
///
@@ -167,6 +207,7 @@ impl Middleware for AuthMiddleware {
/// server or the upstream origin.
pub(crate) fn resolve_geo_for_response(
response: &Response,
+ carried: &GeoLookupState,
client_ip: Option,
lookup_geo: F,
) -> Option
@@ -174,9 +215,12 @@ where
F: FnOnce(Option) -> Option,
{
if response.status() == StatusCode::UNAUTHORIZED {
- None
- } else {
- lookup_geo(client_ip)
+ return None;
+ }
+ match carried {
+ GeoLookupState::Resolved(geo) => Some(geo.clone()),
+ GeoLookupState::Attempted => None,
+ GeoLookupState::NotAttempted => lookup_geo(client_ip),
}
}
@@ -273,6 +317,51 @@ fn apply_fastly_version_header(service_version: Option<&str>, response: &mut Res
mod tests {
use super::*;
+ #[test]
+ fn geo_write_back_preserves_resolved_state_on_401() {
+ // A 401 short-circuits geo resolution before the carried state is
+ // consulted, so the write-back must not downgrade a carried
+ // Resolved to Attempted (which would cost the row its country).
+ let mut response = response_builder()
+ .status(StatusCode::UNAUTHORIZED)
+ .body(Body::empty())
+ .expect("should build a 401 response");
+ response
+ .extensions_mut()
+ .insert(GeoLookupState::Resolved(sample_geo_info()));
+
+ write_back_geo_lookup_state(&mut response, None);
+
+ match response.extensions().get::() {
+ Some(GeoLookupState::Resolved(geo)) => {
+ assert_eq!(
+ geo.country,
+ sample_geo_info().country,
+ "should keep the carried country"
+ );
+ }
+ other => panic!("should keep the Resolved state on a 401, got {other:?}"),
+ }
+ }
+
+ #[test]
+ fn geo_write_back_records_attempted_on_non_401_miss() {
+ let mut response = response_builder()
+ .status(StatusCode::OK)
+ .body(Body::empty())
+ .expect("should build a 200 response");
+
+ write_back_geo_lookup_state(&mut response, None);
+
+ assert!(
+ matches!(
+ response.extensions().get::(),
+ Some(GeoLookupState::Attempted)
+ ),
+ "should record an attempted-but-missed lookup on ordinary responses"
+ );
+ }
+
use std::collections::HashMap;
use std::net::IpAddr;
use std::sync::{Arc, Mutex};
@@ -303,6 +392,19 @@ mod tests {
RequestContext::new(req, PathParams::new(HashMap::new()))
}
+ fn sample_geo_info() -> GeoInfo {
+ GeoInfo {
+ city: "Testville".to_string(),
+ country: "US".to_string(),
+ continent: "NorthAmerica".to_string(),
+ latitude: 0.0,
+ longitude: 0.0,
+ metro_code: 0,
+ region: None,
+ asn: None,
+ }
+ }
+
struct FixedGeo(Option);
impl PlatformGeo for FixedGeo {
@@ -705,6 +807,67 @@ mod tests {
);
}
+ #[test]
+ fn finalize_handle_writes_back_resolved_geo_state_after_fallback_lookup() {
+ // The request phase never attempted a geo lookup (no GeoLookupState
+ // extension on the handler's response), so the middleware resolves
+ // one via the fallback closure. That resolved outcome must be
+ // written back into response extensions -- mirroring
+ // apply_entry_point_finalize_headers in main.rs -- so a downstream
+ // access-telemetry snapshot sees the freshly resolved country
+ // instead of a stale/missing GeoLookupState.
+ let settings = settings_with_response_headers(vec![]);
+ let middleware = FinalizeResponseMiddleware::new(
+ Arc::new(settings),
+ Arc::new(FixedGeo(Some(sample_geo_info()))),
+ );
+ let handler =
+ Arc::new(
+ |_ctx: RequestContext| async move { Ok::(empty_response()) },
+ );
+
+ let response = block_on(middleware.handle(empty_ctx(), Next::new(&[], &*handler)))
+ .expect("should succeed");
+
+ match response.extensions().get::() {
+ Some(GeoLookupState::Resolved(info)) => {
+ assert_eq!(
+ info.country, "US",
+ "should carry the fallback-resolved geo info"
+ );
+ }
+ other => {
+ panic!("expected GeoLookupState::Resolved after a fallback lookup, got {other:?}")
+ }
+ }
+ }
+
+ #[test]
+ fn finalize_handle_writes_back_attempted_geo_state_when_fallback_finds_nothing() {
+ // The fallback lookup ran but resolved no geo info. The middleware
+ // must still record that the lookup was attempted, so a later
+ // consumer of the extension does not mistake this for
+ // GeoLookupState::NotAttempted and retry the lookup.
+ let settings = settings_with_response_headers(vec![]);
+ let middleware =
+ FinalizeResponseMiddleware::new(Arc::new(settings), Arc::new(FixedGeo(None)));
+ let handler =
+ Arc::new(
+ |_ctx: RequestContext| async move { Ok::(empty_response()) },
+ );
+
+ let response = block_on(middleware.handle(empty_ctx(), Next::new(&[], &*handler)))
+ .expect("should succeed");
+
+ assert!(
+ matches!(
+ response.extensions().get::(),
+ Some(GeoLookupState::Attempted)
+ ),
+ "should write back Attempted when the fallback lookup finds no geo info"
+ );
+ }
+
#[test]
fn finalize_handle_marks_response_as_finalized() {
let settings = settings_with_response_headers(vec![]);
@@ -786,6 +949,30 @@ mod tests {
);
}
+ #[test]
+ #[allow(clippy::panic)]
+ fn geo_lookup_skipped_for_unauthorized_responses() {
+ // The 401 short-circuit in resolve_geo_for_response must win
+ // regardless of what state the request phase carried in, and must
+ // never invoke the fallback lookup closure.
+ let mut response = empty_response();
+ *response.status_mut() = StatusCode::UNAUTHORIZED;
+
+ for carried in [
+ GeoLookupState::NotAttempted,
+ GeoLookupState::Attempted,
+ GeoLookupState::Resolved(sample_geo_info()),
+ ] {
+ let geo_info = resolve_geo_for_response(&response, &carried, None, |_| {
+ panic!("401 responses must never trigger a geo lookup");
+ });
+ assert!(
+ geo_info.is_none(),
+ "401 responses should never resolve geo info, regardless of carried state"
+ );
+ }
+ }
+
// ---------------------------------------------------------------------------
// AuthMiddleware::handle tests
// ---------------------------------------------------------------------------
diff --git a/crates/trusted-server-adapter-fastly/src/tinybird.rs b/crates/trusted-server-adapter-fastly/src/tinybird.rs
index 504dbd9fba..271f6bfe31 100644
--- a/crates/trusted-server-adapter-fastly/src/tinybird.rs
+++ b/crates/trusted-server-adapter-fastly/src/tinybird.rs
@@ -10,10 +10,15 @@ use trusted_server_core::auction::telemetry::{
AuctionEventBatch, AuctionTelemetrySink, NoopAuctionTelemetrySink,
};
use trusted_server_core::error::TrustedServerError;
-use trusted_server_core::platform::{PlatformBackendSpec, PlatformHttpRequest, RuntimeServices};
+use trusted_server_core::platform::{
+ PlatformBackend as _, PlatformBackendSpec, PlatformHttpClient, PlatformHttpRequest,
+ RuntimeServices,
+};
use trusted_server_core::redacted::Redacted;
use trusted_server_core::settings::{Settings, TinybirdSettings};
+use crate::platform::FastlyPlatformBackend;
+
const TINYBIRD_EVENTS_PATH: &str = "/v0/events";
const TINYBIRD_NDJSON_CONTENT_TYPE: &str = "application/x-ndjson";
const TINYBIRD_FIRST_BYTE_TIMEOUT: Duration = Duration::from_secs(2);
@@ -21,9 +26,14 @@ const TINYBIRD_BETWEEN_BYTES_TIMEOUT: Duration = Duration::from_secs(2);
const TINYBIRD_MAX_ROWS_PER_AUCTION_BATCH: usize = 512;
/// Build the configured auction telemetry sink.
+///
+/// Auction emission requires both the Tinybird master toggle
+/// (`tinybird.enabled`) and the auction-specific toggle
+/// (`tinybird.auction_enabled`), so access-log telemetry can be enabled
+/// independently without also emitting auction events.
#[must_use]
pub(crate) fn auction_sink_from_settings(settings: &Settings) -> Arc {
- if settings.tinybird.enabled {
+ if settings.tinybird.enabled && settings.tinybird.auction_enabled {
Arc::new(FastlyTinybirdAuctionTelemetrySink::new(
settings.tinybird.clone(),
))
@@ -39,7 +49,7 @@ struct FastlyTinybirdAuctionTelemetrySink {
}
#[derive(Debug, Clone)]
-struct TinybirdEventsTarget {
+pub(crate) struct TinybirdEventsTarget {
api_host: String,
dataset: String,
append_token: Redacted,
@@ -63,6 +73,37 @@ impl TinybirdEventsTarget {
max_body_bytes: config.max_body_bytes,
}
}
+
+ /// Builds the Events API target for the access-log datasource.
+ ///
+ /// Shares [`from_config`](Self::from_config)'s host and body-size-limit
+ /// derivation, but points at `access_dataset` and
+ /// `access_token_secret` instead of the auction pair, so access-log
+ /// emission never shares a datasource or token with auction telemetry
+ /// even though both configs come from the same [`TinybirdSettings`].
+ ///
+ /// # Errors
+ ///
+ /// Returns an error if the access token has not been resolved.
+ pub(crate) fn from_access_config(
+ config: &TinybirdSettings,
+ ) -> Result> {
+ let append_token = config.access_token_secret.clone().ok_or_else(|| {
+ Report::new(TrustedServerError::Configuration {
+ message: "Tinybird access token is not resolved".to_owned(),
+ })
+ })?;
+ let uri = tinybird_events_uri(&config.api_host, &config.access_dataset);
+ let backend_spec = tinybird_backend_spec(&config.api_host);
+ Ok(Self {
+ api_host: config.api_host.clone(),
+ dataset: config.access_dataset.clone(),
+ append_token,
+ uri,
+ backend_spec,
+ max_body_bytes: config.max_body_bytes,
+ })
+ }
}
impl FastlyTinybirdAuctionTelemetrySink {
@@ -182,6 +223,116 @@ impl AuctionTelemetrySink for FastlyTinybirdAuctionTelemetrySink {
}
}
+// ---------------------------------------------------------------------------
+// Access telemetry: post-send emitter
+// ---------------------------------------------------------------------------
+
+/// Decides whether one request's access-telemetry row should be emitted.
+///
+/// `roll` is a uniform draw from `[0, 1)`; callers pass
+/// `rand::thread_rng().r#gen::()`, which the wasm32-wasip1 guest backs with
+/// real WASI randomness (the EC generation path already relies on this and
+/// the CI wasm release build verifies it). Comparing the draw directly
+/// against `rate` keeps the sampling probability exactly `rate` for every
+/// positive value: there is no bucket quantization, so rates below one in a
+/// million sample proportionally instead of never, and emitted rows'
+/// `sample_rate` matches the probability they were sampled at, which the
+/// `sum(1.0 / sample_rate)` volume estimator depends on.
+///
+/// `rate <= 0.0` never samples and `rate >= 1.0` always samples, for any
+/// `roll` in `[0, 1)`. `0.0` cannot actually occur while `access_enabled`
+/// is `true` (`Settings` validation requires `access_sample_rate > 0.0` in
+/// that case), but this function stays total rather than leaning on that
+/// invariant.
+#[must_use]
+pub(crate) fn sampled_in(rate: f64, roll: f64) -> bool {
+ roll < rate
+}
+
+/// Builds the Events API POST request for one access-log row.
+fn build_access_events_request(
+ target: &TinybirdEventsTarget,
+ body: String,
+ auth_header: HeaderValue,
+) -> Result> {
+ request_builder()
+ .method(Method::POST)
+ .uri(target.uri.as_str())
+ .header(header::AUTHORIZATION, auth_header)
+ .header(header::CONTENT_TYPE, TINYBIRD_NDJSON_CONTENT_TYPE)
+ .body(Body::from(body))
+ .change_context(TrustedServerError::Proxy {
+ message: "failed to build Tinybird Events API request".to_owned(),
+ })
+}
+
+/// Starts a best-effort POST of one post-send access-log row to Tinybird.
+///
+/// The pending handle is dropped without waiting for the ingest reply or
+/// retrying. Fastly SDK 0.12.1 documents that `Request::send_async` continues
+/// transmitting headers and body in the background even after the initiating
+/// Compute program exits, and permits discarding `PendingRequest` for side
+/// effects. This avoids holding a reused sandbox until the ingest reply.
+/// Dispatch success does not confirm remote ingest acceptance: later transport
+/// failures and non-2xx statuses are not observable here. Likewise, the earlier
+/// client-response transport handoff does not confirm client receipt.
+///
+/// `client` is the adapter's stateless platform HTTP client in production
+/// ([`crate::platform::FastlyPlatformHttpClient`]); accepting it as `&dyn
+/// PlatformHttpClient` lets tests substitute a recording double.
+/// `target` is derived from settings once at the post-send call site.
+///
+/// # Errors
+///
+/// Returns `Err` when the row exceeds the configured request-body limit, the
+/// authorization header is invalid, the backend cannot be registered, or the
+/// request cannot be built or started.
+pub(crate) async fn emit_access_event(
+ client: &dyn PlatformHttpClient,
+ target: &TinybirdEventsTarget,
+ mut row: String,
+) -> Result<(), Report> {
+ // Match the auction sink's NDJSON framing: every row is
+ // newline-terminated, and the terminator counts toward the body limit.
+ if !row.ends_with('\n') {
+ row.push('\n');
+ }
+ let body_len = row.len();
+ if body_len > target.max_body_bytes {
+ return Err(Report::new(TrustedServerError::Proxy {
+ message: format!(
+ "Tinybird access telemetry request body has {body_len} bytes, exceeding {} byte limit",
+ target.max_body_bytes
+ ),
+ }));
+ }
+
+ let auth_header =
+ FastlyTinybirdAuctionTelemetrySink::authorization_header(target.append_token.expose())?;
+ let backend_name = FastlyPlatformBackend
+ .ensure(&target.backend_spec)
+ .change_context(TrustedServerError::Proxy {
+ message: "Tinybird backend registration failed".to_owned(),
+ })?;
+ let request = build_access_events_request(target, row, auth_header)?;
+
+ log::debug!(
+ "sending access telemetry to Tinybird dataset={} host={} backend={}",
+ target.dataset,
+ target.api_host,
+ backend_name
+ );
+
+ let pending = client
+ .send_async(PlatformHttpRequest::new(request, backend_name))
+ .await
+ .change_context(TrustedServerError::Proxy {
+ message: "failed to start Tinybird access telemetry request".to_owned(),
+ })?;
+ drop(pending);
+ Ok(())
+}
+
fn tinybird_backend_spec(api_host: &str) -> PlatformBackendSpec {
PlatformBackendSpec {
scheme: "https".to_owned(),
@@ -205,6 +356,7 @@ fn tinybird_events_uri(api_host: &str, dataset: &str) -> String {
#[cfg(test)]
mod tests {
use std::collections::HashMap;
+ use std::sync::atomic::{AtomicUsize, Ordering};
use std::sync::{Arc, Mutex};
use error_stack::Report;
@@ -308,25 +460,45 @@ mod tests {
body: Vec,
}
+ struct RecordedPending(Arc);
+
+ impl Drop for RecordedPending {
+ fn drop(&mut self) {
+ self.0.fetch_add(1, Ordering::SeqCst);
+ }
+ }
+
#[derive(Default)]
struct RecordingHttpClient {
requests: Mutex>,
+ send_calls: AtomicUsize,
+ send_async_calls: AtomicUsize,
+ wait_calls: AtomicUsize,
select_calls: Mutex,
+ fail_async_start: bool,
+ pending_drops: Arc,
}
- #[async_trait::async_trait(?Send)]
- impl PlatformHttpClient for RecordingHttpClient {
- async fn send(
- &self,
- _request: PlatformHttpRequest,
- ) -> Result> {
- Err(Report::new(PlatformError::Unsupported))
+ impl RecordingHttpClient {
+ fn assert_no_response_wait(&self) {
+ assert_eq!(
+ self.send_calls.load(Ordering::SeqCst),
+ 0,
+ "must not send synchronously"
+ );
+ assert_eq!(
+ self.wait_calls.load(Ordering::SeqCst),
+ 0,
+ "must not wait on a pending request"
+ );
+ assert_eq!(
+ *self.select_calls.lock().expect("should lock select calls"),
+ 0,
+ "must not select a response"
+ );
}
- async fn send_async(
- &self,
- request: PlatformHttpRequest,
- ) -> Result> {
+ fn record(&self, request: PlatformHttpRequest) {
let backend_name = request.backend_name;
let (parts, body) = request.request.into_parts();
let headers = parts
@@ -350,7 +522,40 @@ mod tests {
.lock()
.expect("should lock recorded requests")
.push(recorded);
- Ok(PlatformPendingRequest::new(()).with_backend_name("tinybird-backend"))
+ }
+ }
+
+ #[async_trait::async_trait(?Send)]
+ impl PlatformHttpClient for RecordingHttpClient {
+ async fn send(
+ &self,
+ _request: PlatformHttpRequest,
+ ) -> Result> {
+ self.send_calls.fetch_add(1, Ordering::SeqCst);
+ Err(Report::new(PlatformError::Unsupported))
+ }
+
+ async fn send_async(
+ &self,
+ request: PlatformHttpRequest,
+ ) -> Result> {
+ self.send_async_calls.fetch_add(1, Ordering::SeqCst);
+ self.record(request);
+ if self.fail_async_start {
+ return Err(Report::new(PlatformError::HttpClient));
+ }
+ Ok(
+ PlatformPendingRequest::new(RecordedPending(Arc::clone(&self.pending_drops)))
+ .with_backend_name("tinybird-backend"),
+ )
+ }
+
+ async fn wait(
+ &self,
+ _pending: PlatformPendingRequest,
+ ) -> Result> {
+ self.wait_calls.fetch_add(1, Ordering::SeqCst);
+ Err(Report::new(PlatformError::Unsupported))
}
async fn select(
@@ -431,18 +636,52 @@ mod tests {
fn enabled_config() -> TinybirdSettings {
TinybirdSettings {
enabled: true,
+ auction_enabled: true,
api_host: "api.us-east.aws.tinybird.co".to_owned(),
secret_store: None,
auction_dataset: "auction_events_raw".to_owned(),
auction_token_secret: Some(Redacted::new("append-token".to_owned())),
access_enabled: false,
- access_dataset: "access_logs_raw".to_owned(),
- access_token_secret: None,
+ access_dataset: "access_logs_v2".to_owned(),
+ access_token_secret: Some(Redacted::new("access-append-token".to_owned())),
access_sample_rate: 0.0,
max_body_bytes: 1024 * 1024,
}
}
+ #[test]
+ fn sink_from_settings_disables_when_auction_enabled_is_false() {
+ let settings = Settings {
+ tinybird: TinybirdSettings {
+ auction_enabled: false,
+ ..enabled_config()
+ },
+ ..Settings::default()
+ };
+
+ let sink = auction_sink_from_settings(&settings);
+
+ assert!(
+ !sink.is_enabled(),
+ "auction telemetry should stay off when auction_enabled is false, even if tinybird.enabled is true"
+ );
+ }
+
+ #[test]
+ fn sink_from_settings_enables_when_both_toggles_are_true() {
+ let settings = Settings {
+ tinybird: enabled_config(),
+ ..Settings::default()
+ };
+
+ let sink = auction_sink_from_settings(&settings);
+
+ assert!(
+ sink.is_enabled(),
+ "auction telemetry should be on when both tinybird.enabled and tinybird.auction_enabled are true"
+ );
+ }
+
#[test]
fn events_uri_targets_dataset_on_region_host() {
assert_eq!(
@@ -619,6 +858,281 @@ mod tests {
);
}
+ #[test]
+ fn access_target_rejects_unresolved_token_without_panicking() {
+ let mut config = enabled_config();
+ config.access_token_secret = None;
+
+ let error = TinybirdEventsTarget::from_access_config(&config)
+ .expect_err("should reject an unresolved access token");
+
+ assert!(
+ matches!(
+ error.current_context(),
+ TrustedServerError::Configuration { .. }
+ ),
+ "should report a configuration error"
+ );
+ assert!(
+ error
+ .to_string()
+ .contains("Tinybird access token is not resolved"),
+ "should explain the missing resolved access token"
+ );
+ }
+
+ #[test]
+ fn access_target_borrows_settings_and_uses_only_access_fields() {
+ let mut config = enabled_config();
+ config.auction_token_secret = None;
+ config.max_body_bytes = 2048;
+
+ let target = TinybirdEventsTarget::from_access_config(&config)
+ .expect("should build access telemetry target");
+
+ assert_eq!(target.api_host, config.api_host);
+ assert_eq!(target.dataset, config.access_dataset);
+ assert_eq!(target.append_token.expose(), "access-append-token");
+ assert_eq!(target.max_body_bytes, config.max_body_bytes);
+ assert_eq!(
+ config
+ .access_token_secret
+ .as_ref()
+ .expect("should retain the access token in settings")
+ .expose(),
+ "access-append-token"
+ );
+ }
+
+ #[test]
+ fn access_emitter_rejects_oversized_row_before_sending() {
+ let mut config = enabled_config();
+ config.max_body_bytes = 1024;
+ let target = TinybirdEventsTarget::from_access_config(&config)
+ .expect("should build access telemetry target");
+ let http_client = RecordingHttpClient::default();
+ let row = "x".repeat(1025);
+
+ let result = futures::executor::block_on(emit_access_event(&http_client, &target, row));
+
+ let error = result.expect_err("should reject a row above the configured body limit");
+ assert!(
+ error.to_string().contains("1024"),
+ "error should name the configured body limit: {error}"
+ );
+ assert!(
+ http_client
+ .requests
+ .lock()
+ .expect("should lock recorded requests")
+ .is_empty(),
+ "should not send an oversized access row"
+ );
+ }
+
+ #[test]
+ fn access_emitter_accepts_row_exactly_at_body_limit_including_newline() {
+ let mut config = enabled_config();
+ config.max_body_bytes = 1024;
+ let target = TinybirdEventsTarget::from_access_config(&config)
+ .expect("should build access telemetry target");
+ let http_client = RecordingHttpClient::default();
+ let row = "x".repeat(1023);
+
+ futures::executor::block_on(emit_access_event(&http_client, &target, row.clone()))
+ .expect("a newline-terminated row exactly at the limit should send");
+
+ let requests = http_client
+ .requests
+ .lock()
+ .expect("should lock recorded requests");
+ assert_eq!(requests.len(), 1, "should send the boundary-sized row");
+ assert_eq!(requests[0].body.len(), 1024, "newline counts toward limit");
+ assert_eq!(requests[0].body.last(), Some(&b'\n'));
+ }
+
+ #[test]
+ fn access_emitter_posts_ndjson_and_drops_pending_without_waiting() {
+ let target = TinybirdEventsTarget::from_access_config(&enabled_config())
+ .expect("should build access telemetry target");
+ let http_client = RecordingHttpClient::default();
+ let row = r#"{"status":200}"#.to_owned();
+
+ futures::executor::block_on(emit_access_event(&http_client, &target, row.clone()))
+ .expect("should start the access telemetry request");
+
+ let requests = http_client
+ .requests
+ .lock()
+ .expect("should lock recorded requests");
+ assert_eq!(requests.len(), 1, "should send exactly one request");
+ assert_eq!(
+ requests[0].uri,
+ "https://api.us-east.aws.tinybird.co/v0/events?name=access_logs_v2"
+ );
+ assert_eq!(requests[0].method, Method::POST.to_string());
+ assert_eq!(
+ header_value(&requests[0].headers, header::CONTENT_TYPE.as_str()),
+ Some(TINYBIRD_NDJSON_CONTENT_TYPE)
+ );
+ assert_eq!(
+ header_value(&requests[0].headers, header::AUTHORIZATION.as_str()),
+ Some("Bearer access-append-token")
+ );
+ let body = std::str::from_utf8(&requests[0].body).expect("should record utf8 body");
+ assert_eq!(
+ body,
+ format!("{row}\n"),
+ "should send newline-delimited JSON, matching the auction sink's framing"
+ );
+ http_client.assert_no_response_wait();
+ assert_eq!(http_client.send_async_calls.load(Ordering::SeqCst), 1);
+ assert_eq!(
+ http_client.pending_drops.load(Ordering::SeqCst),
+ 1,
+ "should drop the pending handle before returning"
+ );
+ }
+
+ #[test]
+ fn access_emitter_surfaces_async_start_failure_without_retrying() {
+ let target = TinybirdEventsTarget::from_access_config(&enabled_config())
+ .expect("should build access telemetry target");
+ let http_client = RecordingHttpClient {
+ fail_async_start: true,
+ ..RecordingHttpClient::default()
+ };
+
+ let error = futures::executor::block_on(emit_access_event(
+ &http_client,
+ &target,
+ r#"{"status":200}"#.to_owned(),
+ ))
+ .expect_err("should surface the dispatch failure");
+
+ assert!(
+ error
+ .to_string()
+ .contains("failed to start Tinybird access telemetry request")
+ );
+ assert_eq!(
+ http_client.send_async_calls.load(Ordering::SeqCst),
+ 1,
+ "must not retry"
+ );
+ assert_eq!(
+ http_client.pending_drops.load(Ordering::SeqCst),
+ 0,
+ "failed dispatch must not create a pending handle"
+ );
+ http_client.assert_no_response_wait();
+ }
+
+ #[test]
+ fn access_emitter_preserves_existing_newline() {
+ let target = TinybirdEventsTarget::from_access_config(&enabled_config())
+ .expect("should build access telemetry target");
+ let http_client = RecordingHttpClient::default();
+ let row = "{\"status\":200}\n".to_owned();
+
+ futures::executor::block_on(emit_access_event(&http_client, &target, row.clone()))
+ .expect("should start the access telemetry request");
+
+ let requests = http_client
+ .requests
+ .lock()
+ .expect("should lock recorded requests");
+ assert_eq!(requests[0].body, row.as_bytes());
+ }
+
+ #[test]
+ fn access_emitter_counts_added_newline_against_body_limit() {
+ let mut config = enabled_config();
+ config.max_body_bytes = 1024;
+ let target = TinybirdEventsTarget::from_access_config(&config)
+ .expect("should build access telemetry target");
+ let http_client = RecordingHttpClient::default();
+
+ let error =
+ futures::executor::block_on(emit_access_event(&http_client, &target, "x".repeat(1024)))
+ .expect_err("should count the added newline toward the body limit");
+
+ assert!(
+ error
+ .to_string()
+ .contains("1025 bytes, exceeding 1024 byte limit"),
+ "error should count the added newline: {error}"
+ );
+ assert_eq!(http_client.send_async_calls.load(Ordering::SeqCst), 0);
+ http_client.assert_no_response_wait();
+ }
+
+ #[test]
+ fn access_emitter_rejects_invalid_authorization_before_dispatch() {
+ let mut config = enabled_config();
+ config.access_token_secret = Some(Redacted::new("invalid\ntoken".to_owned()));
+ let target = TinybirdEventsTarget::from_access_config(&config)
+ .expect("should build access telemetry target");
+ let http_client = RecordingHttpClient::default();
+
+ let error =
+ futures::executor::block_on(emit_access_event(&http_client, &target, "{}".to_owned()))
+ .expect_err("should reject an invalid authorization header");
+
+ assert!(
+ error
+ .to_string()
+ .contains("invalid Tinybird authorization header"),
+ "error should name the invalid authorization header: {error}"
+ );
+ assert_eq!(http_client.send_async_calls.load(Ordering::SeqCst), 0);
+ http_client.assert_no_response_wait();
+ }
+
+ #[test]
+ fn sampled_in_boundary_rates_are_unconditional() {
+ assert!(
+ sampled_in(1.0, 0.0),
+ "a 1.0 sample rate should always sample in"
+ );
+ assert!(
+ sampled_in(1.0, 0.999_999),
+ "a 1.0 sample rate should sample in for the largest roll"
+ );
+ assert!(
+ !sampled_in(0.0, 0.0),
+ "a 0.0 sample rate should never sample in, even on a zero roll"
+ );
+ assert!(
+ !sampled_in(-1.0, 0.0),
+ "a negative rate should never sample in"
+ );
+ }
+
+ #[test]
+ fn sampled_in_keeps_exact_probability_for_tiny_rates() {
+ // The previous bucket-quantized sampler truncated rates below one
+ // in a million to a zero threshold, silently emitting nothing.
+ // Direct comparison keeps every positive rate proportional.
+ let rate = 0.000_000_1;
+ assert!(
+ sampled_in(rate, rate / 2.0),
+ "a roll below a tiny positive rate should sample in"
+ );
+ assert!(
+ !sampled_in(rate, rate * 2.0),
+ "a roll above a tiny positive rate should sample out"
+ );
+ assert!(
+ !sampled_in(0.000_001_9, 0.000_001_95),
+ "no downward quantization: the boundary sits exactly at the rate"
+ );
+ assert!(
+ sampled_in(0.000_001_9, 0.000_001_85),
+ "rolls just under the rate should sample in"
+ );
+ }
+
fn header_value<'a>(headers: &'a [(String, String)], name: &str) -> Option<&'a str> {
headers
.iter()
diff --git a/crates/trusted-server-adapter-spin/src/app.rs b/crates/trusted-server-adapter-spin/src/app.rs
index 804a23b620..4bc2e2d556 100644
--- a/crates/trusted-server-adapter-spin/src/app.rs
+++ b/crates/trusted-server-adapter-spin/src/app.rs
@@ -43,6 +43,7 @@ use trusted_server_core::publisher::{
use trusted_server_core::request_signing::{
handle_trusted_server_discovery, handle_verify_signature,
};
+use trusted_server_core::request_timing::RequestTimingMiddleware;
use trusted_server_core::settings::Settings;
#[cfg(all(feature = "spin", target_arch = "wasm32"))]
use trusted_server_core::settings_data::{default_config_key, default_secret_store_name};
@@ -886,6 +887,7 @@ fn build_router(state: &Arc) -> RouterService {
// any middleware registered ahead of it would observe the
// shared-secret authentication header.
.middleware(SanitizeRequestMiddleware::new(Arc::clone(&state.settings)))
+ .middleware(RequestTimingMiddleware::default().with_excluded_paths(&["/health"]))
.middleware(FinalizeResponseMiddleware::new(Arc::clone(&state.settings)))
.middleware(AuthMiddleware::new(Arc::clone(&state.settings)))
// Innermost middleware: normalize every routed request (strip
diff --git a/crates/trusted-server-adapter-spin/src/middleware.rs b/crates/trusted-server-adapter-spin/src/middleware.rs
index fc1b939bd5..13796286fe 100644
--- a/crates/trusted-server-adapter-spin/src/middleware.rs
+++ b/crates/trusted-server-adapter-spin/src/middleware.rs
@@ -55,9 +55,9 @@ impl Middleware for SanitizeRequestMiddleware {
/// Spin does not expose geo headers to the application, so
/// `X-Geo-Info-Available: false` is emitted for every response.
///
-/// Registered directly inside [`SanitizeRequestMiddleware`] and ahead of
-/// [`AuthMiddleware`] so that every outgoing response — including auth-rejected
-/// ones — carries a consistent set of headers.
+/// Registered inside [`RequestTimingMiddleware`](trusted_server_core::request_timing::RequestTimingMiddleware) and ahead of [`AuthMiddleware`]
+/// so that every outgoing response — including auth-rejected ones — carries a
+/// consistent set of headers.
pub struct FinalizeResponseMiddleware {
settings: Arc,
}
@@ -190,6 +190,8 @@ pub(crate) fn apply_finalize_headers(
#[cfg(test)]
mod tests {
use super::*;
+ use edgezero_core::router::RouterService;
+ use trusted_server_core::request_timing::{RequestTimingMiddleware, RequestTimings};
use std::collections::HashMap;
use std::sync::Mutex;
@@ -209,10 +211,10 @@ mod tests {
.expect("should build empty test response")
}
- fn empty_ctx() -> RequestContext {
+ fn ctx_for_path(path: &str) -> RequestContext {
let req = request_builder()
.method(Method::GET)
- .uri("/test")
+ .uri(path)
.header("x-reader-ip", "198.51.100.7")
.header("x-reader-ip-auth", "fictional-shared-secret-0123456789")
.body(Body::empty())
@@ -220,6 +222,10 @@ mod tests {
RequestContext::new(req, PathParams::new(HashMap::new()))
}
+ fn empty_ctx() -> RequestContext {
+ ctx_for_path("/test")
+ }
+
fn settings_with_response_headers(headers: Vec<(&str, &str)>) -> Settings {
// Build from explicit test settings: the settings baked into the
// binary contain placeholder secrets that `get_settings()` rejects
@@ -318,6 +324,77 @@ mod tests {
);
}
+ #[test]
+ fn request_timing_middleware_preserves_shared_handle_and_health_policy() {
+ for method in [Method::GET, Method::POST] {
+ for path in ["/test", "/health", "/health?probe=1", "/health/child"] {
+ for preinstalled in [false, true] {
+ let route_path = path.split('?').next().expect("should have path");
+ let expected = preinstalled || route_path != "/health";
+ let timings = RequestTimings::new();
+ timings.record(
+ trusted_server_core::request_timing::Phase::Filter,
+ std::time::Duration::from_millis(7),
+ );
+ std::thread::sleep(std::time::Duration::from_millis(2));
+ let router = RouterService::builder()
+ .middleware(
+ RequestTimingMiddleware::default().with_excluded_paths(&["/health"]),
+ )
+ .middleware(
+ RequestTimingMiddleware::default().with_excluded_paths(&["/health"]),
+ )
+ .route(route_path, method.clone(), move |ctx: RequestContext| async move {
+ let installed = RequestTimings::from_extensions(ctx.request().extensions());
+ assert_eq!(installed.is_some(), expected, "should preserve exact health policy");
+ if let Some(installed) = installed {
+ if preinstalled {
+ assert_eq!(installed.snapshot().filter_ms, Some(7), "should retain upstream facts");
+ installed.mark_auction_dispatched();
+ assert!(installed.snapshot().auction_dispatched_ms.expect("should mark dispatch") >= 2,
+ "should retain upstream origin");
+ } else {
+ assert_eq!(installed.snapshot(), trusted_server_core::request_timing::TimingSnapshot::default(),
+ "should install independent empty facts");
+ }
+ installed.record_auction_wait(
+ trusted_server_core::request_timing::AuctionWaitPlacement::PreHeader,
+ std::time::Duration::from_millis(3));
+ }
+ Ok::(empty_response())
+ })
+ .build();
+ let mut request = request_builder()
+ .method(method.clone())
+ .uri(path)
+ .body(Body::empty())
+ .expect("should build request");
+ if preinstalled {
+ request.extensions_mut().insert(timings.handle().clone());
+ }
+ let response =
+ block_on(router.oneshot(request)).expect("should dispatch request");
+ assert!(
+ response.headers().get("server-timing").is_none(),
+ "attachment should not expose timing"
+ );
+ if preinstalled {
+ assert_eq!(
+ timings.snapshot().auction_wait_ms,
+ Some(3),
+ "should share handler updates"
+ );
+ assert_eq!(
+ timings.snapshot().request_elapsed_ms,
+ None,
+ "should not fabricate completion"
+ );
+ }
+ }
+ }
+ }
+ }
+
#[test]
fn sanitize_middleware_strips_configured_trust_headers_before_routing() {
let mut settings = settings_with_response_headers(vec![]);
diff --git a/crates/trusted-server-core/src/access_telemetry.rs b/crates/trusted-server-core/src/access_telemetry.rs
new file mode 100644
index 0000000000..a89162c2a8
--- /dev/null
+++ b/crates/trusted-server-core/src/access_telemetry.rs
@@ -0,0 +1,716 @@
+//! Access telemetry: route classification and the per-request access log row.
+//!
+//! Uses the versioned `access_logs_v2` Tinybird datasource with bounded,
+//! content-free route identity (see [`RouteClass`] and
+//! [`publisher_route_template`]) instead of the raw request path, which would
+//! otherwise carry identifiers, search terms, and other user-generated
+//! content into a 30-day dataset. See the design spec
+//! `docs/superpowers/specs/2026-08-24-request-phase-timing-design.md`
+//! section 9.
+
+use serde_json::json;
+
+use crate::constants::TS_GIT_VERSION;
+use crate::request_timing::{AuctionWaitPlacement, TimingSnapshot};
+
+/// Normalizes an HTTP method token into the bounded set of values stored in
+/// the `method` `LowCardinality` column.
+///
+/// HTTP permits arbitrary extension-method tokens (`PROPFIND`, `MKCOL`, or
+/// any client-supplied garbage), and the token on an inbound request is
+/// entirely client controlled. Capturing one verbatim into a 30-day
+/// `LowCardinality(String)` column would let a single caller inflate that
+/// column's cardinality without bound and would violate this dataset's
+/// bounded-dimension privacy rule (see the module doc). GET, HEAD, POST, PUT,
+/// DELETE, PATCH and OPTIONS map to their uppercase form; all other methods,
+/// including CONNECT and TRACE, map to `"other"`. Runs
+/// inside [`access_event_row`] rather than at each capture site, so every
+/// row-building path is covered regardless of how `method` was populated.
+///
+/// # Examples
+///
+/// ```
+/// use trusted_server_core::access_telemetry::normalize_method;
+///
+/// assert_eq!(normalize_method("get"), "GET");
+/// assert_eq!(normalize_method("PROPFIND"), "other");
+/// assert_eq!(normalize_method(""),
+ "other",
+ "an unbounded client-controlled token must not reach the row verbatim"
+ );
+ }
+
+ #[test]
+ fn row_normalizes_method_even_when_snapshot_carries_a_raw_token() {
+ // The normalizer runs inside `access_event_row` so every row-building
+ // path is covered, regardless of what the snapshot's `method` field
+ // holds — a caller-controlled extension method must never leak into
+ // the row unnormalized.
+ let mut snapshot = unknown_snapshot(RouteClass::Other, "/other/*");
+ snapshot.method = "PROPFIND".to_owned();
+ let row = access_event_row(
+ &snapshot,
+ &TimingSnapshot::default(),
+ DeliveryResult::Complete,
+ 0,
+ );
+ let parsed: serde_json::Value =
+ serde_json::from_str(&row).expect("should serialize valid JSON");
+
+ assert_eq!(parsed["method"], "other");
+ }
+}
diff --git a/crates/trusted-server-core/src/auction/endpoints.rs b/crates/trusted-server-core/src/auction/endpoints.rs
index f364464561..70d84ee5e6 100644
--- a/crates/trusted-server-core/src/auction/endpoints.rs
+++ b/crates/trusted-server-core/src/auction/endpoints.rs
@@ -22,6 +22,7 @@ use crate::ec::registry::PartnerRegistry;
use crate::error::TrustedServerError;
use crate::openrtb::{Eid, Uid};
use crate::platform::RuntimeServices;
+use crate::request_timing::RequestTimings;
use crate::settings::Settings;
use super::AuctionOrchestrator;
@@ -145,6 +146,12 @@ pub async fn handle_auction(
}
let (parts, body) = req.into_parts();
+ // T0-anchored timeline (spec section 18). This route is the auction, so
+ // dispatch and resolve bracket `run_auction` rather than the origin
+ // fetch, and the commit mark lands once the OpenRTB response carrying the
+ // targeting has been built. A defaulted handle records into nothing that
+ // is ever read, so direct-handler tests are unaffected.
+ let timings = RequestTimings::from_extensions(&parts.extensions).unwrap_or_default();
let body_bytes = body.into_bytes().unwrap_or_default();
if body_bytes.len() > MAX_AUCTION_BODY_SIZE {
return Response::builder()
@@ -251,6 +258,7 @@ pub async fn handle_auction(
&auction_request,
ec_context,
);
+ timings.set_auction_id(observation.auction_id);
emit_auction_events_best_effort_lazy(services, || {
build_auction_events(
observation,
@@ -368,24 +376,27 @@ pub async fn handle_auction(
ec_context,
);
- // Run the auction
- let result = match orchestrator.run_auction(&auction_request, &context).await {
- Ok(result) => result,
- Err(err) => {
- let elapsed_ms = observation.elapsed_ms();
+ timings.set_auction_id(observation.auction_id);
+
+ let (result, auction_work_started) = match orchestrator
+ .run_auction_with_timings(&auction_request, &context, &timings)
+ .await
+ {
+ Ok(completed) => completed,
+ Err(failure) => {
emit_auction_events_best_effort_lazy(services, || {
build_auction_events(
observation,
AuctionTerminalOutcome::ExecutionFailed {
request: Some(&auction_request),
- provider_responses: &[],
+ provider_responses: &failure.provider_responses,
reason: "execution_failed",
- elapsed_ms,
+ elapsed_ms: failure.elapsed_ms,
},
)
})
.await;
- return Err(err.change_context(TrustedServerError::Auction {
+ return Err(failure.error.change_context(TrustedServerError::Auction {
message: "Auction orchestration failed".to_string(),
}));
}
@@ -416,6 +427,12 @@ pub async fn handle_auction(
}
};
+ // For this route the response body is the commit, since there is no
+ // page state to write into. Routing-only results cannot commit an auction.
+ if auction_work_started {
+ timings.mark_auction_committed();
+ }
+
emit_auction_events_best_effort_lazy(services, || {
build_auction_events(
observation,
@@ -625,6 +642,7 @@ pub(crate) fn merge_auction_eids(
mod tests {
use super::*;
use crate::auction::config::AuctionConfig;
+ use crate::auction::provider::test_support::LaunchEvidenceProvider as Mediator;
use crate::auction::provider::{AuctionProvider, ProviderRequestOutcome};
use crate::auction::telemetry::{AuctionEventBatch, AuctionTelemetrySink};
use crate::auction::types::{AuctionRequest, AuctionResponse};
@@ -633,10 +651,13 @@ mod tests {
use crate::error::IntoHttpResponse as _;
use crate::openrtb::Uid;
use crate::platform::test_support::{
- NoopBackend, NoopConfigStore, NoopGeo, NoopHttpClient, NoopSecretStore, StubHttpClient,
- noop_services,
+ NoopBackend, NoopConfigStore, NoopGeo, NoopHttpClient, NoopSecretStore, StubBackend,
+ StubHttpClient, noop_services,
+ };
+ use crate::platform::{
+ ClientInfo, PlatformBackend, PlatformHttpClient, PlatformHttpRequest, PlatformResponse,
};
- use crate::platform::{ClientInfo, PlatformHttpClient, PlatformHttpRequest, PlatformResponse};
+ use crate::request_timing::AuctionWaitPlacement;
use crate::test_support::tests::{crate_test_settings_str, create_test_settings};
use base64::Engine as _;
use base64::engine::general_purpose::STANDARD as BASE64;
@@ -664,13 +685,21 @@ mod tests {
}
fn services_with_telemetry(sink: Arc) -> RuntimeServices {
+ services_with_http_and_telemetry(Arc::new(NoopHttpClient), Arc::new(NoopBackend), sink)
+ }
+
+ fn services_with_http_and_telemetry(
+ http: Arc,
+ backend: Arc,
+ sink: Arc,
+ ) -> RuntimeServices {
let telemetry_sink: Arc = sink;
RuntimeServices::builder()
.config_store(Arc::new(NoopConfigStore))
.secret_store(Arc::new(NoopSecretStore))
.kv_store(Arc::new(edgezero_core::key_value_store::NoopKvStore))
- .backend(Arc::new(NoopBackend))
- .http_client(Arc::new(NoopHttpClient))
+ .backend(backend)
+ .http_client(http)
.geo(Arc::new(NoopGeo))
.auction_telemetry_sink(telemetry_sink)
.client_info(ClientInfo::default())
@@ -1070,13 +1099,15 @@ mod tests {
"mediaTypes": { "banner": { "sizes": [[300, 250]] } }
}]
});
- let request = Request::builder()
+ let mut request = Request::builder()
.method("POST")
.uri("https://test-publisher.example/auction")
.body(EdgeBody::from(
serde_json::to_vec(&body).expect("should serialize disabled-auction body"),
))
.expect("should build disabled-auction request");
+ let timings = RequestTimings::new();
+ request.extensions_mut().insert(timings.handle().clone());
let response = handle_auction(
&settings,
@@ -1095,6 +1126,10 @@ mod tests {
StatusCode::OK,
"disabled auction should return a 200 no-bid response"
);
+ assert!(
+ timings.snapshot().auction_id.is_none(),
+ "should keep the disabled /auction access join key null"
+ );
let batches = telemetry_sink
.batches
.lock()
@@ -1111,6 +1146,262 @@ mod tests {
);
}
+ #[tokio::test]
+ async fn planned_endpoint_preserves_installed_collector_across_terminal_states() {
+ for (provider_configured, transport_failure, metadata_missing) in [
+ (true, false, false),
+ (true, true, false),
+ (false, false, false),
+ (true, false, true),
+ ] {
+ let provider = if provider_configured {
+ "[auction.providers.example]\nprotocol = \"openrtb-2.6\"\nprofile = \"standard\"\nendpoint = \"https://bidder.example.com/auction\"\nrouting = \"all_eligible\"\n"
+ } else {
+ ""
+ };
+ let settings = Settings::from_toml(&format!(
+ "{}\n[auction]\nenabled = true\n{provider}",
+ crate_test_settings_str()
+ ))
+ .expect("should parse planned endpoint settings");
+ let plan = Arc::new(
+ crate::auction::compile_auction_plan(&settings)
+ .expect("should compile endpoint plan"),
+ );
+ let orchestrator = AuctionOrchestrator::from_plan(plan, None);
+ let http = Arc::new(StubHttpClient::new());
+ http.push_response(204, Vec::new());
+ if transport_failure {
+ http.push_select_error();
+ }
+ if metadata_missing {
+ http.push_pending_backend_name_override(None);
+ }
+ let sink = Arc::new(RecordingTelemetrySink::default());
+ let services =
+ services_with_http_and_telemetry(http.clone(), Arc::new(StubBackend), sink.clone());
+ let mut ec_context = make_ec_context(Jurisdiction::NonRegulated, None);
+ let body = json!({ "adUnits": [{
+ "code": "example-slot",
+ "mediaTypes": { "banner": { "sizes": [[300, 250]] } }
+ }] });
+ let mut request = Request::builder()
+ .method("POST")
+ .uri("https://publisher.example.com/auction")
+ .body(EdgeBody::from(
+ serde_json::to_vec(&body).expect("should serialize endpoint request"),
+ ))
+ .expect("should build endpoint request");
+ let timings = RequestTimings::new();
+ timings.record(
+ crate::request_timing::Phase::Filter,
+ std::time::Duration::from_millis(11),
+ );
+ request.extensions_mut().insert(timings.handle().clone());
+
+ let response = handle_auction(
+ &settings,
+ &orchestrator,
+ None,
+ None,
+ &mut ec_context,
+ &services,
+ request,
+ )
+ .await;
+
+ if metadata_missing {
+ assert_eq!(
+ response
+ .expect_err("should fail closed after losing pending metadata")
+ .current_context()
+ .status_code(),
+ StatusCode::BAD_GATEWAY
+ );
+ } else {
+ assert_eq!(
+ response
+ .expect("should return a completed or no-bid response")
+ .status(),
+ StatusCode::OK,
+ "should preserve the no-bid HTTP contract"
+ );
+ }
+ let snapshot = timings.snapshot();
+ let auction_id = snapshot
+ .auction_id
+ .expect("should record the attempted auction UUID");
+ let batches = sink.batches.lock().expect("should lock telemetry batches");
+ assert!(
+ batches[0]
+ .rows()
+ .iter()
+ .all(|row| row.auction_id == auction_id.to_string()),
+ "should join the original collector to every emitted auction row"
+ );
+ assert_eq!(
+ snapshot.filter_ms,
+ Some(11),
+ "should retain adapter-recorded phases"
+ );
+ assert_eq!(
+ http.recorded_backend_names().len(),
+ usize::from(provider_configured),
+ "should distinguish a real request launch from the empty plan"
+ );
+ assert_eq!(
+ snapshot.auction_wait_ms.is_some(),
+ provider_configured && !metadata_missing
+ );
+ assert_eq!(
+ snapshot.auction_wait_placement,
+ (provider_configured && !metadata_missing)
+ .then_some(crate::request_timing::AuctionWaitPlacement::PreHeader)
+ );
+ if metadata_missing {
+ assert!(
+ snapshot.auction_dispatched_ms.is_some(),
+ "should retain evidence of the request already launched"
+ );
+ assert!(
+ snapshot.auction_resolved_ms.is_none(),
+ "should not fabricate collection after dispatch failure"
+ );
+ assert!(
+ snapshot.auction_committed_ms.is_none(),
+ "should not commit a failed dispatch"
+ );
+ } else if provider_configured {
+ let dispatched = snapshot
+ .auction_dispatched_ms
+ .expect("should mark a real launch");
+ let resolved = snapshot
+ .auction_resolved_ms
+ .expect("should mark collection even after transport failure");
+ let committed = snapshot
+ .auction_committed_ms
+ .expect("should commit the no-bid response");
+ assert!(
+ dispatched <= resolved && resolved <= committed,
+ "should preserve milestone ordering"
+ );
+ } else {
+ assert!(
+ snapshot.auction_dispatched_ms.is_none(),
+ "should omit zero-launch dispatch"
+ );
+ assert!(
+ snapshot.auction_resolved_ms.is_none(),
+ "should omit zero-launch resolution"
+ );
+ assert!(
+ snapshot.auction_committed_ms.is_none(),
+ "should omit zero-launch commit"
+ );
+ }
+ timings.mark_headers_ready();
+ timings.mark_request_elapsed();
+ assert!(
+ timings
+ .handle()
+ .snapshot(
+ |inner| inner.headers_ready.is_some() && inner.request_complete.is_some()
+ )
+ .expect("should snapshot original handle"),
+ "should retain the same collector through response commitment"
+ );
+ }
+ }
+
+ #[tokio::test]
+ async fn endpoint_mediator_collection_requires_launch_evidence_and_preserves_not_started() {
+ for configured_provider in [false, true] {
+ for (mediator, wait_failure) in [
+ (Mediator::Immediate, false),
+ (Mediator::FailBeforeStart, false),
+ (Mediator::FailAfterStart, false),
+ (Mediator::Pending, false),
+ (Mediator::Pending, true),
+ ] {
+ // Explicit routing without bidders produces the existing routing-only
+ // Dispatched path. An empty provider set must remain NotStarted.
+ let provider = if configured_provider {
+ "[auction.providers.example]\nprotocol = \"openrtb-2.6\"\nprofile = \"standard\"\nendpoint = \"https://bidder.example.com/auction\"\nrouting = \"explicit\"\n"
+ } else {
+ ""
+ };
+ let settings = Settings::from_toml(&format!(
+ "{}\n[auction]\nenabled = true\nmediator = \"adserver_mock\"\n{provider}",
+ crate_test_settings_str()
+ ))
+ .expect("should parse mediator endpoint settings");
+ let orchestrator = AuctionOrchestrator::from_plan(
+ Arc::new(
+ crate::auction::compile_auction_plan(&settings)
+ .expect("should compile mediator plan"),
+ ),
+ Some(Arc::new(mediator)),
+ );
+ let http = Arc::new(StubHttpClient::new());
+ http.push_response(204, Vec::new());
+ if wait_failure {
+ http.push_wait_error();
+ }
+ let sink = Arc::new(RecordingTelemetrySink::default());
+ let services =
+ services_with_http_and_telemetry(http.clone(), Arc::new(StubBackend), sink);
+ let mut ec_context = make_ec_context(Jurisdiction::NonRegulated, None);
+ let mut request = Request::builder()
+ .method("POST")
+ .uri("https://publisher.example.com/auction")
+ .body(EdgeBody::from(
+ serde_json::to_vec(&json!({"adUnits": [{
+ "code": "slot", "mediaTypes": {"banner": {"sizes": [[300, 250]]}}
+ }]}))
+ .expect("should serialize mediator endpoint request"),
+ ))
+ .expect("should construct mediator endpoint request");
+ let timings = RequestTimings::new();
+ request.extensions_mut().insert(timings.handle().clone());
+ let response = handle_auction(
+ &settings,
+ &orchestrator,
+ None,
+ None,
+ &mut ec_context,
+ &services,
+ request,
+ )
+ .await
+ .expect("should return no-bid response");
+ assert_eq!(response.status(), StatusCode::OK);
+ let launched = configured_provider
+ && matches!(mediator, Mediator::Pending | Mediator::FailAfterStart);
+ assert_eq!(
+ http.recorded_backend_names().len(),
+ usize::from(launched),
+ "{configured_provider} {mediator:?}"
+ );
+ let snapshot = timings.snapshot();
+ assert!(
+ snapshot.auction_dispatched_ms.is_none(),
+ "mediator collection must not fabricate provider dispatch"
+ );
+ assert_eq!(
+ snapshot.auction_wait_ms.is_some(),
+ launched,
+ "{configured_provider} {mediator:?}"
+ );
+ assert_eq!(
+ snapshot.auction_wait_placement,
+ launched.then_some(AuctionWaitPlacement::PreHeader)
+ );
+ assert_eq!(snapshot.auction_resolved_ms.is_some(), launched);
+ assert_eq!(snapshot.auction_committed_ms.is_some(), launched);
+ }
+ }
+ }
+
#[tokio::test]
async fn all_planned_launch_failures_return_bad_gateway_and_execution_failed_telemetry() {
let settings_toml = format!(
@@ -1133,13 +1424,15 @@ mod tests {
"mediaTypes": { "banner": { "sizes": [[300, 250]] } }
}]
});
- let request = Request::builder()
+ let mut request = Request::builder()
.method("POST")
.uri("https://test-publisher.example/auction")
.body(EdgeBody::from(
serde_json::to_vec(&body).expect("should serialize launch-failure body"),
))
.expect("should build launch-failure request");
+ let timings = RequestTimings::new();
+ request.extensions_mut().insert(timings.handle().clone());
let error = handle_auction(
&settings,
@@ -1163,10 +1456,25 @@ mod tests {
.expect("should lock telemetry batches");
assert_eq!(batches.len(), 1, "should emit one telemetry batch");
let rows = batches[0].rows();
- assert_eq!(rows.len(), 1, "should emit one execution-failure summary");
- assert_eq!(rows[0].event_kind, "summary");
- assert_eq!(rows[0].terminal_status.as_deref(), Some("execution_failed"));
- assert_eq!(rows[0].terminal_reason.as_deref(), Some("execution_failed"));
+ assert_eq!(
+ rows.len(),
+ 2,
+ "should emit provider failure and summary rows"
+ );
+ let summary = rows
+ .iter()
+ .find(|row| row.event_kind == "summary")
+ .expect("should emit an execution-failure summary");
+ assert_eq!(summary.terminal_status.as_deref(), Some("execution_failed"));
+ assert_eq!(summary.terminal_reason.as_deref(), Some("execution_failed"));
+ let snapshot = timings.snapshot();
+ assert_eq!(
+ Some(summary.auction_id.clone()),
+ snapshot.auction_id.map(|id| id.to_string())
+ );
+ assert!(snapshot.auction_dispatched_ms.is_none());
+ assert!(snapshot.auction_resolved_ms.is_none());
+ assert!(snapshot.auction_committed_ms.is_none());
}
#[tokio::test]
@@ -1198,13 +1506,15 @@ mod tests {
}
]
});
- let req = Request::builder()
+ let mut req = Request::builder()
.method("POST")
.uri("https://test-publisher.com/auction")
.body(EdgeBody::from(
serde_json::to_vec(&body).expect("should serialize body"),
))
.expect("should build auction request");
+ let timings = RequestTimings::new();
+ req.extensions_mut().insert(timings.handle().clone());
let response = handle_auction(
&settings,
@@ -1245,6 +1555,18 @@ mod tests {
assert_eq!(rows[0].event_kind, "summary");
assert_eq!(rows[0].terminal_status.as_deref(), Some("skipped"));
assert_eq!(rows[0].terminal_reason.as_deref(), Some("consent_denied"));
+ let snapshot = timings.snapshot();
+ assert_eq!(
+ rows[0].auction_id,
+ snapshot
+ .auction_id
+ .expect("should record the consent-denied auction UUID")
+ .to_string(),
+ "should retain the skipped-summary join key"
+ );
+ assert!(snapshot.auction_dispatched_ms.is_none());
+ assert!(snapshot.auction_resolved_ms.is_none());
+ assert!(snapshot.auction_committed_ms.is_none());
let ndjson = batches[0]
.to_ndjson(16 * 1024)
.expect("should serialize telemetry");
diff --git a/crates/trusted-server-core/src/auction/orchestrator.rs b/crates/trusted-server-core/src/auction/orchestrator.rs
index 204201e605..9de02077c3 100644
--- a/crates/trusted-server-core/src/auction/orchestrator.rs
+++ b/crates/trusted-server-core/src/auction/orchestrator.rs
@@ -16,6 +16,7 @@ use super::openrtb::unused_bidder_params_count;
use super::plan::AuctionPlan;
use super::provider::{
AuctionProvider, GenericOpenRtbProvider, ProviderParseState, ProviderRequestOutcome,
+ ProviderRequestStarted,
};
#[cfg(test)]
use super::routing::RoutedAuction;
@@ -23,6 +24,7 @@ use super::routing::route_auction;
use super::telemetry::AbandonedProviderCall;
use super::types::{AuctionContext, AuctionRequest, AuctionResponse, Bid, BidStatus};
use crate::request_signing::RequestSigner;
+use crate::request_timing::{AuctionWaitPlacement, RequestTimings};
/// In-flight auction requests dispatched to SSP backends.
///
@@ -33,6 +35,8 @@ use crate::request_signing::RequestSigner;
/// TTFB ≈ auction timeout.
pub struct DispatchedAuction {
pending_requests: Vec,
+ /// Whether dispatch started at least one provider request.
+ provider_launched: bool,
backend_to_provider: HashMap,
planned_backend_to_provider: HashMap,
completed_responses: Vec,
@@ -63,8 +67,10 @@ struct ProviderLaunchState {
pub enum DispatchAuctionOutcome {
/// No provider request was started and no provider failure was observed.
NotStarted,
- /// No provider request could be launched, but launch failures were observed.
+ /// Dispatch failed before collection, possibly after starting a request.
DispatchFailed {
+ /// Whether any provider started a request before dispatch failed.
+ provider_launched: bool,
/// Original auction request.
request: AuctionRequest,
/// Provider launch-failure responses.
@@ -83,7 +89,24 @@ pub enum DispatchAuctionOutcome {
Dispatched(DispatchedAuction),
}
+/// Synchronous execution failure, including outcomes needed by route telemetry.
+pub(crate) struct AuctionExecutionFailure {
+ /// Admission or dispatch error to propagate through the route's error boundary.
+ pub error: Report,
+ /// Provider outcomes materialized before failure, for terminal telemetry.
+ pub provider_responses: Vec,
+ /// Elapsed dispatch time, or execution time when dispatch returned `NotStarted`.
+ /// Excludes the caller's request parsing and targeting preparation.
+ pub elapsed_ms: u64,
+}
+
impl DispatchedAuction {
+ /// Whether at least one provider request was started.
+ #[must_use]
+ pub fn has_provider_launch(&self) -> bool {
+ self.provider_launched
+ }
+
/// Consume the dispatch token without collecting provider responses.
#[must_use]
pub fn abandon(
@@ -122,9 +145,20 @@ impl DispatchedAuction {
#[cfg(test)]
impl DispatchedAuction {
+ /// Creates a token modeling a started provider request that resolved to no bid.
+ pub(crate) fn launched_no_bid_for_test(request: AuctionRequest, timeout_ms: u32) -> Self {
+ let mut dispatched = Self::empty_for_test(request, timeout_ms);
+ dispatched.provider_launched = true;
+ dispatched
+ .completed_responses
+ .push(AuctionResponse::no_bid("example", 0));
+ dispatched
+ }
+
pub(crate) fn empty_for_test(request: AuctionRequest, timeout_ms: u32) -> Self {
Self {
pending_requests: Vec::new(),
+ provider_launched: false,
backend_to_provider: HashMap::new(),
planned_backend_to_provider: HashMap::new(),
completed_responses: Vec::new(),
@@ -852,30 +886,100 @@ impl AuctionOrchestrator {
request: &AuctionRequest,
context: &AuctionContext<'_>,
) -> Result> {
+ self.execute_auction(request, context, None)
+ .await
+ .map(|(result, _)| result)
+ .map_err(|failure| failure.error)
+ }
+
+ /// Execute a synchronous route auction with request-clock collection timing.
+ ///
+ /// Returns the result and whether any provider or mediator request started.
+ /// The bool stays false for Immediate, routing-only, and empty-plan results.
+ /// Only provider launches during dispatch stamp the dispatch offset; actual
+ /// upstream work during collection records wait and resolution timing.
+ ///
+ /// # Errors
+ /// Returns admission or dispatch failures with their provider outcomes and
+ /// elapsed time for route telemetry. Failed dispatch never records collection.
+ pub(crate) async fn run_auction_with_timings(
+ &self,
+ request: &AuctionRequest,
+ context: &AuctionContext<'_>,
+ timings: &RequestTimings,
+ ) -> Result<(OrchestrationResult, bool), AuctionExecutionFailure> {
+ self.execute_auction(request, context, Some(timings)).await
+ }
+
+ async fn execute_auction(
+ &self,
+ request: &AuctionRequest,
+ context: &AuctionContext<'_>,
+ timings: Option<&RequestTimings>,
+ ) -> Result<(OrchestrationResult, bool), AuctionExecutionFailure> {
+ let started = Instant::now();
match self.dispatch_auction(request, context).await {
- DispatchAuctionOutcome::Dispatched(dispatched) => Ok(self
- .collect_dispatched_auction(dispatched, context.services, context)
- .await),
+ DispatchAuctionOutcome::Dispatched(dispatched) => {
+ if dispatched.has_provider_launch()
+ && let Some(timings) = timings
+ {
+ timings.mark_auction_dispatched();
+ }
+ Ok(self
+ .collect_with_timing(
+ dispatched,
+ context.services,
+ context,
+ timings.map(|timings| (timings, AuctionWaitPlacement::PreHeader)),
+ )
+ .await)
+ }
DispatchAuctionOutcome::DispatchFailed {
+ provider_launched,
+ provider_responses,
fatal_admission_error,
+ elapsed_ms,
..
} => {
- if let Some(error) = fatal_admission_error {
- return Err(error.change_context(TrustedServerError::Auction {
- message: "Planned auction admission failed".to_string(),
- }));
+ if provider_launched && let Some(timings) = timings {
+ timings.mark_auction_dispatched();
}
- Err(Report::new(TrustedServerError::Auction {
- message: "All eligible planned provider requests failed to launch".to_string(),
- }))
+ Err(AuctionExecutionFailure {
+ error: fatal_admission_error
+ .map(|error| {
+ error.change_context(TrustedServerError::Auction {
+ message: "Planned auction admission failed".to_string(),
+ })
+ })
+ .unwrap_or_else(|| {
+ Report::new(TrustedServerError::Auction {
+ message: "All eligible planned provider requests failed to launch"
+ .to_string(),
+ })
+ }),
+ provider_responses,
+ elapsed_ms,
+ })
}
DispatchAuctionOutcome::NotStarted => {
- if self.planned_providers.is_empty() {
- Ok(OrchestrationResult::no_bid())
+ #[cfg(test)]
+ let has_providers = if self.plan_backed {
+ !self.planned_providers.is_empty()
} else {
- Err(Report::new(TrustedServerError::Auction {
- message: "No planned provider request was started".to_string(),
- }))
+ !self.config.providers.is_empty()
+ };
+ #[cfg(not(test))]
+ let has_providers = !self.planned_providers.is_empty();
+ if has_providers {
+ Err(AuctionExecutionFailure {
+ error: Report::new(TrustedServerError::Auction {
+ message: "No planned provider request was started".to_string(),
+ }),
+ provider_responses: Vec::new(),
+ elapsed_ms: started.elapsed().as_millis() as u64,
+ })
+ } else {
+ Ok((OrchestrationResult::no_bid(), false))
}
}
}
@@ -1670,6 +1774,7 @@ impl AuctionOrchestrator {
.unwrap_or(usize::MAX)
});
return DispatchAuctionOutcome::DispatchFailed {
+ provider_launched: false,
request: request.clone(),
provider_responses,
fatal_admission_error: Some(error),
@@ -1693,6 +1798,7 @@ impl AuctionOrchestrator {
let mut planned_backend_to_provider = HashMap::new();
let mut reserved_backend_names = HashSet::new();
let mut immediate_response_count = 0usize;
+ let mut provider_launch_count = 0usize;
let mut launch_failure_count = 0usize;
for input in routed.inputs() {
@@ -1740,6 +1846,7 @@ impl AuctionOrchestrator {
request: pending,
parse_state,
}) => {
+ provider_launch_count += 1;
let Some(backend_name) = pending.backend_name().map(str::to_string) else {
launch_failure_count += 1;
completed_responses.push(provider_launch_failed_response(
@@ -1767,10 +1874,14 @@ impl AuctionOrchestrator {
}
}
Ok(ProviderRequestOutcome::Immediate(response)) => {
+ // Planned providers use Immediate for routing-only skips such
+ // as NoImpressions; no request left the edge.
immediate_response_count += 1;
completed_responses.push(response);
}
Err(error) => {
+ provider_launch_count +=
+ usize::from(error.contains::());
log::warn!(
"Planned provider '{}' failed to dispatch: {error:?}",
provider.provider_name()
@@ -1802,6 +1913,7 @@ impl AuctionOrchestrator {
.unwrap_or(usize::MAX)
});
return DispatchAuctionOutcome::DispatchFailed {
+ provider_launched: provider_launch_count > 0,
request: request.clone(),
provider_responses: completed_responses,
fatal_admission_error: None,
@@ -1815,6 +1927,7 @@ impl AuctionOrchestrator {
}
DispatchAuctionOutcome::Dispatched(DispatchedAuction {
+ provider_launched: provider_launch_count > 0,
pending_requests,
backend_to_provider: HashMap::new(),
planned_backend_to_provider,
@@ -1840,10 +1953,12 @@ impl AuctionOrchestrator {
/// [`DispatchedAuction`] token. The Fastly host begins the SSP round-trips
/// while WASM continues to `pending_origin.wait()`.
///
- /// Returns [`DispatchAuctionOutcome::NotStarted`] when no providers are configured or
- /// all providers are disabled / over budget. Returns
- /// [`DispatchAuctionOutcome::DispatchFailed`] when provider launch attempts
- /// happened but none could be started.
+ /// Returns [`DispatchAuctionOutcome::NotStarted`] when the auction is disabled
+ /// or has no providers to execute. Routing-only skips can instead yield a
+ /// [`DispatchAuctionOutcome::Dispatched`] token with immediate responses but
+ /// no provider launch. Admission or launch failures can yield
+ /// [`DispatchAuctionOutcome::DispatchFailed`]; its `provider_launched` flag
+ /// preserves evidence of requests that started before a later failure.
#[must_use]
pub async fn dispatch_auction(
&self,
@@ -1901,8 +2016,12 @@ impl AuctionOrchestrator {
let completed_responses: Vec = Vec::new();
#[cfg(test)]
let mut immediate_response_count = 0usize;
+ #[cfg(test)]
+ let mut provider_launch_count = 0usize;
#[cfg(not(test))]
let immediate_response_count = 0usize;
+ #[cfg(not(test))]
+ let provider_launch_count = 0usize;
#[cfg(test)]
for provider_name in &provider_names {
@@ -1973,6 +2092,10 @@ impl AuctionOrchestrator {
request: pending,
parse_state,
}) => {
+ #[cfg(test)]
+ {
+ provider_launch_count += 1;
+ }
let backend_name = pending.backend_name().map(str::to_string).or_else(|| {
if let Some(backend_name) = predicted_backend_name.as_ref() {
log::warn!(
@@ -2030,6 +2153,7 @@ impl AuctionOrchestrator {
completed_responses.push(response);
}
Err(e) => {
+ provider_launch_count += usize::from(e.contains::());
let response_time_ms = start_time.elapsed().as_millis() as u64;
log::warn!(
"Provider '{}' failed to dispatch request: {:?}",
@@ -2049,6 +2173,7 @@ impl AuctionOrchestrator {
DispatchAuctionOutcome::NotStarted
} else {
DispatchAuctionOutcome::DispatchFailed {
+ provider_launched: provider_launch_count > 0,
request: request.clone(),
provider_responses: completed_responses,
fatal_admission_error: None,
@@ -2067,6 +2192,7 @@ impl AuctionOrchestrator {
);
DispatchAuctionOutcome::Dispatched(DispatchedAuction {
+ provider_launched: provider_launch_count > 0,
pending_requests,
backend_to_provider,
planned_backend_to_provider: HashMap::new(),
@@ -2097,9 +2223,64 @@ impl AuctionOrchestrator {
dispatched: DispatchedAuction,
services: &RuntimeServices,
context: &AuctionContext<'_>,
+ ) -> OrchestrationResult {
+ self.collect_with_timing(dispatched, services, context, None)
+ .await
+ .0
+ }
+
+ /// Collect with measured wait placement and explicit provider/mediator launch evidence.
+ ///
+ /// Returns the result and whether a provider or mediator request started,
+ /// including post-start failures. The bool stays false for Immediate and
+ /// routing-only outcomes. Wait and resolution are recorded only when true;
+ /// mediator-only work does not fabricate a provider dispatch offset.
+ pub(crate) async fn collect_dispatched_auction_with_timings(
+ &self,
+ dispatched: DispatchedAuction,
+ services: &RuntimeServices,
+ context: &AuctionContext<'_>,
+ timings: &RequestTimings,
+ placement: AuctionWaitPlacement,
+ ) -> (OrchestrationResult, bool) {
+ self.collect_with_timing(dispatched, services, context, Some((timings, placement)))
+ .await
+ }
+
+ async fn collect_with_timing(
+ &self,
+ dispatched: DispatchedAuction,
+ services: &RuntimeServices,
+ context: &AuctionContext<'_>,
+ timing: Option<(&RequestTimings, AuctionWaitPlacement)>,
+ ) -> (OrchestrationResult, bool) {
+ let mut auction_work_started = dispatched.has_provider_launch();
+ let wait_started = Instant::now();
+ let result = self
+ .collect_dispatched_auction_inner(
+ dispatched,
+ services,
+ context,
+ &mut auction_work_started,
+ )
+ .await;
+ if auction_work_started && let Some((timings, placement)) = timing {
+ timings.record_auction_wait(placement, wait_started.elapsed());
+ timings.mark_auction_resolved();
+ }
+ (result, auction_work_started)
+ }
+
+ async fn collect_dispatched_auction_inner(
+ &self,
+ dispatched: DispatchedAuction,
+ services: &RuntimeServices,
+ context: &AuctionContext<'_>,
+ auction_work_started: &mut bool,
) -> OrchestrationResult {
let DispatchedAuction {
pending_requests,
+ provider_launched: _,
mut backend_to_provider,
mut planned_backend_to_provider,
completed_responses,
@@ -2417,52 +2598,58 @@ impl AuctionOrchestrator {
Ok(ProviderRequestOutcome::Pending {
request: pending,
parse_state,
- }) => match services.http_client().wait(pending).await.change_context(
- TrustedServerError::Auction {
- message: format!(
- "Mediator {} request failed",
- mediator.provider_name()
- ),
- },
- ) {
- Ok(platform_resp) => {
- let response_time_ms = mediator_start.elapsed().as_millis() as u64;
- if deadline_policy.rejects_late_completion(auction_start, timeout_ms) {
- log::warn!(
- "Mediator '{}' completed after the hard auction deadline; using local ranking ({}ms)",
- mediator.provider_name(),
- response_time_ms
- );
- None
- } else {
- match mediator
- .parse_response_with_context_and_state(
- platform_resp,
- response_time_ms,
- &request,
- &mediator_context,
- parse_state.as_deref(),
- )
- .await
+ }) => {
+ *auction_work_started = true;
+ match services.http_client().wait(pending).await.change_context(
+ TrustedServerError::Auction {
+ message: format!(
+ "Mediator {} request failed",
+ mediator.provider_name()
+ ),
+ },
+ ) {
+ Ok(platform_resp) => {
+ let response_time_ms = mediator_start.elapsed().as_millis() as u64;
+ if deadline_policy
+ .rejects_late_completion(auction_start, timeout_ms)
{
- Ok(response) => Some(response),
- Err(error) => {
- log::warn!(
- "Mediator '{}' parse failed: {:?}",
- mediator.provider_name(),
- error
- );
- None
+ log::warn!(
+ "Mediator '{}' completed after the hard auction deadline; using local ranking ({}ms)",
+ mediator.provider_name(),
+ response_time_ms
+ );
+ None
+ } else {
+ match mediator
+ .parse_response_with_context_and_state(
+ platform_resp,
+ response_time_ms,
+ &request,
+ &mediator_context,
+ parse_state.as_deref(),
+ )
+ .await
+ {
+ Ok(response) => Some(response),
+ Err(error) => {
+ log::warn!(
+ "Mediator '{}' parse failed: {:?}",
+ mediator.provider_name(),
+ error
+ );
+ None
+ }
}
}
}
+ Err(error) => {
+ log::warn!("Mediator request failed: {:?}", error);
+ None
+ }
}
- Err(error) => {
- log::warn!("Mediator request failed: {:?}", error);
- None
- }
- },
+ }
Err(error) => {
+ *auction_work_started |= error.contains::();
log::warn!(
"Mediator '{}' failed to dispatch: {:?}",
mediator.provider_name(),
@@ -2972,6 +3159,10 @@ mod tests {
else {
panic!("all-skipped auction should produce a completed dispatch token");
};
+ assert!(
+ !dispatched.has_provider_launch(),
+ "routing-only skipped outcomes must not claim a provider launch"
+ );
orchestrator
.collect_dispatched_auction(dispatched, &services, &context)
.await
@@ -4454,6 +4645,10 @@ mod tests {
else {
panic!("enabled immediate provider should dispatch");
};
+ assert!(
+ !dispatched.has_provider_launch(),
+ "should not count an immediate no-bid response as a provider request"
+ );
let result = orchestrator
.collect_dispatched_auction(dispatched, &services, &context)
.await;
@@ -5346,6 +5541,108 @@ mod tests {
);
}
+ #[tokio::test]
+ async fn planned_no_impressions_immediate_outcome_is_not_a_provider_launch() {
+ let http = Arc::new(StubHttpClient::new());
+ let backend = Arc::new(NamingBackend::new(BackendNamingPolicy::Axum));
+ let services = build_services_with_backend_and_http_client(
+ Arc::clone(&backend) as Arc<_>,
+ Arc::clone(&http) as Arc<_>,
+ );
+ let mut config = planned_prebid_config(&[(
+ "pbs-a",
+ serde_json::json!({}),
+ NotificationConfig::default(),
+ )]);
+ config.bidders.insert(
+ "alpha".parse().expect("should parse bidder ID"),
+ crate::auction::plan::BidderRouteConfig {
+ provider: "pbs-a".parse().expect("should parse provider ID"),
+ },
+ );
+ let orchestrator = AuctionOrchestrator::from_plan(
+ Arc::new(AuctionPlan::compile(config).expect("should compile PBS plan")),
+ None,
+ );
+ let mut request = planned_prebid_request();
+ request.slots[0].bidders.insert(
+ "trustedServer".to_string(),
+ serde_json::json!({"storedRequest":false,"bidderParams":{"alpha":{}}}),
+ );
+ let settings = create_test_settings();
+ let inbound = http::Request::new(edgezero_core::body::Body::empty());
+ let context = AuctionContext {
+ settings: &settings,
+ request: &inbound,
+ timeout_ms: 777,
+ transport_timeout_ms: 777,
+ provider_responses: None,
+ services: &services,
+ };
+
+ let DispatchAuctionOutcome::Dispatched(dispatched) =
+ orchestrator.dispatch_auction(&request, &context).await
+ else {
+ panic!("should retain the routing-only provider response for collection");
+ };
+ assert_eq!(
+ http.recorded_backend_names().len(),
+ 0,
+ "should not start an outbound request for NoImpressions"
+ );
+ assert!(
+ !dispatched.has_provider_launch(),
+ "should not establish launch evidence for a routing-only Immediate response"
+ );
+ assert_eq!(
+ dispatched.completed_responses[0].metadata["routing"]["skipped_no_usable_demand"], true,
+ "should retain the routing skip response for collection"
+ );
+ }
+
+ #[tokio::test]
+ async fn planned_started_request_keeps_launch_evidence_after_backend_bookkeeping_failure() {
+ let http = Arc::new(StubHttpClient::new());
+ http.push_response(204, Vec::new());
+ http.push_pending_backend_name_override(None);
+ let backend = Arc::new(NamingBackend::new(BackendNamingPolicy::Axum));
+ let services = build_services_with_backend_and_http_client(
+ Arc::clone(&backend) as Arc<_>,
+ Arc::clone(&http) as Arc<_>,
+ );
+ let plan = Arc::new(
+ AuctionPlan::compile(planned_config(
+ &[("provider-a", RoutingMode::AllEligible)],
+ false,
+ ))
+ .expect("should compile planned auction"),
+ );
+ let orchestrator = AuctionOrchestrator::from_plan(plan, None);
+ let request = planned_request();
+ let settings = create_test_settings();
+ let inbound = http::Request::new(edgezero_core::body::Body::empty());
+ let context = AuctionContext {
+ settings: &settings,
+ request: &inbound,
+ timeout_ms: 777,
+ transport_timeout_ms: 777,
+ provider_responses: None,
+ services: &services,
+ };
+
+ let DispatchAuctionOutcome::DispatchFailed {
+ provider_launched, ..
+ } = orchestrator.dispatch_auction(&request, &context).await
+ else {
+ panic!("missing backend bookkeeping should fail dispatch");
+ };
+ assert_eq!(http.recorded_backend_names().len(), 1);
+ assert!(
+ provider_launched,
+ "should retain launch evidence for a started request when bookkeeping fails"
+ );
+ }
+
#[tokio::test]
async fn planned_dispatch_does_not_snapshot_inbound_headers() {
let http = Arc::new(StubHttpClient::new());
diff --git a/crates/trusted-server-core/src/auction/provider.rs b/crates/trusted-server-core/src/auction/provider.rs
index 62b2ddc8fc..4d9517767f 100644
--- a/crates/trusted-server-core/src/auction/provider.rs
+++ b/crates/trusted-server-core/src/auction/provider.rs
@@ -29,6 +29,89 @@ use super::types::{AuctionContext, AuctionRequest, AuctionResponse};
const MAX_PLANNED_RESPONSE_BYTES: usize = 1024 * 1024;
+#[cfg(test)]
+pub(crate) mod test_support {
+ use super::*;
+
+ /// Exercises launch evidence through real route dispatch and collection.
+ #[derive(Clone, Copy, Debug, PartialEq, Eq)]
+ pub(crate) enum LaunchEvidenceProvider {
+ Immediate,
+ FailBeforeStart,
+ FailAfterStart,
+ Pending,
+ }
+
+ #[async_trait(?Send)]
+ impl AuctionProvider for LaunchEvidenceProvider {
+ fn provider_name(&self) -> &str {
+ "launch-evidence"
+ }
+
+ async fn request_bids(
+ &self,
+ _request: &AuctionRequest,
+ context: &AuctionContext<'_>,
+ ) -> Result> {
+ if *self == Self::Immediate {
+ return Ok(ProviderRequestOutcome::Immediate(AuctionResponse::no_bid(
+ self.provider_name(),
+ 0,
+ )));
+ }
+ let failure = || {
+ Report::new(TrustedServerError::Auction {
+ message: "Launch evidence test failure".to_string(),
+ })
+ };
+ if *self == Self::FailBeforeStart {
+ return Err(failure());
+ }
+ let outbound = Request::builder()
+ .uri("https://mediator.example.com/auction")
+ .body(EdgeBody::empty())
+ .expect("should construct mediator request");
+ let pending = context
+ .services
+ .http_client()
+ .send_async(PlatformHttpRequest::new(
+ outbound,
+ "launch-evidence-backend",
+ ))
+ .await
+ .change_context(TrustedServerError::Auction {
+ message: "Launch evidence request failed".to_string(),
+ })?;
+ if *self == Self::FailAfterStart {
+ return Err(failure().attach_opaque(ProviderRequestStarted));
+ }
+ Ok(ProviderRequestOutcome::pending(pending))
+ }
+
+ async fn parse_response(
+ &self,
+ _response: PlatformResponse,
+ response_time_ms: u64,
+ ) -> Result> {
+ Ok(AuctionResponse::no_bid(
+ self.provider_name(),
+ response_time_ms,
+ ))
+ }
+
+ fn timeout_ms(&self) -> u32 {
+ 1_000
+ }
+ }
+}
+
+/// Evidence attached to provider or mediator errors after a request started.
+///
+/// `Immediate` never proves launch. Implementations that fail after a successful
+/// `send_async` must attach this marker so collection retains that evidence.
+#[derive(Debug)]
+pub(crate) struct ProviderRequestStarted;
+
fn attach_provider_routing_metadata(
response: &mut AuctionResponse,
profile: &CompiledOpenRtbProfile,
@@ -392,7 +475,8 @@ impl GenericOpenRtbProvider {
"Provider {} pending request backend did not match registered backend",
self.provider_name()
),
- }));
+ })
+ .attach_opaque(ProviderRequestStarted));
}
let parse_state = match &self.plan.profile {
CompiledOpenRtbProfile::Standard(_) => GenericOpenRtbParseState::Standard {
diff --git a/crates/trusted-server-core/src/cache_policy.rs b/crates/trusted-server-core/src/cache_policy.rs
index 4d920f54a6..cc1427beb3 100644
--- a/crates/trusted-server-core/src/cache_policy.rs
+++ b/crates/trusted-server-core/src/cache_policy.rs
@@ -289,15 +289,18 @@ pub fn is_edge_cache_header_name(name: &str) -> bool {
/// as `not-private` or `no-storey` do not match `private` / `no-store`.
#[must_use]
pub fn cache_control_value_has_directive(value: &str, directive: &str) -> bool {
- let part_has_directive = |part: &str| {
+ cache_control_value_matches(value, |part| {
let part = part.trim();
let directive_name = part
.find(['=', ';'])
.map_or(part, |end| &part[..end])
.trim();
directive_name.eq_ignore_ascii_case(directive)
- };
+ })
+}
+/// Tests comma-delimited directives without splitting quoted values.
+fn cache_control_value_matches(value: &str, part_matches: impl Fn(&str) -> bool) -> bool {
let mut quoted = false;
let mut escaped = false;
let mut part_start = 0;
@@ -313,14 +316,14 @@ pub fn cache_control_value_has_directive(value: &str, directive: &str) -> bool {
} else if character == '"' {
quoted = true;
} else if character == ',' {
- if part_has_directive(&value[part_start..index]) {
+ if part_matches(&value[part_start..index]) {
return true;
}
part_start = index + character.len_utf8();
}
}
- part_has_directive(&value[part_start..])
+ part_matches(&value[part_start..])
}
/// Return true when any `Cache-Control` header value contains `directive`.
@@ -333,13 +336,33 @@ pub fn cache_control_headers_have_directive(headers: &HeaderMap, directive: &str
.any(|value| cache_control_value_has_directive(value, directive))
}
-/// Return true when response cache-control contains exact `private` or `no-store`.
+/// Return true when response cache-control contains `private` or `no-store`,
+/// including directives with arguments.
#[must_use]
pub fn cache_control_headers_are_private_or_no_store(headers: &HeaderMap) -> bool {
cache_control_headers_have_directive(headers, "private")
|| cache_control_headers_have_directive(headers, "no-store")
}
+/// Return true when response cache-control contains a bare `private` or `no-store`.
+///
+/// Field-qualified `private` restricts only named headers, not the whole response,
+/// so it is insufficient permission to append request-specific timing headers.
+/// Directive-shaped text inside quoted values is not a bare directive.
+#[must_use]
+pub(crate) fn cache_control_headers_have_bare_private_or_no_store(headers: &HeaderMap) -> bool {
+ headers
+ .get_all(header::CACHE_CONTROL)
+ .iter()
+ .filter_map(|value| value.to_str().ok())
+ .any(|value| {
+ cache_control_value_matches(value, |part| {
+ let part = part.trim();
+ part.eq_ignore_ascii_case("private") || part.eq_ignore_ascii_case("no-store")
+ })
+ })
+}
+
/// Apply `Cache-Control: no-store, private` and strip all shared-cache headers.
///
/// # Panics
diff --git a/crates/trusted-server-core/src/config.rs b/crates/trusted-server-core/src/config.rs
index e48f5c2f03..72df6e96b0 100644
--- a/crates/trusted-server-core/src/config.rs
+++ b/crates/trusted-server-core/src/config.rs
@@ -184,6 +184,10 @@ impl edgezero_core::app_config::AppConfigMeta for TrustedServerAppConfig {
vec![optional_object("tinybird"), object("auction_token_secret")],
true,
),
+ field(
+ vec![optional_object("tinybird"), object("access_token_secret")],
+ true,
+ ),
field(
vec![
optional_object("integrations"),
@@ -423,7 +427,7 @@ fn validate_secret_key_references(settings: &Settings) -> Result<(), Report Result<(), Report("datadome")? {
if datadome.enable_protection {
let key = datadome
@@ -905,6 +918,7 @@ formats = [{ width = 300, height = 250 }]
("handlers[*].password".to_owned(), false),
("trusted_client_ip.shared_secret".to_owned(), false),
("tinybird.auction_token_secret".to_owned(), true),
+ ("tinybird.access_token_secret".to_owned(), true),
(
"integrations.datadome.server_side_key_secret_name".to_owned(),
true,
diff --git a/crates/trusted-server-core/src/config_payload.rs b/crates/trusted-server-core/src/config_payload.rs
index c9690b01f5..9ca340b252 100644
--- a/crates/trusted-server-core/src/config_payload.rs
+++ b/crates/trusted-server-core/src/config_payload.rs
@@ -72,16 +72,26 @@ pub fn settings_from_config_blob(
}
fn remove_inactive_secret_references(data: &mut serde_json::Value) {
- if data
- .pointer("/tinybird/enabled")
- .and_then(serde_json::Value::as_bool)
- != Some(true)
- && let Some(tinybird) = data
- .get_mut("tinybird")
- .and_then(serde_json::Value::as_object_mut)
+ if let Some(tinybird) = data
+ .get_mut("tinybird")
+ .and_then(serde_json::Value::as_object_mut)
{
- tinybird.remove("auction_token_secret");
- tinybird.remove("access_token_secret");
+ let master_enabled =
+ tinybird.get("enabled").and_then(serde_json::Value::as_bool) == Some(true);
+ let auction_enabled = tinybird
+ .get("auction_enabled")
+ .and_then(serde_json::Value::as_bool)
+ .unwrap_or(true);
+ let access_enabled = tinybird
+ .get("access_enabled")
+ .and_then(serde_json::Value::as_bool)
+ == Some(true);
+ if !master_enabled || !auction_enabled {
+ tinybird.remove("auction_token_secret");
+ }
+ if !master_enabled || !access_enabled {
+ tinybird.remove("access_token_secret");
+ }
}
if let Some(partners) = data
@@ -631,6 +641,92 @@ mod tests {
assert!(error.to_string().contains("ec.partners[0].ts_pull_token"));
}
+ #[test]
+ fn inactive_tinybird_sinks_strip_stale_secret_references_before_resolution() {
+ let mut original = test_settings();
+ let mut data = serde_json::to_value(&original).expect("should serialize settings");
+ data["tinybird"] = serde_json::json!({
+ "enabled": false,
+ "auction_token_secret": "unused-auction-token",
+ "access_token_secret": "unused-access-token",
+ });
+ let envelope = BlobEnvelope::new(data, "2026-01-01T00:00:00Z".to_owned());
+ let envelope_json = serde_json::to_string(&envelope).expect("should serialize envelope");
+
+ let loaded = settings_from_config_blob(
+ &envelope_json,
+ &UnifiedSecretStore,
+ &StoreName::from("ts_secrets"),
+ )
+ .expect("should ignore stale secrets for disabled sinks");
+ assert!(!loaded.tinybird.enabled);
+ assert!(loaded.tinybird.auction_enabled, "auction defaults on");
+ assert!(!loaded.tinybird.access_enabled, "access defaults off");
+ assert!(loaded.tinybird.auction_token_secret.is_none());
+ assert!(loaded.tinybird.access_token_secret.is_none());
+
+ let mut data = serde_json::to_value(&original).expect("should serialize settings");
+ data["tinybird"] = serde_json::json!({
+ "enabled": true,
+ "api_host": "api.example.com",
+ "auction_enabled": false,
+ "auction_token_secret": "unused-auction-token",
+ "access_enabled": true,
+ "access_token_secret": "tinybird-token-key",
+ "access_sample_rate": 1.0,
+ });
+ let envelope = BlobEnvelope::new(data, "2026-01-01T00:00:00Z".to_owned());
+ let envelope_json = serde_json::to_string(&envelope).expect("should serialize envelope");
+ let loaded = settings_from_config_blob(
+ &envelope_json,
+ &UnifiedSecretStore,
+ &StoreName::from("ts_secrets"),
+ )
+ .expect("should load active access telemetry without the disabled auction token");
+ assert!(!loaded.tinybird.auction_enabled);
+ assert!(loaded.tinybird.auction_token_secret.is_none());
+ assert_eq!(
+ loaded
+ .tinybird
+ .access_token_secret
+ .as_ref()
+ .map(Redacted::expose)
+ .map(String::as_str),
+ Some("resolved-tinybird-token")
+ );
+
+ let mut data = serde_json::to_value(&original).expect("should serialize settings");
+ data["tinybird"] = serde_json::json!({
+ "enabled": true,
+ "api_host": "api.example.com",
+ "auction_token_secret": "tinybird-token-key",
+ "access_token_secret": "unused-access-token",
+ });
+ let envelope = BlobEnvelope::new(data, "2026-01-01T00:00:00Z".to_owned());
+ let envelope_json = serde_json::to_string(&envelope).expect("should serialize envelope");
+ let loaded = settings_from_config_blob(
+ &envelope_json,
+ &UnifiedSecretStore,
+ &StoreName::from("ts_secrets"),
+ )
+ .expect("should load the default-on auction sink without the disabled access token");
+ assert!(loaded.tinybird.auction_enabled, "auction defaults on");
+ assert!(!loaded.tinybird.access_enabled, "access defaults off");
+ assert!(loaded.tinybird.access_token_secret.is_none());
+ assert!(loaded.tinybird.auction_token_secret.is_some());
+
+ original.tinybird.enabled = true;
+ original.tinybird.api_host = "api.example.com".to_owned();
+ original.tinybird.auction_token_secret = None;
+ let error = settings_from_config_blob(
+ &self::envelope_json(&original),
+ &UnifiedSecretStore,
+ &StoreName::from("ts_secrets"),
+ )
+ .expect_err("should reject a missing active default-on auction token");
+ assert!(error.to_string().contains("tinybird.auction_token_secret"));
+ }
+
#[test]
fn inactive_optional_features_do_not_resolve_stale_secret_references() {
let mut original = test_settings();
diff --git a/crates/trusted-server-core/src/constants.rs b/crates/trusted-server-core/src/constants.rs
index 1fd3c2382c..63472dd868 100644
--- a/crates/trusted-server-core/src/constants.rs
+++ b/crates/trusted-server-core/src/constants.rs
@@ -48,6 +48,8 @@ pub const TS_GIT_VERSION: Option<&str> = match option_env!("TRUSTED_SERVER__GIT_
// Fastly environment variables
pub const ENV_FASTLY_SERVICE_VERSION: &str = "FASTLY_SERVICE_VERSION";
pub const ENV_FASTLY_IS_STAGING: &str = "FASTLY_IS_STAGING";
+pub const ENV_FASTLY_SERVICE_ID: &str = "FASTLY_SERVICE_ID";
+pub const ENV_FASTLY_POP: &str = "FASTLY_POP";
// Common standard header names used across modules
pub const HEADER_USER_AGENT: HeaderName = HeaderName::from_static("user-agent");
diff --git a/crates/trusted-server-core/src/ec/kv.rs b/crates/trusted-server-core/src/ec/kv.rs
index b0eb83d3fa..8653f2342a 100644
--- a/crates/trusted-server-core/src/ec/kv.rs
+++ b/crates/trusted-server-core/src/ec/kv.rs
@@ -1717,6 +1717,28 @@ mod tests {
assert!(ts > 0, "should return a nonzero timestamp");
}
+ #[test]
+ fn kv_span_accumulates_across_graph_operations() {
+ let timings = crate::request_timing::RequestTimings::new();
+ let graph = KvIdentityGraph::new(crate::platform::TimedKvStore::new(
+ crate::ec::kv_backend::test_support::InMemoryEcKv::new("test-store"),
+ timings.clone(),
+ ));
+
+ graph
+ .create("ec-1", &live_entry())
+ .expect("should create entry through the timed store");
+ graph
+ .get("ec-1")
+ .expect("should read the entry back through the timed store");
+
+ timings.mark_headers_ready();
+ assert!(
+ timings.snapshot().kv_ms.is_some(),
+ "should accumulate Phase::EcKv across both graph operations, not just the last write"
+ );
+ }
+
#[test]
fn serialize_entry_produces_valid_json() {
let entry = KvEntry::tombstone(1000);
diff --git a/crates/trusted-server-core/src/geo.rs b/crates/trusted-server-core/src/geo.rs
index 63f7907f53..fe5785d260 100644
--- a/crates/trusted-server-core/src/geo.rs
+++ b/crates/trusted-server-core/src/geo.rs
@@ -48,6 +48,24 @@ impl GeoInfo {
}
}
+/// Carries the outcome of a request-phase geo lookup across to
+/// response-phase finalization, so a finalize consumer can reuse it instead
+/// of performing a second lookup for the same request.
+///
+/// Attached as a response extension on every exit path that attempted a
+/// lookup, including the asset-route fallback (which does not carry an EC
+/// finalize state).
+#[derive(Debug, Clone)]
+pub enum GeoLookupState {
+ /// No lookup has been attempted for this request.
+ NotAttempted,
+ /// A lookup ran and failed (or returned no result). This must not be
+ /// retried: finalize treats it the same as no geo info being available.
+ Attempted,
+ /// A lookup ran and resolved geo info.
+ Resolved(GeoInfo),
+}
+
fn insert_geo_header(headers: &mut http::HeaderMap, name: http::header::HeaderName, value: &str) {
match HeaderValue::from_str(value) {
Ok(header_value) => {
diff --git a/crates/trusted-server-core/src/integrations/gpt_bootstrap.js b/crates/trusted-server-core/src/integrations/gpt_bootstrap.js
index afae775350..0c2f001337 100644
--- a/crates/trusted-server-core/src/integrations/gpt_bootstrap.js
+++ b/crates/trusted-server-core/src/integrations/gpt_bootstrap.js
@@ -326,7 +326,7 @@
// and deliberately identical to the bundle scheduler — the impression is
// spent on a viewed tab, and the post-hydration guarantee holds whenever
// the request is actually issued.
- ts.scheduleInitialAdInit = function (initialBids, initialSlots) {
+ ts.scheduleInitialAdInit = function (initialBids, initialSlots, initialAuctionDiagnostics) {
// The bundle may replace this scheduler after the fallback claims the initial
// pass. Keep the latch on the shared document API so replacement cannot reset it.
if ((ts.navGeneration || 0) !== 0 || ts.initialAdInitScheduled) return;
@@ -336,6 +336,9 @@
// would overwrite a committed SPA navigation's slots.
if (initialSlots !== undefined) ts.adSlots = initialSlots;
if (initialBids !== undefined) ts.bids = initialBids;
+ if (initialAuctionDiagnostics !== undefined) {
+ ts.auctionDiagnostics = initialAuctionDiagnostics;
+ }
var fire = function () {
if ((ts.navGeneration || 0) !== 0) return;
if (typeof ts.adInit === "function") ts.adInit();
diff --git a/crates/trusted-server-core/src/integrations/gpt_diagnostics.rs b/crates/trusted-server-core/src/integrations/gpt_diagnostics.rs
index 1447a83586..de1aedd365 100644
--- a/crates/trusted-server-core/src/integrations/gpt_diagnostics.rs
+++ b/crates/trusted-server-core/src/integrations/gpt_diagnostics.rs
@@ -62,6 +62,7 @@ pub enum GptDiagnosticsCookieAction {
#[derive(Clone, Debug, Default, PartialEq, Eq)]
pub struct GptDiagnosticsRequestDecision {
active: bool,
+ browser_session_active: bool,
clean_browser_path_and_query: Option,
cookie_action: GptDiagnosticsCookieAction,
}
@@ -73,6 +74,16 @@ impl GptDiagnosticsRequestDecision {
self.active
}
+ /// Whether this request came from an activated diagnostics browser session.
+ ///
+ /// Unlike [`Self::active`], this remains true for non-document requests such
+ /// as the SPA page-bids fetch. It is captured before the private activation
+ /// cookie is stripped from the request.
+ #[must_use]
+ pub(crate) fn browser_session_active(&self) -> bool {
+ self.browser_session_active
+ }
+
/// Whether the response must be private and non-storeable.
#[must_use]
pub fn requires_private_no_store(&self) -> bool {
@@ -121,6 +132,7 @@ impl GptDiagnosticsRequestDecision {
pub(crate) fn active_for_tests() -> Self {
Self {
active: true,
+ browser_session_active: true,
clean_browser_path_and_query: None,
cookie_action: GptDiagnosticsCookieAction::None,
}
@@ -143,6 +155,7 @@ mod head_seam_invariant_tests {
] {
out.push(GptDiagnosticsRequestDecision {
active,
+ browser_session_active: active,
clean_browser_path_and_query: clean.clone(),
cookie_action,
});
@@ -279,12 +292,19 @@ pub fn prepare_request(
replace_path_and_query(request, &clean_path)?;
}
- let mut decision = GptDiagnosticsRequestDecision::default();
+ let mut decision = GptDiagnosticsRequestDecision {
+ browser_session_active: integration_enabled
+ && directive == QueryDirective::Absent
+ && cookie_state.occurrences == 1
+ && cookie_state.canonical,
+ ..GptDiagnosticsRequestDecision::default()
+ };
if integration_enabled && eligible_navigation && had_reserved_query {
decision.clean_browser_path_and_query = Some(clean_path);
match directive {
QueryDirective::Enable => {
decision.active = true;
+ decision.browser_session_active = true;
decision.cookie_action = GptDiagnosticsCookieAction::SetSession;
}
QueryDirective::Disable => {
@@ -547,6 +567,22 @@ mod tests {
assert_eq!(duplicate.headers()[header::COOKIE], "other=value");
}
+ #[test]
+ fn active_cookie_marks_non_document_requests_without_activating_document_behavior() {
+ let mut request = Request::builder()
+ .method(Method::GET)
+ .uri("https://publisher.example/_ts/page-bids?path=/article")
+ .header(header::COOKIE, "__Host-ts-console=1; other=value")
+ .body(EdgeBody::empty())
+ .expect("should build page-bids request");
+
+ let decision = prepare_request(&settings(true), &mut request).expect("should prepare");
+
+ assert!(!decision.active());
+ assert!(decision.browser_session_active());
+ assert_eq!(request.headers()[header::COOKIE], "other=value");
+ }
+
#[test]
fn invalid_duplicate_and_disable_directives_fail_closed() {
for query in [
diff --git a/crates/trusted-server-core/src/integrations/registry.rs b/crates/trusted-server-core/src/integrations/registry.rs
index d3c09cd7d7..8d2195becd 100644
--- a/crates/trusted-server-core/src/integrations/registry.rs
+++ b/crates/trusted-server-core/src/integrations/registry.rs
@@ -723,7 +723,17 @@ impl IntegrationRegistrationBuilder {
}
}
-type RouteValue = (Arc, &'static str);
+/// Proxy handler, integration id, and the registered route pattern (kept so
+/// telemetry can label responses with the integration-defined literal, e.g.
+/// `/integrations/prebid/*`, instead of deriving anything from the request
+/// path).
+type RouteValue = (Arc, &'static str, String);
+
+/// A test-constructor route entry: method, path pattern, and the proxy with
+/// its integration id ([`IntegrationRegistry::from_routes`] fills the
+/// pattern into [`RouteValue`] itself).
+#[cfg(test)]
+type RouteEntry<'a> = (Method, &'a str, (Arc, &'static str));
struct IntegrationRegistryInner {
// Method-specific routers for O(log n) lookups
@@ -869,7 +879,11 @@ impl IntegrationRegistry {
for proxy in registration.proxies {
for route in proxy.routes() {
- let value = (proxy.clone(), registration.integration_id);
+ let value = (
+ proxy.clone(),
+ registration.integration_id,
+ route.path.clone(),
+ );
// Convert /* wildcard to matchit's {*rest} syntax
let matchit_path = if route.path.ends_with("/*") {
@@ -966,6 +980,27 @@ impl IntegrationRegistry {
self.find_route(method, path).is_some()
}
+ /// The registered route pattern matched by `method` and `path`, if any.
+ ///
+ /// Patterns are integration-defined literals (for example
+ /// `/integrations/prebid/*`), so they are bounded and content-free and
+ /// safe to store as a telemetry dimension, unlike the request path.
+ #[must_use]
+ pub fn matched_route_pattern(&self, method: &Method, path: &str) -> Option<&str> {
+ self.find_route(method, path).map(|value| value.2.as_str())
+ }
+
+ /// Return true when at least one integration request filter is
+ /// registered.
+ ///
+ /// Adapters use this to decide whether to record a request-filter phase
+ /// timing span, so unconfigured deployments (no request filters) omit
+ /// that entry from observability output entirely.
+ #[must_use]
+ pub fn has_request_filters(&self) -> bool {
+ !self.inner.request_filters.is_empty()
+ }
+
/// Run pre-routing request filters.
///
/// Request header mutations are applied immediately so later filters and
@@ -1041,7 +1076,7 @@ impl IntegrationRegistry {
services,
mut req,
} = input;
- if let Some((proxy, _)) = self.find_route(method, path) {
+ if let Some((proxy, _, _)) = self.find_route(method, path) {
// Organic proxy handler: generate if needed (best effort).
// Only generate for document navigations — subresource requests
// may lack consent signals such as the Sec-GPC header.
@@ -1354,7 +1389,7 @@ impl IntegrationRegistry {
/// # Panics
///
/// Panics if route registration fails due to duplicate or invalid paths.
- pub fn from_routes(routes: Vec<(Method, &str, RouteValue)>) -> Self {
+ pub fn from_routes(routes: Vec>) -> Self {
let mut get_router = Router::new();
let mut post_router = Router::new();
let mut put_router = Router::new();
@@ -1363,7 +1398,8 @@ impl IntegrationRegistry {
let mut head_router = Router::new();
let mut options_router = Router::new();
- for (method, path, value) in routes {
+ for (method, path, (proxy, integration_id)) in routes {
+ let value: RouteValue = (proxy, integration_id, path.to_owned());
// Convert /* wildcard to matchit's {*rest} syntax
let matchit_path = if path.ends_with("/*") {
format!(
diff --git a/crates/trusted-server-core/src/lib.rs b/crates/trusted-server-core/src/lib.rs
index 1c20179298..1f625faee5 100644
--- a/crates/trusted-server-core/src/lib.rs
+++ b/crates/trusted-server-core/src/lib.rs
@@ -31,6 +31,7 @@
)
)]
+pub mod access_telemetry;
pub(crate) mod asset_image_optimizer;
pub mod auction;
pub mod auction_config_types;
@@ -62,6 +63,7 @@ pub mod proxy;
pub mod publisher;
pub mod redacted;
pub mod request_signing;
+pub mod request_timing;
pub mod response_privacy;
pub mod rsc_flight;
pub(crate) mod s3_sigv4;
diff --git a/crates/trusted-server-core/src/platform/mod.rs b/crates/trusted-server-core/src/platform/mod.rs
index 63f5c2a94e..2802bd3e50 100644
--- a/crates/trusted-server-core/src/platform/mod.rs
+++ b/crates/trusted-server-core/src/platform/mod.rs
@@ -43,6 +43,7 @@ mod template_assembly;
mod template_cache;
#[cfg(test)]
pub(crate) mod test_support;
+mod timed_kv;
mod traits;
mod types;
@@ -72,6 +73,7 @@ pub use template_cache::{
TemplateCookieValue, TemplateEntry, TemplateMetadata, TemplateMetadataEncodeError,
UnavailableTemplateCache, VaryHeaderValues, VarySpec, reader_url_surrogate_key,
};
+pub use timed_kv::TimedKvStore;
pub use traits::{PlatformBackend, PlatformConfigStore, PlatformGeo, PlatformSecretStore};
pub use types::{
ClientInfo, GeoInfo, PlatformBackendSpec, RuntimeServices, RuntimeServicesBuilder, StoreId,
diff --git a/crates/trusted-server-core/src/platform/timed_kv.rs b/crates/trusted-server-core/src/platform/timed_kv.rs
new file mode 100644
index 0000000000..376879cbf7
--- /dev/null
+++ b/crates/trusted-server-core/src/platform/timed_kv.rs
@@ -0,0 +1,266 @@
+//! Latency-only timing decorator for Edge Cookie KV store handles.
+//!
+//! [`TimedKvStore`] wraps an [`EcKvStore`] plus a [`RequestTimings`] handle and
+//! records [`Phase::EcKv`] around every store call at
+//! [`KvIdentityGraph`](crate::ec::kv::KvIdentityGraph) construction sites.
+//! The decorator measures latency only: it never reads, parses, or logs values.
+
+use error_stack::Report;
+
+use crate::ec::kv_backend::{EcKvLookup, EcKvStore, EcKvWrite, EcKvWriteOutcome};
+use crate::error::TrustedServerError;
+use crate::request_timing::{Phase, RequestTimings};
+
+/// Wraps `inner` plus a [`RequestTimings`] handle, recording [`Phase::EcKv`]
+/// around every store call made through it.
+pub struct TimedKvStore {
+ /// The wrapped store handle.
+ inner: S,
+ /// The request's phase-timing collector.
+ timings: RequestTimings,
+}
+
+impl TimedKvStore {
+ /// Creates a decorator around `inner` that records into `timings`.
+ #[must_use]
+ pub fn new(inner: S, timings: RequestTimings) -> Self {
+ Self { inner, timings }
+ }
+}
+
+impl EcKvStore for TimedKvStore {
+ fn store_name(&self) -> &str {
+ self.inner.store_name()
+ }
+
+ fn lookup(&self, key: &str) -> Result, Report> {
+ let _span = self.timings.span(Phase::EcKv);
+ self.inner.lookup(key)
+ }
+
+ fn key_exists(&self, key: &str) -> Result> {
+ let _span = self.timings.span(Phase::EcKv);
+ self.inner.key_exists(key)
+ }
+
+ fn insert(
+ &self,
+ key: &str,
+ write: EcKvWrite<'_>,
+ ) -> Result> {
+ let _span = self.timings.span(Phase::EcKv);
+ self.inner.insert(key, write)
+ }
+
+ fn list_keys_with_prefix(
+ &self,
+ prefix: &str,
+ limit: u32,
+ ) -> Result, Report> {
+ let _span = self.timings.span(Phase::EcKv);
+ self.inner.list_keys_with_prefix(prefix, limit)
+ }
+
+ fn count_keys_with_prefix(
+ &self,
+ prefix: &str,
+ limit: u32,
+ ) -> Result> {
+ let _span = self.timings.span(Phase::EcKv);
+ self.inner.count_keys_with_prefix(prefix, limit)
+ }
+
+ fn delete(&self, key: &str) -> Result<(), Report> {
+ let _span = self.timings.span(Phase::EcKv);
+ self.inner.delete(key)
+ }
+}
+
+#[cfg(test)]
+mod tests {
+ use std::time::Duration;
+
+ use super::*;
+ use crate::ec::kv_backend::test_support::InMemoryEcKv;
+
+ struct DelayingCountingEcKv {
+ inner: InMemoryEcKv,
+ calls: std::sync::Arc>>,
+ }
+
+ impl DelayingCountingEcKv {
+ fn record(&self, operation: &'static str) {
+ self.calls
+ .lock()
+ .expect("should lock KV operation calls")
+ .push(operation);
+ std::thread::sleep(Duration::from_millis(12));
+ }
+ }
+
+ impl EcKvStore for DelayingCountingEcKv {
+ fn store_name(&self) -> &str {
+ self.inner.store_name()
+ }
+
+ fn lookup(&self, key: &str) -> Result, Report> {
+ self.record("lookup");
+ self.inner.lookup(key)
+ }
+
+ fn key_exists(&self, key: &str) -> Result> {
+ self.record("key_exists");
+ self.inner.key_exists(key)
+ }
+
+ fn insert(
+ &self,
+ key: &str,
+ write: EcKvWrite<'_>,
+ ) -> Result> {
+ self.record("insert");
+ self.inner.insert(key, write)
+ }
+
+ fn list_keys_with_prefix(
+ &self,
+ prefix: &str,
+ limit: u32,
+ ) -> Result, Report> {
+ self.record("list_keys_with_prefix");
+ self.inner.list_keys_with_prefix(prefix, limit)
+ }
+
+ fn count_keys_with_prefix(
+ &self,
+ prefix: &str,
+ limit: u32,
+ ) -> Result> {
+ self.record("count_keys_with_prefix");
+ self.inner.count_keys_with_prefix(prefix, limit)
+ }
+
+ fn delete(&self, key: &str) -> Result<(), Report> {
+ self.record("delete");
+ self.inner.delete(key)
+ }
+ }
+
+ #[test]
+ fn ec_kv_store_operations_accumulate_into_ec_kv_phase() {
+ let timings = RequestTimings::new();
+ let store = TimedKvStore::new(InMemoryEcKv::new("test-store"), timings.clone());
+
+ store
+ .insert(
+ "key-a",
+ EcKvWrite {
+ body: "{}",
+ metadata: "{}",
+ ttl: Duration::from_secs(60),
+ mode: crate::ec::kv_backend::EcKvWriteMode::Add,
+ },
+ )
+ .expect("should insert into the in-memory store");
+ store.lookup("key-a").expect("should read back the entry");
+ assert!(store.key_exists("key-a").expect("should check key"));
+ assert_eq!(
+ store
+ .list_keys_with_prefix("key-", 10)
+ .expect("should list keys"),
+ vec!["key-a".to_string()]
+ );
+ assert_eq!(
+ store
+ .count_keys_with_prefix("key-", 10)
+ .expect("should count keys"),
+ 1
+ );
+ store.delete("key-a").expect("should delete key");
+ assert!(!store.key_exists("key-a").expect("should check deletion"));
+
+ timings.mark_headers_ready();
+ assert!(
+ timings.snapshot().kv_ms.is_some(),
+ "should accumulate Phase::EcKv across lookup, key_exists, insert, list, count, and delete"
+ );
+ }
+
+ #[test]
+ fn every_store_operation_contributes_a_separate_timed_span() {
+ let calls = std::sync::Arc::new(std::sync::Mutex::new(Vec::new()));
+ let timings = RequestTimings::new();
+ let store = TimedKvStore::new(
+ DelayingCountingEcKv {
+ inner: InMemoryEcKv::new("test-store"),
+ calls: std::sync::Arc::clone(&calls),
+ },
+ timings.clone(),
+ );
+ let mut previous_ms = 0;
+ let mut assert_span_added = |operation: &str| {
+ let current_ms = timings
+ .snapshot()
+ .kv_ms
+ .expect("each store operation should record an EcKv span");
+ assert!(
+ current_ms > previous_ms,
+ "{operation} should add its own delayed span: previous={previous_ms}ms current={current_ms}ms"
+ );
+ previous_ms = current_ms;
+ };
+
+ store
+ .insert(
+ "key-a",
+ EcKvWrite {
+ body: "{}",
+ metadata: "{}",
+ ttl: Duration::from_secs(60),
+ mode: crate::ec::kv_backend::EcKvWriteMode::Add,
+ },
+ )
+ .expect("should insert into the delaying store");
+ assert_span_added("insert");
+ store.lookup("key-a").expect("should look up key");
+ assert_span_added("lookup");
+ store.key_exists("key-a").expect("should check key");
+ assert_span_added("key_exists");
+ store
+ .list_keys_with_prefix("key-", 10)
+ .expect("should list keys");
+ assert_span_added("list_keys_with_prefix");
+ store
+ .count_keys_with_prefix("key-", 10)
+ .expect("should count keys");
+ assert_span_added("count_keys_with_prefix");
+ store.delete("key-a").expect("should delete key");
+ assert_span_added("delete");
+
+ assert_eq!(
+ *calls.lock().expect("should lock KV operation calls"),
+ vec![
+ "insert",
+ "lookup",
+ "key_exists",
+ "list_keys_with_prefix",
+ "count_keys_with_prefix",
+ "delete",
+ ],
+ "the wrapper should forward every operation exactly once"
+ );
+ }
+
+ #[test]
+ fn store_name_is_not_timed() {
+ let timings = RequestTimings::new();
+ let store = TimedKvStore::new(InMemoryEcKv::new("test-store"), timings.clone());
+
+ assert_eq!(store.store_name(), "test-store");
+ timings.mark_headers_ready();
+ assert!(
+ timings.snapshot().kv_ms.is_none(),
+ "store_name is a metadata accessor, not a store operation"
+ );
+ }
+}
diff --git a/crates/trusted-server-core/src/publisher.rs b/crates/trusted-server-core/src/publisher.rs
index 682ecc0f15..890c53b307 100644
--- a/crates/trusted-server-core/src/publisher.rs
+++ b/crates/trusted-server-core/src/publisher.rs
@@ -77,6 +77,7 @@ use crate::platform::{
reader_url_surrogate_key,
};
use crate::price_bucket::{PriceGranularity, price_bucket};
+use crate::request_timing::{AuctionWaitPlacement, Phase, RequestTimings};
use crate::response_privacy::{
apply_inactive_ad_stack_browser_cache_policy, cache_control_forbids_shared_storage,
enforce_synthesized_html_cache_privacy, enforce_terminal_private_cache_privacy,
@@ -99,21 +100,44 @@ const DEFAULT_PUBLISHER_FIRST_BYTE_TIMEOUT: Duration = Duration::from_secs(15);
const HEADER_X_TS_TEMPLATE_CACHE: &str = "x-ts-template-cache";
const HEADER_X_TS_ASSEMBLY: &str = "x-ts-assembly";
-#[derive(Clone, Copy, PartialEq, Eq)]
-enum TemplateCacheResponseState {
+/// Outcome of a template-cache lookup/store attempt for one response.
+///
+/// Set on every response that passes through the assembly pipeline via
+/// [`set_template_cache_response_state`], which writes both the
+/// `x-ts-template-cache` response header and this same value as a typed
+/// response extension, so the two can never drift. Access telemetry reads
+/// the extension rather than the header, since operator-configured response
+/// headers can override a managed header but cannot touch extensions.
+#[derive(Debug, Clone, Copy, PartialEq, Eq)]
+pub enum TemplateCacheResponseState {
+ /// The cached template was found and reused.
Hit,
+ /// No cached template existed; the cache store is reserved for this
+ /// content type.
MissReserved,
+ /// No cached template existed; one was stored after assembly.
MissStored,
+ /// No cached template existed; storing the freshly assembled template
+ /// failed.
MissStoreError,
+ /// The request bypassed the cache lookup.
BypassRequest,
+ /// The response bypassed the cache store.
BypassResponse,
+ /// The response's content type is not supported by the template cache.
Unsupported,
+ /// The cached template entry was invalid and could not be reused.
Invalid,
+ /// A backend error prevented the cache lookup or store.
BackendError,
}
impl TemplateCacheResponseState {
- const fn as_str(self) -> &'static str {
+ /// Renders this variant as the string written to the
+ /// `x-ts-template-cache` header and the `template_cache_state` access
+ /// telemetry column.
+ #[must_use]
+ pub const fn as_str(self) -> &'static str {
match self {
Self::Hit => "hit",
Self::MissReserved => "miss-reserved",
@@ -136,6 +160,7 @@ fn set_template_cache_response_state(
HEADER_X_TS_TEMPLATE_CACHE,
HeaderValue::from_static(state.as_str()),
);
+ response.extensions_mut().insert(state);
}
#[derive(Clone, Copy, PartialEq, Eq)]
@@ -1730,6 +1755,12 @@ pub struct OwnedProcessResponseParams {
/// rescanned from the output, which cannot tell a `nonce` attribute from the same
/// word inside a script.
pub(crate) csp_nonce_observed: Option>,
+ /// Per-request phase-timing handle, carried into the streaming/buffered
+ /// finalizers so the `` seam wait can be recorded with the right
+ /// [`AuctionWaitPlacement`]. Cheap to clone (an `Arc` handle); a request that
+ /// never attached one to its extensions gets a fresh, unattached collector
+ /// that nothing ever renders.
+ pub(crate) timings: RequestTimings,
}
/// Response-authorized template cache insert inputs. The key is built before origin lookup; the
@@ -1973,6 +2004,8 @@ pub async fn buffer_publisher_response_async(
¶ms.request_scheme,
¶ms.request_host,
),
+ timings: params.timings.clone(),
+ placement: AuctionWaitPlacement::PreHeader,
},
)
.await;
@@ -2139,6 +2172,7 @@ fn build_template_assembly_params(
request_scheme: &str,
price_granularity: PriceGranularity,
ad_bids_state: AdBidsState,
+ timings: RequestTimings,
) -> OwnedProcessResponseParams {
OwnedProcessResponseParams {
csp_nonce_observed: None,
@@ -2161,6 +2195,7 @@ fn build_template_assembly_params(
price_granularity,
gpt_diagnostics: None,
suppress_datadome_client_side_tag: false,
+ timings,
}
}
@@ -2503,6 +2538,8 @@ pub async fn publisher_response_into_streaming_response(
¶ms.request_scheme,
¶ms.request_host,
),
+ timings: params.timings.clone(),
+ placement: AuctionWaitPlacement::InStream,
},
)
.await;
@@ -2621,6 +2658,7 @@ pub async fn publisher_response_into_streaming_response(
&orchestrator,
&services,
&settings,
+ AuctionWaitPlacement::InStream,
)
.await;
// Collection reached a terminal result; disarm only now
@@ -2646,6 +2684,8 @@ pub async fn publisher_response_into_streaming_response(
¶ms.request_scheme,
¶ms.request_host,
),
+ timings: params.timings.clone(),
+ placement: AuctionWaitPlacement::InStream,
};
while let Some(step) = hold_step_next_chunk(
@@ -2990,6 +3030,7 @@ pub async fn stream_publisher_body_async(
orchestrator,
services,
settings,
+ AuctionWaitPlacement::PreHeader,
)
.await;
if body.is_stream() {
@@ -3064,6 +3105,8 @@ pub async fn stream_publisher_body_async(
services,
settings,
request_origin: request_origin(¶ms.request_scheme, ¶ms.request_host),
+ timings: params.timings.clone(),
+ placement: AuctionWaitPlacement::PreHeader,
},
},
)
@@ -3235,6 +3278,47 @@ fn request_origin(scheme: &str, host: &str) -> String {
}
}
+/// Request-clock auction facts exposed only to an active browser diagnostics session.
+#[derive(Clone, Debug, serde::Serialize)]
+#[serde(rename_all = "camelCase")]
+struct BrowserAuctionDiagnostics {
+ #[serde(skip_serializing_if = "Option::is_none")]
+ auction_dispatched_ms: Option,
+ #[serde(skip_serializing_if = "Option::is_none")]
+ auction_resolved_ms: Option,
+ #[serde(skip_serializing_if = "Option::is_none")]
+ auction_committed_ms: Option,
+ #[serde(skip_serializing_if = "Option::is_none")]
+ auction_wait_ms: Option,
+ #[serde(skip_serializing_if = "Option::is_none")]
+ auction_wait_placement: Option<&'static str>,
+}
+
+const fn auction_wait_placement_wire(placement: AuctionWaitPlacement) -> &'static str {
+ match placement {
+ AuctionWaitPlacement::PreHeader => "pre_header",
+ AuctionWaitPlacement::InStream => "in_stream",
+ }
+}
+
+impl BrowserAuctionDiagnostics {
+ fn from_request_timings(timings: &RequestTimings) -> Option {
+ let snapshot = timings.snapshot();
+ if snapshot.auction_dispatched_ms.is_none() && snapshot.auction_wait_ms.is_none() {
+ return None;
+ }
+ Some(Self {
+ auction_dispatched_ms: snapshot.auction_dispatched_ms,
+ auction_resolved_ms: snapshot.auction_resolved_ms,
+ auction_committed_ms: snapshot.auction_committed_ms,
+ auction_wait_ms: snapshot.auction_wait_ms,
+ auction_wait_placement: snapshot
+ .auction_wait_placement
+ .map(auction_wait_placement_wire),
+ })
+ }
+}
+
/// This request's auction result, in both forms the seams need.
///
/// The inline `` seam injects a rendered `` sequences inside the string.
pub(crate) fn build_bids_script(bid_map: &serde_json::Map) -> String {
- let json = serde_json::to_string(bid_map)
- .expect("serde_json::to_string of Map should be infallible");
+ build_bids_script_with_diagnostics(bid_map, None)
+}
+
+fn build_bids_script_with_diagnostics(
+ bid_map: &serde_json::Map,
+ auction_diagnostics: Option<&BrowserAuctionDiagnostics>,
+) -> String {
+ let json = serde_json::to_string(bid_map).expect("should serialize the bids map");
let escaped = html_escape_for_script(&json);
// adInit() defines GPT slots on the publisher's `-container` wrappers, which
// mutates those ad-slot subtrees. Calling it synchronously here (this script
@@ -5969,6 +6185,23 @@ pub(crate) fn build_bids_script(bid_map: &serde_json::Map(function(){{\
+var t=window.tsjs=window.tsjs||{{}};\
+var b=JSON.parse(\"{}\");\
+var d=JSON.parse(\"{}\");\
+var s=t.scheduleInitialAdInit;\
+if(typeof s===\"function\")s(b,void 0,d);\
+else{{t.bids=b;t.auctionDiagnostics=d;}}\
+}})();",
+ escaped,
+ html_escape_for_script(&diagnostics)
+ );
+ }
+
format!(
"",
+ html_escape_for_script(slots_json),
+ html_escape_for_script(&bids),
+ html_escape_for_script(&diagnostics)
+ );
+ }
+
format!(
"