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) {