Fix sweep log levels and advisory-lock timer allocation
Downgrades routine sweep bookkeeping from CRITICAL to WARN (genuine post-charge manual-reconciliation branches keep CRITICAL) and replaces the per-attempt time.After in tryAdvisoryLock with a single reusable timer.
This commit is contained in:
@@ -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
|
// to a bigint exactly like the blocking `pg_advisory_lock(hashtext($1))` calls
|
||||||
// it replaces — the two acquire the same locks.
|
// it replaces — the two acquire the same locks.
|
||||||
func tryAdvisoryLock(ctx context.Context, q queryRower, key, fn string) (bool, error) {
|
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
|
for attempt := 0; attempt < advisoryLockAttempts; attempt++ { // ~3s total
|
||||||
var acquired bool
|
var acquired bool
|
||||||
if err := q.QueryRow(ctx, `SELECT `+fn+`(hashtext($1))`, key).Scan(&acquired); err != nil {
|
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 {
|
if acquired {
|
||||||
return true, nil
|
return true, nil
|
||||||
}
|
}
|
||||||
|
if !timer.Stop() {
|
||||||
|
select {
|
||||||
|
case <-timer.C:
|
||||||
|
default:
|
||||||
|
}
|
||||||
|
}
|
||||||
|
timer.Reset(advisoryLockRetryDelay)
|
||||||
select {
|
select {
|
||||||
case <-time.After(advisoryLockRetryDelay):
|
case <-timer.C:
|
||||||
case <-ctx.Done():
|
case <-ctx.Done():
|
||||||
return false, ctx.Err()
|
return false, ctx.Err()
|
||||||
}
|
}
|
||||||
|
|||||||
@@ -59,11 +59,17 @@ func SweepStalePendingPayments(ctx context.Context) (int, error) {
|
|||||||
if total > 0 {
|
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)
|
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 {
|
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 {
|
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
|
return total, nil
|
||||||
}
|
}
|
||||||
|
|||||||
Reference in New Issue
Block a user