diff --git a/pkg/hold/pds/carstore_contention_test.go b/pkg/hold/pds/carstore_contention_test.go index feb734b..41c1e70 100644 --- a/pkg/hold/pds/carstore_contention_test.go +++ b/pkg/hold/pds/carstore_contention_test.go @@ -2,13 +2,14 @@ package pds import ( "context" - "fmt" + "database/sql" "path/filepath" "strings" - "sync" "testing" "time" + "github.com/ipfs/go-cid" + "atcr.io/pkg/atproto" holddb "atcr.io/pkg/hold/db" ) @@ -25,12 +26,62 @@ func isLockError(err error) bool { strings.Contains(s, "sqlite_busy") } -// TestHoldPDSConcurrentRepoWritesAndSideTable reproduces the production shape of -// the "database is locked on COMMIT" failure: repo record writes (which land in -// the carstore) racing against repo reads and against a second subsystem -// writing its own table in the same database file on a separate goroutine, the -// way the scan broadcaster now does. -func TestHoldPDSConcurrentRepoWritesAndSideTable(t *testing.T) { +// lockHoldDuration is how long the side pool holds the write lock. The repo +// write must take at least this long, which proves it waited rather than +// racing past an already-released lock, and it must finish well inside +// holddb.DefaultBusyTimeoutMs, which proves busy_timeout is what let it +// through. +const lockHoldDuration = 300 * time.Millisecond + +// holdSideWriteLock pins one connection from db, opens a write transaction on +// it and leaves it open, so every other writer on the file must wait. The +// returned release commits and hands the connection back. It is the pds-level +// twin of holdWriteLock in pkg/hold/db. +func holdSideWriteLock(t *testing.T, db *sql.DB) (release func()) { + t.Helper() + ctx := context.Background() + conn, err := db.Conn(ctx) + if err != nil { + t.Fatalf("pin connection: %v", err) + } + if _, err := conn.ExecContext(ctx, "CREATE TABLE IF NOT EXISTS scan_jobs (id TEXT PRIMARY KEY, state TEXT)"); err != nil { + t.Fatalf("create scan_jobs: %v", err) + } + // BEGIN IMMEDIATE takes the write lock now rather than at the first write, + // so the lock is held from the moment this returns. + if _, err := conn.ExecContext(ctx, "BEGIN IMMEDIATE"); err != nil { + t.Fatalf("begin immediate: %v", err) + } + if _, err := conn.ExecContext(ctx, "INSERT INTO scan_jobs (id, state) VALUES ('job-1', 'queued')"); err != nil { + t.Fatalf("insert under lock: %v", err) + } + return func() { + if _, err := conn.ExecContext(ctx, "COMMIT"); err != nil { + t.Errorf("commit lock holder: %v", err) + } + _ = conn.Close() + } +} + +// TestHoldPDSRepoWriteWaitsForSideTableLock pins the production shape of the +// "database is locked on COMMIT" failure fixed in c44a874: a repo record write, +// which lands in the carstore through the hold PDS's own pool, while a second +// subsystem holds the write lock on the same file through its own pool, the +// way the scan broadcaster does when it is not handed the shared pool. +// +// It tests the mechanism, not the weather. The earlier version hammered the +// file with four record writers, two read loops and a tight side-table loop +// and asserted that no lock error surfaced, which is a statement about how +// fast the CI disk is that day: it failed on a loaded runner on 2026-09-14 +// with the code correct, once a writer had been starved past the 5 s +// busy_timeout. Here the side pool deliberately holds the lock, the record +// write is shown to block rather than fail, and to succeed once the lock is +// released. The pool-level mechanism itself (busy_timeout on every connection +// of every pool, both topologies, plus a control that fails without it) is +// covered in pkg/hold/db; this test adds the repomgr path on top of it and the +// repo staying readable afterwards, which a failed COMMIT used to break with +// "loading root from blockstore: nothing to read". +func TestHoldPDSRepoWriteWaitsForSideTableLock(t *testing.T) { ctx := context.Background() tmpDir := t.TempDir() dbPath := filepath.Join(tmpDir, "pds.db") @@ -46,119 +97,62 @@ func TestHoldPDSConcurrentRepoWritesAndSideTable(t *testing.T) { t.Fatalf("InitNewActor failed: %v", err) } - // A second subsystem with its own pool on the same file, as the scan and - // event broadcasters have when they are not handed the shared pool. side, err := holddb.OpenLocalDB(filepath.Join(dbPath, "db.sqlite3")) if err != nil { t.Fatalf("open side pool: %v", err) } defer side.Close() - if _, err := side.Exec("CREATE TABLE IF NOT EXISTS scan_jobs (id TEXT PRIMARY KEY, state TEXT)"); err != nil { - t.Fatalf("create scan_jobs: %v", err) - } - var mu sync.Mutex - var errs []error - record := func(err error) { - if err == nil { - return - } - mu.Lock() - errs = append(errs, err) - mu.Unlock() - } + const rkey = "layer-under-lock" + rec := atproto.NewLayerRecord( + "sha256:"+strings.Repeat("ab", 32), + 1024, + "application/vnd.oci.image.layer.v1.tar+gzip", + "did:plc:testuser", + "at://did:plc:testuser/io.atcr.manifest/abc", + ) - const writers = 4 - const iters = 15 + release := holdSideWriteLock(t, side) - var writeWG, loopWG sync.WaitGroup - stop := make(chan struct{}) - - // Repo record writers. - for w := range writers { - writeWG.Add(1) - go func(w int) { - defer writeWG.Done() - for i := range iters { - rkey := fmt.Sprintf("w%d-layer-%03d", w, i) - rec := atproto.NewLayerRecord( - fmt.Sprintf("sha256:%064x", w*1000+i), - int64(1024+i), - "application/vnd.oci.image.layer.v1.tar+gzip", - "did:plc:testuser", - "at://did:plc:testuser/io.atcr.manifest/abc", - ) - if _, _, err := p.repomgr.PutRecord(ctx, p.uid, atproto.LayerCollection, rkey, rec); err != nil { - record(fmt.Errorf("PutRecord %s: %w", rkey, err)) - return - } - } - }(w) - } - - // Repo readers, hitting the carstore's read transactions concurrently. - for range 2 { - loopWG.Go(func() { - for { - select { - case <-stop: - return - default: - } - if _, err := p.repomgr.GetRepoRoot(ctx, p.uid); err != nil { - record(fmt.Errorf("GetRepoRoot: %w", err)) - return - } - } - }) - } - - // The side subsystem, writing its own table on its own goroutine. - loopWG.Go(func() { - for i := 0; ; i++ { - select { - case <-stop: - return - default: - } - _, err := side.ExecContext(ctx, - "INSERT INTO scan_jobs (id, state) VALUES (?, ?) ON CONFLICT (id) DO UPDATE SET state=excluded.state", - fmt.Sprintf("job-%d", i), "queued") - if err != nil { - record(fmt.Errorf("scan_jobs insert: %w", err)) - return - } - } - }) - - writersDone := make(chan struct{}) + done := make(chan error, 1) + start := time.Now() go func() { - writeWG.Wait() - close(writersDone) + _, _, err := p.repomgr.PutRecord(ctx, p.uid, atproto.LayerCollection, rkey, rec) + done <- err }() select { - case <-writersDone: - case <-time.After(60 * time.Second): - close(stop) - loopWG.Wait() - t.Fatal("contention test timed out waiting for writers") - } - close(stop) - loopWG.Wait() - - mu.Lock() - defer mu.Unlock() - for _, err := range errs { - if isLockError(err) { - t.Fatalf("hold PDS write hit a lock error: %v", err) + case err := <-done: + // Finished while the lock was still held: either it failed (the + // regression) or it never contended for the lock (a broken test), + // and both are reported. + if err != nil { + if isLockError(err) { + t.Fatalf("repo write failed instead of waiting for the write lock: %v", err) + } + t.Fatalf("repo write failed: %v", err) } - t.Fatalf("hold PDS write failed: %v", err) + t.Fatalf("repo write completed in %s while the side pool held the write lock; the test is not contending", time.Since(start)) + case <-time.After(lockHoldDuration): + } + + release() + select { + case err := <-done: + if err != nil { + t.Fatalf("repo write failed after the lock was released: %v", err) + } + case <-time.After(time.Duration(holddb.DefaultBusyTimeoutMs) * time.Millisecond): + t.Fatalf("repo write still blocked %dms after the lock was released", holddb.DefaultBusyTimeoutMs) + } + if waited := time.Since(start); waited < lockHoldDuration { + t.Fatalf("repo write took %s, less than the %s the lock was held", waited, lockHoldDuration) } - // The repo must still be readable after all that: a failed COMMIT used to - // leave the next read reporting "loading root from blockstore: nothing to read". if _, err := p.repomgr.GetRepoRoot(ctx, p.uid); err != nil { - t.Fatalf("repo unreadable after contention: %v", err) + t.Fatalf("repo unreadable after the contended write: %v", err) + } + if _, _, err := p.repomgr.GetRecord(ctx, p.uid, atproto.LayerCollection, rkey, cid.Undef); err != nil { + t.Fatalf("record written under contention is unreadable: %v", err) } }