diff --git a/Makefile b/Makefile index 32d689b..1403a2a 100644 --- a/Makefile +++ b/Makefile @@ -3,7 +3,7 @@ .PHONY: all build build-appview build-hold build-credential-helper build-oauth-helper \ build-trixie \ - generate test test-race test-verbose integration-test stripe-integration-test \ + generate test test-billing test-race test-verbose integration-test stripe-integration-test \ lint lex-lint clean help install-credential-helper \ develop develop-detached develop-down dev \ docker docker-appview docker-hold docker-scanner @@ -96,10 +96,17 @@ build-trixie: generate ## Build all production binaries (appview, hold, credenti ##@ Test Targets -test: ## Run all tests +test: test-billing ## Run all tests @echo "→ Running tests..." go test -cover ./... +# pkg/billing is behind the `billing` build tag, so `go test ./...` never +# compiles it, let alone runs it. Its tests covered the money path and had +# never executed in this target or in CI. +test-billing: ## Run the billing-tagged tests (skipped by plain `go test ./...`) + @echo "→ Running billing-tagged tests..." + go test -tags billing -cover ./pkg/billing/... + test-race: ## Run tests with race detector @echo "→ Running tests with race detector..." go test -race ./... @@ -141,6 +148,8 @@ check-golangci-lint: lint: check-golangci-lint ## Run golangci-lint @echo "→ Running golangci-lint..." golangci-lint run ./... + @echo "→ Running golangci-lint (billing tag)..." + golangci-lint run --build-tags=billing ./pkg/billing/... lex-lint: ## Lint ATProto lexicon schemas goat lex lint ./lexicons/ diff --git a/pkg/billing/billing.go b/pkg/billing/billing.go index 8b10a6d..fa379c3 100644 --- a/pkg/billing/billing.go +++ b/pkg/billing/billing.go @@ -605,9 +605,22 @@ func (m *Manager) handleSubscriptionChange(event stripe.Event) error { } } - // Get user DID from customer metadata - userDID := m.getCustomerDID(sub.Customer.ID) + // The ordering guard above already treats a nil customer as possible; this + // used to dereference it regardless and panic. + if sub.Customer == nil || sub.Customer.ID == "" { + slog.Warn("Subscription event carries no customer", "subscriptionID", sub.ID) + return nil + } + + // Get user DID from customer metadata. A failed lookup must be retried: + // returning nil here records the event as processed, Stripe answers 200 and + // never redelivers, and a paid upgrade is lost to a transient API error. + userDID, err := m.getCustomerDID(sub.Customer.ID) + if err != nil { + return fmt.Errorf("resolve customer DID: %w", err) + } if userDID == "" { + // A conclusion, not a failure: redelivery cannot conjure a user_did. slog.Warn("No user DID found for Stripe customer", "customerID", sub.Customer.ID) return nil } @@ -712,7 +725,9 @@ func (m *Manager) handleInvoicePaymentFailed(event stripe.Event) error { userDID := "" if inv.Customer != nil { customerID = inv.Customer.ID - userDID = m.getCustomerDID(customerID) + // Log-only: a lookup failure here is not worth failing the webhook over, + // and the entry is still useful without the DID. + userDID, _ = m.getCustomerDID(customerID) } nextAttempt := int64(0) @@ -749,7 +764,8 @@ func (m *Manager) handleChargeDisputeCreated(event stripe.Event) error { userDID := "" if dispute.Charge != nil && dispute.Charge.Customer != nil { customerID = dispute.Charge.Customer.ID - userDID = m.getCustomerDID(customerID) + // Log-only, as above. + userDID, _ = m.getCustomerDID(customerID) } evidenceDueBy := int64(0) @@ -876,13 +892,18 @@ func (m *Manager) searchCustomerByDID(userDID string) (*stripe.Customer, error) } // getCustomerDID retrieves the user DID from a Stripe customer's metadata. -func (m *Manager) getCustomerDID(customerID string) string { +// Returns ("", nil) when the customer exists but carries no user_did, and +// ("", err) when the lookup itself failed. Callers acting on the result must +// distinguish the two: the first is a conclusion, the second is a Stripe +// outage, and treating an outage as "not our customer" silently drops the +// subscription change with no redelivery. +func (m *Manager) getCustomerDID(customerID string) (string, error) { cust, err := customer.Get(customerID, nil) if err != nil { slog.Error("Failed to get customer", "customerID", customerID, "error", err) - return "" + return "", fmt.Errorf("get customer %s: %w", customerID, err) } - return cust.Metadata["user_did"] + return cust.Metadata["user_did"], nil } // cacheCustomer stores a customer in the in-memory cache. diff --git a/pkg/billing/webhook_retry_test.go b/pkg/billing/webhook_retry_test.go new file mode 100644 index 0000000..96f168c --- /dev/null +++ b/pkg/billing/webhook_retry_test.go @@ -0,0 +1,287 @@ +//go:build billing + +package billing + +import ( + "database/sql" + "errors" + "fmt" + "net/http" + "net/http/httptest" + "path/filepath" + "strings" + "sync/atomic" + "testing" + "time" + + appdb "atcr.io/pkg/appview/db" + "github.com/stripe/stripe-go/v84" + "github.com/stripe/stripe-go/v84/webhook" +) + +// newTestManager builds a Manager with a REAL database. +// +// test/stripe-integration builds its manager with a nil database, so every +// `m.db != nil` branch — which is all of the idempotency and ordering work +// 12c55ed added — is skipped there. A suite that never touches those branches +// cannot notice them regressing. +func newTestManager(t *testing.T, secret string) (*Manager, *sql.DB) { + t.Helper() + + // A file rather than ":memory:", which is per-connection in libsql and + // produces "no such table" once the pool opens a second one. + database, err := appdb.InitDB(filepath.Join(t.TempDir(), "ui.db"), appdb.LibsqlConfig{}) + if err != nil { + t.Fatalf("init db: %v", err) + } + t.Cleanup(func() { _ = database.Close() }) + + // New() reads these first, so a stray value in the environment would + // otherwise decide the test. + t.Setenv("STRIPE_SECRET_KEY", "sk_test_fake") + t.Setenv("STRIPE_WEBHOOK_SECRET", secret) + + cfg := &Config{ + StripeSecretKey: "sk_test_fake", + WebhookSecret: secret, + // Rank is positional (0-based by list order), not a field. + Tiers: []BillingTierConfig{ + {Name: "free"}, + {Name: "supporter", StripePriceMonthly: "price_monthly_test"}, + }, + } + m := New(cfg, nil, "did:web:test-appview.local", nil, "http://test-appview.local", database) + if !m.Enabled() { + t.Fatal("manager should be enabled") + } + return m, database +} + +// stripeAPIReturning points the global stripe-go backend at a stub that answers +// every API call with the given status and body, so a Stripe-side failure can +// be simulated without network access. +// Returns a counter of API calls made. Counting is what makes the idempotency +// and ordering tests real: both guards short-circuit BEFORE the customer +// lookup, so "did Stripe get called again" is the only observable difference. +// Row counts are not — RecordStripeEvent is an idempotent upsert, so removing +// the guards entirely leaves the table looking identical. +func stripeAPIReturning(t *testing.T, status int, body string) *atomic.Int64 { + t.Helper() + var calls atomic.Int64 + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + calls.Add(1) + w.Header().Set("Content-Type", "application/json") + w.WriteHeader(status) + _, _ = w.Write([]byte(body)) + })) + t.Cleanup(srv.Close) + + prev := stripe.GetBackend(stripe.APIBackend) + stripe.SetBackend(stripe.APIBackend, stripe.GetBackendWithConfig(stripe.APIBackend, &stripe.BackendConfig{ + URL: stripe.String(srv.URL), + MaxNetworkRetries: stripe.Int64(0), + })) + t.Cleanup(func() { stripe.SetBackend(stripe.APIBackend, prev) }) + return &calls +} + +func signedSubscriptionEvent(t *testing.T, secret, eventID, customerID string, created int64) []byte { + t.Helper() + // api_version is required: ConstructEvent rejects a payload whose version + // does not match what stripe-go expects, before any of the logic under test + // runs, and the resulting error looks like a signature failure. + payload := fmt.Sprintf(`{ + "id": %q, + "object": "event", + "api_version": %q, + "type": "customer.subscription.updated", + "created": %d, + "data": {"object": { + "id": "sub_test", + "object": "subscription", + "status": "active", + "customer": %q, + "items": {"object":"list","data":[{"price":{"id":"price_monthly_test"}}]} + }} + }`, eventID, stripe.APIVersion, created, customerID) + return []byte(payload) +} + +func postWebhook(t *testing.T, m *Manager, secret string, payload []byte) error { + t.Helper() + signed := webhook.GenerateTestSignedPayload(&webhook.UnsignedPayload{ + Payload: payload, Secret: secret, Timestamp: time.Now(), + }) + req := httptest.NewRequest(http.MethodPost, "/api/stripe/webhook", strings.NewReader(string(signed.Payload))) + req.Header.Set("Stripe-Signature", signed.Header) + return m.HandleWebhook(req) +} + +func processedCount(t *testing.T, database *sql.DB) int { + t.Helper() + var n int + if err := database.QueryRow("SELECT COUNT(*) FROM stripe_processed_events").Scan(&n); err != nil { + t.Fatalf("count processed events: %v", err) + } + return n +} + +// TestHandleSubscriptionChange_CustomerLookupFailureIsRetryable is the one the +// plan flags as the open defect, and it is real. +// +// getCustomerDID returns "" for a FAILED customer.Get exactly as it does for a +// customer with no user_did metadata. handleSubscriptionChange reads that as +// "not our customer" and returns nil, so HandleWebhook records the event as +// processed and answers 200. Stripe never redelivers, and a paid upgrade is +// dropped permanently by a transient API blip — the precise "paid but never +// received tier" hole 12c55ed was written to close. +// +// The assertion that matters is the empty stripe_processed_events table: an +// error alone would still be wrong if the event had been recorded, because the +// retry would then be skipped as already-seen. +func TestHandleSubscriptionChange_CustomerLookupFailureIsRetryable(t *testing.T) { + const secret = "whsec_test_secret" + m, database := newTestManager(t, secret) + + // Stripe is down, not answering "no such customer". + _ = stripeAPIReturning(t, http.StatusInternalServerError, + `{"error":{"type":"api_error","message":"Stripe is temporarily unavailable"}}`) + + err := postWebhook(t, m, secret, + signedSubscriptionEvent(t, secret, "evt_lookup_fail", "cus_test123", time.Now().Unix())) + + if err == nil { + t.Error("HandleWebhook returned nil after the customer lookup failed; Stripe will not redeliver " + + "and the subscription change is lost permanently") + } else if !errors.Is(err, ErrWebhookProcessing) { + t.Errorf("error = %v, want ErrWebhookProcessing so the webhook 500s and Stripe retries", err) + } + + if n := processedCount(t, database); n != 0 { + t.Errorf("stripe_processed_events has %d row(s); the event must not be recorded when handling "+ + "failed, or the redelivery is skipped as already-seen", n) + } +} + +// A subscription event whose customer is genuinely absent must NOT be retried: +// redelivery cannot make a customer appear, and 500ing to exhaustion buries the +// real failures. This is the case getCustomerDID's "" is legitimately for, and +// it is why the fix has to distinguish the two rather than error on both. +func TestHandleSubscriptionChange_NoCustomerMetadataIsNotRetried(t *testing.T) { + const secret = "whsec_test_secret" + m, database := newTestManager(t, secret) + + // Stripe answers fine; the customer simply carries no user_did. + _ = stripeAPIReturning(t, http.StatusOK, `{"id":"cus_test123","object":"customer","metadata":{}}`) + + if err := postWebhook(t, m, secret, + signedSubscriptionEvent(t, secret, "evt_no_meta", "cus_test123", time.Now().Unix())); err != nil { + t.Errorf("HandleWebhook error = %v, want nil: retrying cannot conjure a user_did", err) + } + if n := processedCount(t, database); n != 1 { + t.Errorf("stripe_processed_events has %d row(s), want 1: the event was handled to a conclusion", n) + } +} + +const custWithDID = `{"id":"cus_test123","object":"customer","metadata":{"user_did":"did:plc:testuser"}}` + +// TestHandleWebhook_RedeliveryIsSkipped is the idempotency 12c55ed added, and +// nothing exercised it: test/stripe-integration passes a nil database, so the +// whole `m.db != nil` path — this check included — is dead there. +func TestHandleWebhook_RedeliveryIsSkipped(t *testing.T) { + const secret = "whsec_test_secret" + m, database := newTestManager(t, secret) + calls := stripeAPIReturning(t, http.StatusOK, custWithDID) + + payload := signedSubscriptionEvent(t, secret, "evt_dedupe", "cus_test123", time.Now().Unix()) + + if err := postWebhook(t, m, secret, payload); err != nil { + t.Fatalf("first delivery: %v", err) + } + if n := processedCount(t, database); n != 1 { + t.Fatalf("after first delivery: %d rows, want 1", n) + } + first := calls.Load() + + // Stripe redelivers on any non-2xx, and the dashboard can resend by hand. + if err := postWebhook(t, m, secret, payload); err != nil { + t.Errorf("redelivery: %v, want nil — a repeat must be a no-op, not an error", err) + } + if n := processedCount(t, database); n != 1 { + t.Errorf("after redelivery: %d rows, want 1 — the event was applied twice", n) + } + if got := calls.Load(); got != first { + t.Errorf("redelivery made %d Stripe call(s), want %d — the seen-check did not short-circuit "+ + "and the event was re-applied", got-first, 0) + } +} + +// Stripe does not guarantee delivery order. A stale `active` arriving after a +// cancellation must not re-grant the tier, which is what the per-customer +// event_created watermark is for. +func TestHandleSubscriptionChange_StaleEventIsIgnored(t *testing.T) { + const secret = "whsec_test_secret" + m, database := newTestManager(t, secret) + calls := stripeAPIReturning(t, http.StatusOK, custWithDID) + + now := time.Now().Unix() + if err := postWebhook(t, m, secret, + signedSubscriptionEvent(t, secret, "evt_newer", "cus_test123", now)); err != nil { + t.Fatalf("newer event: %v", err) + } + + afterNewer := calls.Load() + + // An older event for the same customer, delivered second. + if err := postWebhook(t, m, secret, + signedSubscriptionEvent(t, secret, "evt_older", "cus_test123", now-3600)); err != nil { + t.Errorf("stale event: %v, want nil — dropping it is a conclusion, not a failure", err) + } + + // Both are recorded (the stale one WAS handled, by being ignored), but the + // watermark must not have moved backwards. + var latest int64 + if err := database.QueryRow( + `SELECT MAX(event_created) FROM stripe_processed_events WHERE customer_id = ?`, "cus_test123", + ).Scan(&latest); err != nil { + t.Fatalf("read watermark: %v", err) + } + if latest != now { + t.Errorf("watermark = %d, want %d — a stale event moved it backwards", latest, now) + } + if n := processedCount(t, database); n != 2 { + t.Errorf("processed rows = %d, want 2", n) + } + if got := calls.Load(); got != afterNewer { + t.Errorf("the stale event made %d Stripe call(s) — the ordering guard did not short-circuit, "+ + "so a stale active re-granted a tier", got-afterNewer) + } +} + +// The ordering guard above line 609 checks sub.Customer != nil; the DID lookup +// right below it used to dereference sub.Customer.ID unconditionally. +func TestHandleSubscriptionChange_NilCustomerDoesNotPanic(t *testing.T) { + const secret = "whsec_test_secret" + m, _ := newTestManager(t, secret) + _ = stripeAPIReturning(t, http.StatusOK, custWithDID) + + payload := fmt.Sprintf(`{ + "id": "evt_nocust", + "object": "event", + "api_version": %q, + "type": "customer.subscription.updated", + "created": %d, + "data": {"object": { + "id": "sub_test", + "object": "subscription", + "status": "active", + "items": {"object":"list","data":[{"price":{"id":"price_monthly_test"}}]} + }} + }`, stripe.APIVersion, time.Now().Unix()) + + // A panic here would surface as a 500 and an endless Stripe retry loop, or + // take the appview down outright depending on the recovery middleware. + if err := postWebhook(t, m, secret, []byte(payload)); err != nil { + t.Errorf("HandleWebhook error = %v, want nil for an event with no customer", err) + } +}