From 59dbf27f434b20930be971c80aa64c3d9854db40 Mon Sep 17 00:00:00 2001 From: Arnas Donauskas Date: Tue, 28 Jul 2026 15:21:28 +0300 Subject: [PATCH] fix(automations): stop inbound runs being dropped and mislogged MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Two defects that together produce the reported symptom — automation logs that read `status: 'success'` with `steps_executed: []`. 1. The dispatch loop in the inbound webhook was fire-and-forget inside the route's `after()` block. `after()` only keeps the function alive for promises it can see, so the run could be frozen after the log row was inserted but before any step executed. This is the same failure mode as issue #301, recurring one level down — the comments on the AI auto-reply and `message.received` dispatches immediately below already spell out the invariant this violated. Now awaited; the per-iteration `.catch` is kept so one trigger type can't skip the rest of the loop. 2. `executeAutomation` seeded the log row with `status: 'success'` before running anything. A run that died mid-flight therefore left a permanent success with no steps, indistinguishable from an automation that genuinely had nothing to do. Seeded as `'failed'` instead, so the status only becomes success if execution actually reaches a terminal path. No migration needed — 'failed' is already in the column's CHECK constraint, and every terminal path overwrites it. Two more points from the issue are deliberately not addressed here, as both change existing behaviour and want a maintainer decision: switching `contains` keyword matching to word boundaries (would alter which automations fire for current users) and re-opening a closed conversation on an inbound reply. Refs #409. Co-Authored-By: Claude Opus 5 --- src/app/api/whatsapp/webhook/route.ts | 10 +++++- src/lib/automations/engine.test.ts | 48 ++++++++++++++++++++++++++- src/lib/automations/engine.ts | 10 +++++- 3 files changed, 65 insertions(+), 3 deletions(-) diff --git a/src/app/api/whatsapp/webhook/route.ts b/src/app/api/whatsapp/webhook/route.ts index 7687637..f642e2d 100644 --- a/src/app/api/whatsapp/webhook/route.ts +++ b/src/app/api/whatsapp/webhook/route.ts @@ -781,8 +781,16 @@ async function processMessage( // listens to only one trigger runs only when that trigger matches. if (contactOutcome.wasCreated) automationTriggers.unshift('new_contact_created') if (isFirstInboundMessage) automationTriggers.unshift('first_inbound_message') + // Awaited — not fire-and-forget. We're inside the route's `after()` + // block, which only keeps the function alive for promises it can see, so + // a detached dispatch can be frozen part-way through: the log row is + // inserted, then the steps never run. That is issue #301's failure mode + // recurring one level down, and it's what issue #409 reported as runs + // logging zero steps. `runAutomationsForTrigger` owns its own try/catch + // and never throws; the `.catch` is belt-and-braces so one trigger + // type's failure can't skip the rest of the loop. for (const triggerType of automationTriggers) { - runAutomationsForTrigger({ + await runAutomationsForTrigger({ accountId, triggerType, contactId: contactRecord.id, diff --git a/src/lib/automations/engine.test.ts b/src/lib/automations/engine.test.ts index 7dd0ed0..8c00979 100644 --- a/src/lib/automations/engine.test.ts +++ b/src/lib/automations/engine.test.ts @@ -11,6 +11,7 @@ const h = vi.hoisted(() => ({ fromCalls: [] as string[], updateCalls: [] as { table: string; filters: [string, string, unknown][] }[], upsertCalls: [] as { table: string; payload: unknown }[], + logInserts: [] as Record[], logUpdates: [] as Record[], }, })); @@ -46,7 +47,10 @@ vi.mock("./admin-client", () => { } if (table === "automations") return { data: state.automations, error: null }; if (table === "automation_logs") { - if (type === "insert") return { data: { id: "log1" }, error: null }; + if (type === "insert") { + state.logInserts.push(ops.payload as Record); + return { data: { id: "log1" }, error: null }; + } if (type === "update") { state.logUpdates.push(ops.payload as Record); return { data: null, error: null }; @@ -113,6 +117,7 @@ beforeEach(() => { h.state.fromCalls = []; h.state.updateCalls = []; h.state.upsertCalls = []; + h.state.logInserts = []; h.state.logUpdates = []; }); @@ -170,6 +175,47 @@ describe("runAutomationsForTrigger — tenant isolation", () => { }); }); +describe("automation_logs — status is seeded pessimistically (issue #409)", () => { + it("writes the log row as 'failed' before any step runs", async () => { + h.state.owned = { id: "c1" }; + h.state.automations = [automationWithUpdateStep()]; + h.state.steps = [updateStep()]; + + await runAutomationsForTrigger({ + accountId: ACCOUNT, + triggerType: "new_message_received", + contactId: "c1", + context: {}, + }); + + // The insert happens before execution, so a run killed mid-flight must + // not leave behind a row that claims it succeeded. + expect(h.state.logInserts).toHaveLength(1); + expect(h.state.logInserts[0]).toMatchObject({ + status: "failed", + steps_executed: [], + }); + }); + + it("still promotes the log to 'success' once the steps complete", async () => { + h.state.owned = { id: "c1" }; + h.state.automations = [automationWithUpdateStep()]; + h.state.steps = [updateStep()]; + + await runAutomationsForTrigger({ + accountId: ACCOUNT, + triggerType: "new_message_received", + contactId: "c1", + context: {}, + }); + + // The seed is only a floor — the outermost scope still writes the real + // verdict, so a completed run reports success as it always did. + const withStatus = h.state.logUpdates.filter((u) => "status" in u); + expect(withStatus.at(-1)).toMatchObject({ status: "success" }); + }); +}); + describe("update_contact_field — custom fields", () => { it("upserts contact_custom_values when the field is account-owned", async () => { h.state.owned = { id: "c1" }; diff --git a/src/lib/automations/engine.ts b/src/lib/automations/engine.ts index a87a4cc..37b32f7 100644 --- a/src/lib/automations/engine.ts +++ b/src/lib/automations/engine.ts @@ -189,7 +189,15 @@ async function executeAutomation(automation: Automation, input: DispatchInput) { contact_id: input.contactId ?? null, trigger_event: input.triggerType, steps_executed: [], - status: 'success', + // Seeded pessimistically. The row is written BEFORE any step runs, + // and every terminal path below overwrites it (`appendResults` at + // the outermost scope, or `finalizeLog`). Seeding 'success' meant a + // run that died mid-flight — the process frozen, the pod recycled — + // left a permanent `status: 'success'` with `steps_executed: []`, + // indistinguishable from an automation that genuinely had nothing + // to do. 'failed' inverts that: the status only becomes success if + // execution actually reached the end. See issue #409. + status: 'failed', }) .select() .single()