Extension store cache: results

Run on the EC2 c7i.8xlarge in env.txt (32 vCPU, 61.8 GiB, one NVMe), mentat d34e0177 (perf(sqlite-ext,duckdb): cache the open Store per path), built from git archive (none of the working tree’s uncommitted changes). DuckDB 1.5.5, Python 3.11. REPS=1, MIN_S=10, MAX_S=60, PROBE_S=20. Full per-scenario tables: summary.md (generated by report.py); raw rows: raw.csv; checks: checks.txt (104 PASS, 0 FAIL, incl. the post-write checks).

Columns:

  • (a) per-call open, 1.9.0 — baseline/, the earlier ext-base run: every call opened the store, and Store::open scanned the whole log (O(history)). Only s loaded; at m a single call took 5 s (duckdb) or hit the 20 s probe ceiling (sqlite-ext), and the load through the extension crashed.
  • (a') per-call open, this build — nocache-*.csv: the same build with MENTAT_STORE_CACHE=0. Since 5072ef13 (another agent’s commit) Store::open is O(1), so this column separates the open-cost fix from the cache. Four scenarios only.
  • (b) cached — this run.

m for (a') and (b): the extensions query a copy of the 9.85M-datom store the embedded runner built at 1.9.0, upgraded to schema v2 on first open (16 s, once). Loading m through the extension was not attempted.

Single client, p50 ms

backend scale scenario (a) per-call open 1.9.0 (a') per-call open, O(1) open (b) cached
sqlite-ext s point_lookup 483.8 0.527 0.083
sqlite-ext s ref_traversal 526.8 40.3 37.4
sqlite-ext s aggregate 588.0 94.3 89.4
sqlite-ext s predicate_scan 520.7 31.2
sqlite-ext s pull 486.5 0.526 0.047
sqlite-ext s as_of ceiling (>20 s) 84.8
sqlite-ext s since 536.5 4.666
sqlite-ext s input_bindings 485.8 0.485
sqlite-ext m point_lookup ceiling (>20 s) 1.116 0.514
sqlite-ext m ref_traversal ceiling (>20 s) 518.6 479.3
sqlite-ext m aggregate ceiling (>20 s) 1,122.7 1,083.5
sqlite-ext m predicate_scan ceiling (>20 s) 390.7
sqlite-ext m pull ceiling (>20 s) 2.937 1.149
sqlite-ext m as_of ceiling (>20 s) 1,096.5
sqlite-ext m since ceiling (>20 s) 47.0
sqlite-ext m input_bindings ceiling (>20 s) 2.149
duckdb s point_lookup 465.9 1.171 0.625
duckdb s ref_traversal 510.5 41.0 38.7
duckdb s aggregate 568.1 91.9 89.6
duckdb s predicate_scan 503.3 27.9
duckdb s pull 461.2 1.149 0.559
duckdb s as_of 18,069.0 85.3
duckdb s since 520.6 5.123
duckdb s input_bindings 468.3 1.051
duckdb m point_lookup 5,003.4 1.757 1.126
duckdb m ref_traversal 5,542.9 500.3 493.4
duckdb m aggregate 6,133.1 1,088.8 1,066.9
duckdb m predicate_scan 333.3
duckdb m pull 1.187 1.798
duckdb m as_of ceiling (>20 s) 1,096.0
duckdb m since 48.3
duckdb m input_bindings 2.660

Per call, (a) → (b) is 470-520 ms → 0.05-0.6 ms at s for the cheap queries: that ~480 ms was Store::open. (a') → (b) is what the cache adds on top of the O(1) open: 0.53 → 0.083 ms (sqlite-ext point_lookup at s), 0.53 → 0.047 ms (pull). An open is still a SQLite connection, the WAL/shm mapping, and the schema read. Heavy queries (ref_traversal, aggregate at m) are dominated by the query itself and barely move between (a') and (b). as_of went from ceiling / 18 s to 85 ms, but that is the history index in 5072ef13, not the cache.

duckdb’s cheap reads are ~0.5 ms slower than sqlite-ext’s: that is DuckDB’s bind/plan/execute for a table function plus the Python result conversion, on every call.

bulk_load at s (edn_t per transaction, one writer)

backend (a) 1.9.0 s datoms/s (b) cached s datoms/s
sqlite-ext 92.2 10,683 67.6 14,566
duckdb 89.8 10,962 67.9 14,513

275 transactions of ~3,600 datoms each. How much of the 27% is the cache vs the O(1) open vs transactor changes since 1.9.0 was not separated (no (a') load was run).

concurrency_sweep (processes, each with its own host connection)

backend scale clients (a) ops/s (a) p50 ms (b) ops/s (b) p50 ms (b) p99 ms
sqlite-ext s 1 2.020 491.7 79.4 0.147 38.1
sqlite-ext s 8 15.1 517.4 619.6 0.149 39.1
sqlite-ext s 32 29.8 1,024.3 1,405.2 0.236 68.7
sqlite-ext s 64 31.2 1,914.1 1,390.5 0.233 208.7
sqlite-ext s 128 28.9 3,816.7 1,382.3 0.241 417.6
sqlite-ext m 1 ceiling (>20 s) ceiling (>20 s) 6.120 0.606 488.3
sqlite-ext m 8 47.9 0.713 498.2
sqlite-ext m 32 109.7 1.178 848.2
sqlite-ext m 64 105.7 1.187 2,559.0
sqlite-ext m 128 102.2 1.330 4,392.1
duckdb s 1 2.060 475.7 74.8 0.694 39.4
duckdb s 8 15.2 512.2 578.8 0.717 40.7
duckdb s 32 24.9 1,159.9 1,282.1 1.305 79.3
duckdb s 64 26.7 2,134.8 1,260.8 2.914 197.8
duckdb s 128 27.5 4,060.1 1,205.7 9.997 385.6
duckdb m 1 5.980 1.219 497.4
duckdb m 8 46.5 1.588 509.5
duckdb m 32 109.9 2.859 846.8
duckdb m 64 104.0 9.844 2,500.8
duckdb m 128 101.6 33.7 4,156.5

The mix alternates point_lookup, ref_traversal and pull, so throughput is bounded by ref_traversal (38 ms at s, 480 ms at m). Throughput levels off from 32 clients: 32 vCPUs. (a) ran pinned to 24 CPUs (cpu_affinity 0-23 in baseline/env.txt), (b) to 32. That affects the plateau, not the 1-8 client rows.

write_mixed (8 reader processes + 1 writer, 60 s)

backend scale op (a) ops/s (a) p50 ms (b) ops/s (b) p50 ms
sqlite-ext s read x8 14.7 560.2 348.7 40.0
sqlite-ext s write x1 1.950 518.3 295.7 3.376
sqlite-ext m read x8 15.7 559.2
sqlite-ext m write x1 216.8 3.828
duckdb s read x8 14.9 546.6 329.2 41.1
duckdb s write x1 1.930 517.6 246.7 4.011
duckdb m read x8 17.2 560.2
duckdb m write x1 191.2 4.494

Every write invalidates the other processes' cached stores, so a reader’s next call after a write reopens its store: the staleness check doing its job. The reader p50 is ref_traversal’s cost; the writer’s 3.4-4.5 ms p50 is the transaction itself. The post-write checks pass for both backends at both scales (checks.txt).

Notes

  • pull/duckdb/m shows as a REGRESSION in compare.py nocache-timings.csv timings.csv (1.19 → 1.80 ms). A rerun on the same copy gave 0.588 and 0.584 ms cached vs 1.190 and 1.167 ms uncached: the first run read cold pages of the freshly copied 2 GB file.
  • compare.py baseline timings.csv lists 11 “regressions”: all are rows that were ceiling in (a) and have real numbers now (compare.py counts a changed op as MISSING).