diff --git a/packages/cli/tests/case-inner-timing-fixture.mjs b/packages/cli/tests/case-inner-timing-fixture.mjs new file mode 100644 index 000000000..a7a28c447 --- /dev/null +++ b/packages/cli/tests/case-inner-timing-fixture.mjs @@ -0,0 +1,35 @@ +// Test-copy observations only: bracket the supervisor's inner timer before +// clean_session scans the host's /proc. Keep all shipped control flow intact. +import { readProbeSeconds } from './case-p10-timing-fixture.mjs'; +export { readProbeSeconds }; +const BEGIN = '# row253-supervisor-begin\n'; +const END = '# row253-supervisor-end\n'; +const TIMER = '"$sleep_bin" "$seconds" & timer=$!\n'; +const FINISH = 'finish() {\n local rc="$?"\n'; +function unique(source, anchor) { + const at=source.indexOf(anchor); + if(at<0 || source.indexOf(anchor,at+anchor.length)>=0) throw new Error('inner observer anchor must occur exactly once'); + return at; +} +function innerObservers(clock) { + // The literal path survives env -i in the fake sudo. It is a private scratch + // file, never a product input. Quote even paths containing shell metacharacters. + const file="'"+clock.replaceAll("'", "'\\''")+"'"; + return { + begin:`# inner-observer-begin\n{ read -r timing2_up timing2_spare < /proc/uptime &&\n printf 'begin %s\\n' "$timing2_up" >> ${file}; } 2>/dev/null || :\n# inner-observer-begin-end\n`, + end:` # inner-observer-end\n { read -r timing2_up timing2_spare < /proc/uptime &&\n printf 'end %s\\n' "$timing2_up" >> ${file}; } 2>/dev/null || :\n # inner-observer-end-end\n`, + }; +} +export function instrumentInnerTimer(source,clock) { + const from=unique(source,BEGIN),to=unique(source,END); + if(to<=from)throw new Error('inner observer scope is reversed'); + let supervisor=source.slice(from,to); + unique(supervisor,TIMER);unique(supervisor,FINISH); + const blocks=innerObservers(clock); + supervisor=supervisor.replace(TIMER,blocks.begin+TIMER).replace(FINISH,FINISH+blocks.end); + return source.slice(0,from)+supervisor+source.slice(to); +} +export function removeInnerObservers(source,clock) { + for(const block of Object.values(innerObservers(clock))){unique(source,block);source=source.replace(block,'');} + return source; +} diff --git a/packages/cli/tests/case-inner-timing.test.mjs b/packages/cli/tests/case-inner-timing.test.mjs new file mode 100644 index 000000000..d7dfd3dd3 --- /dev/null +++ b/packages/cli/tests/case-inner-timing.test.mjs @@ -0,0 +1,33 @@ +import { test } from 'node:test'; +import assert from 'node:assert/strict'; +import { readFileSync, writeFileSync } from 'node:fs'; +import { spawnSync } from 'node:child_process'; +import { join } from 'node:path'; +import { tmp } from './helpers.mjs'; +import { instrumentInnerTimer, removeInnerObservers, readProbeSeconds } from './case-inner-timing-fixture.mjs'; +const scripts=['case1-accept.sh','case2-unit.sh']; +const read=name=>readFileSync(new URL(`../../../scripts/${name}`,import.meta.url),'utf8'); +for(const name of scripts)test(`inner timing ${name}: private copy preserves shipped bytes and rejects anchor drift`,t=>{ + const clock=join(tmp(t,'timer-'),'clock'); + const source=read(name),copy=instrumentInnerTimer(source,clock); + assert.equal(removeInnerObservers(copy,clock),read(name)); + for(const marker of ['SO_PEERCRED','MOSAIC_TESTER_SOCKET_V1','MOSAIC_LEGACY_STATUS']) + assert.equal(copy.split(marker).length,source.split(marker).length,marker); + for(const anchor of ['# row253-supervisor-begin\n','# row253-supervisor-end\n','"$sleep_bin" "$seconds" & timer=$!\n','finish() {\n local rc="$?"\n']){ + assert.throws(()=>instrumentInnerTimer(source.replace(anchor,''),clock),/anchor/); + assert.throws(()=>instrumentInnerTimer(source.replace(anchor,anchor+anchor),clock),/anchor/); + } +}); +for(const name of scripts)test(`inner timing ${name}: real supervisor retains streams status and EXIT cleanup`,t=>{ + const clock=join(tmp(t,'timer-'),"clock '$;literal");writeFileSync(clock,''); + const source=instrumentInnerTimer(read(name),clock); + const body=source.slice(source.indexOf('# row253-supervisor-begin'),source.indexOf('# row253-supervisor-end')); + const result=spawnSync('/bin/bash',['-c',body+'\n/bin/bash -c "$TESTER_SUPERVISOR" -- 2 /usr/bin/setsid /usr/bin/sleep /bin/bash -c \'printf exact-out; printf exact-err >&2; /usr/bin/sleep 0.1; exit 7\''],{encoding:'utf8'}); + assert.equal(result.status,87,result.stderr); + assert.equal(result.stdout,'exact-out');assert.equal(result.stderr,'exact-err'); + assert.match(readFileSync(clock,'utf8'),/^begin [0-9]+\.[0-9]{2}\nend [0-9]+\.[0-9]{2}\n$/); + // The same strict parser used by the timing bands rejects a guard's partial, + // duplicate or reversed pair, rather than substituting wall time. + for(const invalid of ['begin 10.00\n','end 11.00\n','begin 10.00\nend 11.00\nbegin 12.00\nend 13.00\n','begin 11.00\nend 10.00\n']) + assert.throws(()=>readProbeSeconds(invalid)); +}); diff --git a/packages/cli/tests/case1-accept.test.mjs b/packages/cli/tests/case1-accept.test.mjs index 2addbd9bf..746fd8eca 100644 --- a/packages/cli/tests/case1-accept.test.mjs +++ b/packages/cli/tests/case1-accept.test.mjs @@ -13,6 +13,7 @@ import { dirname, join } from "node:path"; import { fileURLToPath } from "node:url"; import { tmp } from "./helpers.mjs"; import { instrumentP10Probe, removeP10Observers, readProbeSeconds, P10_OBSERVERS } from "./case-p10-timing-fixture.mjs"; +import { instrumentInnerTimer } from "./case-inner-timing-fixture.mjs"; import { CASE_SUDO_SESSION, recordedLivePids, killRecordedPids, fixtureGuard, cleanupFixture, pollFixtureGone, blockingQuerySource, LEGACY_CASES } from "./case-sudo-fixture.mjs"; const REPO = fileURLToPath(new URL("../../../", import.meta.url)); @@ -968,8 +969,8 @@ test("row 195 accept: the host check runs with --check and never --enforce", (t) // Row276 exercises the real legacy launcher with fixture-only commands, never sudo. -function legacyBody() { - const source=read(SCRIPT),start=source.indexOf('# row253-supervisor-begin'),end=source.indexOf('# row276-legacy-end'); +function legacyBody(source=read(SCRIPT)) { + const start=source.indexOf('# row253-supervisor-begin'),end=source.indexOf('# row276-legacy-end'); assert.ok(start>=0&&end>start,'legacy supervisor block exists'); return source.slice(start,end); } @@ -991,11 +992,18 @@ for(const {tag} of LEGACY_CASES)test(`row276 ${tag} legacy inner timeout cleans const h=host(t),records=join(h.hc,'legacy-pids'),files=[join(h.hc,'session-pids'),records]; put(join(h.hc,'session-mode'),mode); const file=join(h.dir,'blocked.mjs');put(file,blockingQuerySource(records,'signals')+'\nloadSystem();'); - const capture=cleanupFixture(t,files),stop=fixtureGuard(t,files,4500); - const start=performance.now(),r=legacyCall(h,tag,[NODE,file]);capture(); + const clock=join(h.dir,'inner-clock');put(clock,'',0o600); + const body=legacyBody(instrumentInnerTimer(read(SCRIPT),clock)); + const capture=cleanupFixture(t,files),stop=fixtureGuard(t,files,4500,clock); + // The outer watchdog includes startup and cleanup; only the supervisor pair + // measures the inner budget. Seven seconds also lets the 4.5s guard expose a missing timer. + const start=performance.now(),r=legacyCall(h,tag,[NODE,file],{outer:7,body});capture(); assert.equal(r.status,81,r.stdout+r.stderr); assert.equal(r.stderr,`case1-accept: ${tag} inner-timeout\n`); - assert.ok((performance.now()-start)/1000<2,mode); + const seconds=readProbeSeconds(read(clock)),wall=(performance.now()-start)/1000; + assert.ok(seconds>=0.25&&seconds<1.25,`${tag}/${mode}: inner timer ${seconds}s (wall ${wall}s)`); + assert.ok(wall>=seconds,`${mode}: the call contains its timer interval`); + t.diagnostic(`${tag}/${mode}: inner ${seconds}s; wall ${wall}s`); assert.deepEqual(await pollFixtureGone(files),[],mode);await stop(); } }); diff --git a/packages/cli/tests/case2-unit.test.mjs b/packages/cli/tests/case2-unit.test.mjs index cc0a9a1ea..7a6382ec3 100644 --- a/packages/cli/tests/case2-unit.test.mjs +++ b/packages/cli/tests/case2-unit.test.mjs @@ -14,6 +14,7 @@ import { fileURLToPath } from "node:url"; import { businessDoc, systemConfig, writeJson } from "../../business/tests/helpers.mjs"; import { binds, prepareRun, sandboxArgv, sandboxProblem } from "../../seat/src/sandbox.mjs"; import { tmp } from "./helpers.mjs"; +import { instrumentInnerTimer, readProbeSeconds } from "./case-inner-timing-fixture.mjs"; import { CASE_SUDO_SESSION, recordedLivePids, killRecordedPids, fixtureGuard, cleanupFixture, pollFixtureGone, blockingQuerySource } from "./case-sudo-fixture.mjs"; const REPO = fileURLToPath(new URL("../../../", import.meta.url)); @@ -107,13 +108,13 @@ const libraryFlags = (h) => ["--port", "443", "--business", "acme", "--public-ho "--allow-user", "melanie", "--proof-header", "X-Proxy-Proof", "--proof-file", h.proof]; const factoryFlags = () => ["--port", "443", "--business", "acme", "--tester-socket"]; -function unit(h, { profile = "library", node = USR_NODE, copy = COPY_A, extra = [], flags, env = {}, outer = ["--business", "acme"], argv } = {}) { +function unit(h, { profile = "library", node = USR_NODE, copy = COPY_A, extra = [], flags, env = {}, outer = ["--business", "acme"], argv, script: unitScript = UNIT } = {}) { const serve = flags ?? (profile === "factory" ? factoryFlags() : libraryFlags(h)); const args = argv ?? ["--user", "mosaic", "--home", h.home, ...outer, "--copy", copy, "--node", node, "--profile", profile, ...extra, "--", ...serve]; - const r = spawnSync(UNIT, args, { + const r = spawnSync(unitScript, args, { encoding: "utf8", timeout: 30000, - env: { PATH: `${h.bin}:${process.env.PATH}`, CASE2_UNIT_DIR: h.units, CASE2_SYSTEMCTL: join(h.bin, "systemctl"), CASE2_GETENT: join(h.bin, "getent"), ...env }, + env: { HOME: process.env.HOME, TMPDIR: process.env.TMPDIR, LANG: process.env.LANG, PATH: `${h.bin}:${process.env.PATH}`, CASE2_UNIT_DIR: h.units, CASE2_SYSTEMCTL: join(h.bin, "systemctl"), CASE2_GETENT: join(h.bin, "getent"), ...env }, }); return { code: r.status, out: r.stdout, err: r.stderr }; } @@ -197,12 +198,27 @@ for(const kind of ['sleep','signals','member']) test(`row253 C4 ${kind} query ha const member=join(h.root,'q ) '+String.fromCharCode(10)+'mem'),proof=join(h.root,'comm-proof'); if(kind==='member')symlinkSync('/usr/bin/sleep',member); writeFileSync(join(copyDir(h),'packages/cli/src/config.mjs'),blockingQuerySource(queries,kind,member,proof)); - const capture=cleanupFixture(t,files);const stopGuard=fixtureGuard(t,files); - const start=performance.now(),r=unit(h,{profile:'factory'}),seconds=(performance.now()-start)/1000;capture(); + const clock=join(h.root,'inner-clock'),observed=join(h.root,'observed/scripts/case2-unit.sh'); + mkdirSync(dirname(observed),{recursive:true}); + symlinkSync(join(REPO,'scripts/selector.sh'),join(dirname(observed),'selector.sh')); + writeFileSync(clock,'',{mode:0o600}); + // The 7s outer watchdog spans startup and cleanup too. Give the private copy + // cleanup room while retaining a separate band on the unchanged 5s inner timer. + const source=read(UNIT),call='query="$(tester_capture 5 7 4096'; + assert.equal(source.split(call).length,2,'tester query budget anchor is unique'); + script(observed,instrumentInnerTimer(source.replace(call,call.replace(' 5 7 ',' 5 15 ')),clock)); + const capture=cleanupFixture(t,files);const stopGuard=fixtureGuard(t,files,9500,clock); + const start=performance.now(),r=unit(h,{profile:'factory',script:observed,env:{ + CASE2_BUS_TEMPLATE:BUS_TEMPLATE,CASE2_WEBUI_TEMPLATE:WEBUI_TEMPLATE, + CASE2_PROXY_TEMPLATE:join(REPO,'packages/cli/systemd/mosaic-proxy.service.in'), + }}),wall=(performance.now()-start)/1000;capture(); refuses(r,/^case2-unit: tester config query inner-timeout\n$/); + const seconds=readProbeSeconds(read(clock)); const [queryPid,querySid]=read(queries).trim().split('\n')[0].trim().split(/\s+/).map(Number); assert.equal(queryPid,querySid,`${kind}/${mode}: direct query PID must equal its kernel SID`); - assert.ok(seconds<7,`${kind}/${mode}: ${seconds}s exceeds outer bound`); + assert.ok(seconds>=4.25&&seconds<5.75,`${kind}/${mode}: inner timer ${seconds}s (wall ${wall}s)`); + assert.ok(wall>=seconds,`${mode}: the call contains its timer interval`); + t.diagnostic(`${kind}/${mode}: inner ${seconds}s; wall ${wall}s`); assert.deepEqual(await pollFixtureGone(files),[],mode); if(kind==='member')assert.ok(read(proof).includes('('+member.split('/').at(-1)+') '),'member comm with newline and closing parenthesis was observed'); assert.equal(existsSync(h.log),false,mode);await stopGuard();