[GH-ISSUE #6643] [Bug] environment-compare loses submillisecond probe request order #4026

New issue

Closed

opened 2026-10-31 00:46:09 +00:00 by bsakaguchi · 0 comments

bsakaguchi commented

2026-10-31 00:46:09 +00:00

Owner

Originally created by @coygeek on GitHub (Oct 23, 2026).
Original GitHub issue: https://github.com/morluto/rea/issues/6643

Before submitting

I searched the open and closed issues for a related report.
I removed credentials, tokens, private paths, and sensitive target data.

Area

Evidence, artifacts, or reconstruction

Observed behavior

environment-compare replays two probe requests in file order when their distinct recorded start times fall within one millisecond. A synthetic probe lists a GET at fractional second .0002 before a DELETE at .0001; the comparator runs the GET first, returns the seeded entity instead of the recorded 404, and reports agreement 0.5. The same requests compare with agreement 1 when their timestamps differ by whole milliseconds, or when their file order already matches their submillisecond chronology.

Reproduction

Run from the source checkout identified below, with its locked dependencies and compiled runtime already built. This reduced case uses the repository's ordinary synthetic Evidence fixtures, then invokes the public CLI. It writes only temporary files and makes no network calls. The final block ran once per case; all three CLI invocations exited 0 with empty stderr.

repro=$(mktemp /tmp/rea-probe-order.XXXXXX.mts)
cat > "$repro" <<'JS'
import { mkdtempSync, writeFileSync } from 'node:fs';
import { tmpdir } from 'node:os';
import { join, resolve } from 'node:path';
import { pathToFileURL } from 'node:url';
import { spawnSync } from 'node:child_process';
const load = (path) => import(pathToFileURL(resolve(path)).href);
const { timedCaptureEvidence, analysisViewCaptureEvidence, environmentManifestCaptureFixture } = await load('tests/fixtures/analysisView.ts');
const { environmentStateServeFixture } = await load('tests/fixtures/environmentServe.ts');
const { FIRST_BOOK, BOOK_NOT_FOUND } = await load('tests/fixtures/environmentStateWrites.ts');
const root = mkdtempSync(join(tmpdir(), 'rea-probe-order-'));
const capture = timedCaptureEvidence([
 ['GET', '/api/books', [FIRST_BOOK]],
 ['GET', '/api/books/1', FIRST_BOOK],
 ['DELETE', '/api/books/1', '', 204],
 ['GET', '/api/books/1', BOOK_NOT_FOUND, 404],
]);
const fixture = environmentStateServeFixture(capture);
for (const [key, value] of Object.entries({ manifest: fixture.manifest, capture })) writeFileSync(join(root, `${key}.json`), JSON.stringify(value));
for (const [name, fractions] of [['subms', ['0002', '0001']], ['millis', ['002', '001']], ['chronological', ['0001', '0002']]]) {
 const rows = name === 'chronological' ? [['DELETE', '', 204], ['GET', BOOK_NOT_FOUND, 404]] : [['GET', BOOK_NOT_FOUND, 404], ['DELETE', '', 204]];
 const probe = analysisViewCaptureEvidence(environmentManifestCaptureFixture(rows.map(([method, body, status], index) => ({
  startedDateTime: `2026-10-17T18:00:00.${fractions[index]}Z`,
  request: { method, url: 'http://app.example/api/books/1' },
  response: { status, content: { mimeType: 'application/json', text: typeof body === 'string' ? body : JSON.stringify(body) } },
 }))));
 writeFileSync(join(root, `${name}-probe.json`), JSON.stringify(probe));
 const result = spawnSync(process.execPath, ['scripts/rea.mjs', 'environment-compare', join(root, 'manifest.json'), '--evidence', join(root, 'capture.json'), '--probe', join(root, `${name}-probe.json`), '--json'], { encoding: 'utf8', timeout: 30000 });
 writeFileSync(join(root, `${name}-stdout.json`), result.stdout);
 writeFileSync(join(root, `${name}-stderr.txt`), result.stderr);
 const report = JSON.parse(result.stdout);
 console.log(JSON.stringify({ name, exit: result.status, status: report.status, state: report.environment?.state, steps: report.summary?.steps, equal: report.summary?.equal, agreement: report.summary?.agreement, results: report.probes?.[0]?.results.map(({ ordinal, method, live_status, env_status, equal, categories }) => ({ ordinal, method, live_status, env_status, equal, categories })) }));
}
console.log(JSON.stringify({ evidenceDirectory: root }));
JS
mise exec node@24.22.1 -- node --import tsx "$repro"
rm "$repro"

The capture initializes one book, reads it, records its deletion, and confirms its absence. The failing probe contains only the later missing-item GET and the earlier DELETE. Both requests have valid recorded start times; no omitted-time fallback applies.

Expected behavior

Replay the earlier DELETE before the later GET, yielding statuses 204 and 404 and agreement 1. The comparison requirements require start-time order before ordinal order. The user documentation explicitly says timestamp ordering retains submillisecond precision when the source records it.

Impact and scope

The observed result falsely reports that an otherwise faithful served environment disagrees with its probe. Any state change whose ordering affects a later read can produce a misleading status/body difference when different start times collapse into the same millisecond and ordinals disagree with chronology. Only the reduced local DELETE/GET case was tested; real-capture frequency is unknown. A demonstrated workaround is to order the capture entries chronologically before producing the probe Evidence, preserving the original timestamps; the chronological control does this and reports agreement 1.

REA version

Source main at a281455f0b83c088ea30ebbb887398888ed167fb, declaring rea-agents 6.7.0. The compiled runtime from this checkout was executed; no published-package runtime claim is made.

Runtime and platform

Node.js v24.22.1 through the repository-pinned runtime; Linux 7.2.8-9-omarchy x86_64. No Hopper, Ghidra, browser provider, or external application was used.

Target and artifact context

Synthetic web-network-capture Evidence, its projected environment manifest, and three two-request probe captures. The fixture URL uses the reserved .example domain; it is never contacted.

Interface

CLI

Earliest failure stage

Native analysis or reconstruction

Relevant output or evidence

The exact reproduction prints these reduced public CLI results:

{"name":"subms","exit":0,"status":"complete","state":"served","steps":2,"equal":1,"agreement":0.5,"results":[{"ordinal":0,"method":"GET","live_status":404,"env_status":200,"equal":false,"categories":["status","missing-field","extra-field"]},{"ordinal":1,"method":"DELETE","live_status":204,"env_status":204,"equal":true,"categories":[]}]}
{"name":"millis","exit":0,"status":"complete","state":"served","steps":2,"equal":2,"agreement":1,"results":[{"ordinal":1,"method":"DELETE","live_status":204,"env_status":204,"equal":true,"categories":[]},{"ordinal":0,"method":"GET","live_status":404,"env_status":404,"equal":true,"categories":[]}]}
{"name":"chronological","exit":0,"status":"complete","state":"served","steps":2,"equal":2,"agreement":1,"results":[{"ordinal":0,"method":"DELETE","live_status":204,"env_status":204,"equal":true,"categories":[]},{"ordinal":1,"method":"GET","live_status":404,"env_status":404,"equal":true,"categories":[]}]}

Expected source: The linked comparison requirement orders requests by their recorded start time before ordinal; the linked user documentation preserves submillisecond timestamp ordering.
Failure source: The executed CLI result above runs ordinal 0 GET before ordinal 1 DELETE in subms, producing live 404 versus environment 200 and agreement 0.5; both controls produce agreement 1.
Evidence provenance: observed; results came from executing the public CLI against synthetic Evidence.
Local verification: reproduced.
Reproduction completeness: complete.

Typed outcome or recovery expected

A complete comparison whose subms results are ordered DELETE then GET, with summary.steps: 2, summary.equal: 2, and summary.agreement: 1.

Analysis or suspected cause

Source-derived mechanism: startedMs parses each start time with Date.parse, which reduces these distinct instants to the same millisecond. The ordering branch then breaks the resulting false tie by ordinal. This explains the observed reversal without requiring any live service or provider behavior.

Additional context

This differs from #6432: the missing-item body is a nonempty JSON object, and the chronological control compares that same 404 correctly. The failure is the order in which the environment receives the requests, before response comparison.

Restoration check: With the unchanged subms input, require DELETE ordinal 1 before GET ordinal 0, statuses 204/404, no differences, and agreement 1. Preserve agreement 1 for both controls. Also preserve the documented ordinal fallback when a start time is missing; that is a proposed regression check, not an executed result here. No source or implementation was changed.

Triage assessment

Impact level: P2
Assessment status: supported
Impact basis: The public comparison returns a false status/body disagreement and incorrect aggregate agreement for valid probe start times differing within one millisecond; the bounded defect has a demonstrated workaround.
Workaround status: available
Workaround basis: The executed chronological control preserves the original submillisecond instants, orders capture entries by those instants before Evidence creation, and reports agreement 1.

Originally created by @coygeek on GitHub (Oct 23, 2026). Original GitHub issue: https://github.com/morluto/rea/issues/6643 ## Before submitting - [x] I searched the open and closed issues for a related report. - [x] I removed credentials, tokens, private paths, and sensitive target data. ## Area Evidence, artifacts, or reconstruction ## Observed behavior `environment-compare` replays two probe requests in file order when their distinct recorded start times fall within one millisecond. A synthetic probe lists a GET at fractional second `.0002` before a DELETE at `.0001`; the comparator runs the GET first, returns the seeded entity instead of the recorded 404, and reports agreement 0.5. The same requests compare with agreement 1 when their timestamps differ by whole milliseconds, or when their file order already matches their submillisecond chronology. ## Reproduction Run from the source checkout identified below, with its locked dependencies and compiled runtime already built. This reduced case uses the repository's ordinary synthetic Evidence fixtures, then invokes the public CLI. It writes only temporary files and makes no network calls. The final block ran once per case; all three CLI invocations exited 0 with empty stderr. ```sh repro=$(mktemp /tmp/rea-probe-order.XXXXXX.mts) cat > "$repro" <<'JS' import { mkdtempSync, writeFileSync } from 'node:fs'; import { tmpdir } from 'node:os'; import { join, resolve } from 'node:path'; import { pathToFileURL } from 'node:url'; import { spawnSync } from 'node:child_process'; const load = (path) => import(pathToFileURL(resolve(path)).href); const { timedCaptureEvidence, analysisViewCaptureEvidence, environmentManifestCaptureFixture } = await load('tests/fixtures/analysisView.ts'); const { environmentStateServeFixture } = await load('tests/fixtures/environmentServe.ts'); const { FIRST_BOOK, BOOK_NOT_FOUND } = await load('tests/fixtures/environmentStateWrites.ts'); const root = mkdtempSync(join(tmpdir(), 'rea-probe-order-')); const capture = timedCaptureEvidence([ ['GET', '/api/books', [FIRST_BOOK]], ['GET', '/api/books/1', FIRST_BOOK], ['DELETE', '/api/books/1', '', 204], ['GET', '/api/books/1', BOOK_NOT_FOUND, 404], ]); const fixture = environmentStateServeFixture(capture); for (const [key, value] of Object.entries({ manifest: fixture.manifest, capture })) writeFileSync(join(root, `${key}.json`), JSON.stringify(value)); for (const [name, fractions] of [['subms', ['0002', '0001']], ['millis', ['002', '001']], ['chronological', ['0001', '0002']]]) { const rows = name === 'chronological' ? [['DELETE', '', 204], ['GET', BOOK_NOT_FOUND, 404]] : [['GET', BOOK_NOT_FOUND, 404], ['DELETE', '', 204]]; const probe = analysisViewCaptureEvidence(environmentManifestCaptureFixture(rows.map(([method, body, status], index) => ({ startedDateTime: `2026-10-17T18:00:00.${fractions[index]}Z`, request: { method, url: 'http://app.example/api/books/1' }, response: { status, content: { mimeType: 'application/json', text: typeof body === 'string' ? body : JSON.stringify(body) } }, })))); writeFileSync(join(root, `${name}-probe.json`), JSON.stringify(probe)); const result = spawnSync(process.execPath, ['scripts/rea.mjs', 'environment-compare', join(root, 'manifest.json'), '--evidence', join(root, 'capture.json'), '--probe', join(root, `${name}-probe.json`), '--json'], { encoding: 'utf8', timeout: 30000 }); writeFileSync(join(root, `${name}-stdout.json`), result.stdout); writeFileSync(join(root, `${name}-stderr.txt`), result.stderr); const report = JSON.parse(result.stdout); console.log(JSON.stringify({ name, exit: result.status, status: report.status, state: report.environment?.state, steps: report.summary?.steps, equal: report.summary?.equal, agreement: report.summary?.agreement, results: report.probes?.[0]?.results.map(({ ordinal, method, live_status, env_status, equal, categories }) => ({ ordinal, method, live_status, env_status, equal, categories })) })); } console.log(JSON.stringify({ evidenceDirectory: root })); JS mise exec node@24.22.1 -- node --import tsx "$repro" rm "$repro" ``` The capture initializes one book, reads it, records its deletion, and confirms its absence. The failing probe contains only the later missing-item GET and the earlier DELETE. Both requests have valid recorded start times; no omitted-time fallback applies. ## Expected behavior Replay the earlier DELETE before the later GET, yielding statuses 204 and 404 and agreement 1. The [comparison requirements](https://github.com/morluto/rea/blob/a281455f0b83c088ea30ebbb887398888ed167fb/docs/specs/agent-environments/fidelity-compare/spec.md#L24-L25) require start-time order before ordinal order. The [user documentation](https://github.com/morluto/rea/blob/a281455f0b83c088ea30ebbb887398888ed167fb/docs/agent-environments.md#L761) explicitly says timestamp ordering retains submillisecond precision when the source records it. ## Impact and scope The observed result falsely reports that an otherwise faithful served environment disagrees with its probe. Any state change whose ordering affects a later read can produce a misleading status/body difference when different start times collapse into the same millisecond and ordinals disagree with chronology. Only the reduced local DELETE/GET case was tested; real-capture frequency is unknown. A demonstrated workaround is to order the capture entries chronologically before producing the probe Evidence, preserving the original timestamps; the `chronological` control does this and reports agreement 1. ## REA version Source `main` at `a281455f0b83c088ea30ebbb887398888ed167fb`, declaring rea-agents 6.7.0. The compiled runtime from this checkout was executed; no published-package runtime claim is made. ## Runtime and platform Node.js v24.22.1 through the repository-pinned runtime; Linux 7.2.8-9-omarchy x86_64. No Hopper, Ghidra, browser provider, or external application was used. ## Target and artifact context Synthetic web-network-capture Evidence, its projected environment manifest, and three two-request probe captures. The fixture URL uses the reserved `.example` domain; it is never contacted. ## Interface CLI ## Earliest failure stage Native analysis or reconstruction ## Relevant output or evidence The exact reproduction prints these reduced public CLI results: ```json {"name":"subms","exit":0,"status":"complete","state":"served","steps":2,"equal":1,"agreement":0.5,"results":[{"ordinal":0,"method":"GET","live_status":404,"env_status":200,"equal":false,"categories":["status","missing-field","extra-field"]},{"ordinal":1,"method":"DELETE","live_status":204,"env_status":204,"equal":true,"categories":[]}]} {"name":"millis","exit":0,"status":"complete","state":"served","steps":2,"equal":2,"agreement":1,"results":[{"ordinal":1,"method":"DELETE","live_status":204,"env_status":204,"equal":true,"categories":[]},{"ordinal":0,"method":"GET","live_status":404,"env_status":404,"equal":true,"categories":[]}]} {"name":"chronological","exit":0,"status":"complete","state":"served","steps":2,"equal":2,"agreement":1,"results":[{"ordinal":0,"method":"DELETE","live_status":204,"env_status":204,"equal":true,"categories":[]},{"ordinal":1,"method":"GET","live_status":404,"env_status":404,"equal":true,"categories":[]}]} ``` - Expected source: The linked comparison requirement orders requests by their recorded start time before ordinal; the linked user documentation preserves submillisecond timestamp ordering. - Failure source: The executed CLI result above runs ordinal 0 GET before ordinal 1 DELETE in `subms`, producing live 404 versus environment 200 and agreement 0.5; both controls produce agreement 1. - Evidence provenance: observed; results came from executing the public CLI against synthetic Evidence. - Local verification: reproduced. - Reproduction completeness: complete. ## Typed outcome or recovery expected A complete comparison whose `subms` results are ordered DELETE then GET, with `summary.steps: 2`, `summary.equal: 2`, and `summary.agreement: 1`. ## Analysis or suspected cause Source-derived mechanism: [startedMs](https://github.com/morluto/rea/blob/a281455f0b83c088ea30ebbb887398888ed167fb/src/application/environment/environmentCompareProbe.ts#L49-L52) parses each start time with `Date.parse`, which reduces these distinct instants to the same millisecond. The [ordering branch](https://github.com/morluto/rea/blob/a281455f0b83c088ea30ebbb887398888ed167fb/src/application/environment/environmentCompareProbe.ts#L119-L127) then breaks the resulting false tie by ordinal. This explains the observed reversal without requiring any live service or provider behavior. ## Additional context This differs from #6432: the missing-item body is a nonempty JSON object, and the chronological control compares that same 404 correctly. The failure is the order in which the environment receives the requests, before response comparison. Restoration check: With the unchanged `subms` input, require DELETE ordinal 1 before GET ordinal 0, statuses 204/404, no differences, and agreement 1. Preserve agreement 1 for both controls. Also preserve the documented ordinal fallback when a start time is missing; that is a proposed regression check, not an executed result here. No source or implementation was changed. ## Triage assessment - Impact level: P2 - Assessment status: supported - Impact basis: The public comparison returns a false status/body disagreement and incorrect aggregate agreement for valid probe start times differing within one millisecond; the bounded defect has a demonstrated workaround. - Workaround status: available - Workaround basis: The executed chronological control preserves the original submillisecond instants, orders capture entries by those instants before Evidence creation, and reports agreement 1.

bsakaguchi closed this issue

2026-10-31 00:46:09 +00:00

bsakaguchi referenced this issue

2026-10-31 01:11:04 +00:00

[PR #4026] [MERGED] fix(contracts): complete canonical mobile graph inventory examples #5999