diff --git a/docs/evals/2026-08-07-store-connection-cap.md b/docs/evals/2026-08-07-store-connection-cap.md new file mode 100644 index 0000000..9c0b80c --- /dev/null +++ b/docs/evals/2026-08-07-store-connection-cap.md @@ -0,0 +1,69 @@ +# Does one sqlite connection make reads queue? No (V-642) + +Measured 07-08-2026 at `7b507de`, on homesrv. The harness is +`internal/store/conncap_test.go`. It stays in the repo, because this claim gets +re-argued and the numbers should be re-runnable rather than quoted. + +`internal/store/store.go` opens the database with `SetMaxOpenConns(1)`, while +`schema.sql` sets `journal_mode=WAL`. WAL exists to let readers run beside one +writer, so the cap gives up the thing the journal mode was chosen for. The +question was whether that costs anything. + +## What was measured + +A fixed two-second window. One writer calling `SetValue` paced at 2ms, and a +reader loop calling `RecentFacts(50)` over 500 seeded rows as fast as it can. +Same schema, same modernc driver, same machine, three runs per cap. + +The window is wall-clock rather than a read count on purpose. A first version ran +a fixed 300 reads. That finished sooner at the higher cap, so it received fewer +writes, and two runs that did different work cannot be compared. + +| cap | reads | writes | p50 | p95 | max | +|---|---|---|---|---|---| +| 1 | ~3050 | ~760 | 594µs | 900µs | 16-19ms | +| 4 | ~3600 | ~340 | 525µs | 710µs | 1-2ms | + +## What it says + +**Reads do not queue behind writes.** Four connections buy about 70µs at p50. A +turn spends 1.19s in the resident model. The tail does improve, from 19ms to 2ms, +and 19ms is still not a figure anyone notices in a spoken reply. + +**Write throughput more than halves at the higher cap**, 760 writes against 340. +inference, not measured directly: at one connection the reader and the writer take +turns with no lock contention. At four the writer contends for the WAL write lock +with a live reader. Whatever the mechanism, the trade runs the opposite way from +the one the task expected. + +**The cap was not the source of the 2.7s router figure.** CLAUDE.md records that +figure as contention rather than the model. This task was a candidate for where +that contention came from. A 19ms worst case cannot produce it. That line of +enquiry is closed. + +**One transaction is what the cap cannot survive.** With a read-only transaction +open, a second read at cap 1 never completes. The harness gave it two seconds and +got `context deadline exceeded`. The same read at cap 4 took 1ms. The transaction +holds the only connection, so this is not a slow read, it is a stalled database. + +## What was done + +The cap stays at 1. The reason is now written where the cap is set, rather than +inferred from a four-word comment. + +`Store.DB` was deleted. It handed out exactly the read-only transaction measured +above. It had been there since the initial commit with no production caller, and +its doc comment described a loop that never materialised. Its one user was a test +helper reading `delivery_attempts` by raw SQL. `ListDeliveryAttempts` has covered +that since V-390, and the helper now goes through the reader. + +So the hazard is gone by construction, not by documentation. +`TestConnCap_ReadBlocksBehindOpenSnapshot` is the standing measurement of what +re-adding the seam would cost. + +## Not answered + +Whether reads queue on the deployed box under real load, as opposed to a +synthetic loop. The harness writes and reads one table. Digestion reads four and +embeds while it does. The finding that closes this task is the transaction stall, +which is structural and does not depend on load. diff --git a/internal/delivery/durability_test.go b/internal/delivery/durability_test.go index 4f015e7..5f3e00b 100644 --- a/internal/delivery/durability_test.go +++ b/internal/delivery/durability_test.go @@ -94,20 +94,22 @@ func openTestStore(t *testing.T) *store.Store { // attemptStatus reads one attempt row back. Returns ok=false when the row is // gone, which would itself be a broken promise (a dropped attempt). +// +// It goes through ListDeliveryAttempts rather than raw SQL. This helper used to +// reach past the store into store.DB, which was the tell that the outbox was +// write-only; the reader landed in V-390 and this caller was not moved over. func attemptStatus(t *testing.T, st *store.Store, id int64) (status string, completed bool, ok bool) { t.Helper() - tx, err := st.DB(context.Background()) + attempts, err := st.ListDeliveryAttempts(context.Background(), "", 200) if err != nil { - t.Fatalf("read tx: %v", err) + t.Fatalf("ListDeliveryAttempts: %v", err) } - defer func() { _ = tx.Rollback() }() - var completedTS *int64 - err = tx.QueryRowContext(context.Background(), - `SELECT status, completed_ts FROM delivery_attempts WHERE id = ?`, id).Scan(&status, &completedTS) - if err != nil { - return "", false, false + for _, a := range attempts { + if a.ID == id { + return a.Status, a.HasComplete, true + } } - return status, completedTS != nil, true + return "", false, false } // TestCrashBetweenBeginAndCompleteBecomesUnknown — simulate the crash window: diff --git a/internal/ipc/server.go b/internal/ipc/server.go index 1f1a608..c07320b 100644 --- a/internal/ipc/server.go +++ b/internal/ipc/server.go @@ -17,9 +17,11 @@ import ( // Server — the core side of the boundary. Listens on a unix domain socket, // accepts module connections, frames requests to a CoreAPI and responses back. // One Server per daemon process; concurrent connections are handled in their -// own goroutine but share the single CoreAPI (and therefore the single store -// writer — store is single-connection, SetMaxOpenConns(1), so serialization is -// already guaranteed at the db; the Server adds no locking of its own). +// own goroutine but share the single CoreAPI, and so the single store writer. +// The store opens at SetMaxOpenConns(1), so serialisation is already guaranteed +// at the database and the Server adds no locking of its own. That cap is an +// invariant this comment depends on, measured and kept on 07-08-2026 (V-642, +// docs/evals/2026-08-07-store-connection-cap.md). type Server struct { api atomic.Value // stores CoreAPI path string diff --git a/internal/store/conncap_test.go b/internal/store/conncap_test.go new file mode 100644 index 0000000..62d18ff --- /dev/null +++ b/internal/store/conncap_test.go @@ -0,0 +1,154 @@ +package store + +import ( + "context" + "database/sql" + "fmt" + "path/filepath" + "sort" + "sync" + "sync/atomic" + "testing" + "time" +) + +// conncap_test.go measures whether a read queues behind a write at +// SetMaxOpenConns(1), which is what openAt sets (V-642). It is a measurement +// harness, not an assertion: the numbers it prints are the evidence, and the +// decision to move the cap or leave it belongs in docs/evals. +// +// Run it with -v, and note that it is skipped under -short because it spends +// seconds on purpose. + +// openCapped opens a plaintext store at the given connection cap. In-package, +// so it can reach the handle openAt caps at 1. +func openCapped(t *testing.T, cap int) *Store { + t.Helper() + path := filepath.Join(t.TempDir(), "cap.db") + db, err := openAt(context.Background(), path) + if err != nil { + t.Fatalf("openAt: %v", err) + } + db.SetMaxOpenConns(cap) + s := &Store{db: db} + t.Cleanup(func() { _ = s.Close() }) + return s +} + +func percentile(d []time.Duration, p float64) time.Duration { + if len(d) == 0 { + return 0 + } + i := int(float64(len(d)-1) * p) + return d[i] +} + +// seedFacts writes n facts so a read has rows to decode. +func seedFacts(t *testing.T, s *Store, n int) { + t.Helper() + ctx := context.Background() + now := time.Now().UTC() + for i := 0; i < n; i++ { + key := fmt.Sprintf("seed_%d", i) + if _, err := s.SetValue(ctx, KindSelf, key, "tap:test", + map[string]int{"ml": i}, now.Add(time.Duration(i)*time.Millisecond)); err != nil { + t.Fatalf("seed %d: %v", i, err) + } + } +} + +// measureReadsUnderWrites reports read latency percentiles while a writer +// writes at a fixed pace. The pace matters: an unpaced writer completes a +// different number of writes at each cap, because at a higher cap it competes +// with the readers for the write lock instead of taking turns on one +// connection. Two runs that did different work cannot be compared. +// It runs for a fixed wall-clock window rather than a fixed read count, so the +// paced writer does the same work at every cap. Tying the window to a read +// count made the faster configuration receive fewer writes. +func measureReadsUnderWrites(t *testing.T, s *Store, window, pace time.Duration) []time.Duration { + t.Helper() + ctx := context.Background() + + var stop atomic.Bool + var writes atomic.Int64 + var wg sync.WaitGroup + wg.Add(1) + go func() { + defer wg.Done() + now := time.Now().UTC() + for i := 0; !stop.Load(); i++ { + key := fmt.Sprintf("hot_%d", i%16) + if _, err := s.SetValue(ctx, KindSelf, key, "tap:test", + map[string]int{"n": i}, now.Add(time.Duration(i)*time.Millisecond)); err != nil { + t.Errorf("write: %v", err) + return + } + writes.Add(1) + time.Sleep(pace) + } + }() + + var lat []time.Duration + deadline := time.Now().Add(window) + for time.Now().Before(deadline) { + start := time.Now() + if _, err := s.RecentFacts(ctx, 50); err != nil { + t.Fatalf("RecentFacts: %v", err) + } + lat = append(lat, time.Since(start)) + } + stop.Store(true) + wg.Wait() + t.Logf("in %v: %d reads, %d writes", window, len(lat), writes.Load()) + + sort.Slice(lat, func(i, j int) bool { return lat[i] < lat[j] }) + return lat +} + +// TestConnCap_ReadLatencyUnderWrites is the V-642 measurement: read latency at +// cap 1 against cap 4, same workload, same schema, same driver. +func TestConnCap_ReadLatencyUnderWrites(t *testing.T) { + if testing.Short() { + t.Skip("measurement harness; runs for seconds") + } + for _, cap := range []int{1, 4} { + t.Run(fmt.Sprintf("cap=%d", cap), func(t *testing.T) { + s := openCapped(t, cap) + seedFacts(t, s, 500) + lat := measureReadsUnderWrites(t, s, 2*time.Second, 2*time.Millisecond) + t.Logf("cap=%d reads=%d p50=%v p95=%v max=%v", + cap, len(lat), percentile(lat, 0.50), percentile(lat, 0.95), lat[len(lat)-1]) + }) + } +} + +// TestConnCap_ReadBlocksBehindOpenSnapshot is the sharper claim: at cap 1 an +// open read-only transaction holds the only connection, so an unrelated read +// cannot proceed until it commits. This is why the store exposes no way to +// begin one — `Store.DB` used to, and was deleted in V-642 with no caller. The +// test stays as the reason, so re-adding that seam fails a measurement rather +// than shipping a stall. +func TestConnCap_ReadBlocksBehindOpenSnapshot(t *testing.T) { + if testing.Short() { + t.Skip("measurement harness; waits on a timeout") + } + for _, cap := range []int{1, 4} { + t.Run(fmt.Sprintf("cap=%d", cap), func(t *testing.T) { + s := openCapped(t, cap) + seedFacts(t, s, 50) + + tx, err := s.db.BeginTx(context.Background(), &sql.TxOptions{ReadOnly: true}) + if err != nil { + t.Fatalf("BeginTx: %v", err) + } + defer func() { _ = tx.Rollback() }() + + ctx, cancel := context.WithTimeout(context.Background(), 2*time.Second) + defer cancel() + start := time.Now() + _, err = s.RecentFacts(ctx, 10) + t.Logf("cap=%d read alongside an open snapshot: waited %v, err=%v", + cap, time.Since(start).Round(time.Millisecond), err) + }) + } +} diff --git a/internal/store/store.go b/internal/store/store.go index 757c42e..74ed592 100644 --- a/internal/store/store.go +++ b/internal/store/store.go @@ -95,7 +95,20 @@ func openAt(ctx context.Context, path string) (*sql.DB, error) { if err != nil { return nil, fmt.Errorf("open %s: %w", path, err) } - // single writer expected; the daemon is the only process touching the db. + // One connection, so every statement is serialised at the database and no + // caller above needs a lock of its own. internal/ipc's Server relies on + // exactly this, which is why the cap is an invariant rather than a tuning + // knob: raising it moves the serialisation guarantee somewhere it is not + // written down. + // + // Measured on 07-08-2026 (V-642, docs/evals/2026-08-07-store-connection-cap.md). + // WAL exists to let readers run beside one writer, and the cap gives that + // up, but reads do not queue: p50 594µs against 525µs at a cap of four, + // while write throughput more than halves. The one thing the cap cannot + // survive is a long-lived transaction, which holds the only connection and + // stalls every read for its lifetime. So the store begins none, and + // TestConnCap_ReadBlocksBehindOpenSnapshot is the standing measurement of + // what re-adding one would cost. db.SetMaxOpenConns(1) if _, err := db.ExecContext(ctx, schemaSQL); err != nil { if closeErr := db.Close(); closeErr != nil { @@ -133,13 +146,6 @@ func (s *Store) Close() error { return s.enc.closeAndSeal(s.db) } -// DB exposes the underlying handle for internal read-only snapshots. -// Used by the loop to take a consistent read under a single transaction. -// Modules never receive this handle — core mediates. -func (s *Store) DB(ctx context.Context) (*sql.Tx, error) { - return s.db.BeginTx(ctx, &sql.TxOptions{ReadOnly: true}) -} - var ( // ErrNoFact — no non-voided row exists for this key. ErrNoFact = errors.New("store: no fact for key")