Files
minstrel/internal/gc/worker_test.go
T
bvandeusen 258bc1f75c
test-go / test (push) Successful in 29s
test-go / integration (push) Failing after 11m57s
feat(server): drift audit batch 7 — periodic GC worker for 5 lifecycle gaps
New `internal/gc` package with a single Worker that runs all five
lifecycle / retention sweeps from the 2026-06-02 drift audit on a
1-hour tick. Each sweep is small, idempotent (re-running on
already-clean rows is a no-op), and logs its affected-row count.

Sweeps (Scribe parent #552):

- **#566** GcCloseStalePlayEvents — play_events rows opened > 24h
  ago that never got a play_ended (client crash, network drop).
  Synthesizes ended_at from duration_played_ms when known, falls
  back to now() so the row stops looking "open" to downstream
  filters (ended_at IS NULL).

- **#565** GcClosePlaySessionsWithNoRecentEvents — play_sessions
  with last_event_at older than 6h get ended_at = last_event_at
  ("user moved on"); empty sessions older than 1h get closed
  too (stale handshakes from clients that never recorded a play).
  The audit caught that the column was added but never populated
  by any writer — every session row was "open" forever, breaking
  downstream dedup queries that assume closed semantics.

- **#567** GcExpireScrobbleQueueFailedRows — drops scrobble_queue
  rows in status='failed' older than 14 days. The worker stops
  retrying after maxAttempts so these otherwise accumulate
  forever on a persistent ListenBrainz outage / revoked token.

- **#574** GcResetStuckSystemPlaylistRuns — flips
  system_playlist_runs.in_flight back to false on rows whose
  last_run_at is older than 10 minutes. Catches goroutine-panic
  wedges where the generator died between SET in_flight=true and
  SET in_flight=false; the duplicate-prevention check refuses to
  start a fresh regen while in_flight, so a stuck row would
  otherwise deadlock all future regens for that user. Records
  "stuck-row auto-reset by gc" in last_error so the operator can
  tell auto-reset from a recent real failure.

- **#575** GcDeleteExpiredPasswordResets — deletes expired
  password_resets rows. Unused expired rows go after a 1h grace
  (gives the operator time to debug an active reset attempt);
  used rows are kept 7 days for audit.

Wiring:
- main.go `go gcWorker.Run(ctx)` alongside the other periodic
  workers (scrobble, similarity, lidarr).
- tickOnce fires once at start so a freshly-deployed server does
  its initial sweep without waiting a full tick, matching the
  scrobble worker pattern.
- Errors per sweep are logged but do NOT abort the remaining
  ones — a transient pgx error from one query shouldn't prevent
  the others from running.

Tests:
- 4 integration tests, one per UPDATE/DELETE sweep, that seed
  rows-to-sweep + rows-to-leave-alone and assert the right rows
  changed state. Skip unless MINSTREL_TEST_DATABASE_URL is set
  (mirrors the api package pattern).
- Empty-tables no-op smoke test.
- Run() cancellation honoured (no spinning goroutine at
  test-runner exit).

That's all five remaining server-side lifecycle findings from the
audit. The Android LOCAL_USER_ID hardcode (#576) is a separate
refactor that needs auth-store wiring and stays in the queue.
2026-06-02 18:32:22 -04:00

318 lines
10 KiB
Go

package gc
import (
"context"
"io"
"log/slog"
"os"
"testing"
"time"
"github.com/jackc/pgx/v5/pgtype"
"github.com/jackc/pgx/v5/pgxpool"
"git.fabledsword.com/bvandeusen/minstrel/internal/db"
"git.fabledsword.com/bvandeusen/minstrel/internal/db/dbq"
"git.fabledsword.com/bvandeusen/minstrel/internal/dbtest"
)
// testWorker constructs a Worker against MINSTREL_TEST_DATABASE_URL.
// Mirrors the api package's testHandlers pattern — skip when not in
// integration mode, migrate + reset, return the pool for the caller
// to seed.
func testWorker(t *testing.T) (*Worker, *pgxpool.Pool) {
t.Helper()
if testing.Short() {
t.Skip("skipping gc integration in -short mode")
}
dsn := os.Getenv("MINSTREL_TEST_DATABASE_URL")
if dsn == "" {
t.Skip("MINSTREL_TEST_DATABASE_URL not set")
}
logger := slog.New(slog.NewTextHandler(io.Discard, nil))
if err := db.Migrate(dsn, logger); err != nil {
t.Fatalf("migrate: %v", err)
}
pool, err := pgxpool.New(context.Background(), dsn)
if err != nil {
t.Fatalf("pool: %v", err)
}
t.Cleanup(pool.Close)
dbtest.ResetDB(t, pool)
return NewWorker(pool, logger), pool
}
// seedUser creates a minimal user row for tests that need play_events
// / play_sessions / scrobble_queue rows. Username is prefixed so
// dbtest.ResetDB cleans up between runs.
func seedUser(t *testing.T, pool *pgxpool.Pool, name string) pgtype.UUID {
t.Helper()
u, err := dbq.New(pool).CreateUser(context.Background(), dbq.CreateUserParams{
Username: dbtest.TestUserPrefix + name,
PasswordHash: "test-hash",
ApiToken: "test-token-" + name,
IsAdmin: false,
})
if err != nil {
t.Fatalf("CreateUser: %v", err)
}
return u.ID
}
func TestGcCloseStalePlayEvents_ClosesOnly24hOldRows(t *testing.T) {
w, pool := testWorker(t)
ctx := context.Background()
userID := seedUser(t, pool, "alice")
// Need a track + session to satisfy FKs on play_events.
var trackID pgtype.UUID
if err := pool.QueryRow(ctx, `
INSERT INTO artists (name) VALUES ('A') RETURNING id
`).Scan(new(pgtype.UUID)); err != nil {
t.Fatalf("seed artist row: %v", err)
}
// Get the just-inserted artist id.
var artistID pgtype.UUID
if err := pool.QueryRow(ctx, `SELECT id FROM artists WHERE name = 'A'`).Scan(&artistID); err != nil {
t.Fatalf("read artist: %v", err)
}
var albumID pgtype.UUID
if err := pool.QueryRow(ctx, `
INSERT INTO albums (artist_id, title, sort_title) VALUES ($1, 'X', 'X') RETURNING id
`, artistID).Scan(&albumID); err != nil {
t.Fatalf("seed album: %v", err)
}
if err := pool.QueryRow(ctx, `
INSERT INTO tracks (album_id, artist_id, title, file_path, duration_ms)
VALUES ($1, $2, 'T', '/x.mp3', 180000) RETURNING id
`, albumID, artistID).Scan(&trackID); err != nil {
t.Fatalf("seed track: %v", err)
}
var sessionID pgtype.UUID
if err := pool.QueryRow(ctx, `
INSERT INTO play_sessions (user_id, started_at, last_event_at)
VALUES ($1, now() - interval '2 hours', now()) RETURNING id
`, userID).Scan(&sessionID); err != nil {
t.Fatalf("seed session: %v", err)
}
// Stale row (25h old, no ended_at) — should be closed.
if _, err := pool.Exec(ctx, `
INSERT INTO play_events (user_id, track_id, session_id, started_at)
VALUES ($1, $2, $3, now() - interval '25 hours')
`, userID, trackID, sessionID); err != nil {
t.Fatalf("seed stale event: %v", err)
}
// Fresh row (1h old, no ended_at) — should be left alone.
if _, err := pool.Exec(ctx, `
INSERT INTO play_events (user_id, track_id, session_id, started_at)
VALUES ($1, $2, $3, now() - interval '1 hour')
`, userID, trackID, sessionID); err != nil {
t.Fatalf("seed fresh event: %v", err)
}
w.tickOnce(ctx)
var closedStale, openFresh bool
if err := pool.QueryRow(ctx, `
SELECT EXISTS(SELECT 1 FROM play_events
WHERE started_at < now() - interval '24 hours'
AND ended_at IS NOT NULL)
`).Scan(&closedStale); err != nil {
t.Fatalf("check stale: %v", err)
}
if err := pool.QueryRow(ctx, `
SELECT EXISTS(SELECT 1 FROM play_events
WHERE started_at > now() - interval '2 hours'
AND ended_at IS NULL)
`).Scan(&openFresh); err != nil {
t.Fatalf("check fresh: %v", err)
}
if !closedStale {
t.Errorf("stale play_events row not closed")
}
if !openFresh {
t.Errorf("fresh play_events row was closed (should be left alone)")
}
}
func TestGcClosePlaySessions_ClosesIdleAndEmptyStarvedSessions(t *testing.T) {
w, pool := testWorker(t)
ctx := context.Background()
userID := seedUser(t, pool, "bob")
// Idle session — has events, last_event_at 8h ago.
if _, err := pool.Exec(ctx, `
INSERT INTO play_sessions (user_id, started_at, last_event_at, track_count)
VALUES ($1, now() - interval '8 hours', now() - interval '8 hours', 5)
`, userID); err != nil {
t.Fatalf("seed idle session: %v", err)
}
// Empty-starved session — no events, started 2h ago.
if _, err := pool.Exec(ctx, `
INSERT INTO play_sessions (user_id, started_at, last_event_at, track_count)
VALUES ($1, now() - interval '2 hours', now() - interval '2 hours', 0)
`, userID); err != nil {
t.Fatalf("seed empty session: %v", err)
}
// Active session — recent last_event_at, has events.
if _, err := pool.Exec(ctx, `
INSERT INTO play_sessions (user_id, started_at, last_event_at, track_count)
VALUES ($1, now() - interval '30 minutes', now() - interval '5 minutes', 3)
`, userID); err != nil {
t.Fatalf("seed active session: %v", err)
}
w.tickOnce(ctx)
var closedCount, openCount int
if err := pool.QueryRow(ctx, `
SELECT count(*) FROM play_sessions
WHERE user_id = $1 AND ended_at IS NOT NULL
`, userID).Scan(&closedCount); err != nil {
t.Fatalf("count closed: %v", err)
}
if err := pool.QueryRow(ctx, `
SELECT count(*) FROM play_sessions
WHERE user_id = $1 AND ended_at IS NULL
`, userID).Scan(&openCount); err != nil {
t.Fatalf("count open: %v", err)
}
if closedCount != 2 {
t.Errorf("closed sessions = %d, want 2 (idle + empty-starved)", closedCount)
}
if openCount != 1 {
t.Errorf("open sessions = %d, want 1 (active)", openCount)
}
}
func TestGcResetStuckSystemPlaylistRuns(t *testing.T) {
w, pool := testWorker(t)
ctx := context.Background()
stuckUser := seedUser(t, pool, "stuck")
activeUser := seedUser(t, pool, "active")
// Stuck row: in_flight, last_run_at 30 min ago.
if _, err := pool.Exec(ctx, `
INSERT INTO system_playlist_runs (user_id, last_run_at, in_flight)
VALUES ($1, now() - interval '30 minutes', true)
`, stuckUser); err != nil {
t.Fatalf("seed stuck run: %v", err)
}
// Active row: in_flight, last_run_at 2 min ago — still legitimate.
if _, err := pool.Exec(ctx, `
INSERT INTO system_playlist_runs (user_id, last_run_at, in_flight)
VALUES ($1, now() - interval '2 minutes', true)
`, activeUser); err != nil {
t.Fatalf("seed active run: %v", err)
}
w.tickOnce(ctx)
var stuckFlight, activeFlight bool
if err := pool.QueryRow(ctx, `
SELECT in_flight FROM system_playlist_runs WHERE user_id = $1
`, stuckUser).Scan(&stuckFlight); err != nil {
t.Fatalf("read stuck row: %v", err)
}
if err := pool.QueryRow(ctx, `
SELECT in_flight FROM system_playlist_runs WHERE user_id = $1
`, activeUser).Scan(&activeFlight); err != nil {
t.Fatalf("read active row: %v", err)
}
if stuckFlight {
t.Errorf("stuck row still in_flight after sweep")
}
if !activeFlight {
t.Errorf("active row was reset (should be left alone — only 2 min old)")
}
}
func TestGcDeleteExpiredPasswordResets(t *testing.T) {
w, pool := testWorker(t)
ctx := context.Background()
userID := seedUser(t, pool, "pwd")
// Expired-unused (> 1h past expires_at) — should delete.
if _, err := pool.Exec(ctx, `
INSERT INTO password_resets (token, user_id, expires_at)
VALUES ('expired-old', $1, now() - interval '2 hours')
`, userID); err != nil {
t.Fatalf("seed expired: %v", err)
}
// Used (> 7 days past used_at) — should delete.
if _, err := pool.Exec(ctx, `
INSERT INTO password_resets (token, user_id, expires_at, used_at)
VALUES ('used-old', $1, now() - interval '8 days', now() - interval '8 days')
`, userID); err != nil {
t.Fatalf("seed used-old: %v", err)
}
// Active (expires in future) — should survive.
if _, err := pool.Exec(ctx, `
INSERT INTO password_resets (token, user_id, expires_at)
VALUES ('active', $1, now() + interval '1 hour')
`, userID); err != nil {
t.Fatalf("seed active: %v", err)
}
// Recently used (< 7 days) — should survive for audit.
if _, err := pool.Exec(ctx, `
INSERT INTO password_resets (token, user_id, expires_at, used_at)
VALUES ('used-recent', $1, now() - interval '1 hour', now() - interval '1 day')
`, userID); err != nil {
t.Fatalf("seed used-recent: %v", err)
}
w.tickOnce(ctx)
var remaining []string
rows, err := pool.Query(ctx, `SELECT token FROM password_resets WHERE user_id = $1`, userID)
if err != nil {
t.Fatalf("list remaining: %v", err)
}
defer rows.Close()
for rows.Next() {
var tok string
if err := rows.Scan(&tok); err != nil {
t.Fatalf("scan: %v", err)
}
remaining = append(remaining, tok)
}
wantSet := map[string]bool{"active": true, "used-recent": true}
if len(remaining) != len(wantSet) {
t.Errorf("remaining tokens = %v, want %v", remaining, []string{"active", "used-recent"})
}
for _, tok := range remaining {
if !wantSet[tok] {
t.Errorf("unexpected surviving token %q", tok)
}
}
}
// Verifies tickOnce doesn't blow up when the tables are completely
// empty — sweeps just no-op. Regression guard against an EXEC vs
// QUERY-row-count mismatch failing on zero rows.
func TestGcTickOnce_NoOpOnEmptyTables(t *testing.T) {
w, _ := testWorker(t)
w.tickOnce(context.Background())
}
// Sanity check on the Run() loop's cancel behaviour — we don't want
// to leave a goroutine spinning at test-runner exit. 10ms tick with
// an immediate cancel should return promptly.
func TestGcRun_HonoursContextCancel(t *testing.T) {
w, _ := testWorker(t)
w.tick = 10 * time.Millisecond
ctx, cancel := context.WithCancel(context.Background())
done := make(chan struct{})
go func() {
w.Run(ctx)
close(done)
}()
cancel()
select {
case <-done:
case <-time.After(2 * time.Second):
t.Fatal("Run did not return after cancel")
}
}