Skip to content

perf: let per-hash and per-conversation telemetry reads seek instead of sorting - #338

Open
FrameAutomata wants to merge 2 commits into
mainfrom
perf/335-exception-hash-time-index
Open

perf: let per-hash and per-conversation telemetry reads seek instead of sorting#338
FrameAutomata wants to merge 2 commits into
mainfrom
perf/335-exception-hash-time-index

Conversation

@FrameAutomata

Copy link
Copy Markdown
Collaborator

Closes #335. Stacked on #334 — based on that branch so the diff here is one commit. Retarget to main once #334 merges.

idx_exceptions_project_hash stopped at the hash column, so nothing covered (project_id, exception_hash, recorded_at). This widens it. The old index stays a leading prefix, so every query that used it stays covered.

The issue's diagnosis was wrong in both directions

#335 predicted the paginated per-hash read would sort the group's whole history, and asked to "confirm the USE TEMP B-TREE FOR ORDER BY disappears". There is no temp B-tree in that plan to begin with — and more importantly, the old index has a pathology in two different plans, and which one you get flips on whether ANALYZE has ever run. Measuring only one stats state would have justified the change for the wrong reason and missed the worse half.

  • Without stats, SQLite walks idx_exceptions_project_recorded in recorded_at order and re-filters the hash per row. Cost scales inversely with how noisy an issue is: an issue with fewer occurrences than the page holds can never satisfy the LIMIT, so it walks the entire project. That is the common case for a just-appeared issue — exactly when someone opens the page.
  • With stats, it switches to the hash index and sorts. That fixes the two reads above and instead makes the notification dispatch path 2.35s per fired exception.

The widened index is the only shape that is fast in both states.

Measurements

File-backed 2M-row, 500-hash, 30-day database (8.1GB, WAL), median of 3-5 runs. The multi-second figures are I/O-bound and move with page-cache warmth, so they are given as ranges across runs; the sub-millisecond ones were stable.

old old + ANALYZE new new + ANALYZE
issues list (24h) 4.9-24.8s 305ms 361ms 340ms
issue page, 5 occurrences 16.4-33.7s 63µs 44µs 54µs
issue page, 252k occurrences 335-479µs 268µs 323µs 167µs
notify: latest occurrence 64µs 2.35s 37µs 29µs
notify: post-archive count 15µs 409ms 23µs 23µs
no-data poll: MAX(recorded_at) 11µs 28µs 21µs 12µs
CountByHour (control) 40.5ms 39.6ms 40.2ms 43.2ms

PRAGMA optimize (retention/sqlite.go:90) is a no-op on a fresh connection and did not create sqlite_stat1, so the no-stats column is the likelier production state — but both are reachable, which is the point.

Two query sites outside the repository file turned out to be in scope and were not in the issue: the new-error evaluator's latest-occurrence and post-archive-count reads (notifications/evaluator_event_sqlite.go). Both are on the ingest-driven dispatch path.

The no-data poll's MAX(recorded_at) is the query with the most to lose — SQLite's min/max optimisation answers it in one seek only because recorded_at sits directly after project_id in idx_exceptions_project_recorded, which this does not touch. EXPLAIN confirms it keeps that index in all four configurations.

Write cost

Below measurement noise. Three alternating runs: 19.8-22.6k rows/s on the old index, 20.1-23.2k on the widened one — overlapping ranges. This replaces an index rather than adding one, so it does not repeat the ~2x insert penalty the genuinely-new tasks index cost in #334. The entry is ~29% wider (a 30-char timestamp), about +60MB here. Building it took ~10s.

The DROP-then-CREATE ordering is safe because the migration version is recorded only after every statement succeeds (migrations.go:73) and boot panics on migration failure (cmd/run.go:121) — a killed index build re-runs cleanly rather than serving traffic without the index. That property is load-bearing and currently implicit.

Guard test

telemetry_group_index_test.go grew a time-column field, so it now covers check_results, log_records (which uses timestamp, not recorded_at) and metric_points alongside the four recorded_at tables. Those three were already correctly indexed but unguarded — metric_points is the one with actual drift history (0006 did this same drop-and-widen). Verified the test fails without 0021 and passes with it.

Not done here

@FrameAutomata FrameAutomata added the ci Run CI on this PR (remove and re-add to re-validate after a push) label Aug 27, 2026
@dusanstanojeviccs

Copy link
Copy Markdown
Collaborator

We should only have PRs against main

idx_exceptions_project_hash stopped at the hash column, so nothing covered
(project_id, exception_hash, recorded_at). Widen it. The old index stays a
leading prefix, so every query that used it stays covered.

#335 predicted the paginated per-hash read would sort the group's whole
history. That is one of two plans SQLite picks between, and which one it
takes flips on whether ANALYZE has ever run -- so the old index has a
pathology in both states, just a different one each time.

Measured on a file-backed 2M-row, 500-hash, 30-day database (8.1GB, WAL),
median of 3-5. The multi-second figures are I/O-bound and move with page
cache warmth, so those are given as ranges across runs:

                              old         old+ANALYZE   new      new+ANALYZE
  issues list (24h)           4.9-24.8s   305ms         361ms    340ms
  issue page, 5 occurrences   16.4-33.7s  63us          44us     54us
  issue page, 252k            335-479us   268us         323us    167us
  notify: latest occurrence   64us        2.35s         37us     29us
  notify: post-archive count  15us        409ms         23us     23us
  no-data poll: MAX(rec_at)   11us        28us          21us     12us
  CountByHour (control)       40.5ms      39.6ms        40.2ms   43.2ms

Without stats the planner walks idx_exceptions_project_recorded and
re-filters the hash per row, so cost scales inversely with how noisy an
issue is: an issue with fewer occurrences than the page holds can never
satisfy the LIMIT and walks the whole project. With stats it switches to
the hash index and sorts, which fixes those two and instead makes the
notification path 2.35s per dispatch. The widened index is the only shape
that is fast in both states.

Two query sites outside the repository are in that table: the new-error
evaluator's latest-occurrence and post-archive-count reads
(notifications/evaluator_event_sqlite.go). Both are on the ingest-driven
dispatch path and neither was in #335's scope.

The no-data poll's MAX(recorded_at) relies on recorded_at sitting directly
after project_id in idx_exceptions_project_recorded, which this does not
touch; EXPLAIN confirms it keeps that index in all four configurations.

Ingest cost is below measurement noise -- three alternating runs gave
19.8-22.6k rows/s on the old index and 20.1-23.2k on the widened one. This
replaces an index rather than adding one, so it does not repeat the ~2x
insert penalty the new tasks index cost in #334. The entry is ~29% wider
(a 30-char timestamp), about +60MB here. Building it took ~10s.

The guard test grows a time-column field so it can also cover check_results
and log_records, whose indexes are already correct but were unguarded.

Closes #335.
@FrameAutomata
FrameAutomata force-pushed the perf/335-exception-hash-time-index branch from b31876f to 1d76d32 Compare August 28, 2026 22:25
@FrameAutomata
FrameAutomata changed the base branch from perf/323-telemetry-group-time-indexes to main August 28, 2026 22:25
@FrameAutomata

Copy link
Copy Markdown
Collaborator Author

Retargeted to main. The base branch was perf/323-telemetry-group-time-indexes, whose PR (#334) has since merged — rebasing dropped both of its commits as already upstream, leaving one commit here.

The diff is now just the migration (0021_index_exceptions_hash_time.up.sql) and the guard test it extends. go test ./app/migrations/ -run TestTelemetryGroupIndexes passes on the rebased branch.

Covers #335, which you noted can be safely added.


Generated by Claude Code

idx_ai_traces_project_conversation stops at conversation_id, so
FindByConversationId's ORDER BY recorded_at has nothing to walk: SQLite
seeks the conversation, then builds a temp b-tree over every row in it
before the LIMIT 1000 can take the first page. The limit cannot
short-circuit a sort, so the cost is the whole conversation's length no
matter how little of it is asked for.

Same shape as the exception index in the previous commit, so it joins
the same guard.

Measured on a 150k-turn conversation in a 350k-row table, both ANALYZEd:

  old  SEARCH ... (project_id=? AND conversation_id=?)
       USE TEMP B-TREE FOR ORDER BY            31.6ms
  new  SEARCH ... (project_id=? AND conversation_id=?
                   AND recorded_at>? AND recorded_at<?)
       no sort step                             0.5ms

The old plan grows with the conversation; the new one does not.

Closes #336.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@FrameAutomata FrameAutomata changed the title perf: let per-hash exception reads seek instead of scanning perf: let per-hash and per-conversation telemetry reads seek instead of sorting Aug 28, 2026
@FrameAutomata

Copy link
Copy Markdown
Collaborator Author

Extended to also cover #336, which you approved on the same terms ("created at could be part of the index... we should still do this").

Both are the same defect and the same guard test, so splitting them would have produced two PRs against main editing the same file — the merge-order problem you raised, in a smaller form.

0022_index_ai_traces_conversation_time.up.sql widens idx_ai_traces_project_conversation to (project_id, conversation_id, recorded_at). FindByConversationId orders by recorded_at with LIMIT 1000, and a LIMIT cannot short-circuit a sort — so the old index made it read and sort the entire conversation to return the first page, however long the conversation is.

Measured on a 150k-turn conversation in a 350k-row table, both ANALYZEd:

plan time
before SEARCH (project_id=? AND conversation_id=?) + USE TEMP B-TREE FOR ORDER BY 31.6ms
after SEARCH (project_id=? AND conversation_id=? AND recorded_at>? AND recorded_at<?) 0.5ms

The old plan scales with conversation length; the new one is flat.

One thing worth recording since it shapes how much this matters: without ANALYZE, and only when the request carries a date range, SQLite still prefers idx_ai_traces_project_recorded and re-filters conversation_id per row. That is the second bad plan the test comment describes, and it is why this is a guard test rather than a benchmark — which of the two plans you get depends on statistics that may never have been gathered. With statistics, or with no date range, the new index wins outright.

Both are agreed low-severity for the reason you gave — DuckDB is the self-hosted telemetry backend, and DuckDB is columnar with no secondary indexes, so this is SQLite-only by construction. It costs one migration file.


Generated by Claude Code

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

ci Run CI on this PR (remove and re-add to re-validate after a push)

Projects

None yet

Development

Successfully merging this pull request may close these issues.

exception_stack_traces per-hash reads sort the whole group: idx_exceptions_project_hash stops short of recorded_at

2 participants