| 1 | package store_test |
| 2 | |
| 3 | import ( |
| 4 | "context" |
| 5 | "os" |
| 6 | "path/filepath" |
| 7 | "strconv" |
| 8 | "testing" |
| 9 | "time" |
| 10 | |
| 11 | rdb "amadan.net/rastrillo/rastrillo/db" |
| 12 | "amadan.net/rastrillo/rastrillo/migrate" |
| 13 | "gorm.io/gorm" |
| 14 | |
| 15 | "amadan.net/oficina/sheets/internal/sheets" |
| 16 | "amadan.net/oficina/sheets/internal/sheets/calc" |
| 17 | "amadan.net/oficina/sheets/internal/sheets/seal" |
| 18 | "amadan.net/oficina/sheets/internal/sheets/store" |
| 19 | ) |
| 20 | |
| 21 | // TestBlankRecoveryBench reproduces, on demand, the two headline timings |
| 22 | // batching-report.md's "Measurements" section reports for this task: the |
| 23 | // setBlank/markDirty lock-hold time and store.Open's crash-recovery pass, both |
| 24 | // measured over the FIXED code (this file never touches, reverts or |
| 25 | // otherwise reconstructs the pre-fix path — see handle_batch.go for what |
| 26 | // changed). |
| 27 | // |
| 28 | // RECORDED FIGURES (batching-report.md), for comparison against a run of |
| 29 | // this test: |
| 30 | // |
| 31 | // N = 199,999 dependents (calc.MaxCellsPerTab - 1, the real ceiling) |
| 32 | // setBlank (h.mu hold, whole Set call): 2.779s |
| 33 | // store.Open (crash-recovery pass over the N stale dependents): 8.818s |
| 34 | // |
| 35 | // Machine those were measured on: whatever ran the original task session |
| 36 | // — a single unspecified development machine, WAL-mode SQLite via the |
| 37 | // project's real rdb.Open + migrate.Apply boot path (not :memory:), with |
| 38 | // (per the report) "other unrelated background jobs contending for disk" |
| 39 | // noted as a caveat on a related run. No CPU/disk model, core count or |
| 40 | // load average was recorded, which is itself a gap: a wall-clock number |
| 41 | // with no machine description is only reproducible in shape, not in |
| 42 | // absolute value. Treat the figures above as an order-of-magnitude |
| 43 | // target, not a number this test should assert against — a wall-clock |
| 44 | // benchmark that fails CI because a shared runner was slow that day is a |
| 45 | // worse outcome than a benchmark nobody trusts, so this is a Test that |
| 46 | // logs, not a Test that fails, on timing. |
| 47 | // |
| 48 | // WHAT IT MEASURES: |
| 49 | // - Phase 1 ("setBlank"): one store.Handle.Set call blanking a feeder cell |
| 50 | // that N dependent cells reference as "=A1*2", timed end to end. Set |
| 51 | // holds h.mu for its entire body (handle_set.go), so this is the |
| 52 | // real exclusive-lock hold time any other Value/Set call on this tab |
| 53 | // would have queued behind. At N above calc.MaxDirtyPerPass (5,000) |
| 54 | // — true by default here, see below — setBlank's withinCap is false, |
| 55 | // so this call does ONLY markDirty's batched marking; the recompute |
| 56 | // and persistTouched steps do not run inside it. That is what makes |
| 57 | // this a clean read on markDirty specifically at the real ceiling, |
| 58 | // matching how the recorded 2.779s figure above was measured. |
| 59 | // - Phase 2 ("store.Open"): the very next store.Open on the same tab, timed end to |
| 60 | // end. Phase 1 left every dependent's InputVersion ahead of its own |
| 61 | // CacheVersion (markDirty's job), so buildHandle's stale scan |
| 62 | // (handle_open.go) finds all N of them and this store.Open drives |
| 63 | // recoverStale (handle_batch.go) — the batched crash-recovery pass — |
| 64 | // over the whole set before returning. |
| 65 | // |
| 66 | // GATING: skipped unless RUN_BLANK_RECOVERY_BENCH is set, and always |
| 67 | // skipped under -short. This is a Test, not a Benchmark* function, |
| 68 | // specifically so its two phases can be timed separately with plain |
| 69 | // time.Since calls around a single deliberate run — go test's |
| 70 | // -bench/testing.B machinery reruns its body b.N times to reach a |
| 71 | // stable per-op estimate, which would mean rebuilding a |
| 72 | // several-hundred-thousand-row SQLite fixture on every iteration; that |
| 73 | // is the wrong shape for a fixture this expensive to build once. The |
| 74 | // env var is what actually keeps this out of `make test`: CI's test-go |
| 75 | // target runs plain `go test -count=1 ./...` with no -short flag (see |
| 76 | // Makefile), so testing.Short() alone would not skip it there — the |
| 77 | // env var being unset is what does. testing.Short() is kept as a second, |
| 78 | // independent gate for anyone who runs `go test -short ./...` by habit. |
| 79 | // |
| 80 | // N: set BLANK_RECOVERY_BENCH_N to override; unset defaults to |
| 81 | // calc.MaxDirtyPerPass+1 (5,001) — just over the recompute cap, so a |
| 82 | // default run still exercises the marking-only path the recorded figures |
| 83 | // above describe, and finishes in well under a second post-fix (the |
| 84 | // sibling correctness test, TestBlankFeederOverCapDependentsAreRecoverable, |
| 85 | // runs the same shape at the same N as part of every `make test`). Push |
| 86 | // BLANK_RECOVERY_BENCH_N=199999 to reach the real store.MaxCellsPerTab-1 |
| 87 | // ceiling the recorded figures were measured at; expect several minutes |
| 88 | // total, dominated by seeding N rows and cells, not by the two timed |
| 89 | // phases themselves. |
| 90 | func TestBlankRecoveryBench(t *testing.T) { |
| 91 | if testing.Short() { |
| 92 | t.Skip("store: skipping blank/recovery benchmark under -short") |
| 93 | } |
| 94 | if os.Getenv("RUN_BLANK_RECOVERY_BENCH") == "" { |
| 95 | t.Skip("store: set RUN_BLANK_RECOVERY_BENCH=1 to run (see this file's doc comment; minutes at large N)") |
| 96 | } |
| 97 | n := blankRecoveryBenchN(t) |
| 98 | |
| 99 | dir := t.TempDir() |
| 100 | d, err := rdb.Open(filepath.Join(dir, "bench.db"), nil) |
| 101 | if err != nil { |
| 102 | t.Fatalf("open db: %v", err) |
| 103 | } |
| 104 | t.Cleanup(func() { |
| 105 | if err := d.Close(); err != nil { |
| 106 | t.Errorf("close db: %v", err) |
| 107 | } |
| 108 | }) |
| 109 | db := d.G |
| 110 | if _, err := migrate.Apply(context.Background(), d, sheets.BootSchema); err != nil { |
| 111 | t.Fatalf("migrate: %v", err) |
| 112 | } |
| 113 | s, err := seal.New(make([]byte, 32)) |
| 114 | if err != nil { |
| 115 | t.Fatal(err) |
| 116 | } |
| 117 | |
| 118 | const localTab, feederRow, colA uint64 = 1, 1, 1 |
| 119 | seedBlankRecoveryFixture(t, db, s, localTab, feederRow, colA, n) |
| 120 | |
| 121 | h, err := store.Open(db, s, localTab) |
| 122 | if err != nil { |
| 123 | t.Fatalf("store.Open (initial): %v", err) |
| 124 | } |
| 125 | |
| 126 | blankStart := time.Now() |
| 127 | if err := h.Set(feederRow, colA, "", 7); err != nil { |
| 128 | t.Fatalf("blank feeder: %v", err) |
| 129 | } |
| 130 | blankElapsed := time.Since(blankStart) |
| 131 | h.Release() |
| 132 | |
| 133 | openStart := time.Now() |
| 134 | h2, err := store.Open(db, s, localTab) |
| 135 | openElapsed := time.Since(openStart) |
| 136 | if err != nil { |
| 137 | t.Fatalf("store.Open (recovery): %v", err) |
| 138 | } |
| 139 | defer h2.Release() |
| 140 | |
| 141 | t.Logf("N=%d setBlank(h.mu hold)=%s store.Open(recovery pass)=%s", n, blankElapsed, openElapsed) |
| 142 | t.Logf("recorded (batching-report.md, N=199999): setBlank=2.779s store.Open=8.818s") |
| 143 | } |
| 144 | |
| 145 | // blankRecoveryBenchN reads BLANK_RECOVERY_BENCH_N, defaulting to |
| 146 | // calc.MaxDirtyPerPass+1 — see this file's doc comment for why. |
| 147 | func blankRecoveryBenchN(t *testing.T) int { |
| 148 | t.Helper() |
| 149 | raw := os.Getenv("BLANK_RECOVERY_BENCH_N") |
| 150 | if raw == "" { |
| 151 | return calc.MaxDirtyPerPass + 1 |
| 152 | } |
| 153 | n, err := strconv.Atoi(raw) |
| 154 | if err != nil || n <= 0 { |
| 155 | t.Fatalf("store: BLANK_RECOVERY_BENCH_N=%q is not a positive integer", raw) |
| 156 | } |
| 157 | return n |
| 158 | } |
| 159 | |
| 160 | // seedBlankRecoveryFixture seeds one feeder cell holding "5" plus n |
| 161 | // dependent cells each holding "=A1*2" with an already-consistent cache |
| 162 | // (cached value 10) — the exact fixture shape |
| 163 | // TestBlankFeederOverCapDependentsAreRecoverable uses, batched via |
| 164 | // db.CreateInBatches the same way, so seeding N rows stays proportional |
| 165 | // rather than N round trips. The same two sealed blobs are reused for |
| 166 | // every dependent (seal.Sealer.Seal takes no per-call AAD binding it to |
| 167 | // a specific cell), matching that test's own reasoning for doing so. |
| 168 | func seedBlankRecoveryFixture(t *testing.T, db *gorm.DB, s *seal.Sealer, tabID, feederRow, colA uint64, n int) { |
| 169 | t.Helper() |
| 170 | |
| 171 | if err := db.Create(&store.Tab{ID: tabID, SheetID: 1}).Error; err != nil { |
| 172 | t.Fatalf("seed tab: %v", err) |
| 173 | } |
| 174 | if err := db.Create(&store.Col{ID: colA, TabID: tabID, Position: 0}).Error; err != nil { |
| 175 | t.Fatalf("seed col: %v", err) |
| 176 | } |
| 177 | if err := db.Create(&store.Row{ID: feederRow, TabID: tabID, Position: 0}).Error; err != nil { |
| 178 | t.Fatalf("seed feeder row: %v", err) |
| 179 | } |
| 180 | |
| 181 | feederInputSealed, err := s.Seal("cell.input", []byte("5")) |
| 182 | if err != nil { |
| 183 | t.Fatal(err) |
| 184 | } |
| 185 | feederCachedSealed, err := s.Seal("cell.cached", store.EncodeValueForTest(calc.Value{Kind: calc.KindNum, Num: 5})) |
| 186 | if err != nil { |
| 187 | t.Fatal(err) |
| 188 | } |
| 189 | if err := db.Create(&store.Cell{ |
| 190 | TabID: tabID, RowID: feederRow, ColID: colA, |
| 191 | InputSealed: feederInputSealed, InputVersion: 1, |
| 192 | CachedSealed: feederCachedSealed, CacheVersion: 1, |
| 193 | }).Error; err != nil { |
| 194 | t.Fatalf("seed feeder cell: %v", err) |
| 195 | } |
| 196 | |
| 197 | depInputSealed, err := s.Seal("cell.input", []byte("=A1*2")) |
| 198 | if err != nil { |
| 199 | t.Fatal(err) |
| 200 | } |
| 201 | depCachedSealed, err := s.Seal("cell.cached", store.EncodeValueForTest(calc.Value{Kind: calc.KindNum, Num: 10})) |
| 202 | if err != nil { |
| 203 | t.Fatal(err) |
| 204 | } |
| 205 | rows := make([]*store.Row, 0, n) |
| 206 | cells := make([]*store.Cell, 0, n) |
| 207 | for i := 1; i <= n; i++ { |
| 208 | rid := feederRow + uint64(i) |
| 209 | rows = append(rows, &store.Row{ID: rid, TabID: tabID, Position: i}) |
| 210 | cells = append(cells, &store.Cell{ |
| 211 | TabID: tabID, RowID: rid, ColID: colA, |
| 212 | InputSealed: depInputSealed, InputVersion: 1, |
| 213 | CachedSealed: depCachedSealed, CacheVersion: 1, |
| 214 | }) |
| 215 | } |
| 216 | const batch = 500 |
| 217 | if err := db.CreateInBatches(&rows, batch).Error; err != nil { |
| 218 | t.Fatalf("seed dependent rows: %v", err) |
| 219 | } |
| 220 | if err := db.CreateInBatches(&cells, batch).Error; err != nil { |
| 221 | t.Fatalf("seed dependent cells: %v", err) |
| 222 | } |
| 223 | } |
| 224 | |
amadan