From f6240d3a8cdcbecd6a2a78a78b5258776c62e667 Mon Sep 17 00:00:00 2001 From: leemour Date: Thu, 15 Oct 2026 02:45:37 +0200 Subject: [PATCH] perf(mail): re-indexing after a large rules change, with the profile to repeat Why the scheduled memo sync held the import lock for hours after 44,011 emails were cut to envelopes (PERF-42): the index drain deleted vectors by hash alone and scanned the whole vector table per hash. Totals before and after cli-core#1259, and run.sh to repeat it on a store copy. Co-Authored-By: Claude Opus 5.5 (1M context) --- performance/README.md | 4 +- performance/mail/README.md | 2 + performance/mail/indexing/README.md | 64 +++++++++++++++++++++ performance/mail/indexing/profile-words.mjs | 28 +++++++++ performance/mail/indexing/profile.mjs | 58 +++++++++++++++++++ performance/mail/indexing/run.sh | 27 +++++++++ 6 files changed, 181 insertions(+), 2 deletions(-) create mode 100644 performance/mail/indexing/README.md create mode 100644 performance/mail/indexing/profile-words.mjs create mode 100644 performance/mail/indexing/profile.mjs create mode 100755 performance/mail/indexing/run.sh diff --git a/performance/README.md b/performance/README.md index ac2a4d4..bee290e 100644 --- a/performance/README.md +++ b/performance/README.md @@ -3,7 +3,7 @@ - [search](search/README.md): message and document search quality and speed. - [runs](runs/README.md): recorded runs of the `runs` commands. - [documents](documents/README.md): reading documents into text, starting with HTML. -- [mail](mail/README.md): reading a mailbox into the store — Gmail import speed and limits, and checking the - sender score against Gmail's Spam. +- [mail](mail/README.md): reading a mailbox into the store — Gmail import speed and limits, the sender score + against Gmail's Spam, and re-indexing after a large rules change. - [store](store/README.md): the shared SQLite store — filters, migrations. - [tasks](tasks/README.md): tasks found in messages — duplicate detection. diff --git a/performance/mail/README.md b/performance/mail/README.md index 6fe75f5..74c2b64 100644 --- a/performance/mail/README.md +++ b/performance/mail/README.md @@ -6,3 +6,5 @@ Measurements of reading a mailbox into the shared store with memo. batches, a header-only probe, and where Gmail starts throttling (2026-10-14). - [spam-scoring](spam-scoring/README.md): how much of Gmail's Spam memo's sender score catches, and how many replied-to senders it wrongly flags — a calibration script, not run yet. +- [indexing](indexing/README.md): why the scheduled sync held memo's lock for hours after 44,000 emails were cut + to envelopes, and the fix that drains the same queue 266 times faster (2026-10-15). diff --git a/performance/mail/indexing/README.md b/performance/mail/indexing/README.md new file mode 100644 index 0000000..c641b65 --- /dev/null +++ b/performance/mail/indexing/README.md @@ -0,0 +1,64 @@ +# Re-indexing mail after a large rules change + +## Why + +The owner's memo cut 44,011 stored emails down to envelopes with `memo mail rules apply` (their text removed, +sender, date and labels kept). The next scheduled `memo sync` then held memo's import lock for about an hour and +was on course for six more, working through the mail search index; the Gmail import waited behind it +(PERF-42 in the owner's journal). The question: where does the time go, the index drain or embedding with +e5-small, and what makes a scheduled run short again? The answer fed cli-core#1259. + +## Setup + +- Linux laptop, Node 24.19.0, other work running (load average 20–50). +- A copy of the owner's store, taken with SQLite's backup: 1.6 GB, 375,611 chunks, 28,342 vectors of one model + (`local:e5-small:384`), 13,157 email threads queued for re-indexing (13,693 emails, 1 with text). +- cli-core `main` at 66d33597 (before) and with #1259 (after), built from source. +- [run.sh](run.sh) copies the store, points `HOME`, `WIRECAT_STATE_DIR` and `MESSAGING_STORE` at a temp folder, + and runs [profile.mjs](profile.mjs) (drain a slice of the queue, list a batch, embed N chunks) and + [profile-words.mjs](profile-words.mjs) (queue the newest N emails with text and drain their word index). + +```sh +# from a built cli-core checkout; reads ~/.local/share/WireCat/wirecat.db once, writes only under ~/.cache +performance/mail/indexing/run.sh ~/Projects/AI/cli-messaging 300 300 64 +# the whole queue and a full scheduled run's embedding: +performance/mail/indexing/run.sh ~/Projects/AI/cli-messaging 100000 300 600 +``` + +The first step measures whatever the store has queued; on a store with an empty queue it drains nothing and prints +`null` per thread, while the word-index step always queues its own emails. Repeat it before releasing a cli-core +change to indexing or vector cleanup, and after any memo command that rewrites many stored emails. + +## Results + +| What | Before | After #1259 | +|---|---:|---:| +| Draining the whole queue, 13,157 envelope-only threads | 896 s (68 ms a thread) | 3.4 s (0.3 ms a thread) | +| A 300-thread slice of it | 14.0 s (46.7 ms a thread) | 0.06 s (0.2 ms a thread) | +| Word index for 300 emails with text (811,227 chars) | 10.8 s (35.9 ms an email) | 0.45 s (1.5 ms an email) | +| Embedding 600 chunks with e5-small (memo's cap per run) | 82 s (136 ms a chunk) | 52 s (87 ms a chunk) | +| Listing the next batch to embed | 3.2 s | 0.03 s | + +The embedding rows differ only by machine load; #1259 does not touch embedding. + +## What it showed + +- **The drain, not embedding, held the lock.** Every queued thread first drops its old pieces and then deletes + their vectors when nothing else uses them. That delete named only the text hash, while the vector table's key + is (model, hash), so each hash read all 28,000 vectors. The cut emails had pieces before, so every one of the + 13,157 threads paid that scan, with nothing new to index. +- **Naming the model fixes it without a migration**: the models are found by index seeks, then each delete is a + key lookup. 266 times faster on the whole queue. +- **Embedding was already bounded**: memo embeds at most 600 chunks a run, about a minute here, so a time budget + or giving the lock up while embedding is not needed once the drain is fast. +- **The live run was slower than the copy**: about one thread a second against 13 here. The timer runs memo with + `Nice=10` on a loaded machine, and the import loop held the store open beside it. Not measured. + +## Not measured + +- Other places that delete vectors by hash alone (notes, documents' pictures, images, messages); they scan the + same way, but none had a large queue. An index on `embeddings(content_hash)` would fix them all and needs a + store migration. +- Stores with more than one embedding model; the fix seeks once per model. +- A queue of threads with text: one email with text was in this queue, so the word-index row comes from a + separate, synthetic queue of the newest 300 emails with text. diff --git a/performance/mail/indexing/profile-words.mjs b/performance/mail/indexing/profile-words.mjs new file mode 100644 index 0000000..85c33ef --- /dev/null +++ b/performance/mail/indexing/profile-words.mjs @@ -0,0 +1,28 @@ +// Times the word index for emails with text: queues N of them as a fresh import would, then drains. +// usage: node profile-words.mjs +import { performance } from "node:perf_hooks" +import { DatabaseSync } from "node:sqlite" + +const [coreDir, storePath, nArg] = process.argv.slice(2) +const n = Number(nArg ?? 300) +const raw = new DatabaseSync(storePath) +raw.exec("DELETE FROM email_index_pending") +raw.exec(`INSERT INTO email_index_pending (indexable_type, id) + SELECT 'email', id FROM emails WHERE body_text IS NOT NULL ORDER BY id DESC LIMIT ${n}`) +const chars = raw + .prepare(`SELECT sum(length(body_text)) c FROM emails WHERE id IN + (SELECT id FROM email_index_pending WHERE indexable_type = 'email')`) + .get().c +raw.close() +const { openStore } = await import(`${coreDir}/dist/store/index.js`) +const store = await openStore({ path: storePath, env: process.env }) +const t = performance.now() +await store.mail.chunksToEmbed("e5-small", { limit: 1 }) +const ms = performance.now() - t +await store.close() +const after = new DatabaseSync(storePath) +const left = after.prepare("SELECT count(*) c FROM email_index_pending").get().c +after.close() +process.stdout.write( + `${JSON.stringify({ emails: n, text_chars: chars, drain_ms: Math.round(ms), ms_per_email: +(ms / n).toFixed(1), left })}\n`, +) diff --git a/performance/mail/indexing/profile.mjs b/performance/mail/indexing/profile.mjs new file mode 100644 index 0000000..07668b1 --- /dev/null +++ b/performance/mail/indexing/profile.mjs @@ -0,0 +1,58 @@ +// Times what a scheduled memo sync does to mail on a store copy: the index drain, then embedding with e5-small. +// usage: node profile.mjs +import { performance } from "node:perf_hooks" +import { DatabaseSync } from "node:sqlite" + +const [coreDir, storePath, keepArg, embedArg] = process.argv.slice(2) +const keep = Number(keepArg ?? 300) +const toEmbed = Number(embedArg ?? 64) + +const raw = new DatabaseSync(storePath) +const pending = raw.prepare("SELECT indexable_type t, count(*) n FROM email_index_pending GROUP BY 1").all() +raw.exec(`DELETE FROM email_index_pending WHERE indexable_type = 'email_thread' + AND id NOT IN (SELECT id FROM email_index_pending WHERE indexable_type = 'email_thread' ORDER BY id LIMIT ${keep})`) +const sample = raw + .prepare(`SELECT count(*) threads, + sum((SELECT count(*) FROM emails e WHERE e.email_thread_id = p.id)) emails, + sum((SELECT count(*) FROM emails e WHERE e.email_thread_id = p.id AND e.body_text IS NOT NULL)) withText + FROM email_index_pending p WHERE indexable_type = 'email_thread'`) + .get() +const sizes = raw + .prepare("SELECT (SELECT count(*) FROM embeddings) embeddings, (SELECT count(*) FROM chunks) chunks") + .get() +raw.close() + +const { openStore } = await import(`${coreDir}/dist/store/index.js`) +const { embedMail } = await import(`${coreDir}/dist/services/index.js`) +const store = await openStore({ path: storePath, env: process.env }) + +let t = performance.now() +await store.mail.chunksToEmbed("e5-small", { limit: 1 }) +const drainMs = performance.now() - t + +t = performance.now() +await store.mail.chunksToEmbed("e5-small", { limit: 64 }) +const listMs = performance.now() - t + +t = performance.now() +const done = await embedMail(store, { maxChunks: toEmbed, env: process.env }) +const embedMs = performance.now() - t +await store.close() + +process.stdout.write( + `${JSON.stringify( + { + pending_before: pending, + sample, + sizes, + drain_ms: Math.round(drainMs), + drain_ms_per_thread: sample.threads ? +(drainMs / sample.threads).toFixed(1) : null, + list_batch_ms: Math.round(listMs), + embedded: done.embedded, + embed_ms: Math.round(embedMs), + embed_ms_per_chunk: done.embedded ? +(embedMs / done.embedded).toFixed(1) : null, + }, + null, + 1, + )}\n`, +) diff --git a/performance/mail/indexing/run.sh b/performance/mail/indexing/run.sh new file mode 100755 index 0000000..6afaf33 --- /dev/null +++ b/performance/mail/indexing/run.sh @@ -0,0 +1,27 @@ +#!/usr/bin/env bash +# Profiles the mail index drain and e5-small embedding on a copy of the store; the live store is only read once, by +# SQLite's backup. usage: run.sh [threads to keep queued=300] [emails to word-index=300] [chunks to embed=64] +set -euo pipefail + +CORE=$(cd "$1" && pwd) +THREADS=${2:-300} +EMAILS=${3:-300} +CHUNKS=${4:-64} +HERE=$(cd "$(dirname "$0")" && pwd) +STORE=${MESSAGING_STORE_SOURCE:-$HOME/.local/share/WireCat/wirecat.db} +MODELS=${MODELS_DIR:-$HOME/.local/share/WireCat/models} +WORK=$(mktemp -d -p "$HOME/.cache" memo-indexing.XXXXXX) +chmod 700 "$WORK" +trap 'rm -rf "$WORK"' EXIT + +sqlite3 "$STORE" ".backup '$WORK/source.db'" +mkdir -p "$WORK/home" "$WORK/state" +ln -s "$MODELS" "$WORK/state/models" +run() { HOME="$WORK/home" WIRECAT_STATE_DIR="$WORK/state" MESSAGING_STORE="$WORK/copy.db" node "$@"; } + +cp "$WORK/source.db" "$WORK/copy.db" +echo "== queued threads: drain, then embed $CHUNKS chunks" +run "$HERE/profile.mjs" "$CORE" "$WORK/copy.db" "$THREADS" "$CHUNKS" +cp "$WORK/source.db" "$WORK/copy.db" +echo "== word index for the newest $EMAILS emails with text" +run "$HERE/profile-words.mjs" "$CORE" "$WORK/copy.db" "$EMAILS"