perf(zqlite): fetch-template cache, direct SQL formatting, single-shot iterator logging - #6433
Draft
Karavil wants to merge 7 commits into
Draft
perf(zqlite): fetch-template cache, direct SQL formatting, single-shot iterator logging#6433Karavil wants to merge 7 commits into
Karavil wants to merge 7 commits into
Conversation
|
@capyai is attempting to deploy a commit to the Rocicorp Team on Vercel. A member of the Team first needs to authorize it. |
Every exhausted iterator ran the slow-query epilogue twice. `next()` logs when the native iterator reports `done`, and `TableSource.#fetch` then closes the iterator in its `finally`, so `return()` logs the same query again. Each duplicate costs a `performance.now()`, two threshold checks and, when the query is slow, two `LogContext.withContext` calls and two attribute objects. In a profiled warm tracker hydration, 6,822 of 7,795 iterators reached `done` through `next()` and were then closed, so they all logged twice; all 362 roster iterators did the same. The remaining 973 tracker iterators are closed early and still need their `return()` log. `#log()` is now idempotent, so the first completion describes the query and later closes stay silent. Early closes and aborts are unaffected, and the native iterator is still closed exactly once. Covered by a new `db.test.ts` case asserting one total/sqlite pair for an exhausted-then-closed iterator, an early close, and an abort; it fails on main with four log records instead of two.
… slow `logIfSlow` already discards everything it is handed when the query beats the threshold, but every caller paid for the arguments first. `Statement.run/get/all`, `LoggingIterableIterator.#log` and `Database.#run` each derived a `LogContext` -- which spreads the parent context into a fresh object and constructs a new logger -- and spread a new attribute object, on every single call. A fetch does this three times: once for `iterate` and twice for the epilogue. `LogContext.withContext` is 4.7% of self time under `TableSource.#fetch` in the eight-group diagnosis profile, and 1.6-1.9% of a tracker hydration in the follow-up profiles. It buys nothing on the fast path. The context and the attribute object are now built inside the threshold branch, from the method and type the caller passes as plain strings. Log output is unchanged. `logIfSlow` already re-applied every attribute to the context, so the call-site `withContext` calls were setting keys that were about to be set again to the same values, and `withContext` merges rather than appends. `db.test.ts` pins the exact context objects for pragma, exec, prepare, run, get, all and both iterate records at threshold 0, and passes unchanged. Measured on a production-shaped replay of the diagnosis kit's replica (2,060 fetches, 3,049 rows per wave, medians of 25 waves, before/after interleaved from two checkouts): -5.4%.
`@databases/sql`'s generic `formatStandard` ends every format by dedenting the text: it splits on newlines, filters blank lines, measures each line's leading whitespace, takes the minimum, and rejoins. The SQL the query builder emits is a single line, so that pass finds nothing and throws away the arrays it allocated. It also re-escapes the same table and column identifiers on every call. `TableSource.#fetch` formats a query for every fetch, so this is on the hot read path. `formatStandard` is the diagnosis's "SQL formatting 3.0% self", 6.4% of self time under `#fetch`, and 5.2-5.6% self in the follow-up tracker profiles. `format` and `compile` now walk the SQL items directly. The dedent still runs for multi-line templates -- `getUniqueIndexes` has one -- and is skipped when the text has no newline, where it is provably a no-op: with one line the common indent is that line's leading whitespace, and the trailing `trim()` removes it either way. Escaped identifiers are memoized, bounded at 10,000 entries so a client-influenced query shape cannot grow the map without limit. Output is byte-identical. A new `sql.test.ts` case asserts equality with `formatStandard` for single-line, multi-line/dedent, whitespace-only, multi-name and quote-escaped identifier shapes, and the existing `query-builder.test.ts` golden SQL is unchanged. Measured on a production-shaped replay of the diagnosis kit's replica (2,060 fetches, 3,049 rows per wave, medians of 25 waves, before/after interleaved from two checkouts): -5.8%. In isolation the formatter is 45-48% cheaper than `formatStandard` on the four dominant fetch shapes.
`fromSQLiteTypes` converts an arbitrary row: it calls `Object.keys(row)`, then looks every key up in the schema record to find its type. On the fetch path neither is necessary. `#fetch` selects exactly `Object.keys(this.#columns)`, so every row SQLite returns has those keys, in that order, and the types are known when the source is constructed. Row conversion is 4.3% of self time under `TableSource.#fetch` in the eight-group diagnosis profile, and the largest JavaScript cost above raw SQLite in a per-row ladder on the 973-row tracker fetch: native iterate 1.27 us/row, the zqlite iterator wrapper 1.42, `fromSQLiteTypes` 2.00, the generator chain 2.39. `#rowFromSQLiteTypes` walks precomputed name and type arrays instead, producing the same row object with the same key order. Exported `fromSQLiteTypes` is untouched: `getRow`, the snapshotter and the write authorizer still convert rows whose columns they cannot assume. Measured on a production-shaped replay of the diagnosis kit's replica (2,060 fetches, 3,049 rows per wave, medians of 25 waves, before/after interleaved from two checkouts): -2.8%, and 4-8% on a single 973-row fetch where the per-fetch costs amortize. In isolation, row conversion halves: 0.36 -> 0.19 us/row on the 8-column `problem_tracker`, 1.08 -> 0.57 us/row on the 17-column `assignment`. `table-source.test.ts` already covers every value type, bigint bounds and JSON through fetch.
A hydration issues thousands of fetches that differ only in the values they bind. A profiled warm tracker hydration ran 7,795 fetches over 12 distinct SQL texts; the production-shaped replay used here runs 2,064 fetches over 16. Every one of them rebuilt the `@databases/sql` object tree, serialized it, and normalized the result's whitespace before the statement cache could find the already-prepared statement. `buildSelectQuery` is 8.8-9.1% inclusive and zqlite `format` 8.2-8.6% inclusive in those profiles; `normalizeWhitespace` is another ~1% self. Statement preparation was never the problem and is unchanged. `#fetch` now looks up a per-connection template keyed by everything that can change the SQL text, and rebinds values into it. The connection fixes the table, the columns, the filter conditions and the ordering, so the key is the constrained columns in order, each multi-constraint's columns and arity, and `reverse`. Values cannot change the text: `constraintsToSQL` emits `col = ?` even for a null. The bindings are rebuilt in `buildSelectQuery`'s order -- constraints, then each multi-constraint entry by entry using the first entry's column order the way `multiConstraintToSQL` does, then the connection's fixed filter literals, captured when the template was built. `StatementCache` grows a `getNormalized` entry point so the canonical text is normalized once per template instead of once per fetch, and the template map is capped the way the statement cache is, because multi-constraint arity comes from caller-chosen chunk sizes. Requests with a `start` keep the old path. `gatherStartConstraints` picks comparisons from the cursor row's values -- a null bound emits `IS NOT NULL`, or `FALSE`, or nothing -- so their text depends on values, and paging does not repeat a shape often enough to be worth the risk. Results are identical. Replaying the diagnosis kit's replica with the production fetch shapes plus reverse, cursor paging and multi-constraint arities of 1/2/5/17/126, the 4,665 fetched rows are byte-identical before and after, `db.prepare` calls stay at 0, iterators started stay at 2,064, and SQL formats fall from 2,064 to 68 -- exactly the 68 paging fetches that bypass the template. New `table-source.test.ts` cases check every cached shape against building and formatting the query from scratch, over null, boolean and JSON values, compound constraints, the same columns in a different order, chained and compound multi-constraints, varying arity, reverse, and both start bases; each runs twice so it is served once by a fresh template and once by a cached one. Deliberately breaking the key on `reverse`, on the constraint columns, on multi-constraint arity, on the filter-value position, or on the compound column order fails those tests. One invariant is now trusted rather than re-derived: `multiConstraintToSQL` asserts that every entry of a multi-constraint has the first entry's columns, and a templated fetch takes the column order from the first entry without re-checking the rest. FlippedJoin builds them from a single parentKey, which is what that assertion documents. Measured on the same replay (medians of 25 waves, before/after interleaved from two checkouts): 54.95 ms -> 37.30 ms, -32.1%.
… path `multiConstraintToSQL` emits one binding per column of a multi-constraint's first entry, and asserts that every other entry carries those same columns. A fetch served from a cached template never reaches it, so the previous commit trusted that invariant instead of re-deriving it. That turns a loud assertion into silently wrong bindings the moment any caller breaks the shape -- an entry missing a column would bind NULL for it, and the query would return plausible, wrong rows. Today only FlippedJoin builds these, from a single parentKey, but the assertion is the contract and the templated path has to honour it. The binding loop now checks each entry's column count against the first entry's, and checks that each expected column is present. Both halves are needed and both are covered: an entry with an extra column has every expected column present and is only caught by the count, and an entry with a different column of the same arity is only caught by the presence check. The failure message matches the builder's. Cost, measured against the same branch with the check removed. On the production-shaped replay, which binds 787 multi-constraint entries per wave, it is invisible: 37.30 ms without, 37.32 ms with, under 0.1% of the wave and unchanged at -32.1% against main. On a pathological wave that is nothing but arity-126 multi-constraint fetches -- 800 fetches, 100,800 entries checked -- it is 95.7 -> 96.4 ms median, +1.2% of a wave that does nothing else, or about 12 ns per entry. It stays unconditional. The new `table-source.test.ts` case asserts that a heterogeneous multi-constraint throws rather than misbinds on both paths: on the fresh path, where the builder rejects it, and on the cached path, reached by fetching a well-formed request of the same shape first.
Karavil
force-pushed
the
capy/zqlite-fetch-cost
branch
from
August 28, 2026 17:39
778d662 to
7adc22f
Compare
…hape `fetchTemplateKey` joined the constrained column names with `|`, and each multi-constraint's arity with `;`, unescaped. A schema whose column names contain those characters can therefore hash two different request shapes onto one key, and the cached template then serves the first shape's SQL text for the second shape's bindings. When the two shapes bind different numbers of values that fails loudly at bind time; when the counts match it does not. `a|b` + `c` against `a` + `b|c` is two constrained columns either way, so the second shape's values bind into the first shape's columns and the fetch returns plausible, wrong rows. Each column name is now framed by its own length. That makes the key injective: the length is digits terminated by the first `:`, so a name can no longer spell a separator, whatever it contains. The new `table-source.test.ts` case builds a table with columns `a|b`, `c`, `a`, `b|c` and `a;1|b`, and fetches both ambiguous shapes fresh and cached. Against the unfixed key the `a` + `b|c` fetch returns the `a|b` + `c` row. It also pins that SQLite round-trips such names, since the shapes only agree if the emitted identifiers are quoted correctly. Cost: the length field is about 19 ns per key on the wave's shapes, 30 -> 49 ns measured in isolation over 2,000 rounds per side. The wave builds one key per templated fetch, about 2,000 of them, so it is near 0.1% of a 37 ms wave. Priced end to end on 180 templated fetches -- point constraints, a compound constraint, reverse, and multi-constraint `IN` lists of arity 1/2/5/17/126 -- interleaved A/B with the file swapped, six rounds per side: 14.624 ms before, 14.542 ms after on the fastest iteration. It does not show up.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
2 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Per-fetch and per-row cost cuts in
TableSource. Six commits, all insidepackages/zqlite, all behavior-preserving. No API changes outside the package. Measured against a replica built from the synthetic classroom workload behind #6438.54.95 ms → 37.30 ms per hydration wave, −32.1%, with byte-identical rows.
What the evidence said
Statement caching is not the problem, and neither is statement preparation. Driving real
TableSourcefetches against the replica,db.prepareis called 0 times in a warm wave, before and after. Identical shapes hitStatementCacheevery time.Self time under
TableSource.#fetchin a sync-worker CPU profile of the N=8 wave replay from #6438 (#fetchis 28.5% of all samples):#fetchnextformatStandard+ normalize + cache lookupStatement/ iterator wrapper (withContextalone 4.7%)fromSQLiteTypes,#mapFromSQLiteTypes)Per-row ladder on the 973-row tracker fetch: native iterate 1.27 us/row → + wrapper 1.42 → +
fromSQLiteTypes2.00 → + generators 2.39.Follow-up hydration profiles put
buildSelectQueryat 8.8–9.1% inclusive, zqliteformatat 8.2–8.6% inclusive,formatStandardat 5.2–5.6% self, andnormalizeWhitespaceat ~1% self, over a warm tracker hydration that runs 7,795 fetches across only 12 distinct SQL texts.The commits
Log a completed SQLite iterator's slow-query epilogue once. An exhausted iterator logged twice:
next()logs ondone, then#fetch'sfinallycloses it andreturn()logs the same query again. 6,822 of 7,795 profiled tracker iterators and all 362 roster iterators did this.#log()is now idempotent; early closes and aborts still log.Build the slow-query log context only when the query is slow.
Statement.run/get/all/iterate, the iterator epilogue andDatabase.#runeach derived aLogContextand spread an attribute object on every call, thenlogIfSlowdiscarded both.withContextis 4.7% of#fetchself time. Output is unchanged:logIfSlowalready re-applied every attribute, andwithContextmerges rather than appends.Format SQL with a SQLite-specific item walker.
@databases/sql'sformatStandardends every call by dedenting: split, filter, measure each line's indent, take the minimum, rejoin -- dead work for the single-line SQL the builder emits (SQL formatting was 3.0% self in the profile).formatandcompilenow walk the items directly, skip the dedent when the text has no newline (provably a no-op there, since the trailingtrim()removes the leading whitespace either way), and memoize escaped identifiers, bounded at 10,000 entries.Materialize fetched rows from a precomputed column plan.
#fetchselects exactlyObject.keys(this.#columns), so the per-rowObject.keys(row)allocation and schema lookups infromSQLiteTypesare avoidable. ExportedfromSQLiteTypesis untouched forgetRow, the snapshotter and the write authorizer.Reuse a fetch's SQL text across fetches of the same shape. A per-connection template keyed by the constrained columns in order, each multi-constraint's columns and arity, and
reverse; values are rebound inbuildSelectQuery's order, with the same per-entry column checkmultiConstraintToSQLmakes. The connection already fixes the table, columns, filters and ordering, and values never change the text becauseconstraintsToSQLemitscol = ?even for a null.StatementCachegrowsgetNormalizedso the canonical text is normalized once per template rather than once per fetch. Requests with astartkeep the old path, becausegatherStartConstraintschooses comparisons from the cursor row's values.(The sixth commit is the guard priced in its own section below.)
Numbers
Fixture: the SQLite replica (
.db+-wal+-shm) that zero-cache builds by initial-syncing the #6438 fixture -- 136 students, 973 problem trackers, 973 conversations, 957 mastery assessments, all identities synthetic. The wave replays the SQL shapes observed in the #6438 server log:problem_trackerby assignment (973 rows), 973 ×conversationby tracker, 973 ×mastery_assessmentby tracker,assignmentby id,student_class_membershipwith multi-constraintINof arity 1/2/5/17/126 -- plus reverse fetches and cursor paging over both bases. 2,064 fetches, 4,665 rows per wave. Before and after run interleaved from two checkouts of the same base commit to cancel machine drift; each number is the median of 25 waves. One machine; treat the ratio as the portable result.54.98 ms → 37.32 ms, −32.1% on medians, and −32.1% on per-round minima (54.833 → 36.80 ms). The before and after ranges do not overlap.
Cumulative through each commit, same method, three interleaved rounds each:
Commit 1 does not move this benchmark, and that is expected: its duplicate epilogue only becomes expensive when the log context is built eagerly, which commit 2 removes anyway. Its value on top of main is the profiled 1–2% of tracker CPU and, either way, one slow-query record per iterator instead of two.
The win is per-fetch dominated. A single 973-row fetch, where SQL costs amortize over many rows, improves only through the row plan: 2.39 → 2.25 us/row.
Isolated micro-numbers: the formatter is 45–48% cheaper than
formatStandardon the four dominant fetch shapes, and the row plan halves row conversion -- 0.36 → 0.19 us/row on the 8-columnproblem_tracker, 1.08 → 0.57 us/row on the 17-columnassignment.Work eliminated
Counters over one warm wave, before and after:
db.preparecallsThe 68 remaining formats are exactly the 68 cursor-paging fetches (17 rows × 2 bases × 2 directions) that bypass the template by design.
Equality proof
The measurement harness has a dump mode that writes every fetched row, in fetch order, as JSONL (bigints tagged so they survive
JSON.stringify). Before and after are byte-identical:4,665 rows across five tables covering
string,number,boolean,jsonandnullcolumns, ascending and descending multi-column orderings, single and compound constraints, multi-constraintINof five different arities, reverse fetches, and cursor paging on both bases.The unit tests add the shapes the replica does not exercise: the same constrained columns in a different order, chained multi-constraints, compound multi-constraints whose later entries list their columns in a different order, and connection filters. Each cached shape is compared against building and formatting the query from scratch, twice, so it is served once by a fresh template and once by a cached one. Deliberately breaking the template key on
reverse, on the constraint columns, on multi-constraint arity, on the filter-value position, or on the compound column order fails those tests. A heterogeneous multi-constraint must throw rather than misbind, on the fresh path and on the cached one.The template key is injective in the request's shape: each column name is framed by its own length, so a name that itself contains the
|or;separators cannot make two shapes share a template. A regression test pins it with columns nameda|b,c,a,b|canda;1|b-- the two two-column shapes bind the same number of values, so a shared key would return plausible wrong rows rather than fail at bind time.Tests
Reproducing
The A/B wave driver, the counter scripts and the dump-mode equality harness are scratch scripts and are not committed, so the wall-clock tables above cannot be regenerated verbatim from this branch; the method is stated with each table so the numbers carry their context. What an outside reviewer can run:
packages/zqlite/src, which pin every behavioral claim above -- template-key completeness, the multi-constraint guard, formatter/formatStandardequivalence, and row-conversion equivalence.seed/apply-seed.shand let zero-cache initial-sync it; the resulting replica is the one described above, and the wave's fetch shapes and per-shape row counts are listed in the Numbers section.What the multi-constraint guard costs
multiConstraintToSQLasserts that every entry of a multi-constraint carries the first entry's columns, and a fetch served from a template never reaches it. An earlier revision of the template cache trusted that invariant instead of re-deriving it, which would have turned a loud assert into silently wrong bindings on a cache hit for any future caller that broke the shape. The templated binding path now makes the same check -- a column count per entry, plus a presence check per expected column.On the production-shaped wave, which binds 787 multi-constraint entries, the guard is invisible: 37.30 ms without it, 37.32 ms with it, under 0.1% of the wave.
Priced on a pathological wave that is nothing but arity-126 multi-constraint fetches -- 800 fetches, 100,800 entries checked per wave, single-column and compound -- against the same branch with the guard removed:
+1.2% of a wave that does nothing else, or roughly 12 ns per entry. It stays unconditional.
Both halves are load-bearing, and the test proves it: removing the count check lets an entry with an extra column through, and removing the presence check lets an entry with the right number of columns but a different one through.
Not done, and why
Templating cursor-paged fetches.
gatherStartConstraintsderives its comparison operators from the cursor row's values -- a null bound emitsIS NOT NULL, orFALSE, or nothing at all -- so the text depends on values and the key would need a null mask over the ordering fields. Paging fetches do not repeat a shape often enough to pay for that risk; in the replay they are 68 of 2,064 fetches.Per-row
performance.now()inLoggingIterableIterator.next. Two calls per row, 7.8% of#fetchself time.#sqliteRowTimeSumand the total elapsed measure genuinely different intervals, so collapsing them would change when thetype=sqlitewarning fires.