diff --git a/changelog.d/835-viewport-escalation-reasons.md b/changelog.d/835-viewport-escalation-reasons.md index a5246d585..0fe8a1fbd 100644 --- a/changelog.d/835-viewport-escalation-reasons.md +++ b/changelog.d/835-viewport-escalation-reasons.md @@ -1,5 +1,7 @@ -- Voice viewport escalation now emits compact reason-code diagnostics without - recording tool payloads. The policy still prefers structured entity identity, - preserves the live point-and-ask crop added in #837, and does not add image - requests, change image retention or automatically widen visual scope. - This follows asturksever's #835 review; credit the #837 pointer-crop authors. +- The voice debug log now says why OpenAI Realtime did or did not get a + viewport screenshot or pointer crop. Each entity-context answer logs a + reason-coded decision and, when an image was due, one outcome under the same + id, so a crop that was dropped because the pointer went stale or the camera + moved is no longer counted as sent. What is captured, sent and kept is + unchanged, and no image data or user text is logged (kvnloo, manjunath22466, + #835). diff --git a/docs/CURRENT-STATE.md b/docs/CURRENT-STATE.md index 0c5d7e278..246993256 100644 --- a/docs/CURRENT-STATE.md +++ b/docs/CURRENT-STATE.md @@ -5774,6 +5774,7 @@ and unreachable upstream (502/504) separately from road geometry. - **Reliability**: tool-call dedupe (2.5s window across call/item/args keys); response-create queueing that respects active responses and defers follow-ups when the user starts speaking; per-tool follow-up instructions so the agent confirms only what actually happened (zoom confirms only on `ok=true`). - **Aircraft identity honesty:** “What is this aircraft?” reads callsign, operator, registration, type, and route only from the selected contact context. Missing operator, route, or type enrichment is named explicitly rather than silently omitted or inferred from the callsign. - **Diagnostics**: every client/server event is posted to `/api/realtime/debug-log` and appended to `.gev-logs/realtime-conversations.jsonl` (gitignored) with secret/image redaction; last 30 errors persist in `localStorage` (`gev-realtime-errors`); `window.__gevVoiceCommands.getDiagnostics()` in the console. + - **Visual-context escalation** (OpenAI Realtime): when a `get_entity_context` answer reaches the image step (its tool output was sent and the data channel is open), it logs one `viewport_context.decision` (`contextId`, `send`, `kind` `viewport` or `crop`, `reason`, `viewScale`). A send decision is followed by exactly one outcome with the same `contextId` and `kind`: `viewport_context.result` (`sent`, `data-channel-send-failed`) or `viewport_context.skipped`. Pointer-crop skips are `pointer-not-fresh`, `pointer-not-ground`, `pointer-off-screen`, `pointer-already-requested` (the same snapshot was already sent or is still being captured), `pointer-expired`, `pointer-pose-unknown` and `pose-changed`; dropped captures are `capture-unavailable`, `session-reset`, `superseded` (a newer request or turn), `channel-lost` and `frame-stale`; a step that throws closes the pair with `error` before the caller logs `viewport_context.failed`. `channel-closed` and the crop's `pointer-scale-not-useful` are defensive and not expected from the current caller. Payloads are static codes only, never image data, tool payloads or user text, and other tool results log nothing here. Gemini Live uses a different gate in `geminiSession.js` (no pointer crop, a 1 s throttle), which is not instrumented. - **Counting semantics ("near")** — a CONTRACT; new count-bearing tool work inherits it. Three honest numbers exist for one question: the Contacts cohort (250 km around the subject, what the panel shows), `analyst_query`'s count of _currently-loaded_ records for the requested scope, and the layer-wide loaded total in `coverage.layersQueried[].total`. They diverge legitimately — the flights layer loads by viewport, so after a camera dive the loaded set can hold a fraction of the cohort (field case: panel 42, analyst 8). The contract: 1. **Contacts ACTIVE** → "near / nearby / how many aircraft" means the **Contacts window** — the panel's numbers, spoken verbatim. Mechanism: `contactsWindow` (`{centeredOn, radiusKm, flights, military, vessels, complete}`), carried by both `analyst_query` and `get_current_view_state`, derived by `contactsWindowFromSnapshot()` from the same snapshot the panel renders so the two cannot drift. Voice filtering and follow-up memory use that immutable snapshot too. A cohort whose feed cannot answer reports `'unknown'`, never a confident zero; a cohort at the 20,000-row retention bound reports a lower bound. 2. **Contacts OFF** → "nearby" means **in view**; "near \" means a radius around that place. A radius query with Contacts active and no explicit centre is centred on the **active contact**, not the camera. diff --git a/src/voice/realtimeViewport.js b/src/voice/realtimeViewport.js index e35adefd2..89b9051f7 100644 --- a/src/voice/realtimeViewport.js +++ b/src/voice/realtimeViewport.js @@ -339,6 +339,16 @@ export function isBenignViewportDeleteError(payload, pendingDeleteIds = null) { return code === 'item_not_found'; } +/** Pairs one visual-context request's outcome with its decision. */ +function diagnosticsRecord(contextId = null) { + return { contextId, logged: false }; +} + +function reportOutcome(owner, diag, event, kind, reason) { + diag.logged = true; + owner.debugLog?.(event, { contextId: diag.contextId, kind, reason }); +} + /** Own the one retained viewport image and bounded pending deletion identities. */ export class RealtimeViewport { constructor({ @@ -359,6 +369,8 @@ export class RealtimeViewport { // Bumped by every capture request and every new user turn: only the // newest request of the current turn may publish. this.captureSeq = 0; + // Diagnostics only: pairs each visual-context decision with its outcome. + this.contextSeq = 0; this.lastPointerCrop = null; // What the retained image shows: `{kind:'viewport'|'crop', rect, cameraKey}`. // Pixel targeting (screenX/screenY) is read against it. @@ -370,24 +382,47 @@ export class RealtimeViewport { return this.readChannel(); } + /** + * Escalate an entity-context answer to an image when the gate allows it. + * Logs one `viewport_context.decision`, then, for a send decision, exactly + * one `.skipped` or `.result` outcome, even when a step throws. Every + * event carries the same `contextId` and the image `kind`, so overlapping + * requests pair up. + */ async sendVisualContextIfUseful(result) { - const channel = this.dc; + // Runs after every tool output. Only entity context can escalate, so + // other tools log nothing and leave the shared debug-log budget alone. + if (result?.action !== 'get_entity_context') return false; + const contextId = ++this.contextSeq; const decision = viewportContextDecision(result, { - channelOpen: channel?.readyState === 'open', + channelOpen: this.dc?.readyState === 'open', }); - this.debugLog?.('viewport_context.decision', decision); + this.debugLog?.('viewport_context.decision', { contextId, ...decision }); if (!decision.send) return false; - // #837's pointer crop is separate from the full viewport: preserve it. - if (decision.kind === 'crop') - return this.sendPointerCrop(this.readPointer(), { - viewScale: decision.viewScale, - }); - return this.sendRetainedImage( - () => this.capture(), - "Current God's Eye View viewport screenshot. Read any clearly visible street, building, and place labels in the image and combine them with the structured nearbyPlaces, streetLabels, and scene context. Do not invent labels that are not legible.", - 'client.viewport_context', - { kind: 'viewport' }, - ); + const diag = diagnosticsRecord(contextId); + try { + // #837's pointer crop is separate from the full viewport: preserve it. + if (decision.kind === 'crop') + return await this.sendPointerCrop(this.readPointer(), { + viewScale: decision.viewScale, + diag, + }); + return await this.sendRetainedImage( + () => this.capture(), + "Current God's Eye View viewport screenshot. Read any clearly visible street, building, and place labels in the image and combine them with the structured nearbyPlaces, streetLabels, and scene context. Do not invent labels that are not legible.", + 'client.viewport_context', + { kind: 'viewport', diag }, + ); + } catch (error) { + // The caller logs the error itself; close the pair, then rethrow. + if (!diag.logged) + this.debugLog?.('viewport_context.skipped', { + contextId, + kind: decision.kind, + reason: 'error', + }); + throw error; + } } /** A new user turn: captures still in flight from the last one are dropped. */ @@ -401,27 +436,39 @@ export class RealtimeViewport { * @param {object|null} snapshot Fresh pointer snapshot on bare ground. * @returns {Promise} */ - async sendPointerCrop(snapshot, { viewScale } = {}) { - if (!snapshot?.fresh || snapshot.target !== 'ground' || !snapshot.screenPx) + async sendPointerCrop( + snapshot, + { viewScale, diag = diagnosticsRecord() } = {}, + ) { + const skip = (reason) => { + reportOutcome(this, diag, 'viewport_context.skipped', 'crop', reason); return false; + }; + if (!snapshot?.fresh) return skip('pointer-not-fresh'); + if (snapshot.target !== 'ground') return skip('pointer-not-ground'); + if (!snapshot.screenPx) return skip('pointer-off-screen'); // Too far out, the crop is a smear: every path shares this guard. - if (!POINTER_CROP_SCALES.has(viewScale)) return false; - if (snapshot === this.lastPointerCrop) return false; + if (!POINTER_CROP_SCALES.has(viewScale)) + return skip('pointer-scale-not-useful'); + // Set before the capture finishes, so this also covers one in flight. + if (snapshot === this.lastPointerCrop) + return skip('pointer-already-requested'); const capturedAt = Number(snapshot.capturedAt) || 0; - if (this.now() - capturedAt > POINTER_CROP_MAX_AGE_MS) return false; + if (this.now() - capturedAt > POINTER_CROP_MAX_AGE_MS) + return skip('pointer-expired'); // The snapshot's pixels only name its own camera pose. const snapshotCameraKey = snapshot.cameraKey; - if (!snapshotCameraKey) return false; + if (!snapshotCameraKey) return skip('pointer-pose-unknown'); const samePose = () => snapshotCameraKey === this.readCameraKey() && this.now() - capturedAt <= POINTER_CROP_MAX_AGE_MS; - if (!samePose()) return false; + if (!samePose()) return skip('pose-changed'); this.lastPointerCrop = snapshot; const sent = await this.sendRetainedImage( () => this.capturePointer(snapshot.screenPx), "Crop of the map around the user's pointer; the ring marks the exact spot they mean by this or here. Describe only what is clearly visible.", 'client.pointer_crop', - { kind: 'crop', valid: samePose }, + { kind: 'crop', valid: samePose, diag }, ); if (!sent && this.lastPointerCrop === snapshot) this.lastPointerCrop = null; return sent; @@ -429,7 +476,14 @@ export class RealtimeViewport { /** Capture one image and make it the single retained image in context. */ async sendRetainedImage(captureImage, text, label, frame = {}) { - if (!this.dc || this.dc.readyState !== 'open') return false; + const kind = frame.kind || 'viewport'; + const diag = frame.diag || diagnosticsRecord(); + const report = (event, reason) => + reportOutcome(this, diag, event, kind, reason); + if (!this.dc || this.dc.readyState !== 'open') { + report('viewport_context.skipped', 'channel-closed'); + return false; + } const generation = this.generation; const request = ++this.captureSeq; const channel = this.dc; @@ -437,21 +491,23 @@ export class RealtimeViewport { const imageUrl = typeof captured === 'string' ? captured : captured?.dataUrl || null; if (!imageUrl) { - this.debugLog?.('viewport_context.skipped', { - reason: 'capture-unavailable', - }); + report('viewport_context.skipped', 'capture-unavailable'); return false; } - if ( - generation !== this.generation || - request !== this.captureSeq || - this.dc !== channel || - channel.readyState !== 'open' || - (typeof frame.valid === 'function' && !frame.valid()) - ) { - this.debugLog?.('viewport_context.skipped', { - reason: 'capture-invalidated', - }); + // Same guards as before, checked in order so each drop names its cause: + // reset() bumps both counters, so a session reset is tested first. + const invalidated = + generation !== this.generation + ? 'session-reset' + : request !== this.captureSeq + ? 'superseded' + : this.dc !== channel || channel.readyState !== 'open' + ? 'channel-lost' + : typeof frame.valid === 'function' && !frame.valid() + ? 'frame-stale' + : null; + if (invalidated) { + report('viewport_context.skipped', invalidated); return false; } @@ -509,14 +565,15 @@ export class RealtimeViewport { this.lastViewportItemId = sent ? newItemId : null; this.retainedFrame = sent ? { - kind: frame.kind || 'viewport', + kind, rect: captured?.rect || null, cameraKey: this.readCameraKey(), } : null; - this.debugLog?.('viewport_context.result', { - reason: sent ? 'sent' : 'data-channel-send-failed', - }); + report( + 'viewport_context.result', + sent ? 'sent' : 'data-channel-send-failed', + ); return sent; } diff --git a/src/voice/realtimeViewportPolicy.test.mjs b/src/voice/realtimeViewportPolicy.test.mjs index 0d679559f..57a60a13d 100644 --- a/src/voice/realtimeViewportPolicy.test.mjs +++ b/src/voice/realtimeViewportPolicy.test.mjs @@ -229,7 +229,7 @@ test('capture failures and invalidated turns are reason-coded without sending', diagnostics.some( (item) => item.event === 'viewport_context.skipped' && - item.detail.reason === 'capture-invalidated', + item.detail.reason === 'session-reset', ), ); }); @@ -256,3 +256,283 @@ test('successful retained send is logged without recording image contents', asyn ); assert.equal(JSON.stringify(diagnostics).includes('data:image/jpeg'), false); }); + +const outcomeEvents = new Set([ + 'viewport_context.skipped', + 'viewport_context.result', +]); + +function recordingViewport(options = {}) { + const events = []; + const channel = options.channel ?? { readyState: 'open' }; + const viewport = new RealtimeViewport({ + readChannel: () => channel, + readCameraKey: () => 'camera:fixture', + now: () => 1000, + capturePointer: async () => ({ + dataUrl: 'data:image/jpeg;base64,AA==', + rect: { x: 0, y: 0, width: 1, height: 1 }, + }), + capture: async () => 'data:image/jpeg;base64,AA==', + ...options, + operations: { + sendRealtimeEvent: () => true, + debugLog: (event, detail) => events.push({ event, detail }), + ...options.operations, + }, + }); + return { viewport, events }; +} + +const pointerGround = (overrides = {}) => + localContext({ + scope: 'pointer', + pointer: { target: 'ground' }, + scene: { basemap: { viewScale: 'city' } }, + ...overrides, + }); + +const groundSnapshot = (overrides = {}) => ({ + fresh: true, + target: 'ground', + screenPx: { x: 10, y: 10 }, + capturedAt: 900, + cameraKey: 'camera:fixture', + ...overrides, +}); + +test('tool results other than entity context log nothing', async () => { + const { viewport, events } = recordingViewport(); + assert.equal( + await viewport.sendVisualContextIfUseful({ action: 'fly_to' }), + false, + ); + assert.equal(await viewport.sendVisualContextIfUseful(null), false); + assert.deepEqual(events, []); +}); + +test('a crop decision that cannot send logs why, under the same id', async () => { + const cases = [ + [{ fresh: false }, 'pointer-not-fresh'], + [{ target: 'building' }, 'pointer-not-ground'], + [{ screenPx: null }, 'pointer-off-screen'], + [{ capturedAt: -50000 }, 'pointer-expired'], + [{ cameraKey: null }, 'pointer-pose-unknown'], + [{ cameraKey: 'camera:moved' }, 'pose-changed'], + ]; + for (const [override, reason] of cases) { + const snapshot = groundSnapshot(override); + const { viewport, events } = recordingViewport({ + readPointer: () => snapshot, + }); + assert.equal( + await viewport.sendVisualContextIfUseful(pointerGround()), + false, + reason, + ); + assert.equal(events.length, 2, reason); + const [decision, outcome] = events; + assert.equal(decision.event, 'viewport_context.decision'); + assert.equal(decision.detail.reason, 'pointer-ground-crop'); + assert.deepEqual(outcome, { + event: 'viewport_context.skipped', + detail: { contextId: decision.detail.contextId, kind: 'crop', reason }, + }); + } +}); + +test('a repeated pointer snapshot is logged as already requested', async () => { + const snapshot = groundSnapshot(); + const { viewport, events } = recordingViewport({ + readPointer: () => snapshot, + }); + assert.equal(await viewport.sendVisualContextIfUseful(pointerGround()), true); + assert.equal( + await viewport.sendVisualContextIfUseful(pointerGround()), + false, + ); + const outcomes = events.filter((item) => outcomeEvents.has(item.event)); + assert.deepEqual( + outcomes.map((item) => [item.detail.kind, item.detail.reason]), + [ + ['crop', 'sent'], + ['crop', 'pointer-already-requested'], + ], + ); +}); + +test('overlapping requests pair each outcome with its own decision', async () => { + const releases = []; + const { viewport, events } = recordingViewport({ + capture: () => new Promise((resolve) => releases.push(resolve)), + }); + const first = viewport.sendVisualContextIfUseful(localContext()); + const second = viewport.sendVisualContextIfUseful(localContext()); + await Promise.resolve(); + releases[1]('data:image/jpeg;base64,AA=='); + releases[0]('data:image/jpeg;base64,AA=='); + assert.equal(await first, false); + assert.equal(await second, true); + const [firstId, secondId] = events + .filter((item) => item.event === 'viewport_context.decision') + .map((item) => item.detail.contextId); + assert.notEqual(firstId, secondId); + const outcomeFor = (id) => + events.filter( + (item) => outcomeEvents.has(item.event) && item.detail.contextId === id, + ); + assert.deepEqual( + outcomeFor(firstId).map((item) => item.detail), + [{ contextId: firstId, kind: 'viewport', reason: 'superseded' }], + ); + assert.deepEqual( + outcomeFor(secondId).map((item) => item.detail), + [{ contextId: secondId, kind: 'viewport', reason: 'sent' }], + ); +}); + +test('dropped captures name their cause', async () => { + const reasonFor = async (context, interrupt, extra = {}) => { + let release; + const pending = () => new Promise((resolve) => (release = resolve)); + const { viewport, events } = recordingViewport({ + capture: pending, + capturePointer: pending, + ...extra, + }); + const sent = viewport.sendVisualContextIfUseful(context); + await Promise.resolve(); + interrupt(viewport); + release('data:image/jpeg;base64,AA=='); + assert.equal(await sent, false); + return events + .filter((item) => outcomeEvents.has(item.event)) + .map((item) => item.detail.reason); + }; + + assert.deepEqual( + await reasonFor(localContext(), (viewport) => viewport.beginTurn()), + ['superseded'], + ); + assert.deepEqual( + await reasonFor(localContext(), (viewport) => viewport.reset()), + ['session-reset'], + ); + const channel = { readyState: 'open' }; + assert.deepEqual( + await reasonFor(localContext(), () => (channel.readyState = 'closed'), { + channel, + }), + ['channel-lost'], + ); + let cameraKey = 'camera:fixture'; + const snapshot = groundSnapshot(); + assert.deepEqual( + await reasonFor(pointerGround(), () => (cameraKey = 'camera:moved'), { + readPointer: () => snapshot, + readCameraKey: () => cameraKey, + }), + ['frame-stale'], + ); +}); + +test('every send decision is followed by exactly one outcome', async () => { + const snapshots = [ + null, + groundSnapshot(), + groundSnapshot({ fresh: false }), + groundSnapshot({ cameraKey: 'camera:moved' }), + groundSnapshot({ capturedAt: -50000 }), + ]; + const contexts = [ + localContext(), + localContext({ selected: { id: 'x', layerId: 'y' } }), + pointerGround(), + pointerGround({ scene: { basemap: { viewScale: 'global' } } }), + pointerGround({ pointer: null }), + ]; + const captures = [ + async () => 'data:image/jpeg;base64,AA==', + async () => null, + ]; + for (const snapshot of snapshots) + for (const context of contexts) + for (const capture of captures) + for (const sendResult of [true, false]) { + const { viewport, events } = recordingViewport({ + readPointer: () => snapshot, + capture, + capturePointer: capture, + operations: { sendRealtimeEvent: () => sendResult }, + }); + await viewport.sendVisualContextIfUseful(context); + const [decision, ...rest] = events; + assert.equal(decision.event, 'viewport_context.decision'); + const outcomes = rest.filter((item) => outcomeEvents.has(item.event)); + assert.equal(outcomes.length, decision.detail.send ? 1 : 0); + for (const outcome of outcomes) { + assert.equal(outcome.detail.contextId, decision.detail.contextId); + assert.equal(outcome.detail.kind, decision.detail.kind); + if (outcome.event === 'viewport_context.result') + assert.equal( + outcome.detail.reason, + sendResult ? 'sent' : 'data-channel-send-failed', + ); + } + } +}); + +test('a failed data-channel send is never logged as sent', async () => { + for (const [sendResult, reason] of [ + [true, 'sent'], + [false, 'data-channel-send-failed'], + ]) { + const { viewport, events } = recordingViewport({ + operations: { sendRealtimeEvent: () => sendResult }, + }); + assert.equal( + await viewport.sendVisualContextIfUseful(localContext()), + sendResult, + ); + const outcomes = events.filter((item) => outcomeEvents.has(item.event)); + assert.deepEqual( + outcomes.map((item) => [item.event, item.detail.reason]), + [['viewport_context.result', reason]], + ); + } +}); + +test('a step that throws still closes its decision, then rethrows', async () => { + for (const [context, extra] of [ + [ + localContext(), + { + capture: async () => { + throw new Error('capture boom'); + }, + }, + ], + [ + pointerGround(), + { + readPointer: () => { + throw new Error('pointer boom'); + }, + }, + ], + ]) { + const { viewport, events } = recordingViewport(extra); + await assert.rejects(viewport.sendVisualContextIfUseful(context), /boom/); + const [decision, ...rest] = events; + assert.deepEqual(rest, [ + { + event: 'viewport_context.skipped', + detail: { + contextId: decision.detail.contextId, + kind: decision.detail.kind, + reason: 'error', + }, + }, + ]); + } +});