fix(voice): make viewport escalation diagnostics truthful and paired

Review follow-up for #835. What is captured, sent and kept is unchanged.

- Log nothing for tool results other than get_entity_context, so other
  tools stop spending the shared debug-log budget.
- Give every decision and outcome the same contextId and image kind, so
  overlapping requests pair up.
- Log why a crop decision did not send (stale, off ground, off screen,
  expired, pose changed, already requested) instead of leaving a lone
  "pointer-ground-crop" that reads as sent.
- Split capture-invalidated into session-reset, superseded, channel-lost
  and frame-stale.
- Close the pair with "error" when a step throws, then rethrow.
- Document the events in CURRENT-STATE and reword the changelog fragment.

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<boolean>}
    */
-  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;
   }
 

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',
+        },
+      },
+    ]);
+  }
+});