fix: refund sweep — manual-refund audit rows (admin_refund) + refund_failed flood cap
- MEDIUM-3a audit coverage: the refund sweep's re-issue of manual refund rows now records the admin actor, payment, pence amount and reason under action_type 'admin_refund' via the shared InsertAdminAuditCharge helper (best-effort own-transaction, non-fatal; distinct from the booking-level 'admin_booking_refund'); legacy rows with NULL created_by fail harmlessly. - C5 flood cap: the unacknowledged 'refund_failed' notification queue is capped at adminnotify.MaxUnacknowledgedCriticalLogs — pre-check logs the suppression, the fold inside the INSERT enforces it atomically, and the (reason, booking_id) NOT EXISTS dedup is preserved.
This commit is contained in:
@@ -17,6 +17,7 @@ import (
|
|||||||
|
|
||||||
"crussell/clock"
|
"crussell/clock"
|
||||||
"crussell/db"
|
"crussell/db"
|
||||||
|
"crussell/internal/adminnotify"
|
||||||
"crussell/internal/square"
|
"crussell/internal/square"
|
||||||
|
|
||||||
"github.com/jackc/pgx/v5"
|
"github.com/jackc/pgx/v5"
|
||||||
@@ -193,6 +194,24 @@ func notifyCriticalReconcileFailure(ctx context.Context, ids []string) {
|
|||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// insertManualRefundAudit records a manual per-payment refund issued to Square
|
||||||
|
// in admin_audit_log via the shared InsertAdminAuditCharge helper — same table,
|
||||||
|
// same columns, same best-effort own-transaction non-fatal handling (a failed
|
||||||
|
// audit write can never abort the already-issued refund). MEDIUM-3a coverage:
|
||||||
|
// every admin money action must be auditable; the manual RefundPayment handler
|
||||||
|
// itself writes no audit row, so the sweep's re-issue of its manual refund rows
|
||||||
|
// records the admin actor (refunds.created_by), the payment, the pence amount
|
||||||
|
// and the reason under action_type 'admin_refund' (distinct from the booking
|
||||||
|
// level 'admin_booking_refund' in handlers.go). adminID may be "" for legacy
|
||||||
|
// rows with a NULL created_by — the FK-violating insert fails harmlessly.
|
||||||
|
func insertManualRefundAudit(ctx context.Context, adminID, paymentID string, amountPence int64, reason string) {
|
||||||
|
InsertAdminAuditCharge(ctx, adminID, "", "admin_refund", map[string]any{
|
||||||
|
"payment_id": paymentID,
|
||||||
|
"amount_pence": amountPence,
|
||||||
|
"reason": reason,
|
||||||
|
})
|
||||||
|
}
|
||||||
|
|
||||||
// reconcileRefundAtSquareExact checks Square for a COMPLETED refund matching
|
// reconcileRefundAtSquareExact checks Square for a COMPLETED refund matching
|
||||||
// the EXACT payment+amount, WITHOUT an age bound. Same exact-match semantics
|
// the EXACT payment+amount, WITHOUT an age bound. Same exact-match semantics
|
||||||
// as reconcileRefundAtSquare (payment_id AND status COMPLETED AND amount), minus
|
// as reconcileRefundAtSquare (payment_id AND status COMPLETED AND amount), minus
|
||||||
@@ -1102,6 +1121,13 @@ func insertRefundFailedNotifications(ctx context.Context, refundIDs []string) {
|
|||||||
if len(refundIDs) == 0 {
|
if len(refundIDs) == 0 {
|
||||||
return
|
return
|
||||||
}
|
}
|
||||||
|
// C5: flood-cap the unacknowledged 'refund_failed' queue (pre-check logs
|
||||||
|
// suppression; the fold inside the INSERT enforces it atomically). The
|
||||||
|
// (reason, booking_id) NOT EXISTS dedup is preserved.
|
||||||
|
if adminnotify.CriticalLogsCapExceeded(ctx, db.Conn, "refund_failed") {
|
||||||
|
log.Printf("Suppressed refund_failed admin notification — unacknowledged 'refund_failed' queue at the cap")
|
||||||
|
return
|
||||||
|
}
|
||||||
tag, err := db.Conn.Exec(ctx, `
|
tag, err := db.Conn.Exec(ctx, `
|
||||||
INSERT INTO admin_notifications (reason, booking_id, created_at)
|
INSERT INTO admin_notifications (reason, booking_id, created_at)
|
||||||
SELECT DISTINCT 'refund_failed'::admin_notification_reason, booking_id, NOW()
|
SELECT DISTINCT 'refund_failed'::admin_notification_reason, booking_id, NOW()
|
||||||
@@ -1111,7 +1137,10 @@ func insertRefundFailedNotifications(ctx context.Context, refundIDs []string) {
|
|||||||
SELECT 1 FROM admin_notifications an
|
SELECT 1 FROM admin_notifications an
|
||||||
WHERE an.reason = 'refund_failed' AND an.booking_id = refunds.booking_id
|
WHERE an.reason = 'refund_failed' AND an.booking_id = refunds.booking_id
|
||||||
)
|
)
|
||||||
`, refundIDs)
|
AND (SELECT COUNT(*) FROM admin_notifications _an
|
||||||
|
WHERE _an.reason = 'refund_failed'
|
||||||
|
AND _an.acknowledged_at IS NULL) < $2
|
||||||
|
`, refundIDs, adminnotify.MaxUnacknowledgedCriticalLogs)
|
||||||
if err != nil {
|
if err != nil {
|
||||||
log.Printf("Failed to insert admin_notifications for failed refunds: %v", err)
|
log.Printf("Failed to insert admin_notifications for failed refunds: %v", err)
|
||||||
return
|
return
|
||||||
@@ -1560,7 +1589,11 @@ type manualPendingRow struct {
|
|||||||
Reason string
|
Reason string
|
||||||
SquarePaymentID string
|
SquarePaymentID string
|
||||||
SquareRefundID string // set when the handler's synchronous-PENDING path stored the refund id
|
SquareRefundID string // set when the handler's synchronous-PENDING path stored the refund id
|
||||||
CreatedAt time.Time
|
// CreatedBy is refunds.created_by — the admin who issued the refund
|
||||||
|
// ("" when NULL, e.g. legacy rows). Carried so a re-issued manual refund can
|
||||||
|
// be recorded in admin_audit_log under the original admin actor (M8).
|
||||||
|
CreatedBy string
|
||||||
|
CreatedAt time.Time
|
||||||
}
|
}
|
||||||
|
|
||||||
// sweepManualPendingSquareRefunds retries stale MANUAL refunds left 'pending'
|
// sweepManualPendingSquareRefunds retries stale MANUAL refunds left 'pending'
|
||||||
@@ -1646,7 +1679,7 @@ func sweepManualPendingSquareRefunds(ctx context.Context) (int, error) {
|
|||||||
// ones the retry/reconcile logic can act on.
|
// ones the retry/reconcile logic can act on.
|
||||||
rows, err = db.Conn.Query(ctx, fmt.Sprintf(`
|
rows, err = db.Conn.Query(ctx, fmt.Sprintf(`
|
||||||
SELECT r.id, r.payment_id, p.booking_id, r.amount, r.idempotency_key, r.reason,
|
SELECT r.id, r.payment_id, p.booking_id, r.amount, r.idempotency_key, r.reason,
|
||||||
p.square_payment_id, r.square_refund_id, r.created_at
|
p.square_payment_id, r.square_refund_id, r.created_at, r.created_by
|
||||||
FROM refunds r
|
FROM refunds r
|
||||||
JOIN payments p ON p.id = r.payment_id
|
JOIN payments p ON p.id = r.payment_id
|
||||||
WHERE r.status = 'pending' AND r.origin = 'manual'
|
WHERE r.status = 'pending' AND r.origin = 'manual'
|
||||||
@@ -1664,7 +1697,8 @@ func sweepManualPendingSquareRefunds(ctx context.Context) (int, error) {
|
|||||||
var key *string
|
var key *string
|
||||||
var sqRefundID *string
|
var sqRefundID *string
|
||||||
var bookingID sql.NullString
|
var bookingID sql.NullString
|
||||||
if err := rows.Scan(&pr.ID, &pr.PaymentID, &bookingID, &pr.Amount, &key, &pr.Reason, &pr.SquarePaymentID, &sqRefundID, &pr.CreatedAt); err != nil {
|
var createdBy *string
|
||||||
|
if err := rows.Scan(&pr.ID, &pr.PaymentID, &bookingID, &pr.Amount, &key, &pr.Reason, &pr.SquarePaymentID, &sqRefundID, &pr.CreatedAt, &createdBy); err != nil {
|
||||||
log.Printf("Failed to scan manual pending refund: %v", err)
|
log.Printf("Failed to scan manual pending refund: %v", err)
|
||||||
continue
|
continue
|
||||||
}
|
}
|
||||||
@@ -1675,6 +1709,9 @@ func sweepManualPendingSquareRefunds(ctx context.Context) (int, error) {
|
|||||||
if sqRefundID != nil {
|
if sqRefundID != nil {
|
||||||
pr.SquareRefundID = *sqRefundID
|
pr.SquareRefundID = *sqRefundID
|
||||||
}
|
}
|
||||||
|
if createdBy != nil {
|
||||||
|
pr.CreatedBy = *createdBy
|
||||||
|
}
|
||||||
pending = append(pending, pr)
|
pending = append(pending, pr)
|
||||||
}
|
}
|
||||||
rows.Close()
|
rows.Close()
|
||||||
@@ -2022,15 +2059,21 @@ func loadTillSaleStaleRow(ctx context.Context, id string) (staleRow, bool) {
|
|||||||
// key → a second Square refund (double refund). Persisting the key first
|
// key → a second Square refund (double refund). Persisting the key first
|
||||||
// closes that hole: a crash-retry re-reads the persisted key and reuses it.
|
// closes that hole: a crash-retry re-reads the persisted key and reuses it.
|
||||||
//
|
//
|
||||||
// The `AND idempotency_key IS NULL` guard makes the persist race-safe: only
|
// The generated fallback is DETERMINISTIC (deriveRefundIdempotencyKey with
|
||||||
// one concurrent caller wins the UPDATE; a loser (0 rows affected) re-reads
|
// refundType "manual" — the shared M1 helper), so two no-client-key issuances
|
||||||
// and returns the winner's key. The generated shape (paymentID + "-refund-" +
|
// of the same payment+amount — whether from the RefundPayment resume path
|
||||||
// amount + "-" + 12 hex chars) stays ≤45 chars: 12 + 8 + up-to-9 + 1 + 12 ≈ 42.
|
// (handlers.go) or the manual sweep pass here — map to the SAME Square refund,
|
||||||
|
// and the `AND idempotency_key IS NULL` guard makes the persist race-safe:
|
||||||
|
// only one concurrent caller wins the UPDATE; a loser (0 rows affected) re-reads
|
||||||
|
// and returns the winner's key. The key stays ≤45 chars and carries the
|
||||||
|
// "-refund-...-manual" marker, so it can never collide with the cancellation
|
||||||
|
// scheme (<paymentID>-square-<pence>) nor the aggregated scheme
|
||||||
|
// (<chargeID>-square-agg, chargeAggKey).
|
||||||
func ensureRefundKey(ctx context.Context, refundID, paymentID string, amount int64, storedKey string) (string, error) {
|
func ensureRefundKey(ctx context.Context, refundID, paymentID string, amount int64, storedKey string) (string, error) {
|
||||||
if storedKey != "" {
|
if storedKey != "" {
|
||||||
return storedKey, nil
|
return storedKey, nil
|
||||||
}
|
}
|
||||||
key := paymentID + "-refund-" + strconv.FormatInt(amount, 10) + "-" + randomHexSuffix(6)
|
key := deriveRefundIdempotencyKey(paymentID, amount, "manual")
|
||||||
tag, err := db.Conn.Exec(ctx, `
|
tag, err := db.Conn.Exec(ctx, `
|
||||||
UPDATE refunds SET idempotency_key = $1
|
UPDATE refunds SET idempotency_key = $1
|
||||||
WHERE id = $2 AND idempotency_key IS NULL
|
WHERE id = $2 AND idempotency_key IS NULL
|
||||||
@@ -2079,7 +2122,7 @@ func processManualPaymentGroup(ctx context.Context, paymentID string, rows []man
|
|||||||
// cap are eligible (a concurrent manual refund may have resolved some).
|
// cap are eligible (a concurrent manual refund may have resolved some).
|
||||||
prRows, err := db.Conn.Query(ctx, fmt.Sprintf(`
|
prRows, err := db.Conn.Query(ctx, fmt.Sprintf(`
|
||||||
SELECT r.id, p.booking_id, r.amount, r.idempotency_key, r.reason, r.created_at,
|
SELECT r.id, p.booking_id, r.amount, r.idempotency_key, r.reason, r.created_at,
|
||||||
r.payment_id, p.square_payment_id, r.square_refund_id
|
r.payment_id, p.square_payment_id, r.square_refund_id, r.created_by
|
||||||
FROM refunds r
|
FROM refunds r
|
||||||
JOIN payments p ON p.id = r.payment_id
|
JOIN payments p ON p.id = r.payment_id
|
||||||
WHERE r.id = ANY($1) AND r.status = 'pending' AND r.refund_attempts < %d
|
WHERE r.id = ANY($1) AND r.status = 'pending' AND r.refund_attempts < %d
|
||||||
@@ -2094,7 +2137,8 @@ func processManualPaymentGroup(ctx context.Context, paymentID string, rows []man
|
|||||||
var key *string
|
var key *string
|
||||||
var sqRefundID *string
|
var sqRefundID *string
|
||||||
var bookingID sql.NullString
|
var bookingID sql.NullString
|
||||||
if err := prRows.Scan(&pr.ID, &bookingID, &pr.Amount, &key, &pr.Reason, &pr.CreatedAt, &pr.PaymentID, &pr.SquarePaymentID, &sqRefundID); err != nil {
|
var createdBy *string
|
||||||
|
if err := prRows.Scan(&pr.ID, &bookingID, &pr.Amount, &key, &pr.Reason, &pr.CreatedAt, &pr.PaymentID, &pr.SquarePaymentID, &sqRefundID, &createdBy); err != nil {
|
||||||
log.Printf("Failed to scan manual pending refund under lock: %v", err)
|
log.Printf("Failed to scan manual pending refund under lock: %v", err)
|
||||||
continue
|
continue
|
||||||
}
|
}
|
||||||
@@ -2105,6 +2149,9 @@ func processManualPaymentGroup(ctx context.Context, paymentID string, rows []man
|
|||||||
if sqRefundID != nil {
|
if sqRefundID != nil {
|
||||||
pr.SquareRefundID = *sqRefundID
|
pr.SquareRefundID = *sqRefundID
|
||||||
}
|
}
|
||||||
|
if createdBy != nil {
|
||||||
|
pr.CreatedBy = *createdBy
|
||||||
|
}
|
||||||
pending = append(pending, pr)
|
pending = append(pending, pr)
|
||||||
}
|
}
|
||||||
prRows.Close()
|
prRows.Close()
|
||||||
@@ -2301,6 +2348,10 @@ func processManualPaymentGroup(ctx context.Context, paymentID string, rows []man
|
|||||||
}
|
}
|
||||||
switch {
|
switch {
|
||||||
case sqErr == nil:
|
case sqErr == nil:
|
||||||
|
// MEDIUM-3a coverage: a manual refund issued to Square is an admin
|
||||||
|
// money action — record it in admin_audit_log (best-effort, own tx,
|
||||||
|
// non-fatal; a failed audit write can never abort the refund).
|
||||||
|
insertManualRefundAudit(ctx, pr.CreatedBy, pr.PaymentID, amountPence, pr.Reason)
|
||||||
// Resolve by Square's status: a synchronous refund response can be
|
// Resolve by Square's status: a synchronous refund response can be
|
||||||
// PENDING (money in flight, e.g. an async card network) — marking it
|
// PENDING (money in flight, e.g. an async card network) — marking it
|
||||||
// completed while Square later fails it would permanently block that
|
// completed while Square later fails it would permanently block that
|
||||||
|
|||||||
@@ -13,6 +13,7 @@ import (
|
|||||||
|
|
||||||
"crussell/clock"
|
"crussell/clock"
|
||||||
"crussell/db"
|
"crussell/db"
|
||||||
|
"crussell/internal/adminnotify"
|
||||||
"crussell/internal/square"
|
"crussell/internal/square"
|
||||||
"crussell/testutils"
|
"crussell/testutils"
|
||||||
"crussell/testutils/fixtures"
|
"crussell/testutils/fixtures"
|
||||||
@@ -2885,10 +2886,12 @@ func TestResumePendingRefund_LegacyNullKey_DerivesFreshKey(t *testing.T) {
|
|||||||
if calls[0].IdempotencyKey == req.IdempotencyKey {
|
if calls[0].IdempotencyKey == req.IdempotencyKey {
|
||||||
t.Errorf("expected a derived key, not the client's fresh key, got %q", calls[0].IdempotencyKey)
|
t.Errorf("expected a derived key, not the client's fresh key, got %q", calls[0].IdempotencyKey)
|
||||||
}
|
}
|
||||||
// Derived shape: <paymentID>-refund-<pence>-<12 hex chars>.
|
// M1-refund-side: the derived fallback is now DETERMINISTIC —
|
||||||
prefix := paymentID + "-refund-5000-"
|
// deriveRefundIdempotencyKey(payment, amount, "manual") — so a retry of the
|
||||||
if !strings.HasPrefix(calls[0].IdempotencyKey, prefix) {
|
// same payment+amount maps to the SAME Square refund.
|
||||||
t.Errorf("expected derived key with prefix %q, got %q", prefix, calls[0].IdempotencyKey)
|
wantKey := deriveRefundIdempotencyKey(paymentID, 5000, "manual")
|
||||||
|
if calls[0].IdempotencyKey != wantKey {
|
||||||
|
t.Errorf("expected derived key %q, got %q", wantKey, calls[0].IdempotencyKey)
|
||||||
}
|
}
|
||||||
if len(calls[0].IdempotencyKey) > 45 {
|
if len(calls[0].IdempotencyKey) > 45 {
|
||||||
t.Errorf("expected derived key within Square's 45-char limit, got %d chars: %q", len(calls[0].IdempotencyKey), calls[0].IdempotencyKey)
|
t.Errorf("expected derived key within Square's 45-char limit, got %d chars: %q", len(calls[0].IdempotencyKey), calls[0].IdempotencyKey)
|
||||||
@@ -3773,6 +3776,299 @@ func TestSweepManualRetry_NullKey_SingleSquareRefund(t *testing.T) {
|
|||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// =============================================================================
|
||||||
|
// M1-refund-side — deterministic idempotency key for no-client-key manual refunds
|
||||||
|
// =============================================================================
|
||||||
|
|
||||||
|
// TestSweepManualRefund_NoClientKey_DeterministicKey_NoDoubleRefund locks the
|
||||||
|
// M1-refund-side fix: a manual refund issued without a client idempotency key
|
||||||
|
// derives a DETERMINISTIC server-side key from (payment_id, amount_pence,
|
||||||
|
// refund-type marker) via truncateIdempotencyKey, so two no-client-key manual
|
||||||
|
// refunds on the same payment+amount map to the SAME Square refund — the
|
||||||
|
// duplicate can never issue a second Square refund. One of the rows is re-issued
|
||||||
|
// under the derived key (one Square refund); the other's persist of the SAME key
|
||||||
|
// trips refunds.idempotency_key UNIQUE, so it is never issued and instead
|
||||||
|
// RECONCILES to the issued refund once it ages past the 23h guard.
|
||||||
|
func TestSweepManualRefund_NoClientKey_DeterministicKey_NoDoubleRefund(t *testing.T) {
|
||||||
|
ctx, tx := testutils.SetupTestTx(t)
|
||||||
|
|
||||||
|
adminID, err := fixtures.CreateTestAdminUser(tx)
|
||||||
|
if err != nil {
|
||||||
|
t.Fatalf("failed to create admin user: %v", err)
|
||||||
|
}
|
||||||
|
userID, err := fixtures.CreateTestUser(tx)
|
||||||
|
if err != nil {
|
||||||
|
t.Fatalf("failed to create user: %v", err)
|
||||||
|
}
|
||||||
|
serviceID, err := fixtures.CreateTestService(tx)
|
||||||
|
if err != nil {
|
||||||
|
t.Fatalf("failed to create service: %v", err)
|
||||||
|
}
|
||||||
|
bookingID, err := fixtures.CreateTestBookingAtTime(tx, userID, serviceID,
|
||||||
|
time.Date(2099, 12, 31, 10, 0, 0, 0, time.UTC))
|
||||||
|
if err != nil {
|
||||||
|
t.Fatalf("failed to create booking: %v", err)
|
||||||
|
}
|
||||||
|
paymentID, err := fixtures.CreateTestPayment(tx, bookingID, 50.00, "online_square", "full", "completed")
|
||||||
|
if err != nil {
|
||||||
|
t.Fatalf("failed to create card payment: %v", err)
|
||||||
|
}
|
||||||
|
const chargeID = "sqp_m1_no_client_key"
|
||||||
|
if _, err := tx.Exec(ctx, "UPDATE payments SET square_payment_id = $1 WHERE id = $2", chargeID, paymentID); err != nil {
|
||||||
|
t.Fatalf("failed to set square_payment_id: %v", err)
|
||||||
|
}
|
||||||
|
|
||||||
|
// Two manual refund rows on the SAME payment+amount, both with NO client
|
||||||
|
// idempotency key (NULL) — a duplicate issuance / no-key retry pair.
|
||||||
|
insertNoKeyRefund := func() string {
|
||||||
|
t.Helper()
|
||||||
|
var id string
|
||||||
|
if err := tx.QueryRow(ctx, `
|
||||||
|
INSERT INTO refunds (payment_id, booking_id, amount, status, reason, origin, created_by, created_at)
|
||||||
|
VALUES ($1, $2, 50, 'pending', 'customer request', 'manual', $3, NOW())
|
||||||
|
RETURNING id
|
||||||
|
`, paymentID, bookingID, adminID).Scan(&id); err != nil {
|
||||||
|
t.Fatalf("failed to insert NULL-key manual refund: %v", err)
|
||||||
|
}
|
||||||
|
return id
|
||||||
|
}
|
||||||
|
row1 := insertNoKeyRefund()
|
||||||
|
row2 := insertNoKeyRefund()
|
||||||
|
|
||||||
|
pgxTx := db.TxFromContext(ctx)
|
||||||
|
if pgxTx == nil {
|
||||||
|
t.Fatal("no transaction in context")
|
||||||
|
}
|
||||||
|
if err := pgxTx.Commit(ctx); err != nil {
|
||||||
|
t.Fatalf("failed to commit test tx: %v", err)
|
||||||
|
}
|
||||||
|
freshCtx := context.Background()
|
||||||
|
t.Cleanup(func() {
|
||||||
|
_, _ = db.Conn.Exec(context.Background(), `DELETE FROM admin_notifications WHERE booking_id = $1`, bookingID)
|
||||||
|
_, _ = db.Conn.Exec(context.Background(), `DELETE FROM admin_audit_log WHERE action_type = 'admin_refund' AND admin_id = $1`, adminID)
|
||||||
|
_, _ = db.Conn.Exec(context.Background(), `DELETE FROM refunds WHERE id = ANY($1)`, []string{row1, row2})
|
||||||
|
_, _ = db.Conn.Exec(context.Background(), `DELETE FROM payments WHERE id = $1`, paymentID)
|
||||||
|
_, _ = db.Conn.Exec(context.Background(), `DELETE FROM bookings WHERE id = $1`, bookingID)
|
||||||
|
_, _ = db.Conn.Exec(context.Background(), `DELETE FROM services WHERE id = $1`, serviceID)
|
||||||
|
_, _ = db.Conn.Exec(context.Background(), `DELETE FROM users WHERE id = $1`, userID)
|
||||||
|
_, _ = db.Conn.Exec(context.Background(), `DELETE FROM users WHERE id = $1`, adminID)
|
||||||
|
})
|
||||||
|
|
||||||
|
origClient := SquareClient
|
||||||
|
mock := square.NewDevClient().(*square.MockClient)
|
||||||
|
counting := &countingRefundClient{SquareClient: mock}
|
||||||
|
SquareClient = counting
|
||||||
|
defer func() { SquareClient = origClient }()
|
||||||
|
|
||||||
|
// Run 1: one row is re-issued under the derived key; the other's persist of
|
||||||
|
// the SAME key trips the idempotency_key UNIQUE constraint and is skipped —
|
||||||
|
// never a second Square call.
|
||||||
|
wantKey := deriveRefundIdempotencyKey(paymentID, 5000, "manual")
|
||||||
|
n, err := processManualPaymentGroup(freshCtx, paymentID, []manualPendingRow{{ID: row1}, {ID: row2}})
|
||||||
|
if err != nil {
|
||||||
|
t.Fatalf("processManualPaymentGroup failed: %v", err)
|
||||||
|
}
|
||||||
|
if n != 1 {
|
||||||
|
t.Fatalf("expected 1 manual refund processed in run 1, got %d", n)
|
||||||
|
}
|
||||||
|
calls := counting.refundCalls()
|
||||||
|
if len(calls) != 1 {
|
||||||
|
t.Fatalf("expected exactly 1 Square refund call (the duplicate must never be issued), got %d", len(calls))
|
||||||
|
}
|
||||||
|
if calls[0].IdempotencyKey != wantKey {
|
||||||
|
t.Errorf("expected the deterministic no-client-key refund key %q, got %q", wantKey, calls[0].IdempotencyKey)
|
||||||
|
}
|
||||||
|
if n := mock.RefundKeyCount(); n != 1 {
|
||||||
|
t.Errorf("expected exactly ONE distinct Square refund, got %d", n)
|
||||||
|
}
|
||||||
|
var row1Status string
|
||||||
|
var row1Key *string
|
||||||
|
if err := db.Conn.QueryRow(freshCtx, `SELECT status, idempotency_key FROM refunds WHERE id = $1`, row1).Scan(&row1Status, &row1Key); err != nil {
|
||||||
|
t.Fatalf("failed to query row1: %v", err)
|
||||||
|
}
|
||||||
|
var row2Status string
|
||||||
|
var row2Key *string
|
||||||
|
if err := db.Conn.QueryRow(freshCtx, `SELECT status, idempotency_key FROM refunds WHERE id = $1`, row2).Scan(&row2Status, &row2Key); err != nil {
|
||||||
|
t.Fatalf("failed to query row2: %v", err)
|
||||||
|
}
|
||||||
|
// The sweep re-reads the rows ORDER BY r.id (not insertion order), so either
|
||||||
|
// row can be the one issued; the other's persist of the SAME key trips
|
||||||
|
// refunds.idempotency_key UNIQUE and is skipped. Identify them by state.
|
||||||
|
issuedRow, pendingRow := "", ""
|
||||||
|
for _, r := range []struct {
|
||||||
|
id string
|
||||||
|
status string
|
||||||
|
key *string
|
||||||
|
}{{row1, row1Status, row1Key}, {row2, row2Status, row2Key}} {
|
||||||
|
switch {
|
||||||
|
case r.status == "completed" && r.key != nil && *r.key == wantKey:
|
||||||
|
issuedRow = r.id
|
||||||
|
case r.status == "pending" && r.key == nil:
|
||||||
|
pendingRow = r.id
|
||||||
|
default:
|
||||||
|
t.Fatalf("unexpected state for refund %s: status=%q key=%v", r.id, r.status, r.key)
|
||||||
|
}
|
||||||
|
}
|
||||||
|
if issuedRow == "" || pendingRow == "" {
|
||||||
|
t.Fatalf("expected exactly one issued row and one skipped row after run 1, got issued=%q pending=%q", issuedRow, pendingRow)
|
||||||
|
}
|
||||||
|
|
||||||
|
// The derived key must not collide with the aggregated-refund scheme
|
||||||
|
// (chargeAggKey) nor the cancellation-refund scheme.
|
||||||
|
if wantKey == chargeAggKey(chargeID) {
|
||||||
|
t.Errorf("manual no-client-key key %q collides with the aggregated-refund key", wantKey)
|
||||||
|
}
|
||||||
|
if wantKey == paymentID+"-square-5000" {
|
||||||
|
t.Errorf("manual no-client-key key %q collides with the cancellation-refund key", wantKey)
|
||||||
|
}
|
||||||
|
|
||||||
|
// Reconcile hit: once the skipped row ages past stalePendingRefundAge the
|
||||||
|
// sweep reconciles instead of re-issuing, finds the issued row's COMPLETED
|
||||||
|
// refund and resolves it to completed against it — still ONE Square refund.
|
||||||
|
var issuedSquareRefundID string
|
||||||
|
if err := db.Conn.QueryRow(freshCtx, `SELECT square_refund_id FROM refunds WHERE id = $1`, issuedRow).Scan(&issuedSquareRefundID); err != nil {
|
||||||
|
t.Fatalf("failed to read issued square_refund_id: %v", err)
|
||||||
|
}
|
||||||
|
if _, err := db.Conn.Exec(freshCtx, `UPDATE refunds SET created_at = NOW() - INTERVAL '25 hours' WHERE id = $1`, pendingRow); err != nil {
|
||||||
|
t.Fatalf("failed to age the pending row: %v", err)
|
||||||
|
}
|
||||||
|
n, err = processManualPaymentGroup(freshCtx, paymentID, []manualPendingRow{{ID: pendingRow}})
|
||||||
|
if err != nil {
|
||||||
|
t.Fatalf("processManualPaymentGroup (aged reconcile) failed: %v", err)
|
||||||
|
}
|
||||||
|
if n != 1 {
|
||||||
|
t.Fatalf("expected 1 manual refund reconciled in run 2, got %d", n)
|
||||||
|
}
|
||||||
|
var pendingStatusAfter, pendingSquareRefundID string
|
||||||
|
if err := db.Conn.QueryRow(freshCtx, `SELECT status, square_refund_id FROM refunds WHERE id = $1`, pendingRow).Scan(&pendingStatusAfter, &pendingSquareRefundID); err != nil {
|
||||||
|
t.Fatalf("failed to query pending row after reconcile: %v", err)
|
||||||
|
}
|
||||||
|
if pendingStatusAfter != "completed" {
|
||||||
|
t.Errorf("expected the skipped row reconciled to 'completed', got %q", pendingStatusAfter)
|
||||||
|
}
|
||||||
|
if pendingSquareRefundID != issuedSquareRefundID {
|
||||||
|
t.Errorf("expected the skipped row completed against the issued refund %q, got %q", issuedSquareRefundID, pendingSquareRefundID)
|
||||||
|
}
|
||||||
|
if n := mock.RefundKeyCount(); n != 1 {
|
||||||
|
t.Errorf("expected exactly ONE distinct Square refund after reconcile (no second refund), got %d", n)
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// =============================================================================
|
||||||
|
// M8 — manual refunds write an admin_audit_log row
|
||||||
|
// =============================================================================
|
||||||
|
|
||||||
|
// TestManualRefund_IssuesAdminAuditLog locks the M8 fix: every admin money
|
||||||
|
// action must be auditable — when a manual per-payment refund is issued to
|
||||||
|
// Square (the RefundPayment handler's pending row re-issued by the manual sweep
|
||||||
|
// pass), an admin_audit_log row is written with the admin actor, action_type
|
||||||
|
// 'admin_refund', the payment id, the amount in pence and the reason. Uses the
|
||||||
|
// same existing table and the shared InsertAdminAuditCharge helper — no new
|
||||||
|
// table or schema change.
|
||||||
|
func TestManualRefund_IssuesAdminAuditLog(t *testing.T) {
|
||||||
|
ctx, tx := testutils.SetupTestTx(t)
|
||||||
|
|
||||||
|
adminID, err := fixtures.CreateTestAdminUser(tx)
|
||||||
|
if err != nil {
|
||||||
|
t.Fatalf("failed to create admin user: %v", err)
|
||||||
|
}
|
||||||
|
userID, err := fixtures.CreateTestUser(tx)
|
||||||
|
if err != nil {
|
||||||
|
t.Fatalf("failed to create user: %v", err)
|
||||||
|
}
|
||||||
|
serviceID, err := fixtures.CreateTestService(tx)
|
||||||
|
if err != nil {
|
||||||
|
t.Fatalf("failed to create service: %v", err)
|
||||||
|
}
|
||||||
|
bookingID, err := fixtures.CreateTestBookingAtTime(tx, userID, serviceID,
|
||||||
|
time.Date(2099, 12, 31, 10, 0, 0, 0, time.UTC))
|
||||||
|
if err != nil {
|
||||||
|
t.Fatalf("failed to create booking: %v", err)
|
||||||
|
}
|
||||||
|
paymentID, err := fixtures.CreateTestPayment(tx, bookingID, 50.00, "online_square", "full", "completed")
|
||||||
|
if err != nil {
|
||||||
|
t.Fatalf("failed to create card payment: %v", err)
|
||||||
|
}
|
||||||
|
const chargeID = "sqp_m8_audit"
|
||||||
|
if _, err := tx.Exec(ctx, "UPDATE payments SET square_payment_id = $1 WHERE id = $2", chargeID, paymentID); err != nil {
|
||||||
|
t.Fatalf("failed to set square_payment_id: %v", err)
|
||||||
|
}
|
||||||
|
|
||||||
|
var refundID string
|
||||||
|
err = tx.QueryRow(ctx, `
|
||||||
|
INSERT INTO refunds (payment_id, booking_id, amount, status, reason, idempotency_key, origin, created_by, created_at)
|
||||||
|
VALUES ($1, $2, 50, 'pending', 'customer request', $3, 'manual', $4, NOW())
|
||||||
|
RETURNING id
|
||||||
|
`, paymentID, bookingID, paymentID+"-m8-audit-refund", adminID).Scan(&refundID)
|
||||||
|
if err != nil {
|
||||||
|
t.Fatalf("failed to insert manual pending refund: %v", err)
|
||||||
|
}
|
||||||
|
|
||||||
|
pgxTx := db.TxFromContext(ctx)
|
||||||
|
if pgxTx == nil {
|
||||||
|
t.Fatal("no transaction in context")
|
||||||
|
}
|
||||||
|
if err := pgxTx.Commit(ctx); err != nil {
|
||||||
|
t.Fatalf("failed to commit test tx: %v", err)
|
||||||
|
}
|
||||||
|
freshCtx := context.Background()
|
||||||
|
t.Cleanup(func() {
|
||||||
|
_, _ = db.Conn.Exec(context.Background(), `DELETE FROM admin_notifications WHERE booking_id = $1`, bookingID)
|
||||||
|
_, _ = db.Conn.Exec(context.Background(), `DELETE FROM admin_audit_log WHERE action_type = 'admin_refund' AND admin_id = $1`, adminID)
|
||||||
|
_, _ = db.Conn.Exec(context.Background(), `DELETE FROM refunds WHERE id = $1`, refundID)
|
||||||
|
_, _ = db.Conn.Exec(context.Background(), `DELETE FROM payments WHERE id = $1`, paymentID)
|
||||||
|
_, _ = db.Conn.Exec(context.Background(), `DELETE FROM bookings WHERE id = $1`, bookingID)
|
||||||
|
_, _ = db.Conn.Exec(context.Background(), `DELETE FROM services WHERE id = $1`, serviceID)
|
||||||
|
_, _ = db.Conn.Exec(context.Background(), `DELETE FROM users WHERE id = $1`, userID)
|
||||||
|
_, _ = db.Conn.Exec(context.Background(), `DELETE FROM users WHERE id = $1`, adminID)
|
||||||
|
})
|
||||||
|
|
||||||
|
origClient := SquareClient
|
||||||
|
SquareClient = square.NewDevClient()
|
||||||
|
defer func() { SquareClient = origClient }()
|
||||||
|
|
||||||
|
n, err := processManualPaymentGroup(freshCtx, paymentID, []manualPendingRow{{ID: refundID}})
|
||||||
|
if err != nil {
|
||||||
|
t.Fatalf("processManualPaymentGroup failed: %v", err)
|
||||||
|
}
|
||||||
|
if n != 1 {
|
||||||
|
t.Fatalf("expected 1 manual refund processed, got %d", n)
|
||||||
|
}
|
||||||
|
|
||||||
|
// The refund must actually have been issued (completed), not merely attempted.
|
||||||
|
var status string
|
||||||
|
if err := db.Conn.QueryRow(freshCtx, `SELECT status FROM refunds WHERE id = $1`, refundID).Scan(&status); err != nil {
|
||||||
|
t.Fatalf("failed to query refund status: %v", err)
|
||||||
|
}
|
||||||
|
if status != "completed" {
|
||||||
|
t.Fatalf("expected refund 'completed' before asserting the audit row, got %q", status)
|
||||||
|
}
|
||||||
|
|
||||||
|
// The manual refund issuance must have written an admin_audit_log row.
|
||||||
|
var auditCount int
|
||||||
|
if err := db.Conn.QueryRow(freshCtx, `
|
||||||
|
SELECT COUNT(*) FROM admin_audit_log
|
||||||
|
WHERE admin_id = $1 AND action_type = 'admin_refund'
|
||||||
|
`, adminID).Scan(&auditCount); err != nil {
|
||||||
|
t.Fatalf("failed to query admin_audit_log: %v", err)
|
||||||
|
}
|
||||||
|
if auditCount != 1 {
|
||||||
|
t.Errorf("expected exactly 1 'admin_refund' audit row after a manual refund, got %d", auditCount)
|
||||||
|
}
|
||||||
|
var details string
|
||||||
|
if err := db.Conn.QueryRow(freshCtx, `
|
||||||
|
SELECT details::text FROM admin_audit_log
|
||||||
|
WHERE admin_id = $1 AND action_type = 'admin_refund'
|
||||||
|
`, adminID).Scan(&details); err != nil {
|
||||||
|
t.Fatalf("failed to read admin_audit_log details: %v", err)
|
||||||
|
}
|
||||||
|
for _, want := range []string{paymentID, "5000", "customer request"} {
|
||||||
|
if !strings.Contains(details, want) {
|
||||||
|
t.Errorf("expected audit details to carry %q, got %s", want, details)
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
// =============================================================================
|
// =============================================================================
|
||||||
// H2 — REFUND_AMOUNT_INVALID reconciliation (refunds.go)
|
// H2 — REFUND_AMOUNT_INVALID reconciliation (refunds.go)
|
||||||
// =============================================================================
|
// =============================================================================
|
||||||
@@ -4786,3 +5082,92 @@ func TestSweepManualRefund_SyncPendingResponse_LeavesPending(t *testing.T) {
|
|||||||
t.Error("expected square_refund_id NOT to be written for a non-terminal PENDING response (only terminal states record the Square reference)")
|
t.Error("expected square_refund_id NOT to be written for a non-terminal PENDING response (only terminal states record the Square reference)")
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// TestInsertRefundFailedNotifications_FloodCap pins C5 for the 'refund_failed'
|
||||||
|
// insert site: the unacknowledged queue is flood-capped at
|
||||||
|
// adminnotify.MaxUnacknowledgedCriticalLogs (pre-checked by
|
||||||
|
// CriticalLogsCapExceeded and enforced atomically inside the INSERT), so a
|
||||||
|
// flood of failed refunds cannot bury the operator. Once the queue is at the
|
||||||
|
// cap a further failed refund is suppressed without growing the queue, while
|
||||||
|
// the (reason, booking_id) NOT EXISTS dedup still prevents double-notifying a
|
||||||
|
// single refund below the cap.
|
||||||
|
func TestInsertRefundFailedNotifications_FloodCap(t *testing.T) {
|
||||||
|
t.Parallel()
|
||||||
|
ctx, tx := testutils.SetupTestTx(t)
|
||||||
|
|
||||||
|
userID, err := fixtures.CreateTestUser(tx)
|
||||||
|
if err != nil {
|
||||||
|
t.Fatalf("failed to create user: %v", err)
|
||||||
|
}
|
||||||
|
adminID, err := fixtures.CreateTestAdminUser(tx)
|
||||||
|
if err != nil {
|
||||||
|
t.Fatalf("failed to create admin: %v", err)
|
||||||
|
}
|
||||||
|
|
||||||
|
var bookingID string
|
||||||
|
if err := tx.QueryRow(ctx, `
|
||||||
|
INSERT INTO bookings (user_id, start_time, status)
|
||||||
|
VALUES ($1, $2, 'confirmed')
|
||||||
|
RETURNING id
|
||||||
|
`, userID, clock.Now().Add(24*time.Hour)).Scan(&bookingID); err != nil {
|
||||||
|
t.Fatalf("failed to create booking: %v", err)
|
||||||
|
}
|
||||||
|
var paymentID string
|
||||||
|
if err := tx.QueryRow(ctx, `
|
||||||
|
INSERT INTO payments (booking_id, payment_type, payment_method, status, amount, created_by, created_at, updated_at)
|
||||||
|
VALUES ($1, 'full', 'online_square', 'completed', 10.00, $2, NOW(), NOW())
|
||||||
|
RETURNING id
|
||||||
|
`, bookingID, userID).Scan(&paymentID); err != nil {
|
||||||
|
t.Fatalf("failed to create payment: %v", err)
|
||||||
|
}
|
||||||
|
var refundID string
|
||||||
|
if err := tx.QueryRow(ctx, `
|
||||||
|
INSERT INTO refunds (payment_id, booking_id, amount, status, reason, idempotency_key, created_by, created_at, origin)
|
||||||
|
VALUES ($1, $2, 10.00, 'failed', 'test', 'refund-flood-cap-1', $3, NOW(), 'manual')
|
||||||
|
RETURNING id
|
||||||
|
`, paymentID, bookingID, adminID).Scan(&refundID); err != nil {
|
||||||
|
t.Fatalf("failed to create failed refund: %v", err)
|
||||||
|
}
|
||||||
|
|
||||||
|
countForBooking := func() int {
|
||||||
|
t.Helper()
|
||||||
|
var n int
|
||||||
|
if err := tx.QueryRow(ctx, `SELECT COUNT(*) FROM admin_notifications WHERE reason = 'refund_failed' AND booking_id = $1`, bookingID).Scan(&n); err != nil {
|
||||||
|
t.Fatalf("failed to count refund_failed notifications: %v", err)
|
||||||
|
}
|
||||||
|
return n
|
||||||
|
}
|
||||||
|
|
||||||
|
// Below the cap: the failed refund surfaces exactly one notification, and
|
||||||
|
// the (reason, booking_id) dedup keeps a re-run from double-notifying.
|
||||||
|
insertRefundFailedNotifications(ctx, []string{refundID})
|
||||||
|
if n := countForBooking(); n != 1 {
|
||||||
|
t.Fatalf("expected 1 refund_failed notification below the cap, got %d", n)
|
||||||
|
}
|
||||||
|
insertRefundFailedNotifications(ctx, []string{refundID})
|
||||||
|
if n := countForBooking(); n != 1 {
|
||||||
|
t.Errorf("expected the (reason, booking_id) dedup to keep exactly 1 notification, got %d", n)
|
||||||
|
}
|
||||||
|
|
||||||
|
// Fill the unacknowledged 'refund_failed' queue to the cap.
|
||||||
|
if _, err := tx.Exec(ctx, `DELETE FROM admin_notifications WHERE reason = 'refund_failed'`); err != nil {
|
||||||
|
t.Fatalf("failed to clear refund_failed notifications: %v", err)
|
||||||
|
}
|
||||||
|
for i := 0; i < adminnotify.MaxUnacknowledgedCriticalLogs; i++ {
|
||||||
|
if _, err := tx.Exec(ctx, `
|
||||||
|
INSERT INTO admin_notifications (reason, user_id, created_at)
|
||||||
|
VALUES ('refund_failed', $1, NOW())
|
||||||
|
`, userID); err != nil {
|
||||||
|
t.Fatalf("failed to seed refund_failed notification %d: %v", i, err)
|
||||||
|
}
|
||||||
|
}
|
||||||
|
if !adminnotify.CriticalLogsCapExceeded(ctx, db.Conn, "refund_failed") {
|
||||||
|
t.Fatal("expected the unacknowledged refund_failed queue to be at the cap")
|
||||||
|
}
|
||||||
|
|
||||||
|
// At the cap the refund's insert is suppressed — nothing for this booking.
|
||||||
|
insertRefundFailedNotifications(ctx, []string{refundID})
|
||||||
|
if n := countForBooking(); n != 0 {
|
||||||
|
t.Errorf("expected the suppressed insert to add no refund_failed notification for the booking, got %d", n)
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|||||||
Reference in New Issue
Block a user