Skip to content

Commit 747f598

Browse files
committed
fix(scripts): disarm the first-paint deadline once the marker is seen (#2147)
Copilot review round 3. `done()` is first-caller-wins, and the render deadline stayed armed after first paint. So a marker landing near `timeoutMs` let that timer fire *inside* the survival window and settle the run as child did not render "MCP Servers" within 15000ms followed by an output tail that visibly contains "MCP Servers". A TUI that is merely slow fails intermittently, with a diagnostic naming the one thing that demonstrably did happen — the same wrong-attribution class this PR exists to remove, and one that reads as flake. First paint has happened; its deadline no longer has a question to ask, so `onData` clears it at the moment the marker is observed. Also hoists `renderTimer`'s declaration beside `surviveTimer`'s. It was a `const` below both closures that clear it, safe only because `onData` and `done` run from events rather than the synchronous body. That already held for `done`; this fix adds a second reader, so the ordering is now stated rather than relied upon. The test paints at 250ms with timeoutMs 400 and surviveMs 400, so the render deadline expires while the survival window is open — the exact shape. Verified it fails against the module with the clearTimeout removed and passes with it: a wider timeoutMs would have been green either way, which is why the numbers are tight. Signed-off-by: Cliff Hall <cliff@futurescale.com> Signed-off-by: cliffhall <cliff@futurescale.com>
1 parent b7a73e7 commit 747f598

2 files changed

Lines changed: 37 additions & 2 deletions

File tree

‎scripts/lib/render-smoke.mjs‎

Lines changed: 15 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -146,8 +146,15 @@ export function runRenderSmoke({
146146
let childExited = false;
147147
let childClosed = false;
148148
let markerAt = null;
149-
/** @type {ReturnType<typeof setTimeout> | undefined} */
149+
/**
150+
* Both deadlines. Declared up front because `onData` and `done` each clear
151+
* them from closures defined above the `setTimeout` calls that assign them.
152+
*
153+
* @type {ReturnType<typeof setTimeout> | undefined}
154+
*/
150155
let surviveTimer;
156+
/** @type {ReturnType<typeof setTimeout> | undefined} */
157+
let renderTimer;
151158

152159
const t0 = Date.now();
153160
const since = () => Date.now() - t0;
@@ -233,6 +240,12 @@ export function runRenderSmoke({
233240
output += chunk.toString();
234241
if (markerAt !== null || !output.includes(marker)) return;
235242
markerAt = since();
243+
// Disarm the first-paint deadline. It is first-caller-wins with `done`,
244+
// so leaving it armed means a paint landing near `timeoutMs` lets it fire
245+
// *during* the survival window and settle the run as "did not render
246+
// <marker>" — quoting an output tail that visibly contains the marker.
247+
// First paint has happened; its deadline no longer has a question to ask.
248+
clearTimeout(renderTimer);
236249
// First paint is not the verdict — it only starts the clock on the
237250
// question this smoke actually asks.
238251
surviveTimer = setTimeout(() => {
@@ -269,7 +282,7 @@ export function runRenderSmoke({
269282
done(1, `failed to spawn ${command}: ${err.message}`);
270283
});
271284

272-
const renderTimer = setTimeout(() => {
285+
renderTimer = setTimeout(() => {
273286
done(
274287
1,
275288
() =>

‎scripts/lib/render-smoke.test.mjs‎

Lines changed: 22 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -57,6 +57,28 @@ test("passes when the child paints the marker and keeps running", async () => {
5757
assert.match(r.message, /still running 400ms later/);
5858
});
5959

60+
// The first-paint deadline and the survival window overlap: `done` is
61+
// first-caller-wins, so an armed render timer firing during the survival window
62+
// settles the run as "did not render" — while quoting an output tail that
63+
// visibly contains the marker. A slow-but-fine TUI would fail, intermittently,
64+
// with a diagnostic pointing at the wrong thing entirely.
65+
test("a paint landing just under the deadline is not failed by the render timer", async () => {
66+
const paintAt = 250;
67+
const r = await runRenderSmoke({
68+
...opts,
69+
...stub(
70+
`setTimeout(() => { console.log(${JSON.stringify(MARKER)}); ` +
71+
`setInterval(() => {}, 1000); }, ${paintAt});`,
72+
),
73+
// Deliberately tight: the render deadline expires while the survival window
74+
// is still open, which is the whole shape of the bug.
75+
timeoutMs: paintAt + 150,
76+
surviveMs: 400,
77+
});
78+
assert.equal(r.code, 0, `expected pass, got: ${r.message}`);
79+
assert.doesNotMatch(r.message, /did not render/);
80+
});
81+
6082
test("fails when the child exits before painting", async () => {
6183
const r = await runRenderSmoke({
6284
...opts,

0 commit comments

Comments
 (0)