harness(rg3): fix K2 baseline block-skip race + empty-string MOCK_TRACE guard (#169)

* harness(rg3): fix K2 baseline block-skip race (per-connection stream cursor)

The K2 baseline (turnDelayMs:450) aborted at K2-midstream: the mock's /stream
delivered 100→101→103, skipping 102, so the product correctly fataled on a
corrupt sequence (portal-realtime.ts:1101 "unknown parent").

Root cause (mock artifact, NOT a product bug): handleBlocks iterated block
numbers off a MODULE-LEVEL `streamCursor`. K2's 450ms inter-block delay lets the
client open an overlapping /stream (a legitimate reconnect on the finalized-head
advancing 100→103 mid-stream). Two concurrent handleBlocks turns then read+wrote
the one shared cursor across their delays and interleaved: conn1 wrote 102 and
set cursor=102, conn2 woke, read cursor=102 and wrote 103 — skipping 102 on
conn2, the connection the client consumed. Fast classes (K3) never hit it: the
window is too small to overlap. Confirmed via MOCK_TRACE request-interleave.

Fix: seed a per-connection `localCursor` from the request's fromBlock and do all
per-block arithmetic against it; a real Portal serves each /stream connection
independently. The shared `streamCursor` is still mirrored best-effort for the
fromBlock-less default of a subsequent request. Also adds MOCK_TRACE-gated
(no-op when unset) request/cursor tracing for future harness debugging.

No product code under portal/ is touched.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>

* harness(rg3): treat empty-string MOCK_TRACE as tracing-off

orchestrate.sh forwards MOCK_TRACE via `${MOCK_TRACE:-}`, so a caller that
never sets it (the acceptance capstone) reaches node as an empty string, not
undefined. The `=== undefined` guard let that empty value through to
appendFileSync(''), which throws ENOENT — returned as a 500 on the very first
/finalized-head probe and surfacing as a spurious "cannot establish finality
boundary" fatal on every non-tracing run (i.e. the whole capstone). Guard on
`!TRACE_FILE` so unset and empty both mean off; a real trace path is unaffected.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>

---------

Co-authored-by: Claude Opus 4.8 <noreply@anthropic.com>

Author: dzhelezov

harness/chaos/realtime/mock-portal.mjs

@@ -37,6 +37,22 @@ export const DEFAULT_SCENARIO = {
   ],
 };
 
+const TRACE_FILE = process.env.MOCK_TRACE;
+let TRACE_CONN = 0;
+const trace = (msg, extra) => {
+  // Treat unset AND empty-string as "tracing off". orchestrate.sh forwards MOCK_TRACE via
+  // `${MOCK_TRACE:-}`, so an unset caller (e.g. the acceptance capstone) reaches node as an empty
+  // string, not undefined. A bare `=== undefined` guard let that empty value through to
+  // appendFileSync(''), which throws ENOENT — surfacing as a 500 on the very first /finalized-head
+  // probe and a spurious "cannot establish finality boundary" fatal for every non-tracing run.
+  if (!TRACE_FILE) return;
+
+  const line = `${new Date().toISOString()} ${msg}${
+    extra === undefined ? '' : ` ${JSON.stringify(extra)}`
+  }\n`;
+  appendFileSync(TRACE_FILE, line);
+};
+
 const isPlainObject = (value) =>
   value !== null && typeof value === 'object' && Array.isArray(value) === false;
 
@@ -646,6 +662,12 @@ export function createRuntime(initialScenario, options = {}) {
       scenario.finalizedHeadSeq[
         Math.min(finalizedIndex, scenario.finalizedHeadSeq.length - 1)
       ] ?? scenario.finalizedHeadSeq[0];
+    trace('finalizedHead:request', {
+      finalizedIndex,
+      headNumber: head?.number,
+      streamCursor,
+      stepIndex,
+    });
     const phase = gatePhaseForBlock(scenario, head.number);
     if (phase !== undefined) {
       stats.finalizedHeadGates += 1;
@@ -670,6 +692,13 @@ export function createRuntime(initialScenario, options = {}) {
 
   const finalizedStream = async (body, res) => {
     recordRequest('finalizedStream', body);
+    trace('finalizedStream:request', {
+      fromBlock: body?.fromBlock,
+      toBlock: body?.toBlock,
+      finalizedIndex,
+      streamCursor,
+      stepIndex,
+    });
     const from = Number(body?.fromBlock ?? scenario.genesis.number);
     const head = scenario.finalizedHeadSeq[
       Math.max(
@@ -797,14 +826,39 @@ export function createRuntime(initialScenario, options = {}) {
   };
 
   const handleBlocks = async (step, body, res) => {
+    TRACE_CONN += 1;
+    const conn = TRACE_CONN;
     const requestFrom = Number(body?.fromBlock ?? streamCursor + 1);
-    streamCursor = requestFrom - 1;
-    const firstNumber = streamCursor + 1;
+    trace('handleBlocks:enter', {
+      conn,
+      fromBlock: body?.fromBlock,
+      requestFrom,
+      streamCursorBefore: streamCursor,
+      stepIndex,
+      finalizedIndex,
+    });
+    // Per-connection cursor. The block-number arithmetic MUST NOT read the shared module-level
+    // `streamCursor`: a slow step (turnDelayMs) lets the client open an overlapping /stream (e.g. on a
+    // finalized-head advance), and two concurrent handleBlocks turns reading+writing one shared cursor
+    // interleave into a skipped block number (100→101→103) that the product rightly fatals on. A real
+    // Portal serves each /stream connection independently from its own fromBlock, so seed a LOCAL cursor
+    // here and only mirror it back to the shared one (best-effort, for the fromBlock-less default of the
+    // NEXT request) after each write.
+    let localCursor = requestFrom - 1;
+    streamCursor = localCursor;
+    const firstNumber = localCursor + 1;
 
     res.writeHead(200, { 'content-type': 'application/x-ndjson' });
     const count = Math.max(0, Number(step.count ?? 0));
     for (let i = 0; i < count; i++) {
-      const number = streamCursor + 1;
+      const number = localCursor + 1;
+      trace('handleBlocks:writeStart', {
+        conn,
+        number,
+        localCursor,
+        streamCursor,
+        finalizedIndex,
+      });
       const phase = gatePhaseForBlock(step, number);
       if (phase !== undefined) {
         const open = await gate(
@@ -833,8 +887,16 @@ export function createRuntime(initialScenario, options = {}) {
           logs: logsForBlock(step, number),
         }),
       );
+      localCursor = number;
       streamCursor = number;
+      trace('handleBlocks:wrote', { conn, number, localCursor, streamCursor });
       await streamTurnDelay(turnDelayForStep(step));
+      trace('handleBlocks:afterDelay', {
+        conn,
+        wroteNumber: number,
+        localCursor,
+        streamCursorNow: streamCursor,
+      });
       if (res.destroyed || res.writableEnded) return;
     }
     stepIndex += 1;
@@ -1016,6 +1078,13 @@ export function createRuntime(initialScenario, options = {}) {
 
   const stream = async (body, res) => {
     recordRequest('stream', body);
+    trace('stream:request', {
+      fromBlock: body?.fromBlock,
+      parentBlockHash: body?.parentBlockHash,
+      streamCursor,
+      stepIndex,
+      finalizedIndex,
+    });
     observeWrongForkStreamRequest(body);
     const step = scenario.steps[stepIndex];
     if (step === undefined) {

harness/chaos/realtime/orchestrate.sh

@@ -203,7 +203,7 @@ start_mock () {
   local mock_log="$3"
   local killat_block="${4:-}"
   MOCK_PHASE_LOG="$phase_log" MOCK_SCENARIO="$scenario" MOCK_PORT="$MOCK_PORT" \
-  MOCK_KILLAT_BLOCK="$killat_block" \
+  MOCK_KILLAT_BLOCK="$killat_block" MOCK_TRACE="${MOCK_TRACE:-}" \
     node "$CDIR/mock-portal.mjs" >"$mock_log" 2>&1 &
   MOCK_PID="$!"
   wait_http || {