Skip to content

Commit ed9db75

Browse files
committed
web/shell: runtime fix round 3 (stop keeps its notes, the check budget scales, the review's give-up cancels, /tmp folders counted)
1 parent b973e5c commit ed9db75

7 files changed

Lines changed: 632 additions & 75 deletions

File tree

‎web/shell/src/info.js‎

Lines changed: 22 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -46,12 +46,15 @@ const LIMITS = deepFreeze({
4646
fsMs: 60000,
4747
/**
4848
* How long the read-only check of a change set may take in all (the terminal's: has anything changed on disk since
49-
* the command read it?), counted from its first call. It is fsMs on purpose: a provider that does not answer costs
50-
* the visitor one such wait and the set is refused whole ("could not be checked in time"), not one per file, and
51-
* a provider that answers every call just before fsMs is not waited for for 2000 of them. The terminal's cap of
52-
* 2000 entries (a stat and a read each) fits in it at 15 ms a call.
49+
* the command read it?), counted from its first call, and how that grows with the set: `checkMs` is for a set of up
50+
* to `checkEntries` entries, a larger one gets the same time per entry, and no set gets more than `checkMaxMs` (see
51+
* checkBudgetMs). A check is up to two calls an entry (a stat, and the bytes of a file the command read): 60 s is
52+
* 250 ms a call for 120 entries, which is what a slow network folder needs, and 2 minutes are 30 ms a call at the cap
53+
* of 2000 entries. A provider that does not answer is not waited for that long: its first call that is not answered
54+
* in `fsMs` ends the check and the set is refused whole, once ("could not be checked in time"). The budget bounds the
55+
* one that answers every call just before fsMs, and is why it is not "for ever".
5356
*/
54-
checkMs: 60000,
57+
checkMs: 60000, checkEntries: 120, checkMaxMs: 120000,
5558
/**
5659
* How long the part of a commit that WRITES may take in all, counted from its first call: levelcode-ai's review
5760
* of a change set and then the folders it left to the shell (one budget, for the agent), or the shell's own
@@ -66,6 +69,19 @@ const LIMITS = deepFreeze({
6669
},
6770
});
6871

72+
/**
73+
* How long the read-only check of a change set of `entries` entries has in all: `checkMs` for up to `checkEntries` of
74+
* them, in proportion above that, never more than `checkMaxMs` - and never less than `checkMs`, whatever the others
75+
* say. The budget is a bound on a provider that is slow but alive, so it has to go with the work: a constant that
76+
* is right for 20 entries refuses a set of 2000 that a provider answering in 30 ms a call would have had applied.
77+
* @param {{ checkMs: number, checkEntries: number, checkMaxMs: number }} w limits.workers
78+
* @param {number} entries
79+
*/
80+
function checkBudgetMs(w, entries) {
81+
const n = typeof entries === 'number' && Number.isFinite(entries) && entries > 0 ? entries : 0;
82+
return Math.max(w.checkMs, Math.min(w.checkMaxMs, Math.ceil(w.checkMs * n / w.checkEntries)));
83+
}
84+
6985
/** @template T @param {T} o @returns {T} */
7086
function deepFreeze(o) {
7187
if (o && typeof o === 'object') { Object.values(o).forEach(deepFreeze); Object.freeze(o); }
@@ -183,4 +199,4 @@ function createInfo(limitsOver) {
183199
};
184200
}
185201

186-
module.exports = { LIMITS, PROGRAMS, MISSING, BUILTINS, mergeLimits, createInfo };
202+
module.exports = { LIMITS, PROGRAMS, MISSING, BUILTINS, mergeLimits, createInfo, checkBudgetMs };

‎web/shell/src/runtime.js‎

Lines changed: 83 additions & 43 deletions
Large diffs are not rendered by default.

‎web/test/helpers/mutation/mutations.mjs‎

Lines changed: 53 additions & 16 deletions
Large diffs are not rendered by default.

‎web/test/unit/shell-runtime-commit.test.js‎

Lines changed: 283 additions & 4 deletions
Large diffs are not rendered by default.

‎web/test/unit/shell-runtime-info.test.js‎

Lines changed: 19 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -13,7 +13,7 @@ const fs = require('fs');
1313
const path = require('path');
1414
const { pathToFileURL } = require('url');
1515

16-
const { LIMITS, PROGRAMS, MISSING, BUILTINS, mergeLimits, createInfo } = require(path.join(__dirname, '..', '..', 'shell', 'src', 'info.js'));
16+
const { LIMITS, PROGRAMS, MISSING, BUILTINS, mergeLimits, createInfo, checkBudgetMs } = require(path.join(__dirname, '..', '..', 'shell', 'src', 'info.js'));
1717

1818
const MiB = 1024 * 1024;
1919
let n = 0;
@@ -29,10 +29,27 @@ test('the limits are the ones of README section 7, number for number', () => {
2929
read: { file: 4 * MiB, run: 16 * MiB, served: 32 * MiB },
3030
agent: { writeFile: 1 * MiB, writeRun: 8 * MiB, entries: 2000 },
3131
terminal: { writeFile: 8 * MiB, writeRun: 32 * MiB, entries: 2000 },
32-
workers: { max: 4, idleMs: 60000, readyMs: 20000, fsMs: 60000, checkMs: 60000, commitMs: 120000, deadlineGraceMs: 15000, completeMax: 200, completeMs: 2000 },
32+
workers: { max: 4, idleMs: 60000, readyMs: 20000, fsMs: 60000, checkMs: 60000, checkEntries: 120, checkMaxMs: 120000, commitMs: 120000, deadlineGraceMs: 15000, completeMax: 200, completeMs: 2000 },
3333
});
3434
});
3535

36+
test('checkBudgetMs: checkMs up to checkEntries entries, the same per entry above that, never more than checkMaxMs and never less than checkMs', () => {
37+
const w = LIMITS.workers;
38+
assert.deepStrictEqual([0, 1, 5, 119, 120].map((n) => checkBudgetMs(w, n)), [60000, 60000, 60000, 60000, 60000], 'a set of up to 120 entries: a minute');
39+
assert.strictEqual(checkBudgetMs(w, 121), 60500, 'one more: its share, 500 ms');
40+
assert.strictEqual(checkBudgetMs(w, 200), 100000);
41+
assert.strictEqual(checkBudgetMs(w, 240), 120000, 'twice 120 entries: the ceiling is reached');
42+
assert.deepStrictEqual([241, 1000, 2000, 1e9].map((n) => checkBudgetMs(w, n)), [120000, 120000, 120000, 120000], 'and no more');
43+
// what is not a size is no size
44+
for (const bad of [undefined, null, NaN, -1, Infinity, '200', {}]) { assert.strictEqual(checkBudgetMs(w, /** @type {any} */ (bad)), 60000, String(bad)); }
45+
// the floor wins over a ceiling set below it; the share is a whole number of ms
46+
assert.strictEqual(checkBudgetMs({ checkMs: 200000, checkEntries: 10, checkMaxMs: 5000 }, 1000), 200000);
47+
assert.strictEqual(checkBudgetMs({ checkMs: 100, checkEntries: 3, checkMaxMs: 1000 }, 4), 134);
48+
// a table that was overridden is scaled by its own numbers
49+
const m = mergeLimits({ workers: { checkMs: 1000, checkEntries: 10, checkMaxMs: 5000 } });
50+
assert.deepStrictEqual([5, 10, 11, 20, 50, 60, 70].map((k) => checkBudgetMs(m.workers, k)), [1000, 1000, 1100, 2000, 5000, 5000, 5000]);
51+
});
52+
3653
test('the table cannot be edited by whoever holds it: frozen all the way down', () => {
3754
assert.ok(Object.isFrozen(LIMITS) && Object.isFrozen(LIMITS.engine) && Object.isFrozen(LIMITS.workers));
3855
assert.throws(() => { 'use strict'; /** @type {any} */ (LIMITS).engine.maxCommandCount = 1; }, TypeError);

‎web/test/unit/shell-runtime-session.test.js‎

Lines changed: 143 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -4,8 +4,9 @@
44
* README section 3b: what the terminal consumes. A session keeps what must survive a worker's death (cwd,
55
* env), runs one script at a time, stops with Ctrl+C, and completes for Tab from the workspace itself.
66
*
7-
* What it cannot keep it says: when a terminal's engine is replaced and its /tmp held files, the next line
8-
* carries one note that /tmp was emptied; variables over the bounds are named, not silently lost.
7+
* What it cannot keep it says: when a terminal's engine is replaced and its /tmp held anything (files, or only
8+
* folders: stats.tmpEntries), the next line carries one note that /tmp was emptied; variables over the bounds
9+
* are named, not silently lost.
910
*--------------------------------------------------------------------------------------------*/
1011
// @ts-check
1112
'use strict';
@@ -405,6 +406,24 @@ async function test(/** @type {string} */ name, /** @type {() => Promise<void>}
405406
r.rt.dispose();
406407
});
407408

409+
await test('the /tmp note comes before what the commit says too: a replaced worker, then a line whose changes are refused', async () => {
410+
const r = createRig();
411+
const te = new TextEncoder();
412+
/** @type {any[]} */ let changes = [];
413+
r.engines.state.onRun = async (run, w, h) => { h.done({ exitCode: 0, how: 'exit', cwd: run.cwd, changes, stats: { tmpFiles: 2 } }); };
414+
const s = r.rt.createSession();
415+
await s.run('echo x > /tmp/a');
416+
await r.clock.advance(120000);
417+
r.ws.put('/scratch/a.txt', 'changed meanwhile');
418+
changes = [{ kind: 'write', path: '/scratch/a.txt', existed: true, before: te.encode('old'), after: te.encode('new') }];
419+
const res = await s.run('sed -i s/old/new/ a.txt');
420+
assert.strictEqual(res.notes.length, 3, res.notes.join('\n'));
421+
assert.ok(EMPTIED.test(res.notes[0]), 'first: ' + res.notes[0]);
422+
assert.ok(/refused: \/scratch\/a\.txt changed while the command ran/.test(res.notes[1]), res.notes[1]);
423+
assert.ok(/NONE of this command's file changes were applied/.test(res.notes[2]), res.notes[2]);
424+
r.rt.dispose();
425+
});
426+
408427
await test('at the worker cap the one replaced is the least recently used idle worker WITHOUT /tmp files: the files are the one thing that cannot be made again', async () => {
409428
const r = createRig({ limits: { workers: { max: 2 } } });
410429
/** @type {Record<string, number>} */ const files = { keeper: 3, plain: 0 };
@@ -555,6 +574,128 @@ async function test(/** @type {string} */ name, /** @type {() => Promise<void>}
555574
nonsense.rt.dispose();
556575
});
557576

577+
/* ===== fix round 3: what /tmp holds is files AND folders ================================================ */
578+
579+
/**
580+
* The engine's side as the current one reports it for a terminal run: `stats` exactly as given (tmpFiles, and
581+
* tmpEntries: the files and the folders). It is read at every run, so a test can change what /tmp "holds".
582+
* @param {any} r @param {() => any} stats
583+
*/
584+
function reports(r, stats) {
585+
r.engines.state.onRun = async (/** @type {any} */ run, /** @type {any} */ w, /** @type {any} */ h) => {
586+
if (run.script === 'hang') { await new Promise(() => { }); }
587+
h.done({ exitCode: 0, how: 'exit', cwd: run.cwd, stats: stats() });
588+
};
589+
}
590+
/** Every note about /tmp in `notes`. @param {string[]} notes */
591+
const tmpNotes = (notes) => notes.filter((t) => /\/tmp was emptied/.test(t)).map((t) => (/\(it held ([^)]*)\)/.exec(t) || [])[1]);
592+
593+
await test('a /tmp that holds only an empty folder is something: the worker is kept twice as long, and the loss is said, as "1 file or folder"', async () => {
594+
const r = createRig();
595+
reports(r, () => ({ tmpFiles: 0, tmpEntries: 1 }));
596+
const s = r.rt.createSession();
597+
await s.run('mkdir /tmp/emptydir');
598+
await r.clock.advance(60000);
599+
assert.strictEqual(r.engines.workers[0].terminated, false, 'a minute is not enough for a /tmp that holds a folder');
600+
await r.clock.advance(59999);
601+
assert.strictEqual(r.engines.workers[0].terminated, false);
602+
await r.clock.advance(1);
603+
assert.strictEqual(r.engines.workers[0].terminated, true, 'two minutes are');
604+
const after = await s.run('ls /tmp');
605+
assert.deepStrictEqual(tmpNotes(after.notes), ['1 file or folder']);
606+
assert.deepStrictEqual(tmpNotes((await s.run('ls /tmp')).notes), [], 'said once');
607+
r.rt.dispose();
608+
});
609+
610+
await test('the note says "N files and folders" with the engine\'s own number: five entries of which two are files', async () => {
611+
const r = createRig();
612+
reports(r, () => ({ tmpFiles: 2, tmpEntries: 5 }));
613+
const s = r.rt.createSession();
614+
await s.run('x');
615+
await r.clock.advance(120000);
616+
const after = await s.run('ls /tmp');
617+
assert.strictEqual(after.notes.length, 1, after.notes.join('\n'));
618+
assert.ok(/^\[LevelCode Shell: \/tmp was emptied when the shell restarted \(it held 5 files and folders\): /.test(after.notes[0]), after.notes[0]);
619+
assert.ok(/Keep what matters in a workspace folder\]$/.test(after.notes[0]), after.notes[0]);
620+
r.rt.dispose();
621+
});
622+
623+
await test('an engine that reports only stats.tmpFiles is believed as before: files, and the old wording', async () => {
624+
for (const [files, said] of /** @type {Array<[number, string]>} */ ([[3, '3 files'], [1, '1 file']])) {
625+
const r = createRig();
626+
reports(r, () => ({ tmpFiles: files }));
627+
const s = r.rt.createSession();
628+
await s.run('x');
629+
await r.clock.advance(120000);
630+
assert.deepStrictEqual(tmpNotes((await s.run('x')).notes), [said]);
631+
r.rt.dispose();
632+
}
633+
});
634+
635+
await test('a tmpEntries that is not a count is as good as none: the files count is used, with the wording of files', async () => {
636+
for (const bad of [-1, NaN, Infinity, '3', null, {}, true]) {
637+
const r = createRig();
638+
reports(r, () => ({ tmpFiles: 3, tmpEntries: bad }));
639+
const s = r.rt.createSession();
640+
await s.run('x');
641+
await r.clock.advance(120000);
642+
assert.deepStrictEqual(tmpNotes((await s.run('x')).notes), ['3 files'], JSON.stringify(bad));
643+
r.rt.dispose();
644+
}
645+
});
646+
647+
await test('both counts present and in disagreement (fewer entries than files): the larger is believed - a loss of files is not to go unsaid', async () => {
648+
const r = createRig();
649+
reports(r, () => ({ tmpFiles: 4, tmpEntries: 1 }));
650+
const s = r.rt.createSession();
651+
await s.run('x');
652+
await r.clock.advance(120000);
653+
assert.deepStrictEqual(tmpNotes((await s.run('x')).notes), ['4 files and folders']);
654+
r.rt.dispose();
655+
});
656+
657+
await test('an empty /tmp, or counts that are not counts, say nothing and keep the worker for the usual minute', async () => {
658+
for (const stats of [{ tmpFiles: 0, tmpEntries: 0 }, { tmpEntries: 0 }, { tmpEntries: -3, tmpFiles: NaN }, { tmpEntries: '2' }, { tmpEntries: 0.4 }, {}]) {
659+
const r = createRig();
660+
reports(r, () => stats);
661+
const s = r.rt.createSession();
662+
await s.run('x');
663+
await r.clock.advance(60000);
664+
assert.strictEqual(r.engines.workers[0].terminated, true, JSON.stringify(stats) + ': the usual minute');
665+
assert.deepStrictEqual((await s.run('x')).notes, [], JSON.stringify(stats));
666+
r.rt.dispose();
667+
}
668+
});
669+
670+
await test('at the worker cap a worker whose /tmp holds only a folder is kept in preference to an empty one, like one that holds files', async () => {
671+
const r = createRig({ limits: { workers: { max: 2 } } });
672+
/** @type {Record<string, any>} */ const by = { keeper: { tmpFiles: 0, tmpEntries: 1 }, plain: { tmpFiles: 0, tmpEntries: 0 } };
673+
r.engines.state.onRun = async (run, w, h) => { h.done({ exitCode: 0, how: 'exit', cwd: run.cwd, stats: by[run.script.split(' ')[0]] || {} }); };
674+
const keeper = r.rt.createSession();
675+
const plain = r.rt.createSession();
676+
await keeper.run('keeper'); // the older one, and it holds a folder
677+
await r.clock.advance(1000);
678+
await plain.run('plain');
679+
await r.clock.advance(1000);
680+
await r.rt.createSession().run('plain');
681+
assert.deepStrictEqual(r.engines.workers.map((w) => w.terminated), [false, true, false], 'the newer, empty one was replaced');
682+
assert.deepStrictEqual((await keeper.run('keeper')).notes, [], 'its /tmp is there');
683+
r.rt.dispose();
684+
});
685+
686+
await test('an agent\'s worker never remembers its /tmp, folders or not: the usual minute, and no note', async () => {
687+
const r = createRig();
688+
reports(r, () => ({ tmpFiles: 2, tmpEntries: 9 }));
689+
for (let i = 0; i < 2; i++) {
690+
const o = observe(r.rt.spawnAgent('x', { cwd: '/scratch' }), 3000);
691+
await o.closed;
692+
await r.clock.advance(60000);
693+
assert.strictEqual(r.engines.workers[r.engines.workers.length - 1].terminated, true);
694+
assert.ok(!/\/tmp was emptied/.test(o.stderr), o.stderr);
695+
}
696+
r.rt.dispose();
697+
});
698+
558699
/* ===== completion =============================================================================== */
559700

560701
await test('complete(command): what exists, by prefix, sorted, the engine\'s own list once it has started, builtins too', async () => {

‎web/test/unit/shell-runtime-worker.test.js‎

Lines changed: 29 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -134,7 +134,10 @@ const sleep = (/** @type {number} */ ms) => new Promise((r) => setTimeout(r, ms)
134134
assert.strictEqual(r.out, 'start\n', 'what it printed before is kept');
135135
assert.strictEqual(x.ws.exists('/scratch/sub/made.txt'), false);
136136
assert.ok(settled < 2000, 'Stop took ' + settled + ' ms');
137-
assert.ok(Date.now() - t0 >= 400, 'the loop really ran');
137+
// (not `>= 400` after a sleep(400): a timer is counted from the loop's cached time, so it is routinely seen a millisecond
138+
// early - or more when the thread was busy - and a suite that fails by itself one run in fifty is not a test. What this
139+
// says is that the script had been going for a good while, and a margin of a quarter says it.)
140+
assert.ok(Date.now() - t0 >= 300, 'the loop really ran');
138141
// 10 ms ticks over 400+ ms: a thread that is blocked by the script cannot tick at all
139142
assert.ok(hb.maxGap < 1000 && hb.ticks >= 10, 'the host thread was never blocked: longest silence ' + hb.maxGap + ' ms, ' + hb.ticks + ' ticks');
140143
// and on
@@ -154,7 +157,8 @@ const sleep = (/** @type {number} */ ms) => new Promise((r) => setTimeout(r, ms)
154157
const hb = beat.stop();
155158
assert.deepStrictEqual({ how: r.how, exit: r.exitCode, applied: r.applied }, { how: 'deadline', exit: 124, applied: 0 });
156159
assert.ok(/ran out of time/.test(r.notes.join('\n')), r.notes.join('\n'));
157-
assert.ok(r.ms >= 580 && r.ms < 3000, 'the deadline was 600 ms; the run lasted ' + r.ms);
160+
// (a timer is seen early by what the thread did before it was set: 600 ms is the host's, the margin is for that)
161+
assert.ok(r.ms >= 500 && r.ms < 3000, 'the deadline was 600 ms; the run lasted ' + r.ms);
158162
assert.ok(hb.maxGap < 1000 && hb.ticks >= 10, 'the host thread was never blocked: ' + hb.maxGap + ' ms, ' + hb.ticks + ' ticks');
159163
assert.strictEqual(x.ws.exists('/scratch/made.txt'), false);
160164
assert.strictEqual((await line(s, 'echo ok')).out, 'ok\n');
@@ -256,6 +260,29 @@ const sleep = (/** @type {number} */ ms) => new Promise((r) => setTimeout(r, ms)
256260
assert.ok(await real.allExited(5000));
257261
});
258262

263+
await test('a /tmp that holds only an empty folder is lost with the thread and said: kept twice the idle time, then "files and folders" (needs stats.tmpEntries)', async () => {
264+
const x = setup({ limits: { workers: { idleMs: 600 } } });
265+
const s = x.rt.createSession();
266+
const r0 = await line(s, 'mkdir /tmp/emptydir; ls /tmp');
267+
assert.strictEqual(r0.out, 'emptydir\n');
268+
const done = x.threads()[0].lastDone;
269+
if (!done || !done.stats || typeof done.stats.tmpEntries !== 'number') {
270+
console.log(' SKIPPED - the empty-folder /tmp note: this engine does not report stats.tmpEntries yet, so a /tmp of folders only is not seen');
271+
x.rt.dispose();
272+
return 'skipped';
273+
}
274+
assert.deepStrictEqual([done.stats.tmpFiles, done.stats.tmpEntries], [0, 1], JSON.stringify(done.stats));
275+
await sleep(850); // past the idle time, inside twice of it: still the same thread
276+
assert.strictEqual((await line(s, 'ls /tmp')).out, 'emptydir\n', 'a worker whose /tmp holds a folder is kept for twice the idle time');
277+
assert.strictEqual(x.threads().length, 1);
278+
await sleep(1500); // past twice the idle time: replaced
279+
const after = await line(s, 'ls /tmp');
280+
assert.strictEqual(after.out, '', 'the folder went with the thread');
281+
assert.ok(after.notes.some((t) => /\/tmp was emptied when the shell restarted \(it held 1 file or folder\)/.test(t)), JSON.stringify(after.notes));
282+
x.rt.dispose();
283+
assert.ok(await real.allExited(5000));
284+
});
285+
259286
// Nothing is left alive. A watchdog that does not itself keep the process up fires only if something does.
260287
const leak = setTimeout(() => { console.error('not ok - something is still alive: the process did not exit'); process.exit(1); }, 15000);
261288
leak.unref();

0 commit comments

Comments
 (0)