Files
feuerwerk/tools/e2e/18-pause.mjs
T
admin 7e5003b590
game-maker / suite (push) Successful in 6m48s
A test that waits for a deadline somebody guessed is waiting for the wrong thing, so it waits for the editor (#93)
The suite spent 88% of its step time asleep: 564 s of steps, 496 s of
them in sleep(n) - fixed spans estimated by hand and then copied from
step to step. That is why it was slow, and why it flickered.

The signal is afterFrames(count, timeout) in ui/render.ts, exposed as
__gm.afterFrames(). It wakes the loop itself, because an editor that
draws nothing would never redeem a promise of a frame, and it gives up
after a timeout instead of hanging the run. settle() in the harness
waits two drawn frames (~32 ms) instead of 150-300 ms and falls back to
sleep(150) when the hook is missing (an old build): silently not
waiting would make every later check a coin toss.

Every action goes through it now - click, doubleClick, wheel, drag,
dragAsset, press, typeText, select, mutate, undo, redo - and with that
about 550 sleep() calls behind those actions became redundant, helpers
that are nothing but a mutate in a coat included. What a frame cannot
answer got its own condition instead: waitUntil(expr), play()/stop()
waiting on __gm.state.mode rather than on 300 ms, saved() for the
autosave (the two hand-written polling loops sampled at 300 ms for
something that arrives after a second), and showTab() as a real tool -
47 places called evaluate("__gm.showTab(...)") raw, and 24 of them
waited for nothing at all and read the old panel.

564 s -> 243 s of step time, the waiting share 88% -> 76%. Three kinds
of wait were kept, and each one bit when it was taken away: loading
bytes (textures, fonts), game time that a repaint cannot stand in for
(time scale, shader and particle clocks, the live values a running
graph carries), and the inertia the scroll step measures on purpose.

Two things the new speed uncovered, both real: 25-animation read the
frame menu unfiltered and had frozen an incomplete list (the CI failure
on c990dbc), and 33-render-on-change measured idleness while the
autosave of the step before was still painting - it waits for
saveStatus to leave dirty/saving now, so it measures that nothing
happens any more instead of that it waited long enough.
2026-09-16 08:08:10 +02:00

314 lines
12 KiB
JavaScript
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
import { edge, node } from '../lib/builders.mjs';
import { LANES, scaffoldBehavior } from './lib/scaffold.mjs';
/**
* Pausing freezes world and clock and drops input instead of replaying it on resume. Brings its own
* self-drifting box, since the fixture's Mover only moves on arrow keys and a pause would look like idling.
*/
const DRIFT_PER_SECOND = 100;
const KEY_LOG = 'arrow down';
/**
* Two independent things in one graph: `On update → Move` drifts the owner right without any
* input, and `On key down → Log` leaves a mark for every *edge* the world saw – which is what a
* pause has to swallow.
*/
const pauseGraph = {
nodes: [
node('p-update', 'OnUpdate', 0, 0),
node('p-owner', 'Owner', 0, 120),
node('p-move', 'Move', 340, 0, { dx: 1, scale: DRIFT_PER_SECOND }),
node('p-key', 'OnKeyDown', 0, 260, { key: 'ArrowRight' }),
node('p-log', 'Log', 340, 260, { message: KEY_LOG }),
],
edges: [
edge('p-e1', 'p-update', 'exec', 'p-move', 'exec'),
edge('p-e2', 'p-update', 'dt', 'p-move', 'dt'),
edge('p-e3', 'p-owner', 'object', 'p-move', 'object'),
edge('p-e4', 'p-key', 'exec', 'p-log', 'exec'),
],
};
export async function pause(t) {
const {
check,
sleep,
json,
has,
shot,
click,
clickText,
press,
entity,
world,
stop,
select,
evaluate,
asset,
showTab,
} = t;
const playInfo = () => json('__gm.playInfo()');
const boxX = async () => (await entity('p-box'))?.x ?? NaN;
const keyHits = async () => (await world()).log.filter((line) => line.includes(KEY_LOG)).length;
// 18a. A box with a drifting behavior below it, written into the model directly: what is under
// test is the pause, not another way of building a graph.
const rig = await scaffoldBehavior(t, {
assetId: 'pauser',
name: 'Pauser',
graph: pauseGraph,
boxId: 'p-box',
boxName: 'Pause box',
logicId: 'p-logic',
y: LANES.pause,
});
await t.play();
const running = await playInfo();
const beforeDrift = await boxX();
await sleep(500);
const drifted = await boxX();
// The precondition of everything below: without movement, "it stood still" is trivially true.
check(
'the box drifts on its own while playing, with nothing held down',
running.playing === true && running.paused === false && drifted > beforeDrift + 20,
`x ${beforeDrift} → ${drifted}, ${JSON.stringify(running)}`,
);
// 18b. The toolbar button holds it. Both the clock and the box have to stop – a world that keeps
// ticking while the picture happens to look the same would pass a position check alone.
await clickText('❚❚ Pause');
const held = await playInfo();
const heldX = await boxX();
await sleep(1000);
const stillHeld = await playInfo();
check(
'pausing stops the world where it is: the box and the clock both stand still',
held.paused === true &&
stillHeld.playing === true &&
Math.abs((await boxX()) - heldX) < 0.001 &&
Math.abs(stillHeld.time - held.time) < 0.05,
`x ${heldX} → ${await boxX()}, clock ${held.time.toFixed(2)} → ${stillHeld.time.toFixed(2)} over 1 s`,
);
// `locate` throws on a missing label, so the button that must be *gone* is asked for through
// the hook, which answers with null.
check(
'the button offers to resume while it is held, and no longer to pause',
(await has('▶ Resume')) === true && (await has('❚❚ Pause')) === false,
`resume=${await has('▶ Resume')} pause=${await has('❚❚ Pause')}`,
);
await shot('36-paused');
// 18c. Keys pressed while it is held are dropped, not queued: resuming must not fire an edge for
// each of them. The count before proves the graph reacts at all.
const hitsBefore = await keyHits();
await press('ArrowRight');
await sleep(1000);
const hitsWhilePaused = await keyHits();
await press('ArrowRight');
await press('ArrowRight');
// 18d. Ctrl+Enter resumes, the same shortcut that started play.
await press('Enter', { ctrl: true });
const resumed = await playInfo();
const resumedX = await boxX();
check(
'resuming lets it move on from where it stopped, without catching up the held time',
resumed.paused === false &&
resumedX > heldX &&
// A second of pause plus the pressing above: catching up would show as a jump far beyond
// what the resumed run itself had time for.
resumedX < heldX + DRIFT_PER_SECOND * 1.2,
`x ${heldX} → ${resumedX}, clock ${stillHeld.time.toFixed(2)} → ${resumed.time.toFixed(2)}`,
);
const hitsAfter = await keyHits();
check(
'a key pressed while paused is swallowed instead of firing on resume',
hitsWhilePaused === hitsBefore && hitsAfter === hitsBefore,
`${hitsBefore} hits before, ${hitsWhilePaused} while held, ${hitsAfter} after resuming`,
);
// Without this the check above would also pass on a graph that never logs anything at all.
await press('ArrowRight');
check(
'the same key does fire once the game is running again',
(await keyHits()) === hitsBefore + 1,
`${hitsBefore} → ${await keyHits()}`,
);
// 18e. A hold must never outlive its play: Esc stops from a paused game, and the next run starts
// moving. A pause left standing would leave the editor unable to run anything.
await press('Enter', { ctrl: true });
check('Ctrl+Enter holds it again', (await playInfo()).paused === true);
await stop();
const afterStop = await playInfo();
await t.play();
await sleep(500);
const restartedX = await boxX();
await sleep(400);
check(
'stopping clears the hold, so the next play runs',
afterStop.playing === false &&
afterStop.paused === false &&
(await playInfo()).paused === false &&
(await boxX()) > restartedX,
`after stop ${JSON.stringify(afterStop)}, x ${restartedX} → ${await boxX()}`,
);
// 18f. The graph stays editable while the game runs, with the mouse as in edit mode: a click
// selects the Move node, Delete removes it, and the running world stops drifting the box.
await select({ kind: 'asset', assetId: 'pauser' });
await showTab('graph');
// The live values are not drawn, they are carried: the running graph has to execute once while
// this tab is open before a node output holds anything. That is game time, not frames.
await sleep(150);
const outputs = (id) => json(`__gm.graph.nodeOutputs(${JSON.stringify(id)})`);
const live = {
owner: await outputs('p-owner'),
update: await outputs('p-update'),
move: await outputs('p-move'),
};
check(
'while playing, each output shows the value it last carried in front of its name',
live.owner[0] === 'Pause box object' &&
/^0\.\d{3} {2}dt$/.test(live.update[1]) &&
live.move[1] === 'false blocked x',
JSON.stringify(live),
);
await shot('36b-graph-live-values');
const beadsOn = async (edgeId) =>
(await json('__gm.graph.beads()')).filter((b) => b.edgeId === edgeId).map((b) => b.progress);
const chain = await beadsOn('p-e1');
const gaps = chain.slice(1).map((p, i) => chain[i] - p);
check(
'an exec edge firing every frame carries an evenly spaced chain of beads',
chain.length >= 1 && chain.length <= 3 && gaps.every((g) => Math.abs(g - 0.5) < 0.1),
JSON.stringify(chain),
);
check(
'data edges carry no beads',
(await beadsOn('p-e2')).length === 0 && (await beadsOn('p-e3')).length === 0,
);
const beforeKey = await beadsOn('p-e4');
await press('ArrowRight');
const onKey = await beadsOn('p-e4');
await sleep(500);
const afterKey = await beadsOn('p-e4');
check(
'a single key press sends exactly one bead, and it arrives',
beforeKey.length === 0 && onKey.length === 1 && afterKey.length === 0,
JSON.stringify({ beforeKey, onKey, afterKey }),
);
const movePos = await json(`__gm.graph.nodeAt('p-move')`);
await click(movePos.x, movePos.y);
check(
'a click selects a node while playing',
JSON.stringify(await json('__gm.graph.selected()')) === '["p-move"]',
JSON.stringify(await json('__gm.graph.selected()')),
);
const area = await json('__gm.graph.canvasRect()');
await click(area.x + area.w - 15, area.y + area.h - 15, 'right');
check('right-clicking the canvas opens the node palette while playing', await has('Search nodes…'));
await press('Escape');
check(
'Escape closes the palette and leaves the game running',
!(await has('Search nodes…')) && (await playInfo()).playing === true,
);
await click(movePos.x, movePos.y);
await press('Delete');
const stoppedAt = await boxX();
await sleep(500);
check(
'deleting the Move node while playing stops the drift on the next frames',
!(await asset('pauser')).graph.nodes.some((n) => n.id === 'p-move') &&
Math.abs((await boxX()) - stoppedAt) < 0.001,
`x ${stoppedAt} → ${await boxX()}`,
);
await stop();
check(
'stopping takes the values off the nodes',
JSON.stringify(await outputs('p-owner')) === '["object"]',
JSON.stringify(await outputs('p-owner')),
);
check(
'stopping discards the graph edit with the rest of the run',
(await asset('pauser')).graph.nodes.some((n) => n.id === 'p-move'),
JSON.stringify((await asset('pauser')).graph.nodes.map((n) => n.id)),
);
// 18g. (#90) One clock under everything that moves by itself – the world's delta, particle age and
// shader time. It starts over with a run and ends with it, and a pause is a scale of 0.
const clock = () => json('__gm.globalTime()');
// The bounds are a multiple apart rather than an epsilon: reading the clock costs a round trip,
// and without the reset the run would start at everything the editor counted, not a little of it.
await sleep(2500);
const beforePlay = await clock();
check(
'the clock runs in edit mode too, so the previews move without a game',
beforePlay.now > 2 && beforePlay.effective === 1,
JSON.stringify(beforePlay),
);
await t.play();
const atStart = await clock();
check(
'a run starts the clock over, however long the editor has been counting',
atStart.now < 1 && atStart.now < beforePlay.now / 2,
`editor at ${beforePlay.now.toFixed(2)} s → run at ${atStart.now.toFixed(2)} s`,
);
await sleep(400);
const runningClock = await clock();
await clickText('❚❚ Pause');
const heldClock = await clock();
await sleep(800);
const stillHeldClock = await clock();
check(
'a pause is an effective scale of 0, and it gates the scale instead of overwriting it',
runningClock.effective === 1 &&
heldClock.effective === 0 &&
heldClock.scale === 1 &&
Math.abs(stillHeldClock.now - heldClock.now) < 0.02,
`effective ${runningClock.effective} → ${heldClock.effective} (scale ${heldClock.scale}), clock ${heldClock.now.toFixed(2)} → ${stillHeldClock.now.toFixed(2)} over 0.8 s`,
);
// Twice the scale has to move the clock and the world by the same factor: the delta a behavior
// reads is the step the clock took, not a second measurement of the wall clock.
await press('Enter', { ctrl: true });
const slowFrom = { t: await clock(), x: await boxX() };
await sleep(600);
const slowTo = { t: await clock(), x: await boxX() };
await evaluate('__gm.setTimeScale(2)');
await sleep(150);
const fastFrom = { t: await clock(), x: await boxX() };
await sleep(600);
const fastTo = { t: await clock(), x: await boxX() };
await evaluate('__gm.setTimeScale(1)');
const slow = { time: slowTo.t.now - slowFrom.t.now, drift: slowTo.x - slowFrom.x };
const fast = { time: fastTo.t.now - fastFrom.t.now, drift: fastTo.x - fastFrom.x };
const twice = (a, b) => b > a * 1.7 && b < a * 2.3;
check(
'at scale 2 the clock and the drifting box both move twice as far in the same wall second',
slow.drift > 20 && twice(slow.time, fast.time) && twice(slow.drift, fast.drift),
JSON.stringify({ slow, fast }),
);
await stop();
const afterStopClock = await clock();
check(
'stopping puts the clock back to zero, so the editor shows a freshly started scene again',
afterStopClock.now < 1 &&
afterStopClock.now < fastTo.t.now / 2 &&
afterStopClock.scale === 1 &&
afterStopClock.effective === 1,
`run ended at ${fastTo.t.now.toFixed(2)} s → editor at ${afterStopClock.now.toFixed(2)} s`,
);
// 18h. Play discarded its copy, so the box is back at the position the model holds.
const left = await rig.remove();
check(
'the step leaves nothing of its own behind',
left.objects === 0 && left.assets === 0,
JSON.stringify(left),
);
}