Skip to content

Commit 4c5a62d

Browse files
authored
fix(org-drain): classify /update 409 lock contention as drain-superseded, not drain-failed (#1823)
fix(org-drain): classify /update 409 as drain-superseded, not drain-failed The OrgActor drain races the source's own SourceActor scrape. When a stale scrape source's 4h SourceActor poll lands within the scrape window of a drain dispatch, the SourceActor grabs the per-source scrape lock (#1814/#1815) a beat before the OrgActor dispatches its /update — so /update returns 409 "Source has an active MA session". The lock guard is working correctly (it prevents a double-scrape), and the source drains anyway via the lock holder's scrape. But the OrgActor logged every non-ok /update as `drain-failed` (warn), so this expected, benign contention polluted the drain-error signal. Treat a 409 (the only status the /update source-dedup lock returns) as `drain-superseded` at info level; every other non-ok status (spend cap 429, kill switch 503, mint failure) stays `drain-failed`.
1 parent c92b608 commit 4c5a62d

2 files changed

Lines changed: 62 additions & 6 deletions

File tree

workers/api/src/org-actor.ts

Lines changed: 14 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -12,8 +12,10 @@
1212
* No in-app budget: the discovery `/update` endpoint already enforces the per-org
1313
* ($2/day) + global ($15/day) dollar spend cap (checkSpendCap, #1055) and the
1414
* per-source scrape lock (#1815) before minting a session, so this actor just
15-
* dispatches. A rejected /update (cap hit / locked) is logged and dropped; the
16-
* source stays flagged and re-drains on a later SourceActor notify.
15+
* dispatches. A rejected /update is logged and dropped; the source stays flagged
16+
* and re-drains on a later SourceActor notify. A 409 (per-source scrape lock held
17+
* by the source's own SourceActor scrape) is the expected benign race — logged as
18+
* `drain-superseded`, not `drain-failed`, since the lock holder drains the source.
1719
*/
1820

1921
import { DurableObject } from "cloudflare:workers";
@@ -126,9 +128,17 @@ export class OrgActor extends DurableObject<OrgActorEnv> {
126128
});
127129
if (!res.ok) {
128130
const body = await res.text().catch(() => "");
129-
logEvent("warn", {
131+
// A 409 from /update is the per-source dedup scrape lock (#1814) firing:
132+
// the source's own SourceActor scrape grabbed the lock a beat before this
133+
// drain dispatched. That's benign — the lock holder drains the source, so
134+
// our /update was redundant, not failed. Classify it as `drain-superseded`
135+
// (info) rather than `drain-failed` so expected lock contention doesn't
136+
// pollute the drain-error signal. Every other non-ok status (spend cap
137+
// 429, kill switch 503, mint failure) is a genuine drop worth a warn.
138+
const superseded = res.status === 409;
139+
logEvent(superseded ? "info" : "warn", {
130140
component: "org-actor",
131-
event: "drain-failed",
141+
event: superseded ? "drain-superseded" : "drain-failed",
132142
orgId,
133143
status: res.status,
134144
detail: body.slice(0, 200),

workers/api/test/org-actor.test.ts

Lines changed: 48 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -119,7 +119,51 @@ describe("OrgActor", () => {
119119
expect(h.dispatched.length).toBe(0);
120120
});
121121

122-
it("does not throw when /update returns an error (spend cap / lock)", async () => {
122+
// Capture the JSON logEvent lines a run emits, by severity (info→log, warn→warn).
123+
async function captureLogs(fn: () => Promise<void>) {
124+
const info: any[] = [];
125+
const warn: any[] = [];
126+
const origLog = console.log;
127+
const origWarn = console.warn;
128+
const parse = (sink: any[]) => (line?: unknown) => {
129+
try {
130+
sink.push(JSON.parse(String(line)));
131+
} catch {
132+
/* non-JSON line, ignore */
133+
}
134+
};
135+
console.log = parse(info) as typeof console.log;
136+
console.warn = parse(warn) as typeof console.warn;
137+
try {
138+
await fn();
139+
} finally {
140+
console.log = origLog;
141+
console.warn = origWarn;
142+
}
143+
return { info, warn };
144+
}
145+
146+
it("classifies a 409 (scrape lock held) as drain-superseded, not drain-failed", async () => {
147+
const db = mkDb();
148+
seedFlaggedScrape(db, "src_a");
149+
const h = mkActor(
150+
db,
151+
() =>
152+
new Response("Source src_a has an active MA session (ma-abc)", {
153+
status: 409,
154+
headers: { "Retry-After": "900" },
155+
}),
156+
);
157+
await h.actor.ensureDrainScheduled("org_x");
158+
const { info, warn } = await captureLogs(() => h.actor.alarm()); // must not throw
159+
expect(h.dispatched.length).toBe(1);
160+
expect(h.alarmAt()).toBeNull();
161+
// Benign race: emitted at info level as drain-superseded, never as an error.
162+
expect(info.some((l) => l.event === "drain-superseded" && l.status === 409)).toBe(true);
163+
expect(warn.some((l) => l.event === "drain-failed")).toBe(false);
164+
});
165+
166+
it("classifies a non-409 error (spend cap 429) as drain-failed", async () => {
123167
const db = mkDb();
124168
seedFlaggedScrape(db, "src_a");
125169
const h = mkActor(
@@ -128,9 +172,11 @@ describe("OrgActor", () => {
128172
new Response(JSON.stringify({ error: "Daily global spend cap reached" }), { status: 429 }),
129173
);
130174
await h.actor.ensureDrainScheduled("org_x");
131-
await h.actor.alarm(); // must not throw
175+
const { info, warn } = await captureLogs(() => h.actor.alarm()); // must not throw
132176
expect(h.dispatched.length).toBe(1);
133177
expect(h.alarmAt()).toBeNull();
178+
expect(warn.some((l) => l.event === "drain-failed" && l.status === 429)).toBe(true);
179+
expect(info.some((l) => l.event === "drain-superseded")).toBe(false);
134180
});
135181

136182
it("does NOT dispatch when the kill switch is off at alarm time", async () => {

0 commit comments

Comments
 (0)