Replaces raw t.Error/t.Errorf/t.Fatal/t.Fatalf across every test file that has any (domains/accounts, domains/authentication, domains/raw_events, domains/amazon, domains/reports x2) with testify's assert (non-halting) / require (halting) equivalents. The three Example-based tests (server/ui/svg, server/ui/charts) have no *testing.T at all - nothing to convert there. require.Eventually replaces several hand-rolled polling loops in domains/amazon/mock_test.go. Its condition function runs on a separate goroutine (confirmed in testify's source), so calling require.* from inside one - which two of the new Eventually calls initially did, via the isProcessed helper - is unsafe per Go's testing rules (t.FailNow must only be called from the test's own goroutine). Fixed by splitting a *testing.T-free queryIsProcessed(ctx, pool, shopID, eventID) out of isProcessed for use inside those closures specifically. github.com/stretchr/testify promoted from an indirect to a direct dependency (go.mod only - it was already present transitively, so go.sum is unchanged). Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01XEDaCB7C2NEBgyvqEtZuxY
460 lines
16 KiB
Go
460 lines
16 KiB
Go
package amazon
|
|
|
|
import (
|
|
"context"
|
|
"sync"
|
|
"testing"
|
|
"time"
|
|
|
|
"github.com/google/uuid"
|
|
"github.com/jackc/pgx/v5/pgxpool"
|
|
"github.com/stretchr/testify/assert"
|
|
"github.com/stretchr/testify/require"
|
|
|
|
"ruben/inventory2/domains/raw_events"
|
|
"ruben/inventory2/internal/testdb"
|
|
)
|
|
|
|
// notifySpy is a MockEventListener that records every event it's notified
|
|
// about, along with the ack callback it was given. By default it acks
|
|
// immediately (autoAck=true), matching a well-behaved listener; tests
|
|
// exercising the retry path set autoAck=false to simulate a listener that
|
|
// received the notification but hasn't finished yet, and call ackAt
|
|
// explicitly once it "finishes".
|
|
type notifySpy struct {
|
|
mu sync.Mutex
|
|
events []raw_events.Event
|
|
acks []func(context.Context) error
|
|
completedCount int // Notify calls that have returned, including any auto-ack
|
|
autoAck bool
|
|
}
|
|
|
|
func newNotifySpy() *notifySpy {
|
|
return ¬ifySpy{autoAck: true}
|
|
}
|
|
|
|
func (s *notifySpy) Notify(ctx context.Context, e raw_events.Event, ack func(context.Context) error) error {
|
|
s.mu.Lock()
|
|
s.events = append(s.events, e)
|
|
s.acks = append(s.acks, ack)
|
|
autoAck := s.autoAck
|
|
s.mu.Unlock()
|
|
|
|
var ackErr error
|
|
if autoAck {
|
|
ackErr = ack(ctx)
|
|
}
|
|
|
|
s.mu.Lock()
|
|
s.completedCount++
|
|
s.mu.Unlock()
|
|
|
|
return ackErr
|
|
}
|
|
|
|
func (s *notifySpy) eventsSnapshot() []raw_events.Event {
|
|
s.mu.Lock()
|
|
defer s.mu.Unlock()
|
|
return append([]raw_events.Event(nil), s.events...)
|
|
}
|
|
|
|
func (s *notifySpy) setAutoAck(v bool) {
|
|
s.mu.Lock()
|
|
defer s.mu.Unlock()
|
|
s.autoAck = v
|
|
}
|
|
|
|
// ackAt manually invokes the i-th recorded ack callback (0-indexed, in
|
|
// Notify call order), simulating the listener finally finishing work it
|
|
// had earlier only been notified about.
|
|
func (s *notifySpy) ackAt(t *testing.T, i int) {
|
|
t.Helper()
|
|
s.mu.Lock()
|
|
ack := s.acks[i]
|
|
s.mu.Unlock()
|
|
require.NoError(t, ack(context.Background()), "ack()")
|
|
}
|
|
|
|
// completedCountSnapshot is safe to call from another goroutine (e.g. from
|
|
// inside require.Eventually's condition), unlike helpers that call t.Fatal.
|
|
func (s *notifySpy) completedCountSnapshot() int {
|
|
s.mu.Lock()
|
|
defer s.mu.Unlock()
|
|
return s.completedCount
|
|
}
|
|
|
|
// waitForCount blocks until at least n Notify calls have fully completed
|
|
// (including any auto-ack), cumulatively across the test - safe to call
|
|
// more than once with increasing n.
|
|
func (s *notifySpy) waitForCount(t *testing.T, n int, timeout time.Duration) {
|
|
t.Helper()
|
|
require.Eventually(t, func() bool {
|
|
return s.completedCountSnapshot() >= n
|
|
}, timeout, 5*time.Millisecond, "timed out waiting for %d total completed notifications (got %d)", n, s.completedCountSnapshot())
|
|
}
|
|
|
|
// insertRawAmazonEvent inserts directly into mock.raw_shop_events, the same
|
|
// entry point real mock sale/refund/inventory simulations use. A DB trigger
|
|
// (mock.process_raw_amazon_event, see migrations 000026/000028) copies the
|
|
// row into mock.shop_amazon_events and fires pg_notify on
|
|
// mock_shop_amazon_event_inserted - so this one insert exercises the exact
|
|
// same path production traffic does, instead of faking the downstream
|
|
// table directly.
|
|
func insertRawAmazonEvent(t *testing.T, pool *pgxpool.Pool, shopID, eventID string) {
|
|
t.Helper()
|
|
_, err := pool.Exec(context.Background(), `
|
|
INSERT INTO mock.raw_shop_events (platform, shop_id, event_timestamp, event_id, raw_payload)
|
|
VALUES ('amazon', $1, NOW(), $2, '{}'::jsonb)
|
|
`, shopID, eventID)
|
|
require.NoError(t, err, "insert raw amazon event")
|
|
}
|
|
|
|
// insertRawAmazonEvents bulk-inserts n events for shopID in one statement,
|
|
// each with a distinct event_id/event_timestamp.
|
|
func insertRawAmazonEvents(t *testing.T, pool *pgxpool.Pool, shopID string, n int) {
|
|
t.Helper()
|
|
_, err := pool.Exec(context.Background(), `
|
|
INSERT INTO mock.raw_shop_events (platform, shop_id, event_timestamp, event_id, raw_payload)
|
|
SELECT 'amazon', $1, NOW() + (s || ' milliseconds')::interval, 'evt-' || s, '{}'::jsonb
|
|
FROM generate_series(1, $2) AS s
|
|
`, shopID, n)
|
|
require.NoError(t, err, "insert %d raw amazon events", n)
|
|
}
|
|
|
|
// queryIsProcessed has no *testing.T dependency, so it's safe to call from
|
|
// require.Eventually's condition function (which testify runs on a
|
|
// separate goroutine - t.Fatal/require must only be called from the main
|
|
// test goroutine). isProcessed wraps it for direct, main-goroutine use.
|
|
func queryIsProcessed(ctx context.Context, pool *pgxpool.Pool, shopID, eventID string) (bool, error) {
|
|
var processed bool
|
|
err := pool.QueryRow(ctx, `
|
|
SELECT processed_at IS NOT NULL
|
|
FROM mock.shop_amazon_events
|
|
WHERE shop_id = $1 AND event_id = $2
|
|
`, shopID, eventID).Scan(&processed)
|
|
return processed, err
|
|
}
|
|
|
|
func isProcessed(t *testing.T, pool *pgxpool.Pool, shopID, eventID string) bool {
|
|
t.Helper()
|
|
processed, err := queryIsProcessed(context.Background(), pool, shopID, eventID)
|
|
require.NoError(t, err, "check processed state")
|
|
return processed
|
|
}
|
|
|
|
// isNotified reports whether the event has been notified (at least once)
|
|
// but not yet acked/processed.
|
|
func isNotified(t *testing.T, pool *pgxpool.Pool, shopID, eventID string) bool {
|
|
t.Helper()
|
|
var notified bool
|
|
err := pool.QueryRow(context.Background(), `
|
|
SELECT notified_at IS NOT NULL AND processed_at IS NULL
|
|
FROM mock.shop_amazon_events
|
|
WHERE shop_id = $1 AND event_id = $2
|
|
`, shopID, eventID).Scan(¬ified)
|
|
require.NoError(t, err, "check notified state")
|
|
return notified
|
|
}
|
|
|
|
func countUnprocessed(t *testing.T, pool *pgxpool.Pool, shopID string) int {
|
|
t.Helper()
|
|
var n int
|
|
err := pool.QueryRow(context.Background(), `
|
|
SELECT count(*) FROM mock.shop_amazon_events WHERE shop_id = $1 AND processed_at IS NULL
|
|
`, shopID).Scan(&n)
|
|
require.NoError(t, err, "count unprocessed events")
|
|
return n
|
|
}
|
|
|
|
// cleanupShop registers deletion of every row this test's shopID may have
|
|
// produced, in FK-safe order (shop_amazon_events references raw_shop_events).
|
|
func cleanupShop(t *testing.T, pool *pgxpool.Pool, shopID string) {
|
|
t.Cleanup(func() {
|
|
ctx := context.Background()
|
|
pool.Exec(ctx, `DELETE FROM mock.shop_amazon_events WHERE shop_id = $1`, shopID)
|
|
pool.Exec(ctx, `DELETE FROM mock.raw_shop_events WHERE platform = 'amazon' AND shop_id = $1`, shopID)
|
|
})
|
|
}
|
|
|
|
// terminateListenConnection finds the backend holding this package's LISTEN
|
|
// registration (identified by its last query text, which Postgres keeps
|
|
// showing while the connection sits idle waiting for notifications) and
|
|
// forcibly kills it - the same failure mode a dropped connection or a
|
|
// Postgres restart produces, so tests can exercise real reconnect behavior
|
|
// instead of a simulated one.
|
|
func terminateListenConnection(t *testing.T, pool *pgxpool.Pool) {
|
|
t.Helper()
|
|
ctx := context.Background()
|
|
|
|
var pid int
|
|
err := pool.QueryRow(ctx, `
|
|
SELECT pid FROM pg_stat_activity
|
|
WHERE query = 'LISTEN ' || $1
|
|
ORDER BY backend_start DESC
|
|
LIMIT 1
|
|
`, eventChannelName).Scan(&pid)
|
|
require.NoError(t, err, "find the LISTEN connection's backend pid")
|
|
|
|
_, err = pool.Exec(ctx, `SELECT pg_terminate_backend($1)`, pid)
|
|
require.NoError(t, err, "terminate backend %d", pid)
|
|
}
|
|
|
|
// waitReady blocks until m signals it's actively listening, failing the
|
|
// test if that doesn't happen within timeout.
|
|
func waitReady(t *testing.T, m *Mocks, timeout time.Duration) {
|
|
t.Helper()
|
|
select {
|
|
case <-m.Ready():
|
|
case <-time.After(timeout):
|
|
require.Fail(t, "ProcessEvents() did not become ready (LISTEN registered)", "within %v", timeout)
|
|
}
|
|
}
|
|
|
|
// waitStopped blocks until ProcessEvents returns on errCh, asserting it
|
|
// returns a nil error, failing the test if that doesn't happen within
|
|
// timeout.
|
|
func waitStopped(t *testing.T, errCh <-chan error, timeout time.Duration) {
|
|
t.Helper()
|
|
select {
|
|
case err := <-errCh:
|
|
require.NoError(t, err, "ProcessEvents() after context cancellation")
|
|
case <-time.After(timeout):
|
|
require.Fail(t, "ProcessEvents() did not return", "within %v of context cancellation", timeout)
|
|
}
|
|
}
|
|
|
|
func TestProcessUnprocessedEvents_ProcessesAllEventsAcrossBatches(t *testing.T) {
|
|
pool := testdb.Pool(t)
|
|
spy := newNotifySpy()
|
|
m := NewMocks(testdb.Logger(), pool).SetListener(spy)
|
|
ctx := context.Background()
|
|
|
|
shopID := "test-shop-" + uuid.NewString()
|
|
cleanupShop(t, pool, shopID)
|
|
|
|
const n = 150 // exceeds the 100-row LIMIT per batch inside processUnprocessedEvents
|
|
insertRawAmazonEvents(t, pool, shopID, n)
|
|
|
|
require.NoError(t, m.processUnprocessedEvents(ctx), "processUnprocessedEvents()")
|
|
|
|
spy.waitForCount(t, n, 5*time.Second)
|
|
|
|
assert.Zero(t, countUnprocessed(t, pool, shopID),
|
|
"countUnprocessed() should be 0 (all %d events should be processed across multiple 100-row batches)", n)
|
|
}
|
|
|
|
func TestProcessUnprocessedEvents_NoListenerConfigured(t *testing.T) {
|
|
pool := testdb.Pool(t)
|
|
m := NewMocks(testdb.Logger(), pool) // no SetListener call
|
|
ctx := context.Background()
|
|
|
|
shopID := "test-shop-" + uuid.NewString()
|
|
cleanupShop(t, pool, shopID)
|
|
|
|
insertRawAmazonEvent(t, pool, shopID, "evt-1")
|
|
|
|
require.NoError(t, m.processUnprocessedEvents(ctx), "processUnprocessedEvents()")
|
|
|
|
// with no listener, nothing ever acks - the event is expected to stay
|
|
// "notified" forever, not silently marked processed.
|
|
assert.False(t, isProcessed(t, pool, shopID, "evt-1"),
|
|
"event was marked processed despite no listener being configured to ack it")
|
|
assert.True(t, isNotified(t, pool, shopID, "evt-1"),
|
|
"event should be in the notified state after being handed off with no listener to ack it")
|
|
}
|
|
|
|
// TestProcessUnprocessedEvents_RetriesUnackedNotification is the core of
|
|
// insight #2's fix: a listener that receives a notification but never acks
|
|
// gets notified again after notifyRetryAfter, and once it does ack (however
|
|
// late), the event settles into processed and stops being retried.
|
|
func TestProcessUnprocessedEvents_RetriesUnackedNotification(t *testing.T) {
|
|
pool := testdb.Pool(t)
|
|
spy := newNotifySpy()
|
|
spy.setAutoAck(false)
|
|
m := NewMocks(testdb.Logger(), pool).
|
|
SetListener(spy).
|
|
WithNotifyRetryAfter(50 * time.Millisecond)
|
|
ctx := context.Background()
|
|
|
|
shopID := "test-shop-" + uuid.NewString()
|
|
cleanupShop(t, pool, shopID)
|
|
|
|
insertRawAmazonEvent(t, pool, shopID, "evt-1")
|
|
|
|
require.NoError(t, m.processUnprocessedEvents(ctx), "processUnprocessedEvents() (1st pass)")
|
|
spy.waitForCount(t, 1, 2*time.Second)
|
|
|
|
require.False(t, isProcessed(t, pool, shopID, "evt-1"), "event was marked processed despite the listener never acking")
|
|
require.True(t, isNotified(t, pool, shopID, "evt-1"), "event should be in the notified state after the first dispatch")
|
|
|
|
// still within notifyRetryAfter: shouldn't be re-notified yet.
|
|
require.NoError(t, m.processUnprocessedEvents(ctx), "processUnprocessedEvents() (immediate 2nd pass)")
|
|
require.Len(t, spy.eventsSnapshot(), 1, "listener should not have been notified again before notifyRetryAfter elapsed")
|
|
|
|
time.Sleep(60 * time.Millisecond) // past notifyRetryAfter
|
|
|
|
require.NoError(t, m.processUnprocessedEvents(ctx), "processUnprocessedEvents() (3rd pass, after retry window)")
|
|
spy.waitForCount(t, 2, 2*time.Second)
|
|
|
|
// the listener "finishes" the first notification late, via the ack it
|
|
// was originally handed - not a fresh one from the retry.
|
|
spy.ackAt(t, 0)
|
|
|
|
require.True(t, isProcessed(t, pool, shopID, "evt-1"), "event should be processed once any recorded ack for it is called")
|
|
|
|
require.NoError(t, m.processUnprocessedEvents(ctx), "processUnprocessedEvents() (4th pass, after ack)")
|
|
assert.Len(t, spy.eventsSnapshot(), 2, "listener should not be notified again after being acked")
|
|
}
|
|
|
|
// TestProcessEvents_PollFallbackPicksUpRetryDueEvents proves the poll
|
|
// branch of ProcessEvents' select actually causes reprocessing, decoupled
|
|
// from NOTIFY entirely: after the one real insert (which does fire NOTIFY,
|
|
// same as any other test here), nothing ever triggers another notification
|
|
// for the rest of the test. The event becomes retry-due almost immediately
|
|
// (notifyRetryAfter is tiny), so the *only* way it can be dispatched a
|
|
// second time is the poll timer in the select firing on its own.
|
|
func TestProcessEvents_PollFallbackPicksUpRetryDueEvents(t *testing.T) {
|
|
pool := testdb.Pool(t)
|
|
spy := newNotifySpy()
|
|
spy.setAutoAck(false)
|
|
m := NewMocks(testdb.Logger(), pool).
|
|
SetListener(spy).
|
|
WithNotifyRetryAfter(30 * time.Millisecond).
|
|
WithPollInterval(60 * time.Millisecond)
|
|
|
|
shopID := "test-shop-" + uuid.NewString()
|
|
cleanupShop(t, pool, shopID)
|
|
|
|
ctx, cancel := context.WithCancel(context.Background())
|
|
defer cancel()
|
|
|
|
errCh := make(chan error, 1)
|
|
go func() {
|
|
errCh <- m.ProcessEvents(ctx)
|
|
}()
|
|
|
|
waitReady(t, m, 5*time.Second)
|
|
|
|
insertRawAmazonEvent(t, pool, shopID, "evt-1")
|
|
|
|
// first dispatch, via the real NOTIFY.
|
|
spy.waitForCount(t, 1, 2*time.Second)
|
|
|
|
// second dispatch: nothing will notify again from here on, so this can
|
|
// only come from the poll branch of the select waking the loop up on
|
|
// its own and finding the event retry-due.
|
|
spy.waitForCount(t, 2, 3*time.Second)
|
|
|
|
cancel()
|
|
waitStopped(t, errCh, 5*time.Second)
|
|
}
|
|
|
|
// TestProcessEvents_ReactsToNotification drives the actual long-running
|
|
// loop: LISTEN registration, a real Postgres NOTIFY fired by the DB trigger
|
|
// on insert, WaitForNotification waking the loop, and the listener callback
|
|
// - the full stateful path, not just the deterministic batch-processing
|
|
// core covered above.
|
|
func TestProcessEvents_ReactsToNotification(t *testing.T) {
|
|
pool := testdb.Pool(t)
|
|
spy := newNotifySpy()
|
|
m := NewMocks(testdb.Logger(), pool).SetListener(spy)
|
|
|
|
shopID := "test-shop-" + uuid.NewString()
|
|
cleanupShop(t, pool, shopID)
|
|
|
|
ctx, cancel := context.WithCancel(context.Background())
|
|
defer cancel()
|
|
|
|
errCh := make(chan error, 1)
|
|
go func() {
|
|
errCh <- m.ProcessEvents(ctx)
|
|
}()
|
|
|
|
waitReady(t, m, 5*time.Second)
|
|
|
|
insertRawAmazonEvent(t, pool, shopID, "evt-1")
|
|
|
|
require.Eventually(t, func() bool {
|
|
processed, _ := queryIsProcessed(context.Background(), pool, shopID, "evt-1")
|
|
return processed
|
|
}, 5*time.Second, 20*time.Millisecond,
|
|
"event was not processed within 5s of insertion - the reactive LISTEN/NOTIFY wake-up did not fire "+
|
|
"(the 1-minute poll fallback would eventually catch it, but this test intentionally doesn't wait that long)")
|
|
|
|
spy.waitForCount(t, 1, 2*time.Second)
|
|
got := spy.eventsSnapshot()[0]
|
|
assert.Equal(t, shopID, got.StoreID, "listener notified with unexpected StoreID")
|
|
assert.Equal(t, "evt-1", got.EventID, "listener notified with unexpected EventID")
|
|
|
|
cancel()
|
|
waitStopped(t, errCh, 5*time.Second)
|
|
}
|
|
|
|
// TestProcessEvents_ShutsDownOnContextCancel checks the lifecycle in
|
|
// isolation, without depending on NOTIFY timing at all - a fast, low-flake
|
|
// guard against shutdown regressions (hangs, goroutine leaks) independent
|
|
// of whether the reactive path above is working.
|
|
func TestProcessEvents_ShutsDownOnContextCancel(t *testing.T) {
|
|
pool := testdb.Pool(t)
|
|
m := NewMocks(testdb.Logger(), pool)
|
|
|
|
ctx, cancel := context.WithCancel(context.Background())
|
|
|
|
errCh := make(chan error, 1)
|
|
go func() {
|
|
errCh <- m.ProcessEvents(ctx)
|
|
}()
|
|
|
|
waitReady(t, m, 5*time.Second)
|
|
cancel()
|
|
|
|
waitStopped(t, errCh, 5*time.Second)
|
|
}
|
|
|
|
// TestProcessEvents_ReconnectsAfterListenConnectionDrops is insight #4's
|
|
// fix: forcibly kills the real backend connection ProcessEvents is
|
|
// LISTEN-ing on (the same failure mode a dropped connection or a Postgres
|
|
// restart produces) and confirms it reconnects and keeps working on its
|
|
// own, rather than the error propagating out of ProcessEvents entirely.
|
|
func TestProcessEvents_ReconnectsAfterListenConnectionDrops(t *testing.T) {
|
|
pool := testdb.Pool(t)
|
|
spy := newNotifySpy()
|
|
m := NewMocks(testdb.Logger(), pool).SetListener(spy)
|
|
|
|
shopID := "test-shop-" + uuid.NewString()
|
|
cleanupShop(t, pool, shopID)
|
|
|
|
ctx, cancel := context.WithCancel(context.Background())
|
|
defer cancel()
|
|
|
|
errCh := make(chan error, 1)
|
|
go func() {
|
|
errCh <- m.ProcessEvents(ctx)
|
|
}()
|
|
|
|
waitReady(t, m, 5*time.Second)
|
|
|
|
terminateListenConnection(t, pool)
|
|
|
|
// ProcessEvents should still be running, just reconnecting (initial
|
|
// backoff is 1s) - it must not have returned because of this.
|
|
select {
|
|
case err := <-errCh:
|
|
require.Fail(t, "ProcessEvents() returned after its LISTEN connection was killed, want it to reconnect and keep running",
|
|
"err = %v", err)
|
|
case <-time.After(2 * time.Second):
|
|
}
|
|
|
|
insertRawAmazonEvent(t, pool, shopID, "evt-1")
|
|
|
|
require.Eventually(t, func() bool {
|
|
processed, _ := queryIsProcessed(context.Background(), pool, shopID, "evt-1")
|
|
return processed
|
|
}, 5*time.Second, 20*time.Millisecond,
|
|
"event was not processed within 5s of insertion after the LISTEN connection was forcibly dropped - "+
|
|
"reconnection did not restore the reactive path")
|
|
|
|
cancel()
|
|
waitStopped(t, errCh, 5*time.Second)
|
|
}
|