admin
7e5003b590
game-maker / suite (push) Successful in 6m48s
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.
68 lines
2.8 KiB
JavaScript
68 lines
2.8 KiB
JavaScript
#!/usr/bin/env node
|
||
/**
|
||
* Headless end-to-end checks of the editor, driven over the Chrome DevTools Protocol.
|
||
* Usage: node tools/seed-e2e.mjs && node tools/e2e.mjs [projectId] [baseUrl]
|
||
* Prints PASS/FAIL per check, writes screenshots to /tmp/gm-e2e-*.png. No dependencies.
|
||
*
|
||
* Runs against the fixture project written by tools/seed-e2e.mjs and mutates it heavily; the
|
||
* steps in tools/e2e/ run in order and build on each other's scene state.
|
||
*
|
||
* `GM_STEPS=1-12` or `GM_STEPS=6,20` runs a subset while working on one step. Since later steps
|
||
* rely on what earlier ones leave behind, a subset that skips a prerequisite fails on purpose.
|
||
*/
|
||
import { STEPS } from './e2e/index.mjs';
|
||
import { runChecks, waited } from './lib/harness.mjs';
|
||
import { PROJECTS, cliArgs } from './lib/projects.mjs';
|
||
|
||
const { projectId, baseUrl } = cliArgs('e2e.mjs', PROJECTS.fixture);
|
||
|
||
function selectSteps(spec) {
|
||
if (!spec) return STEPS;
|
||
const wanted = new Set();
|
||
for (const part of spec.split(',')) {
|
||
const [from, to] = part.trim().split('-').map(Number);
|
||
if (!Number.isInteger(from) || from < 1) {
|
||
console.error(`GM_STEPS: cannot read "${part}" – use 20, 1-12 or 6,20`);
|
||
process.exit(2);
|
||
}
|
||
for (let i = from; i <= (Number.isInteger(to) ? to : from); i++) wanted.add(i);
|
||
}
|
||
return STEPS.filter((_, i) => wanted.has(i + 1));
|
||
}
|
||
|
||
const steps = selectSteps(process.env.GM_STEPS);
|
||
if (steps.length !== STEPS.length) {
|
||
console.log(`running ${steps.length}/${STEPS.length} steps: ${steps.map((s) => s.name).join(', ')}`);
|
||
}
|
||
|
||
/**
|
||
* One line per step, printed as it finishes: how long it took and how much of that was the
|
||
* harness sitting out a fixed wait. It also puts the run's position into the log, so a run that
|
||
* dies half-way says where it stood instead of leaving the last check as the only clue.
|
||
*/
|
||
const timings = [];
|
||
async function timed(step, t) {
|
||
const at = Date.now();
|
||
const waitedAt = waited.ms;
|
||
await step(t);
|
||
const ms = Date.now() - at;
|
||
const slept = waited.ms - waitedAt;
|
||
timings.push({ name: step.name, ms, slept });
|
||
const no = String(STEPS.indexOf(step) + 1).padStart(2, '0');
|
||
console.log(`STEP ${no} ${step.name} – ${(ms / 1000).toFixed(1)}s (waited ${(slept / 1000).toFixed(1)}s)`);
|
||
}
|
||
|
||
await runChecks({ projectId, baseUrl, port: 9333, shotPrefix: 'gm-e2e' }, async (t) => {
|
||
await t.navigate();
|
||
await t.shot('01-loaded');
|
||
for (const step of steps) await timed(step, t);
|
||
const total = timings.reduce((sum, s) => sum + s.ms, 0);
|
||
const slept = timings.reduce((sum, s) => sum + s.slept, 0);
|
||
const worst = [...timings].sort((a, b) => b.ms - a.ms).slice(0, 8);
|
||
console.log(
|
||
`\nTIMING ${(total / 1000).toFixed(0)}s in steps, ${(slept / 1000).toFixed(0)}s of it waiting ` +
|
||
`(${Math.round((slept / total) * 100)}%). Slowest: ` +
|
||
worst.map((s) => `${s.name} ${(s.ms / 1000).toFixed(1)}s`).join(', '),
|
||
);
|
||
});
|