From 6332f3dd3b20c63b241892f31b31e4080a227a9c Mon Sep 17 00:00:00 2001 From: JSONbored <49853598+JSONbored@users.noreply.github.com> Date: Fri, 10 Jul 2026 04:17:30 -0700 Subject: [PATCH] fix(selfhost): gate maintenance admission on genuine live pressure, not raw pending count (#4669) evaluateMaintenanceAdmission's live_pending_high/live_job_age_high checks used livePendingCount/oldestLivePendingAgeMs, which include work deliberately deferred to the future (e.g. agent-regate-pr's normal, staggered per-PR backlog). That let a routine, expected backlog starve the maintenance lane for hours even when the box was otherwise idle, since the checks never reached the drain escape meant to prevent exactly this. Switch both checks to the runnable-now/processing signal they were always meant to use, and broaden that signal to also count actively processing jobs as genuine current pressure (not just due-and-unclaimed ones). --- src/selfhost/maintenance-admission.ts | 41 +++++++++---- src/selfhost/pg-queue.ts | 8 ++- src/selfhost/sqlite-queue.ts | 8 ++- .../selfhost-maintenance-admission.test.ts | 61 +++++++++++++------ test/unit/selfhost-pg-queue.test.ts | 4 +- test/unit/selfhost-sqlite-queue.test.ts | 5 +- 6 files changed, 92 insertions(+), 35 deletions(-) diff --git a/src/selfhost/maintenance-admission.ts b/src/selfhost/maintenance-admission.ts index 3d3bfefeda..f71d088843 100644 --- a/src/selfhost/maintenance-admission.ts +++ b/src/selfhost/maintenance-admission.ts @@ -73,18 +73,31 @@ export function isMaintenanceJobType(type: string): boolean { } export interface MaintenancePressureSignals { + /** Foreground-priority rows in pending/processing regardless of run_after -- includes work deliberately + * scheduled for later (e.g. agent-regate-pr's staggered/rate-deferred per-PR backlog, index.ts:24-29's + * "normal, expected, can legitimately stay nonzero for long periods"). Retained ONLY for the + * gittensory_queue_live_pending observability gauge (server.ts) -- evaluateMaintenanceAdmission deliberately + * does NOT gate on this (#selfhost-maintenance-admission-runnable-signal): a raw count would starve + * maintenance on backlog that was never actually competing for a claim slot. Use liveRunnableNowCount for + * any real pressure decision. */ livePendingCount: number; + /** Age in ms of the oldest live row by created_at, regardless of run_after -- same "observability only, + * not an admission signal" caveat as livePendingCount above; a deliberately future-scheduled job inflates + * this without meaning anything is stuck. Use oldestLiveRunnableAgeMs for a real pressure decision. */ oldestLivePendingAgeMs: number | null; - /** Foreground-priority pending jobs that are RUNNABLE right now (run_after<=now), i.e. not currently - * deferred by any mechanism -- distinct from livePendingCount, which also includes deferred/processing - * work. #selfhost-queue-liveness's own diagnostic: "queue large but intentionally deferred" (this count can - * be 0 with livePendingCount > 0, transiently, and that is fine) vs. "queue stuck" (this count stays 0 - * while oldestLiveRunnableAgeMs -- once something IS runnable -- climbs, or while releaseStaleForegroundDeferrals - * keeps finding stale work every sweep). */ + /** Foreground-priority jobs that are genuinely active RIGHT NOW: either 'processing' (already claimed, + * real in-flight resource use) or 'pending' AND due (run_after<=now, not currently deferred by any + * mechanism) -- distinct from livePendingCount, which also includes work deliberately deferred to the + * future. #selfhost-queue-liveness's own diagnostic: "queue large but intentionally deferred" (this count + * can be 0 with livePendingCount > 0, transiently, and that is fine) vs. "queue stuck" (this count stays 0 + * while oldestLiveRunnableAgeMs -- once something IS active -- climbs, or while releaseStaleForegroundDeferrals + * keeps finding stale work every sweep). This is the field evaluateMaintenanceAdmission's live_pending_high + * check actually gates on. */ liveRunnableNowCount: number; - /** Age in ms of the oldest RUNNABLE (run_after<=now) foreground pending job -- null when none is runnable - * right now. Distinct from oldestLivePendingAgeMs, which is dominated by a job intentionally scheduled far - * in the future and says nothing about how long already-due work has sat unclaimed. */ + /** Age in ms of the oldest genuinely-active (processing, or pending AND due) foreground job -- null when + * none qualifies right now. Distinct from oldestLivePendingAgeMs, which is dominated by a job intentionally + * scheduled far in the future and says nothing about how long already-active work has sat unclaimed/running. + * This is the field evaluateMaintenanceAdmission's live_job_age_high check actually gates on. */ oldestLiveRunnableAgeMs: number | null; maintenancePendingCount: number; oldestMaintenancePendingAgeMs: number | null; @@ -220,8 +233,14 @@ export function evaluateMaintenanceAdmission( ): MaintenanceAdmissionDecision { if (!config.enabled) return { admit: true, reason: "disabled" }; if (nowMs - pendingSinceMs >= config.maxDeferAgeMs) return { admit: true, reason: "trickle_max_defer_age" }; - if (signals.livePendingCount > config.maxLivePendingCount) return { admit: false, reason: "live_pending_high" }; - if (signals.oldestLivePendingAgeMs !== null && signals.oldestLivePendingAgeMs > config.maxLiveJobAgeMs) { + // Gated on genuinely ACTIVE live work (processing, or pending AND due), not the raw pending/processing + // count (#selfhost-maintenance-admission-runnable-signal): agent-regate-pr's normal, expected, staggered/ + // rate-deferred per-PR backlog (index.ts:24-29) sits in 'pending' for a long time by design without being + // due yet, so counting it here would starve maintenance on work that was never actually competing for a + // claim slot -- exactly the "queue large but intentionally deferred" case liveRunnableNowCount's own doc + // comment (above) distinguishes from a genuinely stuck queue. + if (signals.liveRunnableNowCount > config.maxLivePendingCount) return { admit: false, reason: "live_pending_high" }; + if (signals.oldestLiveRunnableAgeMs !== null && signals.oldestLiveRunnableAgeMs > config.maxLiveJobAgeMs) { return { admit: false, reason: "live_job_age_high" }; } if (signals.backlogConvergencePendingCount > config.maxBacklogConvergencePendingCount) { diff --git a/src/selfhost/pg-queue.ts b/src/selfhost/pg-queue.ts index a59585578f..932a422514 100644 --- a/src/selfhost/pg-queue.ts +++ b/src/selfhost/pg-queue.ts @@ -416,10 +416,14 @@ export function createPgQueue( * distinguishes "queue large but intentionally deferred" from "queue stuck, nothing runnable" without * manual SQL. Host load is an independent, optional signal. */ async function maintenancePressureSignals(now: number): Promise { + // runnable_cnt/oldest_runnable count a row as genuinely active RIGHT NOW when it's either already + // 'processing' (real, in-flight resource use) or 'pending' AND due (run_after<=now) -- NOT merely present + // in the outer pending/processing set, which also includes work deliberately deferred to the future (see + // maintenance-admission.ts's MaintenancePressureSignals doc comments). const liveRes = await pool.query( `SELECT COUNT(*) AS cnt, MIN(created_at) AS oldest, - COUNT(*) FILTER (WHERE status='pending' AND run_after<=$2) AS runnable_cnt, - MIN(created_at) FILTER (WHERE status='pending' AND run_after<=$2) AS oldest_runnable + COUNT(*) FILTER (WHERE status='processing' OR run_after<=$2) AS runnable_cnt, + MIN(created_at) FILTER (WHERE status='processing' OR run_after<=$2) AS oldest_runnable FROM ${TABLE} WHERE status IN ('pending','processing') AND priority>=$1`, [FOREGROUND_QUEUE_PRIORITY_FLOOR, now], ); diff --git a/src/selfhost/sqlite-queue.ts b/src/selfhost/sqlite-queue.ts index 672af9665b..19eb5071fd 100644 --- a/src/selfhost/sqlite-queue.ts +++ b/src/selfhost/sqlite-queue.ts @@ -1379,10 +1379,14 @@ function backfillJobForegroundLanes(driver: SqliteDriver): number { * distinguishes "queue large but intentionally deferred" from "queue stuck, nothing runnable" without manual * SQL. Host load is an independent, optional signal (see host-pressure.ts). */ function maintenancePressureSignals(driver: SqliteDriver, now: number): MaintenancePressureSignals { + // runnable_cnt/oldest_runnable count a row as genuinely active RIGHT NOW when it's either already + // 'processing' (real, in-flight resource use) or 'pending' AND due (run_after<=now) -- NOT merely present + // in the outer pending/processing set, which also includes work deliberately deferred to the future (see + // maintenance-admission.ts's MaintenancePressureSignals doc comments). const live = driver.query( `SELECT COUNT(*) as cnt, MIN(created_at) as oldest, - SUM(CASE WHEN status='pending' AND run_after<=? THEN 1 ELSE 0 END) as runnable_cnt, - MIN(CASE WHEN status='pending' AND run_after<=? THEN created_at ELSE NULL END) as oldest_runnable + SUM(CASE WHEN status='processing' OR run_after<=? THEN 1 ELSE 0 END) as runnable_cnt, + MIN(CASE WHEN status='processing' OR run_after<=? THEN created_at ELSE NULL END) as oldest_runnable FROM ${TABLE} WHERE status IN ('pending','processing') AND priority>=?`, [now, now, FOREGROUND_QUEUE_PRIORITY_FLOOR], ).rows[0] as { cnt: number; oldest: number | null; runnable_cnt: number | null; oldest_runnable: number | null }; diff --git a/test/unit/selfhost-maintenance-admission.test.ts b/test/unit/selfhost-maintenance-admission.test.ts index 3308daf4e3..6c3eb8514c 100644 --- a/test/unit/selfhost-maintenance-admission.test.ts +++ b/test/unit/selfhost-maintenance-admission.test.ts @@ -71,7 +71,7 @@ describe("evaluateMaintenanceAdmission", () => { it("admits unconditionally when disabled, even under extreme pressure", () => { const decision = evaluateMaintenanceAdmission( - { ...CLEAR_SIGNALS, livePendingCount: 999 }, + { ...CLEAR_SIGNALS, liveRunnableNowCount: 999 }, { ...CONFIG, enabled: false }, now - 1_000, now, @@ -79,9 +79,9 @@ describe("evaluateMaintenanceAdmission", () => { expect(decision).toEqual({ admit: true, reason: "disabled" }); }); - it("defers when live pending count exceeds the threshold", () => { + it("defers when live runnable-now count exceeds the threshold", () => { const decision = evaluateMaintenanceAdmission( - { ...CLEAR_SIGNALS, livePendingCount: 6 }, + { ...CLEAR_SIGNALS, liveRunnableNowCount: 6 }, CONFIG, now - 1_000, now, @@ -89,9 +89,9 @@ describe("evaluateMaintenanceAdmission", () => { expect(decision).toEqual({ admit: false, reason: "live_pending_high" }); }); - it("admits when live pending count is AT (not over) the threshold", () => { + it("admits when live runnable-now count is AT (not over) the threshold", () => { const decision = evaluateMaintenanceAdmission( - { ...CLEAR_SIGNALS, livePendingCount: 5 }, + { ...CLEAR_SIGNALS, liveRunnableNowCount: 5 }, CONFIG, now - 1_000, now, @@ -99,9 +99,23 @@ describe("evaluateMaintenanceAdmission", () => { expect(decision.admit).toBe(true); }); - it("defers when the oldest live job has waited past the max age", () => { + // Regression (#4669): a raw pending/processing count includes agent-regate-pr's normal, expected, + // staggered/rate-deferred per-PR backlog (index.ts:24-29), which can sit well above maxLivePendingCount for + // long periods without any of it actually being due -- before this fix, that alone starved the maintenance + // lane even with zero real live pressure. + it("does NOT defer on a high raw live-pending count alone when nothing is actually runnable", () => { const decision = evaluateMaintenanceAdmission( - { ...CLEAR_SIGNALS, oldestLivePendingAgeMs: 120_001 }, + { ...CLEAR_SIGNALS, livePendingCount: 999, liveRunnableNowCount: 0 }, + CONFIG, + now - 1_000, + now, + ); + expect(decision).toEqual({ admit: true, reason: "pressure_clear" }); + }); + + it("defers when the oldest RUNNABLE live job has waited past the max age", () => { + const decision = evaluateMaintenanceAdmission( + { ...CLEAR_SIGNALS, oldestLiveRunnableAgeMs: 120_001 }, CONFIG, now - 1_000, now, @@ -109,9 +123,9 @@ describe("evaluateMaintenanceAdmission", () => { expect(decision).toEqual({ admit: false, reason: "live_job_age_high" }); }); - it("admits when there is no live job at all (null oldest age)", () => { + it("admits when there is no runnable live job at all (null oldest runnable age)", () => { const decision = evaluateMaintenanceAdmission( - { ...CLEAR_SIGNALS, oldestLivePendingAgeMs: null }, + { ...CLEAR_SIGNALS, oldestLiveRunnableAgeMs: null }, CONFIG, now - 1_000, now, @@ -119,6 +133,19 @@ describe("evaluateMaintenanceAdmission", () => { expect(decision.admit).toBe(true); }); + // Regression (#4669): oldestLivePendingAgeMs is created_at-based, not run_after-based, so it is dominated by + // a job intentionally scheduled far in the future -- before this fix, a deliberately staggered/deferred job + // could trip this the same way a genuinely stuck job would. + it("does NOT defer on a high raw oldest-live-pending age alone when nothing runnable is stale", () => { + const decision = evaluateMaintenanceAdmission( + { ...CLEAR_SIGNALS, oldestLivePendingAgeMs: 999_999_999, oldestLiveRunnableAgeMs: null }, + CONFIG, + now - 1_000, + now, + ); + expect(decision).toEqual({ admit: true, reason: "pressure_clear" }); + }); + it("defers when the maintenance lane itself is already backed up", () => { const decision = evaluateMaintenanceAdmission( { ...CLEAR_SIGNALS, maintenancePendingCount: 16 }, @@ -226,9 +253,9 @@ describe("evaluateMaintenanceAdmission", () => { expect(decision).toEqual({ admit: true, reason: "pressure_clear" }); }); - it("admits when the oldest live job's age is AT (not over) the threshold", () => { + it("admits when the oldest runnable live job's age is AT (not over) the threshold", () => { const decision = evaluateMaintenanceAdmission( - { ...CLEAR_SIGNALS, oldestLivePendingAgeMs: 120_000 }, + { ...CLEAR_SIGNALS, oldestLiveRunnableAgeMs: 120_000 }, CONFIG, now - 1_000, now, @@ -238,7 +265,7 @@ describe("evaluateMaintenanceAdmission", () => { it("force-admits via trickle once pending since exceeds the max defer age, even under pressure", () => { const decision = evaluateMaintenanceAdmission( - { ...CLEAR_SIGNALS, livePendingCount: 999, hostLoadAvg1PerCore: 99 }, + { ...CLEAR_SIGNALS, liveRunnableNowCount: 999, hostLoadAvg1PerCore: 99 }, CONFIG, now - CONFIG.maxDeferAgeMs, now, @@ -248,7 +275,7 @@ describe("evaluateMaintenanceAdmission", () => { it("does not trickle-admit a job that hasn't waited long enough yet", () => { const decision = evaluateMaintenanceAdmission( - { ...CLEAR_SIGNALS, livePendingCount: 999 }, + { ...CLEAR_SIGNALS, liveRunnableNowCount: 999 }, CONFIG, now - (CONFIG.maxDeferAgeMs - 1), now, @@ -258,7 +285,7 @@ describe("evaluateMaintenanceAdmission", () => { it("checks live pressure before maintenance-lane pressure (priority order)", () => { const decision = evaluateMaintenanceAdmission( - { ...CLEAR_SIGNALS, livePendingCount: 6, maintenancePendingCount: 16 }, + { ...CLEAR_SIGNALS, liveRunnableNowCount: 6, maintenancePendingCount: 16 }, CONFIG, now - 1_000, now, @@ -266,9 +293,9 @@ describe("evaluateMaintenanceAdmission", () => { expect(decision.reason).toBe("live_pending_high"); }); - it("checks the oldest-live-job age before maintenance-lane pressure (priority order)", () => { + it("checks the oldest-runnable-live-job age before maintenance-lane pressure (priority order)", () => { const decision = evaluateMaintenanceAdmission( - { ...CLEAR_SIGNALS, oldestLivePendingAgeMs: 120_001, maintenancePendingCount: 16 }, + { ...CLEAR_SIGNALS, oldestLiveRunnableAgeMs: 120_001, maintenancePendingCount: 16 }, CONFIG, now - 1_000, now, @@ -305,7 +332,7 @@ describe("evaluateMaintenanceAdmission", () => { ); expect(beforeMaintenance.reason).toBe("backlog_convergence_high"); const afterLive = evaluateMaintenanceAdmission( - { ...CLEAR_SIGNALS, backlogConvergencePendingCount: 11, livePendingCount: 6 }, + { ...CLEAR_SIGNALS, backlogConvergencePendingCount: 11, liveRunnableNowCount: 6 }, CONFIG, now - 1_000, now, diff --git a/test/unit/selfhost-pg-queue.test.ts b/test/unit/selfhost-pg-queue.test.ts index 5aafbf0532..90d405064a 100644 --- a/test/unit/selfhost-pg-queue.test.ts +++ b/test/unit/selfhost-pg-queue.test.ts @@ -3217,7 +3217,7 @@ describe("createPgQueue (durable #977)", () => { it("defers a maintenance job when live queue pressure is high", async () => { const m = makePool(); - m.setPressureSignals({ live: { cnt: 6, oldest: now } }); // default threshold is 5 + m.setPressureSignals({ live: { cnt: 6, oldest: now, runnableCnt: 6 } }); // default threshold is 5 m.enqueueResult({ rows: [], rowCount: 0 }); // empty foreground claim m.enqueueResult({ rows: [maintenanceRow], rowCount: 1 }); // background claim const started: string[] = []; @@ -3236,7 +3236,7 @@ describe("createPgQueue (durable #977)", () => { it("logs a deferred maintenance admission at info level, not warn (#selfhost-backpressure-noise)", async () => { const m = makePool(); - m.setPressureSignals({ live: { cnt: 6, oldest: now } }); // default threshold is 5 + m.setPressureSignals({ live: { cnt: 6, oldest: now, runnableCnt: 6 } }); // default threshold is 5 m.enqueueResult({ rows: [], rowCount: 0 }); // empty foreground claim m.enqueueResult({ rows: [maintenanceRow], rowCount: 1 }); // background claim const logged = vi.spyOn(console, "log").mockImplementation(() => undefined); diff --git a/test/unit/selfhost-sqlite-queue.test.ts b/test/unit/selfhost-sqlite-queue.test.ts index 9f2d27a2ba..4e3d52a49a 100644 --- a/test/unit/selfhost-sqlite-queue.test.ts +++ b/test/unit/selfhost-sqlite-queue.test.ts @@ -3379,7 +3379,10 @@ describe("createSqliteQueue (durable #980)", () => { }); // Directly occupies rows the way currently-pending/processing live work would, without needing worker-slot - // choreography -- the admission check reads real table state, not the consumer callback. + // choreography -- the admission check reads real table state, not the consumer callback. Defaults to + // 'processing' (stably occupied for the whole test, unlike a genuinely due 'pending' row which this + // queue's own pump would claim and complete during drain()) -- liveRunnableNowCount counts 'processing' + // rows as genuine current pressure alongside due-and-unclaimed 'pending' ones (see maintenance-admission.ts). function seedLiveRows(driver: ReturnType, count: number, status: "pending" | "processing" = "processing"): void { const now = Date.now(); for (let i = 0; i < count; i += 1) {