test(#3395): pin the clock and scope the stale-prose scan that reddened windows shard 2/3 (#3669)

* test(#3395): failing-first coverage for the silently-ignored clock pin

Lands the regression matrix BEFORE the fix so the failure is proven rather than asserted. Three assertions fail deterministically on this commit:

1. PINNED_ENV does not actually pin. `_pinnedNowMs()` (src/clock.cts) returns null unless GSD_TEST_MODE is set, so GSD_NOW_MS alone is discarded and last_updated is stamped from the live wall clock. An instant ending ...:35.149Z contains the substring 35.1, which is what reddens the windows-latest shard 2/3 lane roughly 1 run in 600.

2. The colliding-instant regression cannot reach its instant, for the same reason.

3. The #3052 same-date test never lands on 2020-09-10, so it has been exercising the different-date path and passing for the wrong reason.

Also adds currentPositionBlock() plus boundary (ms 099/100/199/200, second 34/35/36, LF and CRLF) and two-arm fast-check coverage for the scoped read the fix will switch to.

Refs #3395

* test(#3395): pin the clock and scope the stale-prose scan to the body

Drives the failing-first coverage from a5a919ffb green. Two changes, both needed:

1. PINNED_ENV now sets GSD_TEST_MODE alongside GSD_NOW_MS. _pinnedNowMs() (src/clock.cts:44) returns null without it, so the pin was silently discarded and last_updated carried a live wall-clock instant. src/clock.cts is deliberately NOT changed: requiring both keys is what stops an ambient GSD_NOW_MS from freezing a production clock, so the caller was the side that was wrong.

2. The stale-prose assertion now reads currentPositionBlock(stateContent) instead of the whole document. Frontmatter is not phase prose, and an instant ending ...:35.149Z contains the substring 35.1 — which is exactly how a document with no stale prose in it produced 'the stale 35.1 phase prose must be refreshed away'.

Confirmed hypothesis: the two defects compose. The inert pin supplies a live timestamp; the whole-document scan turns it into a failure. Either alone is latent, which is why this sat unnoticed for five days and then reddened a lane the release never touched.

Also corrects two things the failing-first run exposed. The property test used fc.date() without noInvalidDate, so ~1 sample in 300 was an Invalid Date whose toISOString() threw (counterexample: new Date(NaN)); re-soaked at 5000 runs. And a precondition assertion added to the #3052 block was measured to pass with or without the pin, so it was removed rather than shipped as vacuous truth — last_activity there is body-derived, not clock-derived.

Refs #3395

* test(#3395): apply review findings — pin #3052, one fixture builder, CRLF coverage

Spec-axis review caught a real slip: the #3052 block carried a comment saying its pin was being added as hygiene, but the RED-state revert had removed GSD_TEST_MODE and the fix commit never restored it. A comment describing an action that was not taken is worse than either doing it or leaving it alone — the pin is now actually there.

Standards-axis review flagged the same frontmatter+heading fixture shape being rebuilt in three tests. Extracted one stateDoc({iso, lines, eol}) builder; eol is a parameter rather than a constant because the helper's CRLF behavior is a claim under test.

Self-review finding: CRLF was only exercised on a single-heading document, and the following-heading case only under LF — so the exact claim the helper's comment rests on (`\n## ` matches inside `\r\n## ` because the CR precedes the newline) was never actually run. The control test now loops both line endings WITH a following heading.

Also drops a comment that restated the PINNED_INSTANT rationale verbatim.

Refs #3395

---------

Co-authored-by: sim <sim@local>
This commit is contained in:
Tom Boucher
2026-08-19 11:25:24 -04:00
committed by GitHub
parent cd22667b27
commit 8d1f770dfe

View File

@@ -3661,10 +3661,17 @@ describe('#3052: planned-phase preserves same-date last_activity_desc', () => {
].join('\n'),
);
// GSD_TEST_MODE is required alongside GSD_NOW_MS or the pin is silently dropped
// (src/clock.cts `_pinnedNowMs`). Measured: this test's `last_activity` is derived
// from the BODY's `**Last Activity:**` line, so the same-date branch it exercises is
// reached either way — only `last_updated` was being stamped from the live wall
// clock. Pinning it is hygiene rather than a live-defect fix: a declared pin that
// silently does nothing is still wrong, and leaving it here teaches the pattern that
// put a wall-clock timestamp into the #3395 block below.
const result = runGsdTools(
['state', 'planned-phase', '--phase', '1', '--plans', '3'],
tmpDir,
{ GSD_NOW_MS: String(Date.parse('2020-09-10T15:00:00.000Z')) },
{ GSD_TEST_MODE: '1', GSD_NOW_MS: String(Date.parse('2020-09-10T15:00:00.000Z')) },
);
assert.ok(result.success, `Command failed: ${result.error}`);
@@ -3702,13 +3709,49 @@ describe('#3395: planned-phase refreshes the stale Phase line and persists --nam
cleanup(tmpDir);
});
const PINNED_ENV = { GSD_NOW_MS: String(Date.parse('2026-08-14T15:00:00.000Z')) };
// GSD_TEST_MODE is load-bearing here, not decoration. `_pinnedNowMs()` (src/clock.cts)
// opens with `if (!process.env.GSD_TEST_MODE) return null;`, so GSD_NOW_MS ALONE is
// silently discarded and every `last_updated` below is stamped from the live wall clock
// instead. That is what put a real timestamp into a document this block asserts over,
// and an instant ending `...:35.149Z` contains the substring `35.1` — reddening
// `full test (windows-latest, 24, shard 2/3)` about 1 run in 600 (second == 35 AND
// millisecond in 100..199). The pin is what makes that window unreachable; scoping the
// assertion to `## Current Position` below is what makes it HARMLESS even when a pinned
// value does collide. Both are needed: either alone leaves the defect latent.
const PINNED_INSTANT = '2026-08-14T15:00:00.000Z';
const PINNED_ENV = { GSD_TEST_MODE: '1', GSD_NOW_MS: String(Date.parse(PINNED_INSTANT)) };
// An instant chosen to sit INSIDE that collision window on purpose, so the regression
// below reproduces the CI failure deterministically instead of 1-in-600.
const COLLIDING_INSTANT = '2026-08-14T15:00:35.149Z';
const COLLIDING_ENV = { GSD_TEST_MODE: '1', GSD_NOW_MS: String(Date.parse(COLLIDING_INSTANT)) };
function frontmatterBlock(stateContent) {
const m = stateContent.match(/^---\r?\n([\s\S]*?)\r?\n---/);
return m ? m[1] : '';
}
// `## Current Position` is the body prose #3395 is about — the source `state json`
// re-derives current_phase from. Frontmatter is NOT phase prose: `last_updated`,
// `last_activity` and friends legitimately carry digit runs that can spell a phase id,
// so scanning the WHOLE document for a stale id reports staleness that does not exist.
// indexOf rather than a regex: nothing for local/no-unbounded-quantifier to flag, and
// `\n## ` still matches under CRLF because the `\r` precedes the newline.
function currentPositionBlock(stateContent) {
const start = stateContent.indexOf('## Current Position');
if (start === -1) return '';
const rest = stateContent.slice(start);
const nextHeading = rest.indexOf('\n## ', 1);
return nextHeading === -1 ? rest : rest.slice(0, nextHeading);
}
// One builder for every synthetic STATE.md below — the frontmatter + heading shape was
// being rebuilt independently in three tests. `eol` is a parameter because the CRLF
// behavior of currentPositionBlock is a claim under test, not an assumption.
function stateDoc({ iso = PINNED_INSTANT, lines = [], eol = '\n' }) {
return ['---', `last_updated: "${iso}"`, '---', '', '## Current Position', '', ...lines, ''].join(eol);
}
// The issue's repro shape: frontmatter already carries the correct decimal
// sub-phase, but the body's `## Current Position` still describes the
// PREVIOUS phase's completion prose.
@@ -3748,8 +3791,8 @@ describe('#3395: planned-phase refreshes the stale Phase line and persists --nam
// The stale body source must not survive the transition that just
// declared 35.3 planned — it is the source every body-derived consumer
// (state json included) re-reads.
assert.ok(!stateContent.includes('35.1'),
`the stale 35.1 phase prose must be refreshed away; STATE.md was:\n${stateContent}`);
assert.ok(!currentPositionBlock(stateContent).includes('35.1'),
`the stale 35.1 phase prose must be refreshed away from ## Current Position; STATE.md was:\n${stateContent}`);
assert.ok(/Phase: 35\.3 — READY TO EXECUTE/m.test(stateContent),
`Current Position Phase line must read "Phase: 35.3 — READY TO EXECUTE"; STATE.md was:\n${stateContent}`);
// The read path must agree with the write path.
@@ -3758,6 +3801,116 @@ describe('#3395: planned-phase refreshes the stale Phase line and persists --nam
`state json must report the refreshed phase, got: ${json.current_phase}`);
});
test('regression: PINNED_ENV actually pins the clock — GSD_NOW_MS needs GSD_TEST_MODE', () => {
writeStalePhaseLineFixture();
const result = runGsdTools(['state', 'planned-phase', '--phase', '35.3', '--plans', '3'], tmpDir, PINNED_ENV);
assert.ok(result.success, `Command failed: ${result.error}`);
const fm = frontmatterBlock(fs.readFileSync(path.join(tmpDir, '.planning', 'STATE.md'), 'utf-8'));
assert.ok(fm.includes(PINNED_INSTANT),
`last_updated must be the pinned instant ${PINNED_INSTANT} — GSD_NOW_MS is only honored when GSD_TEST_MODE is set too (src/clock.cts _pinnedNowMs); frontmatter was:\n${fm}`);
});
test('regression: a last_updated containing the phase-number substring does not trip the stale-prose check', () => {
writeStalePhaseLineFixture();
const result = runGsdTools(['state', 'planned-phase', '--phase', '35.3', '--plans', '3'], tmpDir, COLLIDING_ENV);
assert.ok(result.success, `Command failed: ${result.error}`);
const stateContent = fs.readFileSync(path.join(tmpDir, '.planning', 'STATE.md'), 'utf-8');
// Precondition: we really are at the colliding instant. Fails loudly if the pin ever
// stops working again, rather than degrading this back into a 1-in-600 coin flip.
assert.ok(stateContent.includes(COLLIDING_INSTANT),
`precondition: the clock must be pinned to ${COLLIDING_INSTANT}; STATE.md was:\n${stateContent}`);
// Precondition: the OLD whole-file scan genuinely does match here. This is the exact
// CI failure, reproduced deterministically.
assert.ok(stateContent.includes('35.1'),
`precondition: the whole-document scan must see 35.1 at this instant; STATE.md was:\n${stateContent}`);
// The property actually under test.
assert.ok(!currentPositionBlock(stateContent).includes('35.1'),
`a timestamp containing 35.1 must not be read as stale phase prose; STATE.md was:\n${stateContent}`);
});
test('control: the narrowed scan still catches genuinely stale phase prose in the body', () => {
// Both line endings, and both WITH a following `## ` heading — that combination is the
// one the helper's CRLF claim actually rests on (`\n## ` matches inside `\r\n## `
// because the `\r` precedes the newline). Testing CRLF only on a single-heading
// document would leave exactly that claim unexercised.
for (const eol of ['\n', '\r\n']) {
const stale = stateDoc({
lines: [
'Phase: 35.1 (unattended-launch-prerequisites) — COMPLETE (4/4 plans)',
'',
'## Next',
'',
'unrelated 35.1 mention outside the block',
],
eol,
});
// Narrowing must not defang the check the fix exists to keep.
assert.ok(currentPositionBlock(stale).includes('35.1'),
`genuinely stale phase prose inside ## Current Position must still be reported (eol=${JSON.stringify(eol)})`);
// The slice stops at the next heading, so the trailing mention is out of scope.
assert.ok(!currentPositionBlock(stale).includes('unrelated'),
`the block must end at the next ## heading (eol=${JSON.stringify(eol)})`);
}
// Missing-input class: no heading at all yields an empty block, never a throw.
assert.strictEqual(currentPositionBlock('# Project State\n\nno position heading\n'), '');
});
test('boundary: the 35.1 collision window is exactly milliseconds 100-199 at second 35', () => {
// limit-1 / limit / limit+1 on BOTH axes of the collision. The scoped reader must be
// blind to every one of them; the whole-document reader must match exactly the window.
const cases = [
{ iso: '2026-08-14T15:00:35.099Z', collides: false, why: 'limit-1 (ms 099)' },
{ iso: '2026-08-14T15:00:35.100Z', collides: true, why: 'limit (ms 100)' },
{ iso: '2026-08-14T15:00:35.199Z', collides: true, why: 'limit (ms 199)' },
{ iso: '2026-08-14T15:00:35.200Z', collides: false, why: 'limit+1 (ms 200)' },
{ iso: '2026-08-14T15:00:34.149Z', collides: false, why: 'limit-1 (second 34)' },
{ iso: '2026-08-14T15:00:36.149Z', collides: false, why: 'limit+1 (second 36)' },
];
for (const { iso, collides, why } of cases) {
for (const eol of ['\n', '\r\n']) {
const doc = stateDoc({ iso, lines: ['Phase: 35.3 — READY TO EXECUTE'], eol });
assert.strictEqual(doc.includes('35.1'), collides,
`whole-document scan for ${iso} (${why}, eol=${JSON.stringify(eol)})`);
assert.ok(!currentPositionBlock(doc).includes('35.1'),
`scoped scan must never match a timestamp: ${iso} (${why}, eol=${JSON.stringify(eol)})`);
}
}
});
test('property: no last_updated value can trip the scoped check, and real stale prose always does', () => {
// Two arms against the SAME generated inputs. Arm 1 alone would be satisfied by a
// helper that always returns ''; arm 2 is what makes that impossible.
fc.assert(fc.property(
// noInvalidDate is load-bearing: without it fc.date() emits an Invalid Date about
// 1 sample in 300 and `.toISOString()` throws RangeError. Verified on fast-check
// 4.8.0 — 0 invalid in 300 samples with the flag, 1 without.
fc.date({
min: new Date('2000-01-01T00:00:00.000Z'),
max: new Date('2099-12-31T23:59:59.999Z'),
noInvalidDate: true,
}),
fc.integer({ min: 1, max: 99 }),
fc.integer({ min: 1, max: 9 }),
(when, major, minor) => {
const iso = when.toISOString();
const clean = stateDoc({ iso, lines: [`Phase: ${major}.${minor} — READY TO EXECUTE`] });
// Deterministic guard: the frontmatter instant is NEVER inside the block. If the
// helper ever widened back to the whole document this fails on every run, not
// only on the runs where the generated timestamp happens to spell a phase id.
assert.ok(!currentPositionBlock(clean).includes(iso));
// Arm 1: a clean block never reports the STALE id, whatever the timestamp is.
const staleId = `${major}.${minor}9`;
assert.ok(!currentPositionBlock(clean).includes(staleId));
// Arm 2: inject genuinely stale prose and it is always reported.
const dirty = stateDoc({ iso, lines: [`Phase: ${staleId} (x) — COMPLETE`] });
assert.ok(currentPositionBlock(dirty).includes(staleId));
return true;
},
), { numRuns: 200 });
});
test('--name is persisted into the Phase line and frontmatter, not silently dropped', () => {
writeStalePhaseLineFixture();
const result = runGsdTools(