diff --git a/packages/cli/tests/case-p10-timing-fixture.mjs b/packages/cli/tests/case-p10-timing-fixture.mjs index 28b47d569..6af98a2e8 100644 --- a/packages/cli/tests/case-p10-timing-fixture.mjs +++ b/packages/cli/tests/case-p10-timing-fixture.mjs @@ -5,6 +5,13 @@ const LEGACY = '# row276-legacy-begin'; // Stable even when a mutant removes the outer timeout from this command. const LAUNCH = ' LC_ALL=C '; const WAIT = ' wait "$child" 2>/dev/null || rc=$?\n'; +// org-base-reds: the root pair above also spans supervisor start-up and clean_session, a scan of +// every host /proc entry whose cost grows with the host's process count. The timer pair brackets +// only the inner timer: from just before the supervisor starts its sleep to the start of finish(). +const SUPERVISOR = '# row253-supervisor-begin\n'; +const SUPERVISOR_END = '# row253-supervisor-end\n'; +const TIMER = '"$sleep_bin" "$seconds" & timer=$!\n'; +const FINISH = 'finish() {\n local rc="$?"\n'; export const P10_OBSERVERS = Object.freeze({ begin: ` # row299-observer-begin-start @@ -20,6 +27,26 @@ export const P10_OBSERVERS = Object.freeze({ printf 'end %s\\n' "$row299_up" >> "$ROW299_TIMING_FILE"; } 2>/dev/null || : fi # row299-observer-end-end +`, + // Supervisor-side pair. Only the P10 peer's arguments carry the peer-credential option name. + // The pattern is split so this block never adds that literal to the supervisor text: the fake + // sudo stalls any command whose arguments contain it, and the supervisor text is an argument of + // every capture. finish() has no arguments of its own, so its stamp follows exactly one begin + // and is written at most once. + timerBegin: `# row299-timer-begin-start +if [ -n "\${ROW299_TIMER_FILE-}" ] && [[ "$*" == *SO_PEER*CRED* ]]; then + { read -r row299_up row299_spare < /proc/uptime && + printf 'begin %s\\n' "$row299_up" >> "$ROW299_TIMER_FILE"; } 2>/dev/null || : +fi +# row299-timer-begin-end +`, + timerEnd: ` # row299-timer-end-start + if [ -n "\${ROW299_TIMER_FILE-}" ]; then + { read -r row299_up row299_spare < /proc/uptime && + [[ "$(< "$ROW299_TIMER_FILE")" == begin* && "$(< "$ROW299_TIMER_FILE")" != *end* ]] && + printf 'end %s\\n' "$row299_up" >> "$ROW299_TIMER_FILE"; } 2>/dev/null || : + fi + # row299-timer-end-end `, }); @@ -40,7 +67,15 @@ export function instrumentP10Probe(source) { uniqueIndex(capture, WAIT); capture = capture.replace(LAUNCH, P10_OBSERVERS.begin + LAUNCH); capture = capture.replace(WAIT, WAIT + P10_OBSERVERS.end); - return source.slice(0, start) + capture + source.slice(end); + source = source.slice(0, start) + capture + source.slice(end); + const from = uniqueIndex(source, SUPERVISOR), to = uniqueIndex(source, SUPERVISOR_END); + if (to <= from) throw new Error('P10 observer supervisor scope is reversed'); + let supervisor = source.slice(from, to); + uniqueIndex(supervisor, TIMER); + uniqueIndex(supervisor, FINISH); + supervisor = supervisor.replace(TIMER, P10_OBSERVERS.timerBegin + TIMER); + supervisor = supervisor.replace(FINISH, FINISH + P10_OBSERVERS.timerEnd); + return source.slice(0, from) + supervisor + source.slice(to); } export function removeP10Observers(source) { diff --git a/packages/cli/tests/case1-accept.test.mjs b/packages/cli/tests/case1-accept.test.mjs index 5f0c9592a..2addbd9bf 100644 --- a/packages/cli/tests/case1-accept.test.mjs +++ b/packages/cli/tests/case1-accept.test.mjs @@ -378,6 +378,9 @@ test('row299 P10 timing copy preserves shipped bytes and isolates observer varia assert.deepEqual([...block.matchAll(/\b([A-Za-z_][A-Za-z0-9_]*)=/g)],[],'no other assignments in observer blocks'); assert.doesNotMatch(block,/\$ROOT|\$\{ROOT/,'fixture root cannot supply the clock'); } + // The fake sudo keys its faults on these argument markers; observers must not add or remove any. + for(const marker of['SO_PEERCRED','MOSAIC_TESTER_SOCKET_V1','MOSAIC_LEGACY_STATUS']) + assert.equal(copy.split(marker).length,source.split(marker).length,`observers keep the ${marker} count`); const changedTimer=source.replace('tester_capture 2 4 128','tester_capture 1 4 128'); assert.equal(removeP10Observers(instrumentP10Probe(changedTimer)),changedTimer,'copy keeps current timer mutants'); }); @@ -402,6 +405,34 @@ capture`; assert.match(read(clock),/^begin [0-9]+\.[0-9]{2}\nend [0-9]+\.[0-9]{2}\n$/); }); +test('row299 P10 timer observers keep supervisor status and record one P10 pair',t=>{ + const dir=tmp(t,'p10-timer-'),clock=join(dir,'clock'),trapFile=join(dir,'trap'); + put(clock,'',0o600); + // Same shape as TESTER_SUPERVISOR: positional arguments are the setsid command, finish() has none. + const program=`set +m +finish() { + local rc="$?" +${P10_OBSERVERS.timerEnd} printf trap > "$ROW299_TRAP_FILE" + exit "$rc" +} +trap finish EXIT +${P10_OBSERVERS.timerBegin}printf stdout-without-newline +printf stderr-without-newline >&2 +exit 81`; + const supervise=(...args)=>spawnSync('/bin/bash',['-c',program,'--',...args],{encoding:'utf8',env:{...process.env,ROW299_TIMER_FILE:clock,ROW299_TRAP_FILE:trapFile}}); + let r=supervise('node','-e','query'); + assert.equal(r.status,81);assert.equal(read(clock),'','a supervisor without the P10 peer records nothing'); + r=supervise('python','-c','getsockopt(SO_PEERCRED)'); + assert.equal(r.status,81); + assert.equal(r.stdout,'stdout-without-newline'); + assert.equal(r.stderr,'stderr-without-newline'); + assert.equal(read(trapFile),'trap'); + assert.match(read(clock),/^begin [0-9]+\.[0-9]{2}\nend [0-9]+\.[0-9]{2}\n$/); + const pair=read(clock); + r=supervise('node','-e','later'); + assert.equal(r.status,81);assert.equal(read(clock),pair,'a later supervisor cannot add a second end'); +}); + test('row299 P10 observer records are complete and ordered',()=>{ assert.equal(readProbeSeconds('begin 100.01\nend 102.03\n'),2.02); const invalid={ @@ -433,23 +464,33 @@ for(const fault of ['inner','outer','overflow'])test(`row253 C4 P10 ${fault} rea if(fault==='inner')put(join(h.hc,'peer-hang'),''); if(fault==='outer'){put(join(h.hc,'stall-probe'),'');put(join(h.hc,'stall-output'),'200 997 997\n');} if(fault==='overflow'){put(join(h.hc,'peer-output'),'200 997 997\n'+'X'.repeat(256));put(join(h.hc,'peer-status'),'0');} - let observedScript=SCRIPT,timingFile; + let observedScript=SCRIPT,timingFile,timerFile; if(fault==='inner'||fault==='outer'){ observedScript=join(h.dir,'case1-p10-observed.sh');timingFile=join(h.hc,'probe-uptime'); put(timingFile,'',0o600);put(observedScript,instrumentP10Probe(read(SCRIPT)),0o700); + // The outer fault stalls before the supervisor starts, so only the inner fault has a timer pair. + if(fault==='inner'){timerFile=join(h.hc,'timer-uptime');put(timerFile,'',0o600);} put(join(h.dir,'selector.sh'),read(join(REPO,'scripts','selector.sh')),0o644); assert.equal(removeP10Observers(read(observedScript)),read(SCRIPT),'observer reversal equals a fresh shipped script read'); } const stop=fixtureGuard(t,files,7000,timingFile); - const start=performance.now(),r=run(h,timingFile?{ROW299_TIMING_FILE:timingFile}:{},undefined,observedScript),seconds=(performance.now()-start)/1000;capture(); + const observe={...(timingFile?{ROW299_TIMING_FILE:timingFile}:{}),...(timerFile?{ROW299_TIMER_FILE:timerFile}:{})}; + const start=performance.now(),r=run(h,observe,undefined,observedScript),seconds=(performance.now()-start)/1000;capture(); assert.equal(r.status,0,r.out+r.err); const reason=fault==='inner'?'inner-timeout':fault==='outer'?'outer-timeout':'output-limit'; assert.match(r.out,new RegExp('P10 tester-socket-squat unnamed boundary=failed reason=probe-'+reason+' ')); assert.doesNotMatch(r.out,/boundary=observed/); - let probeSeconds=seconds; + let probeSeconds=seconds,timerSeconds; if(timingFile)assert.doesNotThrow(()=>{probeSeconds=readProbeSeconds(read(timingFile));},'P10 observer pair is required'); - if(fault==='inner'||fault==='outer')t.diagnostic(JSON.stringify({fault,mode,baselineSeconds,faultSeconds:seconds,probeSeconds})); - if(fault==='inner')assert.ok(probeSeconds>=1.25&&probeSeconds<2.75,`${mode}: direct probe ${probeSeconds}s; baseline ${baselineSeconds}s is diagnostic only`); + if(timerFile)assert.doesNotThrow(()=>{timerSeconds=readProbeSeconds(read(timerFile));},'P10 timer observer pair is required'); + if(fault==='inner'||fault==='outer')t.diagnostic(JSON.stringify({fault,mode,baselineSeconds,faultSeconds:seconds,probeSeconds,timerSeconds})); + // org-base-reds: the band applies to the inner timer itself. The root pair adds supervisor start-up and + // clean_session's whole-host /proc scan, which grows with the host's process count, so it must contain + // the timer pair but has no band of its own; probe-inner-timeout above already places it before the outer bound. + if(fault==='inner'){ + assert.ok(timerSeconds>=1.25&&timerSeconds<2.75,`${mode}: inner timer ${timerSeconds}s (root probe ${probeSeconds}s); baseline ${baselineSeconds}s is diagnostic only`); + assert.ok(probeSeconds>=timerSeconds,`${mode}: root probe ${probeSeconds}s must contain the inner timer ${timerSeconds}s`); + } if(fault==='outer'){ assert.ok(probeSeconds>=3.25&&probeSeconds<4.75,`${mode}: direct probe ${probeSeconds}s; baseline ${baselineSeconds}s is diagnostic only`); if(mode==='hop')assert.ok(recordedLivePids(files[0]).length>0,'stalled supervisor is R3 residual'); diff --git a/scripts/case2/launch.mjs b/scripts/case2/launch.mjs index f5250949e..eeb3b007e 100644 --- a/scripts/case2/launch.mjs +++ b/scripts/case2/launch.mjs @@ -8,6 +8,7 @@ import { startBroker } from '../../packages/bus/src/runtime.mjs'; import { grantDecision } from '../../packages/bus/tests/host-fixtures.mjs'; import { launchDoc } from '../../packages/organization/tests/helpers.mjs'; import { fakeHarnesses, fixture } from '../../packages/cli/tests/helpers.mjs'; +import { requestHostOps } from '../../packages/cli/tests/request-host-ops.mjs'; import { bootConfig, loadSystem } from '../../packages/cli/src/config.mjs'; import { createLauncher } from '../../packages/cli/src/launcher.mjs'; import { SESSION_CREDENTIALS } from '../../packages/seat/src/session.mjs'; @@ -101,6 +102,9 @@ export async function launchFixture(root, entry, { fetchToken, seatToken, humanT landHeld: m => runtime.landHeld(m.record), landHolders: m => runtime.landHolders(m.business), landRelease: m => runtime.landRelease(m.record), sessionClears: m => runtime.sessionClears(m.business), lifecycleRequests: m => runtime.lifecycleRequests(m.business), + // f23a998ee (#797) made every launch call request.admission; this fixture was the one host + // left without the request ops, so S3b's launch was refused. Shared with the cli fixtures. + ...requestHostOps(runtime), }; const wrap = fn => async value => { try { return await fn(value); }