From 2c462ff5ccca41ad3baf73f38689cf2754df8f1a Mon Sep 17 00:00:00 2001 From: Marcel Wege Date: Mon, 3 Aug 2026 17:42:29 +0200 Subject: [PATCH] fix(plugins): bound the setup-field match, not the worker's birth (#607) The pattern match budget measured a window that included worker startup and module evaluation, so a valid credential could be rejected because the host was busy and a healthy pattern could be permanently reported to the operator as uncheckable. - The worker now handshakes when its message handler is installed, and readiness waits for that instead of the 'online' event. 'online' fires when the thread starts, well before the module has been evaluated; under tsx that gap is the loader re-running (84-212 ms measured), and on a cold start it was ~838 ms. All of it was charged to the budget. - The worker stays ref'd until it handshakes. Unref'ing on 'online' deadlocks: nothing holds the event loop open while awaiting the handshake, which surfaced as "Promise resolution is still pending but the event loop has already resolved" across the suite on node 22. - Budget raised 50 ms -> 250 ms. The worker boundary is what protects the event loop; this number only bounds how long one admin-only write waits. The measured IPC floor alone was 4-36 ms, so 50 ms rejected valid values with no regex work to speak of. - A budget overrun no longer records a pattern problem on its own. The write still fails closed immediately, but the durable "this field is unchecked" verdict now needs three consecutive overruns; any completed match resets the count. - A dead worker is retried once on a fresh thread. A budget expiry is never retried, so a hostile pattern still costs exactly one budget. - warmPatternWorker() is called at startup so the first operator to save a credential does not pay thread creation inside their request. Tests pin the cold-start path, the strike counter and its reset, using a pattern calibrated by measurement (500-char subject ~1.6 s vs 'abcd' ~0 ms on the same source). Verified on node 22.22.3 and 26.3.0. --- middleware/src/index.ts | 7 + middleware/src/plugins/setupFieldPattern.ts | 276 ++++++++++++++---- .../test/setupFieldPatternValidation.test.ts | 166 +++++++++++ 3 files changed, 387 insertions(+), 62 deletions(-) diff --git a/middleware/src/index.ts b/middleware/src/index.ts index 2fe2073e..536fa893 100644 --- a/middleware/src/index.ts +++ b/middleware/src/index.ts @@ -250,6 +250,7 @@ import { retryErroredPlugins, runLegacyBootstrap, } from './plugins/bootstrap.js'; +import { warmPatternWorker } from './plugins/setupFieldPattern.js'; import { BuiltInPackageStore } from './plugins/builtInPackageStore.js'; import { LocalDevPackageStore } from './plugins/localDevPackageStore.js'; import { FileSecretVault, resolveMasterKey } from './secrets/fileVault.js'; @@ -4424,6 +4425,12 @@ async function main(): Promise { // IPv4 (legacy + local dev) clients are served. Default `0.0.0.0` would // miss IPv6-only Fly-internal traffic — Stolperfalle #4 in // memory/feedback-fly-operational. + // Boot the setup-field pattern worker now, so the first operator to save a + // plugin credential does not pay thread creation inside their request's + // match budget (#607). Fire-and-forget: the worker is created on demand + // anyway, this only moves the cost off the critical path. + void warmPatternWorker(); + const server = app.listen(config.PORT, config.HOST, () => { console.log(`[middleware] listening on [${config.HOST}]:${config.PORT}`); console.log(`[middleware] skills dir: ${config.SKILLS_DIR}`); diff --git a/middleware/src/plugins/setupFieldPattern.ts b/middleware/src/plugins/setupFieldPattern.ts index 26a9461e..cdb45b2b 100644 --- a/middleware/src/plugins/setupFieldPattern.ts +++ b/middleware/src/plugins/setupFieldPattern.ts @@ -83,11 +83,38 @@ export const MAX_PATTERN_SOURCE_LENGTH = 512; export const MAX_PATTERN_INPUT_LENGTH = 8192; /** - * Wall-clock budget for one match, enforced by terminating the worker. Setup - * writes are rare and admin-only, so a generous bound costs nothing; a sane - * credential pattern completes in microseconds. + * Wall-clock budget for one match, enforced by terminating the worker. The + * clock starts when the worker has ACKNOWLEDGED it is ready to take work (see + * {@link ensureWorker}), so this bounds regex execution plus one IPC round + * trip — not thread creation and not module evaluation. + * + * WHY 250 AND NOT 50. The budget is not what protects the event loop; the + * worker boundary is. A runaway regex burns a thread that nothing else is + * waiting on, so the only thing this number really bounds is how long ONE + * admin-only setup write waits before giving up. Making it tight buys no + * safety and costs correctness: the first revision used 50 ms while the + * measured IPC floor alone was 4-36 ms on an idle machine, so a loaded host + * rejected valid values with no regex work to speak of (#607). 250 ms leaves + * an order of magnitude of headroom over the floor and is still imperceptible + * on a form submit. + */ +export const PATTERN_MATCH_BUDGET_MS = 250; + +/** + * How many times in a row a pattern must overrun before it is reported to the + * operator as unusable. + * + * An overrun is evidence about ONE execution — the host may simply have been + * busy — whereas {@link getPatternProblems} is a durable statement about the + * PATTERN. Conflating the two let a single unlucky match permanently label a + * healthy pattern "format check could not be applied" for the life of the + * process (#607). A genuinely hostile pattern overruns every time and trips + * this within three writes; a valid one recovers and resets the count. + * + * The individual write still fails CLOSED on the very first overrun. Only the + * durable verdict waits for corroboration. */ -export const PATTERN_MATCH_BUDGET_MS = 50; +export const PATTERN_OVERRUN_STRIKES = 3; /** Deepest group nesting the allowlist accepts (root counts as depth 0). */ const MAX_GROUP_DEPTH = 2; @@ -102,7 +129,8 @@ const MAX_GROUP_DEPTH = 2; * the `+` form the allowlist has always accepted, not a new one. (V8 compiles * counted repetition with a counter rather than unrolling it, so a huge bound * is not a compile-time blowup either: `^a{100000,}$` compiles AND matches a - * 100k subject in 0.43 ms.) The load-bearing bound is the 50 ms worker budget. + * 100k subject in 0.43 ms.) The load-bearing bound is the worker budget, see + * {@link PATTERN_MATCH_BUDGET_MS}. * * The cap is kept because it is free and it keeps an untrusted manifest from * naming an arbitrary number, and it is kept at 100 rather than raised because @@ -477,10 +505,34 @@ function compileUncached(source: string, context: string): CacheEntry { } } -/** Test-only: clears the compile cache and problem registry. */ +/** + * Consecutive budget overruns per `context|pattern`, reset by any completed + * match. See {@link PATTERN_OVERRUN_STRIKES}. + */ +const overrunStrikes = new Map(); + +/** + * Record one overrun. Returns true once the pattern has overrun + * {@link PATTERN_OVERRUN_STRIKES} times in a row — i.e. once it is fair to + * call the PATTERN broken rather than blaming a busy host. + */ +function noteOverrun(context: string, pattern: string): boolean { + const key = `${context}|${pattern}`; + const strikes = (overrunStrikes.get(key) ?? 0) + 1; + overrunStrikes.set(key, strikes); + return strikes >= PATTERN_OVERRUN_STRIKES; +} + +/** Any completed match clears the pattern's strike count. */ +function clearOverrunStrikes(context: string, pattern: string): void { + overrunStrikes.delete(`${context}|${pattern}`); +} + +/** Test-only: clears the compile cache, problem registry and strike counts. */ export function resetSetupPatternCache(): void { compiled.clear(); problems.length = 0; + overrunStrikes.clear(); } // --------------------------------------------------------------------------- @@ -505,6 +557,14 @@ parentPort.on('message', (msg) => { } parentPort.postMessage({ id: msg.id, matched, error }); }); +// Readiness HANDSHAKE — the whole point of #607. The 'online' event fires when +// the THREAD starts, which is well before this module has been evaluated and +// the listener above exists. Under tsx the gap is the loader re-running, which +// measured 84-212 ms; on a cold start it measured ~838 ms. Anything that waits +// on 'online' therefore charges module evaluation to the match budget and +// rejects valid values. This message is the only trustworthy "I can take work +// now" signal, so it is what the parent waits for. +parentPort.postMessage({ ready: true }); `; interface WorkerReply { @@ -513,6 +573,19 @@ interface WorkerReply { readonly error: string | null; } +/** Sent once by the worker when its message handler is installed. */ +interface WorkerHandshake { + readonly ready: true; +} + +function isHandshake(raw: unknown): raw is WorkerHandshake { + return ( + typeof raw === 'object' && + raw !== null && + (raw as { ready?: unknown }).ready === true + ); +} + let worker: Worker | null = null; let workerReady: Promise | null = null; let requestId = 0; @@ -525,17 +598,35 @@ function ensureWorker(): { w: Worker; ready: Promise } { return { w: worker, ready: workerReady }; } const w = new Worker(WORKER_SOURCE, { eval: true }); - // Starts REF'd so thread boot cannot be starved by an otherwise-idle event - // loop, then unrefs itself: an idle pattern worker must never be the reason - // the process (or a test run) refuses to exit. + // Readiness waits for the worker's own handshake, NOT for 'online' — see + // WORKER_SOURCE. The boot timeout resolves anyway rather than rejecting: a + // worker that never handshakes still degrades to an overrun on the first + // match, which is the same fail-closed path a wedged regex takes, instead of + // turning a broken thread pool into a 500. const ready = new Promise((resolve) => { - const boot = setTimeout(resolve, WORKER_BOOT_TIMEOUT_MS); - boot.unref(); - w.once('online', () => { + // The worker stays REF'd until it has handshaked. Unref'ing earlier (on + // 'online', as an intermediate revision did) is a deadlock: nothing else + // holds the event loop open while we await the handshake, so on an + // otherwise-idle loop node settles and the promise never resolves. That + // surfaced as "Promise resolution is still pending but the event loop has + // already resolved" across the whole suite on node 22. + const settle = (): void => { clearTimeout(boot); + w.off('message', onHandshake); + // Past this point an IDLE pattern worker must never be the reason the + // process (or a test run) refuses to exit. An in-flight match is held + // open by its own budget timer, not by the worker handle. w.unref(); resolve(); - }); + }; + const boot = setTimeout(settle, WORKER_BOOT_TIMEOUT_MS); + boot.unref(); + const onHandshake = (raw: unknown): void => { + if (!isHandshake(raw)) return; + settle(); + }; + w.on('message', onHandshake); + w.once('error', settle); }); const drop = (): void => { if (worker === w) { @@ -552,57 +643,89 @@ function ensureWorker(): { w: Worker; ready: Promise } { export type MatchOutcome = 'match' | 'no-match' | 'overrun'; +/** + * Internal outcome. `'timeout'` is evidence about the PATTERN (it burned the + * budget); `'worker-failed'` is evidence about the WORKER (it died, or never + * came up) and says nothing about the regex at all. Both surface publicly as + * `'overrun'`, but only the first is worth a retry decision — see + * {@link matchWithBudget}. + */ +type RunOutcome = MatchOutcome | 'timeout' | 'worker-failed'; + +/** One attempt, on whatever worker is current. Never throws. */ +async function runOnce(regex: RegExp, value: string): Promise { + const { w, ready } = ensureWorker(); + await ready; + const id = (requestId += 1); + return await new Promise((resolve) => { + let settled = false; + const finish = (outcome: RunOutcome): void => { + if (settled) return; + settled = true; + clearTimeout(timer); + w.off('message', onMessage); + w.off('error', onFailure); + w.off('exit', onFailure); + resolve(outcome); + }; + // The clock starts HERE, after `await ready` — i.e. after the worker's + // handshake — so it measures the match, not the thread's birth. + const timer = setTimeout(() => { + finish('timeout'); + if (worker === w) { + worker = null; + workerReady = null; + } + void w.terminate(); + }, PATTERN_MATCH_BUDGET_MS); + const onMessage = (raw: unknown): void => { + if (isHandshake(raw)) return; // late handshake from a warm-up race + const reply = raw as WorkerReply | null; + if (!reply || reply.id !== id) return; + if (reply.error !== null) { + // The pattern did not compile inside the worker. That is a property of + // the pattern, so it counts as a pattern-side failure. + finish('timeout'); + return; + } + finish(reply.matched ? 'match' : 'no-match'); + }; + const onFailure = (): void => { + finish('worker-failed'); + }; + w.on('message', onMessage); + w.on('error', onFailure); + w.on('exit', onFailure); + w.postMessage({ id, source: regex.source, flags: regex.flags, value }); + }); +} + /** * Run `regex` against `value` in a worker under {@link PATTERN_MATCH_BUDGET_MS}. * * Returns `'overrun'` when the budget expired (the worker is terminated and * discarded — a wedged regex cannot be interrupted any other way), when the - * worker died, or when the pattern failed to compile inside the worker. + * worker could not be kept alive, or when the pattern failed to compile inside + * the worker. + * + * A dead worker is retried ONCE on a fresh thread. That is not leniency toward + * runaway patterns — a budget expiry is never retried, so a hostile pattern + * still costs exactly one budget — it only stops an unrelated thread death + * (the previous caller's terminate landing on this caller's worker) from being + * reported as "your value is invalid". */ export async function matchWithBudget( regex: RegExp, value: string, ): Promise { const run = async (): Promise => { - const { w, ready } = ensureWorker(); - await ready; - const id = (requestId += 1); - return await new Promise((resolve) => { - let settled = false; - const finish = (outcome: MatchOutcome): void => { - if (settled) return; - settled = true; - clearTimeout(timer); - w.off('message', onMessage); - w.off('error', onFailure); - w.off('exit', onFailure); - resolve(outcome); - }; - const timer = setTimeout(() => { - finish('overrun'); - if (worker === w) { - worker = null; - workerReady = null; - } - void w.terminate(); - }, PATTERN_MATCH_BUDGET_MS); - const onMessage = (raw: unknown): void => { - const reply = raw as WorkerReply | null; - if (!reply || reply.id !== id) return; - if (reply.error !== null) { - finish('overrun'); - return; - } - finish(reply.matched ? 'match' : 'no-match'); - }; - const onFailure = (): void => { - finish('overrun'); - }; - w.on('message', onMessage); - w.on('error', onFailure); - w.on('exit', onFailure); - w.postMessage({ id, source: regex.source, flags: regex.flags, value }); - }); + let outcome = await runOnce(regex, value); + if (outcome === 'worker-failed') { + outcome = await runOnce(regex, value); + } + return outcome === 'timeout' || outcome === 'worker-failed' + ? 'overrun' + : outcome; }; const result = queue.then(run, run); @@ -613,6 +736,22 @@ export async function matchWithBudget( return await result; } +/** + * Boot the pattern worker ahead of any request. Optional but wired into + * middleware startup: without it the FIRST operator to save a credential pays + * thread creation, which measured ~838 ms (#607). Idempotent, never throws, + * and cheap to skip — the worker is created on demand regardless. + */ +export async function warmPatternWorker(): Promise { + try { + const { ready } = ensureWorker(); + await ready; + } catch { + // A pattern worker that refuses to boot must not take startup with it; the + // on-demand path will retry and fail closed per write if it stays broken. + } +} + /** Test/shutdown seam: terminate the pooled worker. */ export async function shutdownPatternWorker(): Promise { const w = worker; @@ -725,19 +864,32 @@ export async function checkSetupFieldPattern( const outcome = await matchWithBudget(regex, value); if (outcome === 'overrun') { - // The pattern (not the value) is the problem, but we cannot prove the value - // is acceptable, so fail CLOSED for this write and make the pattern - // diagnosable. The operator sees the field's generic "wrong format" copy. + // We cannot prove the value is acceptable, so this WRITE fails closed and + // the operator sees the field's generic "wrong format" copy — unchanged. + // + // The durable verdict is a separate question. One overrun does not prove + // the pattern is broken; it may just be a busy host losing a race with the + // budget. Only a run of them earns an entry in the problems registry, + // because that entry is what tells the operator the field is permanently + // unchecked (#607). + const proven = noteOverrun(context, field.pattern); console.error( `[setup] pattern match exceeded ${PATTERN_MATCH_BUDGET_MS}ms for ${context}; ` + - `treating the value as a violation. pattern=${JSON.stringify(field.pattern)}`, - ); - recordProblem( - context, - field.pattern, - `match exceeded the ${PATTERN_MATCH_BUDGET_MS}ms execution budget`, + `treating the value as a violation. pattern=${JSON.stringify(field.pattern)}` + + (proven + ? ` — ${String(PATTERN_OVERRUN_STRIKES)} consecutive overruns, marking the pattern unusable.` + : ''), ); + if (proven) { + recordProblem( + context, + field.pattern, + `match exceeded the ${String(PATTERN_MATCH_BUDGET_MS)}ms execution budget ` + + `${String(PATTERN_OVERRUN_STRIKES)} times in a row`, + ); + } return violation; } + clearOverrunStrikes(context, field.pattern); return outcome === 'match' ? null : violation; } diff --git a/middleware/test/setupFieldPatternValidation.test.ts b/middleware/test/setupFieldPatternValidation.test.ts index 9ef4c19a..d0bea672 100644 --- a/middleware/test/setupFieldPatternValidation.test.ts +++ b/middleware/test/setupFieldPatternValidation.test.ts @@ -23,6 +23,7 @@ import { resetSetupPatternCache, screenPatternSource, shutdownPatternWorker, + warmPatternWorker, MAX_PATTERN_INPUT_LENGTH, } from '../src/plugins/setupFieldPattern.js'; @@ -796,3 +797,168 @@ describe('OM-17 / F4 — server anchoring matches HTML `pattern=` semantics', () ); }); }); + +/** + * #607 — the budget has to bound the MATCH, not the worker's birth. + * + * The shipped first revision started its clock at dispatch and waited only for + * the worker's `'online'` event. `'online'` fires when the THREAD starts, which + * is well before the worker module has been evaluated — so module evaluation + * was charged to the match budget. Measured on a cold process: 838 ms for a + * trivial email pattern. Under `node --import tsx` — which is exactly how this + * suite runs — every call overran, because the worker re-runs tsx's loader. + * + * That is the point of running these assertions here rather than in a + * hand-driven script: if the handshake regresses, the tsx path breaks first and + * these tests are the ones that notice. + */ +describe('#607 — the match budget must not include worker startup', () => { + beforeEach(() => { + resetSetupPatternCache(); + }); + + after(async () => { + await shutdownPatternWorker(); + }); + + it('a trivial match on a COLD worker stays well inside the budget', async () => { + // Force a genuinely cold worker: this is the 838 ms case. + await shutdownPatternWorker(); + const field = { + key: 'gw_subject_default', + pattern: '^[^@\\s]+@[^@\\s]+\\.[A-Za-z]{2,63}$', + }; + const started = Date.now(); + const violation = await checkSetupFieldPattern( + field, + 'assistant@te-printline.de', + ); + const elapsed = Date.now() - started; + + assert.equal(violation, null, 'a valid address was rejected on a cold worker'); + // The whole call may legitimately take longer than the budget — it includes + // thread creation. What must NOT happen is the value being rejected, or the + // pattern being blamed, because of that startup cost. + assert.deepEqual( + getPatternProblems(), + [], + `a healthy pattern was marked unusable after a ${String(elapsed)}ms cold start`, + ); + }); + + it('warmPatternWorker is idempotent and leaves the worker usable', async () => { + await shutdownPatternWorker(); + await warmPatternWorker(); + await warmPatternWorker(); + assert.equal(await matchWithBudget(/^a+$/, 'aaa'), 'match'); + }); + + it('repeated cold starts never reject a valid value', async () => { + const field = { key: 'k', pattern: '^[a-z]+@[a-z]+\\.[a-z]{2,63}$' }; + for (let i = 0; i < 3; i += 1) { + await shutdownPatternWorker(); + assert.equal( + await checkSetupFieldPattern(field, 'ops@example.de'), + null, + `cold start #${String(i + 1)} rejected a valid value`, + ); + } + assert.deepEqual(getPatternProblems(), []); + }); +}); + +/** + * #607 — an overrun is evidence about ONE execution, not about the pattern. + * + * `getPatternProblems()` is what surfaces "this field declares a format check + * that could not be applied" to the operator, for the life of the process. The + * first revision wrote into it on the very first overrun, so a single unlucky + * match permanently mislabelled a healthy pattern. The write still fails closed + * immediately; only the durable verdict now waits for corroboration. + */ +describe('#607 — one overrun must not permanently blame the pattern', () => { + beforeEach(() => { + resetSetupPatternCache(); + }); + + after(async () => { + await shutdownPatternWorker(); + }); + + /** + * Passes the allowlist — deliberately. Every quantifier sits on a bare + * character class, so no "quantified group containing a quantifier" rule + * fires; the cost comes from four adjacent unbounded runs splitting a + * non-matching subject every possible way. This is precisely the shape the + * allowlist cannot catch and the execution bound must. + * + * Calibrated by measurement on node 22, first call in a fresh process: + * + * 'a'*100 + '!' → 10 ms 'abcd' → 0 ms + * 'a'*200 + '!' → 125 ms + * 'a'*400 + '!' → 1604 ms + * + * SLOW_SUBJECT sits an order of magnitude past the 250 ms budget so the + * overrun is not a race, and FAST_SUBJECT completes immediately — the SAME + * pattern, which is what makes the reset test meaningful (strikes are keyed + * by context AND pattern). + * + * A NOTE ON MEASURING THIS, because it cost a round: V8 caches compiled + * regexes by source, so timing a subject AFTER another subject has already + * run the same source reports the warm number. An earlier revision of this + * test picked a subject that measured 0.011 ms that way and was 2152 ms on a + * cold first call. Always measure the first call in a fresh process. + */ + const SLOW_PATTERN = '^[a-z]+[a-z]+[a-z]+[a-z]+$'; + const SLOW_SUBJECT = `${'a'.repeat(500)}!`; + const FAST_SUBJECT = 'abcd'; + + it('the allowlist really does accept this pattern (so the bound is what stops it)', () => { + assert.equal(screenPatternSource(SLOW_PATTERN), null); + }); + + it('the first overrun rejects the write but does NOT record a problem', async () => { + const field = { key: 'slow', pattern: SLOW_PATTERN }; + const violation = await checkSetupFieldPattern(field, SLOW_SUBJECT); + assert.equal(violation?.field, 'slow', 'the write must still fail closed'); + assert.deepEqual( + getPatternProblems(), + [], + 'a single overrun must not mark the pattern unusable', + ); + }); + + it('three consecutive overruns do record a problem', async () => { + const field = { key: 'slow', pattern: SLOW_PATTERN }; + for (let i = 0; i < 3; i += 1) { + await checkSetupFieldPattern(field, SLOW_SUBJECT); + } + const problems = getPatternProblems(); + assert.equal(problems.length, 1, 'the pattern should now be reported'); + assert.equal(problems[0]?.context, 'slow'); + assert.match(String(problems[0]?.reason), /times in a row/); + }); + + it('a completed match resets the strike count', async () => { + const slow = { key: 'slow', pattern: SLOW_PATTERN }; + // Two strikes... + await checkSetupFieldPattern(slow, SLOW_SUBJECT); + await checkSetupFieldPattern(slow, SLOW_SUBJECT); + // ...then a value the SAME pattern disposes of immediately, proving the + // pattern was never the problem. + assert.equal( + await checkSetupFieldPattern(slow, FAST_SUBJECT), + null, + 'expected a clean match, not an overrun', + ); + assert.deepEqual( + getPatternProblems(), + [], + 'the run was broken by a completed match', + ); + // A third slow value is therefore only strike one again — without the + // reset this call would be the third and would record a problem. + await checkSetupFieldPattern(slow, SLOW_SUBJECT); + assert.deepEqual(getPatternProblems(), []); + }); +});