From 56bfcadca962235ea8c52818fff135de92132f44 Mon Sep 17 00:00:00 2001 From: Georgy Butaev <41178744+g-but@users.noreply.github.com> Date: Fri, 28 Aug 2026 22:52:14 +0200 Subject: [PATCH 1/2] fix(payments): a crash mid-settlement lost the order, silently and forever MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit handlePaymentConfirmed flips the intent to `paid` FIRST — deliberately, because that conditional update is the lock that makes settlement run exactly once — and only then writes the order, decrements inventory, notifies the seller, grants entitlements and fans out webhooks. A crash in that gap lost every one of them, permanently and in total silence: * the row is paid, so every later observer's claimPaidTransition returns false and skips the side-effects as "already settled"; * refreshPaymentStatus short-circuits on terminal statuses; * the reconcile cron sweeps only CREATED / INVOICE_READY / PENDING_CONFIRMATION, so it never looks at a paid row again. The buyer's money is gone, their order sits in pending_payment forever, and nothing anywhere reports a problem. bitbaum/orangecat#563 finding 4. `side_effects_at` is the marker: stamped when the settlement path completes, on both the tip branch and the main one. NULL on a paid intent means the side-effects did not finish, and the reconcile sweep now reports those — riding the existing cron tick rather than adding a second timer, and running even when there is nothing to reconcile, since an incomplete settlement is a PAID row and never appears among the sweep's own candidates. WHY IT REPORTS AND DOES NOT REPLAY Replaying looks like the obvious fix and is a worse bug. decrement_inventory is a blind `inventory_count - 1` with no idempotency key — read from the live database, not assumed — so re-running settlement for one sale decrements twice and quietly destroys stock; plan grants and entitlements have the same shape. Trading an invisible loss for a silent corruption is not progress. Safe replay needs per-effect receipts, which is a separate and larger piece of work. This converts a permanent silent loss into a named, actionable one, which is the part that could not wait. The marker also does not claim every async fan-out landed: several effects are deliberately fire-and-forget, so it says the settlement path RAN TO COMPLETION. Stated in the code rather than implied. The column is deliberately NOT granted to anon/authenticated — payment_intents uses column-level SELECT grants and this is an internal operations marker. A partial index on (paid_at) WHERE status='paid' AND side_effects_at IS NULL keeps the per-minute check off a seq scan, and is empty whenever things are healthy. Mutation-proven: dropping the side_effects_at filter fails the predicate test, and downgrading the report from error to warn fails the loudness test. A detector that goes quiet is indistinguishable from one finding nothing, which is this whole bug. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_018waGt1ieA9TjpscqrbrnGb --- .../payments/incomplete-settlement.test.ts | 114 ++++++++++++++++++ src/domain/payments/paymentSettlement.ts | 45 +++++++ src/services/payments/reconcile.ts | 94 ++++++++++++++- ...8220000_settlement_side_effects_marker.sql | 40 ++++++ 4 files changed, 292 insertions(+), 1 deletion(-) create mode 100644 __tests__/unit/payments/incomplete-settlement.test.ts create mode 100644 supabase/migrations/20260828220000_settlement_side_effects_marker.sql diff --git a/__tests__/unit/payments/incomplete-settlement.test.ts b/__tests__/unit/payments/incomplete-settlement.test.ts new file mode 100644 index 000000000..4feb9c15f --- /dev/null +++ b/__tests__/unit/payments/incomplete-settlement.test.ts @@ -0,0 +1,114 @@ +/** + * Incomplete-settlement detection — bitbaum/orangecat#563 finding 4. + * + * handlePaymentConfirmed flips the intent to `paid` FIRST, because that + * conditional update is the lock that makes settlement run exactly once. Only + * then does it write the order, decrement inventory, notify the seller and fan + * out webhooks. + * + * A crash in that gap used to lose all of it in total silence — the row is + * paid, so every later observer's claimPaidTransition returns false and skips + * it as already settled, refresh short-circuits on terminal statuses, and the + * reconcile sweep only looks at CREATED / INVOICE_READY / PENDING_CONFIRMATION. + * The buyer's money is gone and their order sits in pending_payment forever. + * + * These tests pin the query that finds those rows, and — just as important — + * that it does NOT try to replay them. + */ + +import { findIncompleteSettlements } from '@/services/payments/reconcile'; +import { STATUS } from '@/config/database-constants'; + +jest.mock('@/utils/logger', () => ({ + logger: { error: jest.fn(), warn: jest.fn(), info: jest.fn() }, +})); + +import { logger } from '@/utils/logger'; + +/** Records the filters applied, so the predicate itself can be asserted. */ +function makeAdmin(result: { data: unknown; error: unknown }) { + const calls: Record = {}; + const chain = { + select: jest.fn().mockReturnThis(), + eq: jest.fn((col: string, val: unknown) => { + calls[`eq:${col}`] = val; + return chain; + }), + is: jest.fn((col: string, val: unknown) => { + calls[`is:${col}`] = val; + return chain; + }), + lt: jest.fn((col: string, val: unknown) => { + calls[`lt:${col}`] = val; + return chain; + }), + order: jest.fn().mockReturnThis(), + limit: jest.fn().mockResolvedValue(result), + }; + return { + admin: { from: jest.fn(() => chain) } as never, + calls, + chain, + }; +} + +describe('findIncompleteSettlements', () => { + beforeEach(() => jest.clearAllMocks()); + + it('asks for paid intents with no side-effects marker', async () => { + const { admin, calls } = makeAdmin({ data: [], error: null }); + await findIncompleteSettlements(admin); + + expect(calls['eq:status']).toBe(STATUS.PAYMENT_INTENTS.PAID); + expect(calls['is:side_effects_at']).toBeNull(); + // Only rows old enough that settlement cannot still be in flight — a + // detector that reports mid-flight work gets ignored. + expect(typeof calls['lt:paid_at']).toBe('string'); + expect(Date.parse(calls['lt:paid_at'] as string)).toBeLessThan(Date.now()); + }); + + it('says nothing when every paid intent completed', async () => { + const { admin } = makeAdmin({ data: [], error: null }); + const result = await findIncompleteSettlements(admin); + + expect(result).toEqual({ count: 0, ids: [] }); + expect(logger.error).not.toHaveBeenCalled(); + }); + + it('reports loudly, naming the intents, when settlement was lost', async () => { + const { admin } = makeAdmin({ + data: [{ id: 'pi-1' }, { id: 'pi-2' }], + error: null, + }); + const result = await findIncompleteSettlements(admin); + + expect(result.count).toBe(2); + expect(result.ids).toEqual(['pi-1', 'pi-2']); + // error, not warn: a buyer paid and their order never moved. + expect(logger.error).toHaveBeenCalledTimes(1); + const [, payload] = (logger.error as jest.Mock).mock.calls[0]; + expect(payload.paymentIntentIds).toEqual(['pi-1', 'pi-2']); + }); + + it('never throws the sweep away when the check itself fails', async () => { + const { admin } = makeAdmin({ data: null, error: { message: 'boom' } }); + const result = await findIncompleteSettlements(admin); + + // The reconciliation half is load-bearing and must still run… + expect(result).toEqual({ count: 0, ids: [] }); + // …but a detector that goes quiet on error is indistinguishable from one + // finding nothing, which is the exact bug this exists to end. + expect(logger.error).toHaveBeenCalledTimes(1); + }); + + it('does not attempt to repair anything', async () => { + // Replaying settlement looks like the obvious fix and is a worse bug: + // decrement_inventory is a blind `inventory_count - 1` with no idempotency + // key, so a replay quietly destroys stock. Detection only, on purpose. + const { admin, chain } = makeAdmin({ data: [{ id: 'pi-1' }], error: null }); + await findIncompleteSettlements(admin); + + expect(chain).not.toHaveProperty('update'); + expect((chain.select as jest.Mock).mock.calls[0][0]).toBe('id'); + }); +}); diff --git a/src/domain/payments/paymentSettlement.ts b/src/domain/payments/paymentSettlement.ts index ef8a12689..0d8297383 100644 --- a/src/domain/payments/paymentSettlement.ts +++ b/src/domain/payments/paymentSettlement.ts @@ -64,6 +64,48 @@ async function claimPaidTransition(paymentIntentId: string): Promise { return (data?.length ?? 0) > 0; } +/** + * Record that the settlement path finished. + * + * `claimPaidTransition` flips the intent to paid FIRST — that conditional update + * is the lock that makes settlement run exactly once — so between it and the + * work below there is a window where a crash loses the order, the inventory + * decrement, the notifications and the webhooks FOREVER: the row is paid, so + * every later observer skips it as already settled, refresh short-circuits on + * terminal statuses, and the reconcile cron only sweeps non-terminal ones. + * + * This marker makes that window visible. NULL on a paid intent means the + * side-effects did not complete, which the reconcile sweep reports. + * + * What it does NOT claim: several effects are deliberately fire-and-forget + * (`void ...`), so this says the settlement path RAN TO COMPLETION, not that + * every async fan-out landed. Distinguishing those needs per-effect receipts, + * which is a different piece of work. + * + * Never throws. The payment is already settled; failing the caller here would + * 500 a buyer whose money has moved, and the terminal-status short-circuit + * means the retry would not re-run anything anyway. + */ +async function markSideEffectsComplete( + paymentIntentId: string, + admin: SupabaseClient +): Promise { + const { error } = await admin + .from(DATABASE_TABLES.PAYMENT_INTENTS) + .update({ side_effects_at: new Date().toISOString() }) + .eq('id', paymentIntentId); + + if (error) { + // The sweep will now report this intent as incomplete when it is not. A + // false positive that names a real settled payment is a far better failure + // than a silent one that names nothing. + logger.error('Failed to mark settlement side-effects complete', { + paymentIntentId, + error, + }); + } +} + /** * Settle a payment verified OUTSIDE the polling loop — e.g. an L402 preimage * proof. Callers must hold cryptographic (or rail-confirmed) evidence of @@ -119,6 +161,7 @@ export async function handlePaymentConfirmed(paymentIntent: PaymentIntent): Prom void enqueuePaymentSettledWebhook(paymentIntent).catch(err => logger.warn('payment.settled webhook enqueue failed (tip)', { err }, 'paymentFlowService') ); + await markSideEffectsComplete(piId, admin); return; } @@ -207,4 +250,6 @@ export async function handlePaymentConfirmed(paymentIntent: PaymentIntent): Prom sourceEntityId: entityId, actionUrl: `/dashboard`, }); + + await markSideEffectsComplete(piId, admin); } diff --git a/src/services/payments/reconcile.ts b/src/services/payments/reconcile.ts index 9e38dfedf..2c26cb430 100644 --- a/src/services/payments/reconcile.ts +++ b/src/services/payments/reconcile.ts @@ -120,11 +120,91 @@ async function markPolled(admin: SupabaseClient, id: string): Promise { } } +/** + * Grace before a paid-but-unmarked intent counts as incomplete. + * + * Settlement is fast, but it is not instantaneous, and reporting an intent that + * is mid-flight would train everyone to ignore this. Five minutes is far longer + * than the path takes and far shorter than anyone would want to sit on a lost + * order. + */ +const SIDE_EFFECT_GRACE_MS = 5 * 60 * 1000; + +/** Most incomplete settlements to name in one report. */ +const INCOMPLETE_REPORT_LIMIT = 20; + +/** + * Paid intents whose settlement side-effects never finished. + * + * handlePaymentConfirmed flips the intent to paid FIRST — that conditional + * update is the lock making settlement run exactly once — and only then writes + * the order, decrements inventory, notifies and fans out webhooks. A crash in + * that gap used to lose all of it in total silence: the row is paid, so every + * later observer skips it as already settled, refresh short-circuits on + * terminal statuses, and the sweep above only looks at non-terminal ones. The + * buyer's money is gone and their order sits in pending_payment forever. + * + * WHY THIS REPORTS AND DOES NOT REPLAY + * + * Replaying looks like the obvious fix and is a worse bug. `decrement_inventory` + * is a blind `inventory_count - 1` with no idempotency key, so re-running + * settlement for one sale decrements twice and quietly destroys stock; plan + * grants and entitlements have the same shape. Trading an invisible loss for a + * silent corruption is not progress. Making replay safe needs per-effect + * receipts — a separate, larger piece of work. Until then this converts a + * permanent silent loss into a named, actionable one, which is the part that + * could not wait. + */ +export async function findIncompleteSettlements( + admin: SupabaseClient +): Promise<{ count: number; ids: string[] }> { + const cutoff = new Date(Date.now() - SIDE_EFFECT_GRACE_MS).toISOString(); + + const { data, error } = await admin + .from(DATABASE_TABLES.PAYMENT_INTENTS) + .select('id') + .eq('status', STATUS.PAYMENT_INTENTS.PAID) + .is('side_effects_at', null) + .lt('paid_at', cutoff) + .order('paid_at', { ascending: true }) + .limit(INCOMPLETE_REPORT_LIMIT + 1); + + if (error) { + // Never fail the sweep over the report: the reconciliation above is the + // load-bearing half. But say so — a detector that goes quiet on error is + // indistinguishable from one finding nothing, which is this whole bug. + logger.error('Could not check for incomplete settlements', { error }, 'PaymentSweep'); + return { count: 0, ids: [] }; + } + + const rows = data ?? []; + if (rows.length === 0) { + return { count: 0, ids: [] }; + } + + const ids = rows.slice(0, INCOMPLETE_REPORT_LIMIT).map(r => (r as { id: string }).id); + logger.error( + 'Paid payment intents whose settlement side-effects never completed — needs reconciliation', + { + shown: ids.length, + more: rows.length > INCOMPLETE_REPORT_LIMIT, + paymentIntentIds: ids, + whatIsMissing: + 'order status, inventory decrement, seller notification, webhooks — check each before repairing by hand', + }, + 'PaymentSweep' + ); + + return { count: ids.length, ids }; +} + export interface ReconcileSweepResult { scanned: number; settled: number; expired: number; skippedForBudget?: number; + /** Paid intents whose side-effects never finished — reported, never replayed. */ + incompleteSettlements: number; ranAt: string; } @@ -134,8 +214,19 @@ export async function runPaymentReconcileSweep(): Promise const admin = getAdminClient() as unknown as SupabaseClient; const candidates = await pickCandidates(admin, BATCH_SIZE); + // Runs even when there is nothing to reconcile: an incomplete settlement is a + // PAID row, so it never appears among the candidates above. Skipping the + // check on a quiet tick would hide exactly the case it exists for. + const incomplete = await findIncompleteSettlements(admin); + if (candidates.length === 0) { - return { scanned: 0, settled: 0, expired: 0, ranAt: new Date().toISOString() }; + return { + scanned: 0, + settled: 0, + expired: 0, + incompleteSettlements: incomplete.count, + ranAt: new Date().toISOString(), + }; } let scanned = 0; @@ -192,6 +283,7 @@ export async function runPaymentReconcileSweep(): Promise settled, expired, skippedForBudget, + incompleteSettlements: incomplete.count, ranAt: new Date().toISOString(), }; } diff --git a/supabase/migrations/20260828220000_settlement_side_effects_marker.sql b/supabase/migrations/20260828220000_settlement_side_effects_marker.sql new file mode 100644 index 000000000..219cbf0f1 --- /dev/null +++ b/supabase/migrations/20260828220000_settlement_side_effects_marker.sql @@ -0,0 +1,40 @@ +-- Settlement side-effects: record that they ran, so a crash is visible. +-- +-- handlePaymentConfirmed flips the intent to `paid` FIRST — deliberately, since +-- the conditional update is the lock that makes settlement run exactly once — +-- and only then writes the order, decrements inventory, notifies the seller and +-- fans out webhooks. +-- +-- A crash in that gap loses all of it, permanently and silently: +-- +-- * the intent is `paid`, so every later observer's claimPaidTransition +-- returns false and skips the side-effects as "already settled"; +-- * refreshPaymentStatus short-circuits on terminal statuses; +-- * the reconcile cron sweeps only CREATED / INVOICE_READY / +-- PENDING_CONFIRMATION, so it never looks at a paid row again. +-- +-- The buyer's money is gone and their order sits in pending_payment forever, +-- with nothing anywhere reporting a problem. bitbaum/orangecat#563 finding 4. +-- +-- This column is the marker. Set when the settlement path completes; NULL on a +-- paid intent means the side-effects did not finish, which the reconcile sweep +-- now reports. +-- +-- DELIBERATELY NOT GRANTED to anon/authenticated. payment_intents uses +-- column-level SELECT grants (same shape as wallets), and this is an internal +-- operations marker with no client use — a column no client can read is a +-- column no client can be confused by. Server-side reads go through +-- service_role. + +ALTER TABLE public.payment_intents + ADD COLUMN IF NOT EXISTS side_effects_at timestamptz; + +COMMENT ON COLUMN public.payment_intents.side_effects_at IS + 'When settlement side-effects finished (order, inventory, notifications, webhooks). NULL on a paid intent means they did not complete — the reconcile sweep reports these. Server-side only: no client SELECT grant.'; + +-- Finding the stragglers must not seq-scan the whole table every minute. Partial +-- index: only paid rows that have not been marked, which is the exact predicate +-- the sweep asks and — when everything is healthy — an empty index. +CREATE INDEX IF NOT EXISTS payment_intents_settlement_incomplete_idx + ON public.payment_intents (paid_at) + WHERE status = 'paid' AND side_effects_at IS NULL; From 8ebf51684e87b436725bdb05d4613aced450e6bb Mon Sep 17 00:00:00 2001 From: Georgy Butaev <41178744+g-but@users.noreply.github.com> Date: Fri, 28 Aug 2026 22:57:06 +0200 Subject: [PATCH 2/2] fix(test): the reconcile fixture modelled one query shape, the sweep now makes two MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit CI caught this, which is what it is for. Adding the incomplete-settlement check to runPaymentReconcileSweep broke four existing tests in payment-reconcile-cron.test.ts, and the failure was entirely mine. Its admin fixture had a single `eq` that always RESOLVED and recorded the id into `polled` — correct for the stamping path, `update().eq(id)`. The new check is `select().eq().is().lt().order().limit()`, where `eq` must keep CHAINING. So the second query blew up mid-chain AND pushed 'paid' into `polled`, breaking assertions that had nothing to do with it. The fixture now tracks which shape it is in: `update()` marks the resolving path, `is()` marks the check, and `limit()` returns no rows for the check so the existing assertions stay about reconciliation. The fixture was under-specified for the code it exercises; the production query is unchanged. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_018waGt1ieA9TjpscqrbrnGb --- .../unit/api/payment-reconcile-cron.test.ts | 27 +++++++++++++++++-- 1 file changed, 25 insertions(+), 2 deletions(-) diff --git a/__tests__/unit/api/payment-reconcile-cron.test.ts b/__tests__/unit/api/payment-reconcile-cron.test.ts index 7794b737c..3794641f7 100644 --- a/__tests__/unit/api/payment-reconcile-cron.test.ts +++ b/__tests__/unit/api/payment-reconcile-cron.test.ts @@ -43,6 +43,14 @@ jest.mock('@/lib/supabase/admin', () => ({ getAdminClient: () => ({ from: () => { const builder: Record = {}; + // The sweep now runs TWO queries against payment_intents, and they use + // `eq` for opposite purposes: the stamp is `update().eq(id)` and RESOLVES, + // the incomplete-settlement check is `select().eq().is().lt()` and must + // keep CHAINING. One `eq` that always resolved made the second query blow + // up mid-chain and push 'paid' into `polled`, so this fixture tracks + // which shape it is in. + let isUpdate = false; + let isIncompleteCheck = false; for (const m of ['select', 'in', 'order']) { builder[m] = jest.fn(() => builder); } @@ -50,9 +58,24 @@ jest.mock('@/lib/supabase/admin', () => ({ orFilters.push(filter); return builder; }); - builder.limit = jest.fn(() => Promise.resolve({ data: candidates, error: null })); - builder.update = jest.fn(() => builder); + builder.is = jest.fn(() => { + isIncompleteCheck = true; + return builder; + }); + builder.lt = jest.fn(() => builder); + // Nothing half-settled in these fixtures: the incomplete check finds none, + // so the assertions below stay about reconciliation. + builder.limit = jest.fn(() => + Promise.resolve({ data: isIncompleteCheck ? [] : candidates, error: null }) + ); + builder.update = jest.fn(() => { + isUpdate = true; + return builder; + }); builder.eq = jest.fn((_col: string, id: string) => { + if (!isUpdate) { + return builder; + } polled.push(id); return Promise.resolve({ error: null }); });