Improve GPT auction diagnostics observability - #1121
Conversation
prk-Jr
left a comment
prk-Jr
left a comment
There was a problem hiding this comment.
Summary
Solid, well-tested addition: stable Ad #N identity, auction classification, and server auction timings all land behind the existing activation gate, with a normalization boundary and tests for the malformed cases. No correctness, security, or WASM-compatibility problem found; all 14 CI checks pass. The findings below are all non-blocking — the substantive ones are about the SPA timing anchor and label accuracy in a tool whose value is precise facts.
1 of the inline comments below carries a one-click GitHub
suggestion— use Commit suggestion to apply it as a commit on the PR branch. The remaining comments describe the fix in prose because the change touches test files, spans more than one hunk, or is a design choice rather than a mechanical edit.
Non-blocking
🤔 thinking
- SPA
auctionDispatchedMsis always0by construction — see inline atcrates/trusted-server-core/src/publisher.rs:6748 Navigation T0overstates the anchor — see inline atcrates/trusted-server-js/lib/src/integrations/gpt_diagnostics/overlay.ts:246- The store infers
ssatwhen auction facts are absent or malformed — see inline atcrates/trusted-server-js/lib/src/integrations/gpt_diagnostics/store.ts:1129 1x1suppression conflates "GPT reported 1x1" with "GPT reported nothing" — see inline atcrates/trusted-server-js/lib/src/integrations/gpt_diagnostics/presentation_helpers.ts:9
♻️ refactor
set_auction_diagnosticsrebuilds the script cell and drops a debug prefix — see inline atcrates/trusted-server-core/src/publisher.rs:3209(suggestion)- Placement wire string has two sources of truth — see inline at
crates/trusted-server-core/src/publisher.rs:6767
⛏ nitpick
- Duplicated 5-arg / 6-arg recorder call — see inline at
crates/trusted-server-js/lib/src/integrations/gpt/index.ts:1113 - Browser spec traded away its only non-
1x1fill-size case — see inline atcrates/trusted-server-integration-tests/browser/tests/nextjs/gpt-diagnostics.spec.ts:223
👍 praise
- Stable
Ad #Non re-entry, and fail-closed dispatch gating — see inline atcrates/trusted-server-js/lib/src/integrations/gpt_diagnostics/store.ts:1201
Cross-cutting / body-level findings
- 📝 Stacked base — this targets
spec/auction-timeline-offsets(stacked on #1076 → #1074). Retarget tomainafter those land, as the description says. Nothing in the diff depends on that ordering beyond the base itself. - 📝 Coverage of the server write path is complete —
write_bids_to_statehas exactly two production call sites (collect_non_html_auction,collect_stream_auction) and both are now paired withset_auction_diagnostics, so there is no document path that commits bids without the timing facts. Verified by grep rather than assumed.
CI Status
- browser integration tests: PASS
- integration tests: PASS
- integration tests (Fastly EC lifecycle): PASS
- prepare integration artifacts: PASS
- cargo test: PASS
- cargo test (axum native): PASS
- cargo test (ts CLI, native): PASS
- cargo test (cross-adapter parity): PASS
- cargo check (cloudflare native + wasm32-unknown-unknown): PASS
- cargo check/build/test (spin native + wasm32-wasip1): PASS
- cargo fmt: PASS
- vitest: PASS
- format-typescript: PASS
- format-docs: PASS
gh pr checks --required returned no names for this base, so none of the above are annotated as branch-protection-required; all of them are gates CLAUDE.md treats as PR gates, and all pass.
| }; | ||
| match auction | ||
| let timing_started = web_time::Instant::now(); | ||
| let auction_dispatched_ms = elapsed_millis(&timing_started); |
There was a problem hiding this comment.
🤔 thinking — This field is a constant 0 on every SPA cycle: the clock starts on the line above and is read immediately, so auction_dispatched_ms can only ever be sub-millisecond. auction_wait_ms (resolved - dispatched) then becomes an exact duplicate of auction_resolved_ms, and the panel does render the zero — formatMilliseconds(0) returns "0 ms", so every SPA cycle shows SPA auction T0 → auction dispatched 0 ms.
The anchor also excludes everything the handler already did before this line (CSRF gate, consent gate, slot matching, EC/KV lookups) — which is precisely the pre-dispatch cost the initial-document path does surface, because there auctionDispatchedMs is a real T0 offset. So the two paths look comparable in the UI while measuring different things, and a slow pre-dispatch phase is invisible on the SPA side.
The request already carries a T0-anchored RequestTimings in its extensions (inserted at crates/trusted-server-adapter-fastly/src/main.rs:216 and crates/trusted-server-adapter-axum/src/timing.rs:87), so this path could use the same instrument it uses on the document path:
let timings = req
.extensions()
.get::<RequestTimings>()
.cloned()
.unwrap_or_default();
// … around the auction:
timings.mark_auction_dispatched(auction_id);
let result = auction.orchestrator.run_auction(&auction_request, &auction_context).await;
timings.record_auction_wait(AuctionWaitPlacement::PreHeader, wait_started.elapsed());
timings.mark_auction_resolved();
// after the bid map is built:
timings.mark_auction_committed();
let auction_diagnostics = gpt_diagnostics
.browser_session_active()
.then(|| BrowserAuctionDiagnostics::from_request_timings(&timings))
.flatten();That gives both paths one clock semantics, removes the parallel timing mechanism, and — because these are the same marks the Server-Timing header and auction telemetry read — makes the console numbers reconcilable with the logs instead of existing only in the JSON response. If you'd rather keep the local clock, then dropping auctionDispatchedMs (and with it the redundant auctionWaitMs) from the SPA payload is more honest than shipping a measured-looking 0.
Apply manually — spans the timing setup, the Ok(result) arm, and the commit patch below, so it can't be expressed as one contiguous suggestion.
| auction_wait_ms: Some( | ||
| auction_resolved_ms.saturating_sub(auction_dispatched_ms), | ||
| ), | ||
| auction_wait_placement: Some("pre_header"), |
There was a problem hiding this comment.
♻️ refactor — The wire values for this field now have two sources of truth: BrowserAuctionDiagnostics::from_request_timings maps the enum (publisher.rs:3140-3148), and this site hardcodes the string. The TS side pins them as a closed union ('pre_header' | 'in_stream' in core/types.ts) and normalizedServerAuctionTimings drops anything else, so a typo here degrades silently to placement unknown in the panel rather than failing anywhere.
Proposed fix (apply manually — the helper definition and this call site are in separate hunks):
const fn placement_wire(placement: AuctionWaitPlacement) -> &'static str {
match placement {
AuctionWaitPlacement::PreHeader => "pre_header",
AuctionWaitPlacement::InStream => "in_stream",
}
}Then from_request_timings becomes snapshot.auction_wait_placement.map(placement_wire) and this line becomes auction_wait_placement: Some(placement_wire(AuctionWaitPlacement::PreHeader)), which also documents at the call site which placement the page-bids wait is being claimed as.
| *self.bids.lock().expect("should lock bid map") = bid_map; | ||
| } | ||
|
|
||
| fn set_auction_diagnostics(&self, timings: &RequestTimings) { |
There was a problem hiding this comment.
♻️ refactor — This writes *self.script.lock() = Some(build_bids_script_with_diagnostics(...)), discarding whatever the cell already held. That is safe today only because prepend_auction_debug_comment (publisher.rs:4138) runs after it in collect_stream_auction; swap those two statements and the ts-debug comment silently disappears from the inline bids script, with no test covering the pair. prepend_to_script keeps debug_prefix for exactly this reason, but only build_seam_script re-applies it.
Cheapest fix is to record the ordering requirement next to the new write:
| fn set_auction_diagnostics(&self, timings: &RequestTimings) { | |
| /// Attach the server auction facts to the rendered bid script. | |
| /// | |
| /// Rebuilds the script cell from scratch, so it must run **before** | |
| /// [`Self::prepend_to_script`]: a debug comment already written into the | |
| /// script cell would be discarded here, and only the shared-template seam | |
| /// re-applies the retained `debug_prefix`. | |
| fn set_auction_diagnostics(&self, timings: &RequestTimings) { |
If you'd rather have it enforced than documented, re-apply the retained prefix the way build_seam_script already does, so the write cannot lose it regardless of call order.
| const timingOrigin = | ||
| cycle.serverAuctionTimingOrigin ?? | ||
| (cycle.auctionType === 'trusted_server' ? 'spa_auction' : 'navigation'); | ||
| const timingAnchor = timingOrigin === 'spa_auction' ? 'SPA auction T0' : 'Navigation T0'; |
There was a problem hiding this comment.
🤔 thinking — RequestTimings::t0 is stamped when the edge starts processing the request, not at the browser's navigationStart. Labeling it Navigation T0 invites the operator to line these offsets up against browser Navigation Timing — the exact cross-clock subtraction the new documentation forbids two paragraphs earlier ("Server auction timing and browser GPT timing use separate clocks and are never subtracted from each other").
Edge request T0 (or Server request T0) names what is actually being measured and keeps the SPA/initial distinction intact:
const timingAnchor = timingOrigin === 'spa_auction' ? 'SPA auction T0' : 'Edge request T0';Apply manually — test/integrations/gpt_diagnostics/overlay.test.ts asserts the rendered Navigation T0 → … strings, so the rename has to land with those assertions.
| const hasClientSideAuction = intent?.sources.has('prebid_refresh') === true; | ||
| if (hasTrustedServerAuction && hasClientSideAuction) return 'competing'; | ||
| if (hasClientSideAuction) return 'client_side'; | ||
| if (hasTrustedServerAuction) return trustedServerEvidence?.auctionType ?? 'ssat'; |
There was a problem hiding this comment.
🤔 thinking — This is the one place the console infers rather than reports. Any direct evidence whose auctionFacts failed normalization is labelled SSAT, including a SPA request — your own test pins the behaviour (auctionType: 'invalid' → 'ssat'), and the same fallback fires when the facts object is missing entirely. The panel then makes a positive claim about a path that was never observed, in a document that opens with "reports positive observations, not inferred ownership".
The producer side is already almost there: diagnosticsAuctionFacts always emits auctionType when generation > 0, and only returns undefined for the generation-0 case with no winner and no diagnostics. If it emitted { auctionType: 'ssat' } for that case too, this line could be return trustedServerEvidence?.auctionType; and a malformed payload would stay unlabelled instead of being relabelled.
Apply manually — touches gpt/index.ts, this file, and the store/ad_init expectations together.
| } | ||
|
|
||
| /** Hide GPT's ubiquitous 1×1 placeholder from presentation while retaining it in exports. */ | ||
| export function displayableGptFillSize(size: Size | undefined): Size | undefined { |
There was a problem hiding this comment.
🤔 thinking — Returning undefined for 1x1 means the badge and panel omit the Fill line entirely, which is indistinguishable from a cycle where slotRenderEnded carried no size at all. The export keeps the truth (and the browser spec now asserts that), but the console is the first place an operator looks, and "GPT told us 1x1" and "GPT told us nothing" are different diagnoses — the first is a live flexible/APS creative, the second is a missing observation.
Labeling rather than hiding keeps the noise down without erasing the fact, e.g. render Fill 1x1 (GPT placeholder) and leave the helper as a presentation predicate:
/** GPT's ubiquitous 1x1 fill size carries no layout information on its own. */
export function isGptFillSizePlaceholder(size: Size | undefined): boolean {
return size?.[0] === 1 && size[1] === 1;
}Apply manually — the badge and overlay call sites plus their assertions move with it.
| bid.hb_auction_id, | ||
| requestedSlotSizes | ||
| ); | ||
| const auctionFacts = diagnosticsAuctionFacts(generation, auctionDiagnostics, bid); |
There was a problem hiding this comment.
⛏ nitpick — The if (auctionFacts) … else … branch repeats five arguments to make the sixth conditional, but auctionFacts is an optional parameter, so passing it through directly is equivalent:
ts.gptDiagnosticsRecorder?.recordTrustedServerOpportunity(
gptSlot,
slot.id,
opportunity,
bid.hb_auction_id,
requestedSlotSizes,
diagnosticsAuctionFacts(generation, auctionDiagnostics, bid)
);I verified this in a scratch worktree rather than guessing: npx tsc --noEmit reports no new errors, but 8 assertions in test/integrations/gpt/ad_init.test.ts fail, because toHaveBeenCalledWith compares argument-list length and a trailing explicit undefined no longer matches a 5-argument expectation. So the branch currently exists only to preserve the call arity those assertions pin.
Apply manually — worth relaxing the assertions (they care about the facts payload, not the argument count) rather than keeping the duplicated call, but it needs the test file, so it can't be a one-click suggestion.
| await emit(page, "slotRenderEnded", "gpt-diagnostics-slot-primary", { | ||
| isEmpty: false, | ||
| size: [300, 250], | ||
| size: [1, 1], |
There was a problem hiding this comment.
⛏ nitpick — This was the only place the browser suite asserted an exported GPT fill size, and it changed from [300, 250] to [1, 1] rather than gaining a case. The new "1x1 stays in the JSON evidence" behaviour deserves end-to-end coverage, but so does the ordinary size, which is now only covered in vitest (badges.test.ts). Emitting the second cycle with a real size — or adding one 1x1 slot alongside the existing [300, 250] one — keeps both paths proven against a real GPT surface.
|
|
||
| const runtimeSlotNumber = this.nextRuntimeSlotNumber; | ||
| this.nextRuntimeSlotNumber += 1; | ||
| const runtimeSlotNumber = existingNumber ?? this.nextRuntimeSlotNumber; |
There was a problem hiding this comment.
👍 praise — Reusing the WeakMap number on re-entry is what finally makes the documented "Ad #N identity and request numbers remain stable and monotonic for the console lifetime" claim true, and it composes correctly with the surrounding bookkeeping: the eviction branch above is the only slots.delete site and it also splices slotOrder and shifts slotActivityOrder, so the reused number can't produce a duplicate slotOrder entry or clobber a live record. requestNumbers being a WeakMap too means the cycle numbering survives the same round trip.
Two other things worth calling out in this PR: gating the page-bids timings on the Ok(result) arm so a failure before any provider dispatch can't fabricate dispatch evidence (with a test that asserts exactly that), and the bounded normalization boundary in normalizedServerAuctionTimings / normalizedAuctionWinner — including the price-bucket shape check — backed by a malformed-input test.
prk-Jr
left a comment
prk-Jr
left a comment
There was a problem hiding this comment.
Verdict: APPROVE
Follow-up to the detailed review above, correcting its verdict: none of its findings are blocking (no 🔧 wrench, no ❓ question), and all 14 CI checks pass, so this should have been submitted as an approval rather than a comment.
Every inline comment there stands as written and remains worth reading — 4 🤔 thinking, 2 ♻️ refactor (one as a one-click suggestion), 2 ⛏ nitpick, 1 👍 praise — but each is a merge-can-proceed observation. The two most substantive, if you want to pick any of them up here rather than in a follow-up:
- SPA
auctionDispatchedMsis a structural0(the clock is read on the line after it starts), which also makesauctionWaitMsa duplicate ofauctionResolvedMs—crates/trusted-server-core/src/publisher.rs:6748. Navigation T0in the panel is the edge request-receipt offset, not the browser'snavigationStart—crates/trusted-server-js/lib/src/integrations/gpt_diagnostics/overlay.ts:246.
Approved on ffc0438dd5f872e68c3ccad36d5c35bde47101d2.
2 participants
Summary
Ad #Nin the TS Console panel and export.1×1and size terminology.This is stacked on #1076, which is stacked on #1074. Retarget this PR to
mainafter those dependencies merge.Changes
crates/trusted-server-core/src/publisher.rscrates/trusted-server-js/lib/src/integrations/gpt/crates/trusted-server-js/lib/src/integrations/gpt_diagnostics/crates/trusted-server-js/lib/test/and browser integration testsdocs/guide/integrations/gpt-diagnostics.mdCloses
Closes #1081
Test plan
cargo test-fastly && cargo test-axumcargo test-cloudflarecargo clippy-fastly && cargo clippy-axum && cargo clippy-cloudflarecargo fmt --all -- --checkcd crates/trusted-server-js/lib && npx vitest run(898 passed, no type errors)npm run lint && npm run buildcd crates/trusted-server-js/lib && npm run formatcd docs && npm run format && npm run lint && npm run buildcargo build --package trusted-server-adapter-fastly --release --target wasm32-wasip1Checklist
unwrap()added in production codeprintln!/eprintln!added