Skip to content

Improve GPT auction diagnostics observability #1121

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
ChristianPavilonis wants to merge 5 commits into from
Closed

Improve GPT auction diagnostics observability #1121

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
dae88a0
Improve GPT auction diagnostics observability
ChristianPavilonis Sep 4, 2026
30ccab8
Fix GPT auction diagnostics timing accuracy
ChristianPavilonis Sep 4, 2026
563670d
Address GPT diagnostics review feedback
ChristianPavilonis Sep 14, 2026
f951955
Fix cross-adapter GPT diagnostic timing origins
ChristianPavilonis Sep 21, 2026
2791ceb
Use shared EdgeZero request timing across adapters
ChristianPavilonis Sep 28, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
16 changes: 8 additions & 8 deletions Cargo.lock
View file
Open in desktop

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

14 changes: 8 additions & 6 deletions Cargo.toml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -55,12 +55,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", tag = "v0.0.7", default-features = false }
edgezero-adapter-cloudflare = { git = "https://github.com/stackpop/edgezero", tag = "v0.0.7", default-features = false }
edgezero-adapter-fastly = { git = "https://github.com/stackpop/edgezero", tag = "v0.0.7", default-features = false }
edgezero-adapter-spin = { git = "https://github.com/stackpop/edgezero", tag = "v0.0.7", default-features = false }
edgezero-cli = { git = "https://github.com/stackpop/edgezero", tag = "v0.0.7" }
edgezero-core = { git = "https://github.com/stackpop/edgezero", tag = "v0.0.7", 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 = "9c03cc59300363ae5339fc970dded08ede563e98", default-features = false }
edgezero-adapter-cloudflare = { git = "https://github.com/stackpop/edgezero", rev = "9c03cc59300363ae5339fc970dded08ede563e98", default-features = false }
edgezero-adapter-fastly = { git = "https://github.com/stackpop/edgezero", rev = "9c03cc59300363ae5339fc970dded08ede563e98", default-features = false }
edgezero-adapter-spin = { git = "https://github.com/stackpop/edgezero", rev = "9c03cc59300363ae5339fc970dded08ede563e98", default-features = false }
edgezero-cli = { git = "https://github.com/stackpop/edgezero", rev = "9c03cc59300363ae5339fc970dded08ede563e98" }
edgezero-core = { git = "https://github.com/stackpop/edgezero", rev = "9c03cc59300363ae5339fc970dded08ede563e98", default-features = false }
Comment on lines +58 to +65

@aram356 aram356 Oct 2, 2026

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

🔧 wrench — This pins six crates to an unmerged EdgeZero revision that has outstanding requested changes, so the PR cannot merge as it stands.

The comment above is honest that the pin is temporary, and stacking a cross-repo change this way is the right shape. Two facts make it blocking rather than a bookkeeping note, though:

9c03cc59 is the head of EdgeZero PR #389, which is open and not an ancestor of main (git merge-base --is-ancestor 9c03cc59 origin/main fails). So a cargo build from a clean checkout resolves a revision that exists only on an unmerged branch.

More importantly, #389 currently reports reviewDecision: CHANGES_REQUESTED and mergeStateStatus: BLOCKED, with two 🔧 items outstanding against exactly the surface this PR consumes:

  • TimingError is not #[non_exhaustive], inconsistent with EdgeError / KvError / ConfigStoreError, and adding it after a tag is a breaking change.
  • t0 should be hoisted out of the mutex so elapsed() becomes infallible.

Neither of those touches Trusted Server's call sites at this revision, so the code here is compatible today. But both change the published API shape, which means the revision this PR pins is expected to be rewritten before it can be tagged. Merging now would land a dependency edge that is known to be going away.

What I would ask for, in preference order:

  1. Land Convert VCL into Rust code in TS to not require extra CDN VCL hop and increase reponse times #389 with those two items addressed, cut the release tag, and repin all six entries to it. That is the end state the comment already describes, and it is the only one where this PR is self-consistently mergeable.
  2. If you would rather not block this PR on an EdgeZero release, the alternative is to split: merge the diagnostics work with the middleware hosted in trusted-server-core (a pure move, no API decisions, no external pin), and let the EdgeZero extraction land separately once Convert VCL into Rust code in TS to not require extra CDN VCL hop and increase reponse times #389 settles. I raised that option last round and it remains available.

Either way, please keep the pin visible in the PR description or as a merge checklist item rather than only in this comment — a rev = pin is easy to lose track of, and the failure mode is silent (a stale rev keeps resolving long after the tag exists).

Apply manually — repinning depends on an EdgeZero release that does not exist yet, so there is no replacement text to suggest.

env_logger = "0.11"
error-stack = "0.6"
esi = "0.7.2"
Expand Down
155 changes: 122 additions & 33 deletions crates/trusted-server-adapter-axum/src/timing.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,9 +1,10 @@
//! 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 creates a
//! 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)
//! collector per request, threads it through request extensions so
//! facade so
//! downstream core handlers can record into it, and on the way back stamps
//! `mark_headers_ready` and appends the `Server-Timing` header via
//! [`append_server_timing_if_private`](trusted_server_core::request_timing::append_server_timing_if_private).
Expand All @@ -21,8 +22,8 @@
//!
//! `/health` is excluded by path match before a
//! [`RequestTimings`](trusted_server_core::request_timing::RequestTimings)
//! collector is even created: health checks never carry timing data on any
//! adapter.
//! collector is even created: this wrapper bypasses timing for every method
//! on that path, leaving any preinstalled handle unchanged.
//!
//! Unlike the Fastly adapter (state built per request, adding
//! `Phase::AppBuild` to the rendered header), the Axum dev server builds its
Expand All @@ -40,7 +41,7 @@ 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 never carry timing data on any adapter.
/// checks bypass this wrapper for every method.
const HEALTH_PATH: &str = "/health";

/// Wraps an inner Axum tower service with the request-phase timing freeze
Expand Down Expand Up @@ -78,15 +79,18 @@ where
fn call(&mut self, mut req: Request<AxumBody>) -> Self::Future {
let mut inner = self.inner.clone();

// Excluded before a collector is even created: `/health` never
// carries timing data, on any adapter.
// Bypass installation and finalization for `/health`, regardless of method.
// A preinstalled collector remains available to the inner service.
if req.uri().path() == HEALTH_PATH {

@aram356 aram356 Oct 2, 2026

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

📝 note — Worth recording what this costs in cross-adapter consistency, because the answer is "nothing observable" and that took checking.

Fastly's health bypass is GET-only and ignores the query string, and the new test at main.rs pins that. The shared middleware excludes by path for every method, and the Axum wrapper does the same, which the comment there states plainly ("regardless of method").

So on three adapters a POST /health skips timing entirely, while on Fastly it is timed and routed. I checked whether that difference is reachable: every adapter registers /health as GET-only (app.rs in Axum and Spin, the short-circuit in Fastly's main.rs), so a non-GET request to that path is a 405 everywhere and carries no timing worth collecting either way.

No action needed. Flagging it only so the divergence is a recorded decision rather than something a future reader has to re-derive, and because with_excluded_paths(&["/health"]) now repeats the literal at each registration site — which is the right call for policy that belongs to the adapter, but does mean four places to update if the probe path ever changes.

return Box::pin(async move { inner.call(req).await });
}

let server_timing_enabled = self.server_timing_enabled;
let timings = RequestTimings::new();
req.extensions_mut().insert(timings.clone());
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?;
Expand Down Expand Up @@ -132,6 +136,69 @@ mod tests {
.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<AxumBody>| {
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()
Expand Down Expand Up @@ -201,7 +268,7 @@ mod tests {
// here instead of silently losing every phase.
let router = RouterService::builder()
.get("/private", |ctx: RequestContext| async move {
if let Some(timings) = ctx.request().extensions().get::<RequestTimings>() {
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),
Expand Down Expand Up @@ -283,28 +350,50 @@ mod tests {

#[tokio::test(flavor = "multi_thread", worker_threads = 2)]
async fn axum_health_is_excluded() {
let router = RouterService::builder()
.get("/health", |_ctx: RequestContext| async {
private_ok_response()
})
.build();
let mut service = TimingService::new(EdgeZeroAxumService::new(router), true);

let request = Request::builder()
.uri("/health")
.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(),
"/health must never carry a server-timing header"
);
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<AxumBody>| 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"
);
}
}
}
}
}
2 changes: 2 additions & 0 deletions crates/trusted-server-adapter-cloudflare/src/app.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,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};
Expand Down Expand Up @@ -467,6 +468,7 @@ fn build_router(state: &Arc<AppState>) -> 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(
Expand Down
Loading
Loading