diff --git a/backend/handlers/payments/locks.go b/backend/handlers/payments/locks.go index de3128e..4dcabd5 100644 --- a/backend/handlers/payments/locks.go +++ b/backend/handlers/payments/locks.go @@ -78,6 +78,14 @@ func acquireAdvisoryXactLockBlocking(ctx context.Context, tx pgx.Tx, key string) // to a bigint exactly like the blocking `pg_advisory_lock(hashtext($1))` calls // it replaces — the two acquire the same locks. func tryAdvisoryLock(ctx context.Context, q queryRower, key, fn string) (bool, error) { + // ONE reusable timer for the whole retry loop instead of time.After per + // attempt: a contended lock spins ~30 times, and allocating a fresh timer + // (with its own goroutine) on every attempt is wasteful. The timer is + // Stop+drained before each Reset so a previously-fired tick can never make + // the next wait return early (missed-tick semantics). Timing is preserved: + // 100ms between attempts, ~3s total bound. + timer := time.NewTimer(advisoryLockRetryDelay) + defer timer.Stop() for attempt := 0; attempt < advisoryLockAttempts; attempt++ { // ~3s total var acquired bool if err := q.QueryRow(ctx, `SELECT `+fn+`(hashtext($1))`, key).Scan(&acquired); err != nil { @@ -86,8 +94,15 @@ func tryAdvisoryLock(ctx context.Context, q queryRower, key, fn string) (bool, e if acquired { return true, nil } + if !timer.Stop() { + select { + case <-timer.C: + default: + } + } + timer.Reset(advisoryLockRetryDelay) select { - case <-time.After(advisoryLockRetryDelay): + case <-timer.C: case <-ctx.Done(): return false, ctx.Err() } diff --git a/backend/handlers/payments/sweep.go b/backend/handlers/payments/sweep.go index 61f2861..3465c01 100644 --- a/backend/handlers/payments/sweep.go +++ b/backend/handlers/payments/sweep.go @@ -59,11 +59,17 @@ func SweepStalePendingPayments(ctx context.Context) (int, error) { if total > 0 { log.Printf("[SWEEP] Resolved %d stale pending payments (%d payments, %d till sales) older than %s — late retries will be rejected, preventing a second Square charge; %d reconciled to completed against Square (%d payments, %d till sales)", total, payCount, tillCount, stalePendingPaymentAge, payCompleted+tillCompleted, payCompleted, tillCompleted) } + // Routine sweep bookkeeping, not an incident: failing stale pending rows is + // the sweep's DESIGNED behaviour. A row swept to failed may still have been + // charged at Square with a lost response, so note it at WARN level for an + // admin doing a periodic money reconciliation — but this fires on every + // normal run and must not be elevated to CRITICAL (which is reserved for + // genuinely unrecoverable post-charge branches). if payCount > 0 { - log.Printf("CRITICAL: %d pending payments swept to failed may have been charged at Square with a lost response — manual reconciliation required before refunding/charging", payCount-payCompleted) + log.Printf("[SWEEP] WARN: %d pending payments marked failed may have been charged at Square with a lost response — verify before refunding/charging", payCount-payCompleted) } if tillCount > 0 { - log.Printf("CRITICAL: %d pending till sales swept to failed may have been charged at Square with a lost response — manual reconciliation required", tillCount-tillCompleted) + log.Printf("[SWEEP] WARN: %d pending till sales marked failed may have been charged at Square with a lost response", tillCount-tillCompleted) } return total, nil }