Skip to content

Commit 2875a31

Browse files
fix(pm): write-pace fails closed on an unrecordable log, and its lock is bounded by attempts
Three things the first draft got wrong, all found by its own new cases: - an unwritable log threw out of the transport. `paceWrite` now REFUSES with the distinct exit code and a one-line remedy — a throttle that cannot record cannot count, so it cannot honestly allow the write either; - `noteResponse` is the asymmetric half: it runs one line before the caller throws the platform's own refusal, so it never throws, and reports the consequence (the marker did not land) instead; - the lock retry was bounded only by a deadline read from an injected clock. A recursive mkdir over a path that is a FILE answers EEXIST, the same code contention answers, so an unusable path read as a busy lock and spun forever under a clock that does not advance. Bounded by attempts as well, the directory mkdir moved out of the retry, and both pinned. Claude-Session: https://claude.ai/code/session_012GcsUbuqFGBibkEDMRC1eE Co-Authored-By: Claude <noreply@anthropic.com>
1 parent 63f55e3 commit 2875a31

1 file changed

Lines changed: 107 additions & 29 deletions

File tree

‎scripts/pm/write-pace.mjs‎

Lines changed: 107 additions & 29 deletions
Original file line numberDiff line numberDiff line change
@@ -147,6 +147,9 @@ export const TOKEN_KEY_LENGTH = 12;
147147
const LOCK_WAIT_MS = 5_000;
148148
const LOCK_STALE_MS = 15_000;
149149
const LOCK_POLL_MS = 40;
150+
// The second bound. See `withPaceLock`: a deadline read from an injected clock
151+
// is not a bound on its own.
152+
const LOCK_MAX_ATTEMPTS = 400;
150153

151154
// ---------------------------------------------------------------------------
152155
// Pure core — every decision this file makes is one of the functions below,
@@ -373,6 +376,26 @@ export function stoppedText(d) {
373376
].join('\n');
374377
}
375378

379+
/**
380+
* The log could not be written.
381+
*
382+
* `paceWrite` FAILS CLOSED here, and the asymmetry with `noteResponse` below is
383+
* deliberate: a throttle that cannot record cannot enforce a budget, so it
384+
* cannot honestly let the write through either — writing unrecorded is exactly
385+
* the state that suspended two accounts. It runs BEFORE the request, so nothing
386+
* is half-written, and the remedy is one line long.
387+
*/
388+
export function unrecordableText(file, error) {
389+
return [
390+
`✗ write-pace: REFUSED — the throttle cannot write its log at ${file}`,
391+
` (${error?.message ?? String(error)}).`,
392+
' A throttle that cannot record cannot count, so it cannot allow this write either — writing',
393+
' unrecorded is the state this instrument exists to prevent. ⛔ Nothing was written.',
394+
' Fix: make that path writable, or point `OS_PM_WRITE_PACE_FILE` at a path that is.',
395+
` Exit ${EXIT_WRITE_PACE_REFUSED} is this refusal and nothing else.`,
396+
].join('\n');
397+
}
398+
376399
/** Rule ① — the pause, said out loud. */
377400
export function gapText(d, kind) {
378401
return (
@@ -444,29 +467,41 @@ export function withPaceLock(file, fn, { now = () => Date.now(), sleep = sleepSy
444467
const lock = `${file}.lock`;
445468
const deadline = now() + LOCK_WAIT_MS;
446469
let held = false;
447-
for (;;) {
470+
471+
// Outside the retry, because its failures are not contention. A recursive
472+
// mkdir over a path that exists and is NOT a directory answers EEXIST — the
473+
// same code lock contention answers — so leaving it inside made an unusable
474+
// PATH look like a busy lock and spun. `fn()` below reports it properly.
475+
try {
476+
mkdirSync(dirname(file), { recursive: true });
477+
} catch {
478+
/* fn() will fail with the real reason, and paceWrite refuses on it */
479+
}
480+
481+
// ⛔ Bounded by ATTEMPTS as well as by the deadline. A deadline alone is not
482+
// a bound: it is read from an injected clock, and a clock that does not
483+
// advance — a test's, a suspended container's — turns `now() >= deadline` into
484+
// a condition that is never true. Two bounds, so neither can be the only one.
485+
for (let attempt = 0; attempt < LOCK_MAX_ATTEMPTS && now() < deadline; attempt++) {
448486
try {
449-
mkdirSync(dirname(file), { recursive: true });
450487
mkdirSync(lock);
451488
held = true;
452489
break;
453490
} catch (e) {
454-
if (e?.code !== 'EEXIST') break;
455-
let age = 0;
491+
if (e?.code !== 'EEXIST') break; // an unusable lock never blocks a write
492+
let age = null;
456493
try {
457494
age = now() - statSync(lock).mtimeMs;
458495
} catch {
459-
continue; // it went away between the mkdir and the stat — try again
496+
age = null; // it went away between the mkdir and the stat
460497
}
461-
if (age > LOCK_STALE_MS) {
498+
if (age !== null && age > LOCK_STALE_MS) {
462499
try {
463500
rmdirSync(lock);
464501
} catch {
465502
/* someone else broke it first */
466503
}
467-
continue;
468504
}
469-
if (now() >= deadline) break;
470505
sleep(LOCK_POLL_MS);
471506
}
472507
}
@@ -519,16 +554,22 @@ export async function paceWrite({ token, kind = 'write' } = {}, deps = {}) {
519554
const nowMs = now();
520555
let decision;
521556

522-
withPaceLock(
523-
file,
524-
() => {
525-
const kept = pruneRecords(readRecordsFrom(file), nowMs);
526-
decision = decidePace({ records: kept, key, nowMs, minGapMs, hourlyMax });
527-
if (decision.verdict === 'ok') kept.push({ t: decision.issueAtMs, k: key, kind });
528-
writeRecordsTo(file, kept);
529-
},
530-
{ now, sleep: deps.sleepSync ?? sleepSync },
531-
);
557+
try {
558+
withPaceLock(
559+
file,
560+
() => {
561+
const kept = pruneRecords(readRecordsFrom(file), nowMs);
562+
decision = decidePace({ records: kept, key, nowMs, minGapMs, hourlyMax });
563+
if (decision.verdict === 'ok') kept.push({ t: decision.issueAtMs, k: key, kind });
564+
writeRecordsTo(file, kept);
565+
},
566+
{ now, sleep: deps.sleepSync ?? sleepSync },
567+
);
568+
} catch (e) {
569+
log(unrecordableText(file, e));
570+
exit(EXIT_WRITE_PACE_REFUSED);
571+
return { verdict: 'unrecordable', key, refused: true, exitCode: EXIT_WRITE_PACE_REFUSED, file, error: e?.message ?? String(e) };
572+
}
532573

533574
if (decision.verdict === 'stopped') {
534575
log(stoppedText(decision));
@@ -566,17 +607,33 @@ export function noteResponse({ token, status, headers, body, verdict } = {}, dep
566607
if (!signal) return null;
567608

568609
const key = tokenKey(token);
569-
withPaceLock(
570-
file,
571-
() => {
572-
const kept = pruneRecords(readRecordsFrom(file), nowMs);
573-
kept.push({ stop: signal.untilMs, k: key, why: signal.why, at: nowMs });
574-
writeRecordsTo(file, kept);
575-
},
576-
{ now, sleep: deps.sleepSync ?? sleepSync },
577-
);
610+
try {
611+
withPaceLock(
612+
file,
613+
() => {
614+
const kept = pruneRecords(readRecordsFrom(file), nowMs);
615+
kept.push({ stop: signal.untilMs, k: key, why: signal.why, at: nowMs });
616+
writeRecordsTo(file, kept);
617+
},
618+
{ now, sleep: deps.sleepSync ?? sleepSync },
619+
);
620+
} catch (e) {
621+
// ⛔ This half NEVER throws, and that is not the same judgement as
622+
// `paceWrite`'s. It is called on a transport's error path, one line before
623+
// the caller throws the platform's own refusal — an exception raised here
624+
// would REPLACE that error and hide what the platform said. So it reports
625+
// the consequence instead, in the one line it has, and lets the real error
626+
// travel.
627+
log(
628+
`write-pace: ⚠ could not record the stop marker in ${file} (${e?.message ?? String(e)}). ` +
629+
`${signal.why}, so this identity has been asked to back off until ${stampUtc(signal.untilMs)} — but the ` +
630+
'NEXT write by this token will NOT be refused, because nothing is on disk to refuse it. Stop writing by ' +
631+
'hand until then, and fix the path or point `OS_PM_WRITE_PACE_FILE` somewhere writable.',
632+
);
633+
return { ...signal, key, file, recorded: false };
634+
}
578635
log(markerText(signal, key, nowMs));
579-
return { ...signal, key, file };
636+
return { ...signal, key, file, recorded: true };
580637
}
581638

582639
/** `--status`: this token's budget and any active marker, without writing anything. */
@@ -634,7 +691,7 @@ const SELF_TEST_BATTERIES = Object.freeze({
634691
'rule ②: the 41st is REFUSED, with a prescription': 8,
635692
'rule ③: what writes a stop marker, how long it lasts, what it refuses': 10,
636693
'the prune: the trailing hour for writes, the expiry for markers': 6,
637-
'the log, --status and the CLI: what lands on disk, and what must never': 9,
694+
'the log, --status and the CLI: what lands on disk, and what must never': 14,
638695
'the wiring: both halves, in every write transport, on write verbs only': 7,
639696
});
640697
const SELF_TEST_BATTERY_FLOOR = 9;
@@ -873,6 +930,27 @@ export async function selfTest() {
873930
});
874931
t('the CLI reports a budget nobody has spent yet, at exit 0', spawned.status === 0 && spawned.stdout.includes(`budget : 0 of ${DEFAULT_HOURLY_MAX}`), true, JSON.stringify(spawned.stdout));
875932
t('an unrecognised flag is usage, ⛔ never a silent pass', spawnSync(process.execPath, [SELF, '--paec'], { encoding: 'utf8' }).status, EXIT_USAGE);
933+
934+
// An unwritable log: the parent of the path is a FILE, so every mkdir on
935+
// the way to it fails. The two halves answer this DIFFERENTLY on purpose.
936+
const blocker = join(dir, 'not-a-directory');
937+
writeFileSync(blocker, 'x', 'utf8');
938+
const bad = harness(join(blocker, 'pace.jsonl'));
939+
const unrecordable = await paceWrite({ token: TOKEN, kind: 'label-write POST' }, bad.deps);
940+
t('⛔ a log it cannot write REFUSES the write — unrecorded is the state this exists to prevent', [unrecordable.verdict, bad.state.exits], ['unrecordable', [EXIT_WRITE_PACE_REFUSED]]);
941+
t('…naming the path and the one-line remedy', bad.text().includes('OS_PM_WRITE_PACE_FILE'));
942+
const noted = noteResponse({ token: TOKEN, status: 429 }, bad.deps);
943+
t('⛔ but `noteResponse` does NOT throw — it runs one line before the caller throws the platform\'s own error', [noted.recorded, noted.why], [false, 'HTTP 429']);
944+
945+
// ⛔ THE case the attempt bound exists for, found by the case above: a
946+
// lock somebody else holds, plus a clock that does not advance. The
947+
// deadline can then never fire, so only the attempt bound ends the wait.
948+
const heldFile = join(dir, 'held.jsonl');
949+
mkdirSync(`${heldFile}.lock`, { recursive: true });
950+
let ran = false;
951+
withPaceLock(heldFile, () => { ran = true; }, { now: () => T0, sleep: () => {} });
952+
t('⛔ a held lock under a FROZEN clock still returns — the attempt bound, never the deadline, ends it', ran);
953+
t('…and the lock it could not take is left alone, ⛔ never stolen', existsSync(`${heldFile}.lock`));
876954
}
877955
} finally {
878956
rmSync(dir, { recursive: true, force: true });

0 commit comments

Comments
 (0)