test(cli): band the P10 inner timer at the supervisor, not around cleanup (#1873)
The row299 root-side pair (mos-1409) spans supervisor start-up and clean_session, which scans every /proc entry on the host. With about 1,850 processes that adds 0.6 to 1.6 s, so the unchanged inner probe read 2.5 to 3.9 s and failed the [1.25, 2.75) band, while the 1 s inner-timer mutant read 2.06 to 2.38 s and passed. Widening the bound alone would have kept that mutant alive. A second observer pair, also confined to the private test copy, brackets only the inner timer: begin just before the supervisor starts its sleep, end at the start of finish(). It writes only for the SO_PEERCRED peer and at most one pair. The unchanged band now applies to that interval (2.01 s on base, 1.00 s and 3.00 s for the 1 s and 3 s mutants, so both fail). The root pair remains required and must contain the timer pair; probe-inner-timeout already places it before the outer bound.
This commit was merged in pull request #1925.
This commit is contained in:
1 parent
e3577e9d31
commit
e588fb32cb
2 files changed
+82
-6
No files matched your search
@@ -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) {
|
||||
|
||||
@@ -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');
|
||||
|
||||
Reference in new issue
Block a user