From 263a6502ea3653cdf56735c567bc575628928ab4 Mon Sep 17 00:00:00 2001 From: Superlogicai Date: Fri, 6 Nov 2026 07:11:02 -1000 Subject: [PATCH 1/3] fix(db): index events by type to stop query pile-ups listAttentionEvidence runs after every hook, and with no index on events.type each run scanned the whole table: 12-33 s on an 18 GB database. Runs already in flight are not cancelled, so they stacked until all 10 pool workers were busy, showing as 300-900% CPU in the Rust process. Migration 15 adds events(type, ts). On a clone of that database the query drops from 12.7 s to 112 ms with identical output, and listToolEvents from 1.4 s to 4 ms. Nothing is deleted. A new test pins that the query uses the index and was confirmed to fail without it. Co-Authored-By: Claude Opus 5.5 --- docs/LANDMINES.md | 14 ++++++++++++++ docs/TESTING.md | 17 +++++++++++++++++ src-tauri/src/dashboard_checks.rs | 25 +++++++++++++++++++++++++ src-tauri/src/lib.rs | 11 +++++++++++ 4 files changed, 67 insertions(+) diff --git a/docs/LANDMINES.md b/docs/LANDMINES.md index 75ff7a4..8187f51 100644 --- a/docs/LANDMINES.md +++ b/docs/LANDMINES.md @@ -525,3 +525,17 @@ fix is ever reverted or bypassed. Referenced from CLAUDE.md. touching extraction: count tethered `hook:SessionStart` rows with no `session_bindings` row, then check what the tab held at that moment (`tab_active` events carry the held session id). Structural queries only. +- **Logic Loop at 300-900% CPU is the Attention query, not the UI (found + 2026-11-06).** `listAttentionEvidence` runs after every hook through + `scheduleAttentionRefresh`. `events` had no index on `type`, so each run + scanned the whole table: 12-33 s on an 18 GB database. The `cancelled` flag + only ignores the result, and the microtask coalescer doesn't wait for a run + in flight, so runs stacked until all 10 pool workers were busy. CPU reads as + roughly 100% per busy worker, which is why the top end is about 900%. + Migration 15 adds `events(type, ts)`: 12.7 s down to 112 ms on a full clone, + with identical output. An explicit `type` filter in the CTE only reached + 9.8 s, and the Phase 68 cleanup alone only 3.7 s. Triage next time: run + `sample 6` and count threads with `sqlite3` frames, plus + `jsonValidFunc` versus `jsonExtractFunc`. Any new read filtering `events` + without a usable index repeats this. `eventsSince` still filters on `ts` + alone and was not fixed here. diff --git a/docs/TESTING.md b/docs/TESTING.md index 153636b..8ba2162 100644 --- a/docs/TESTING.md +++ b/docs/TESTING.md @@ -7066,3 +7066,20 @@ Manual, installed app after `npm run reinstall`: run a long Claude session with subagents and confirm no "transcript format doesn't match" banner appears. Not yet run; the banner isn't persisted, so the old false trip was only reproduced by replay. + +### Events type index, migration 15 (2026-11-06) + +Automated: `cargo test --lib` pins that the Attention query's `valid_events` +read uses `idx_events_type_ts`. On an APFS clone of the maintainer database +(18 GB, warm cache, `node:sqlite`): `listAttentionEvidence` 12.7 s to 112 ms, +`listToolEvents` 1.4 s to 4 ms, `lastLeft` 235 ms to under 1 ms, identical +output hashes, index build 1.6 s. + +Manual, installed app after `npm run reinstall` (not yet run): + +1. Note first launch time; the migration builds on a cold database and may take + longer than 1.6 s. Terminals should appear normally. +2. With agents active, read CPU with `top -l 2 -s 2 -pid -stats cpu,th`. + Before this fix it sat at 500-900%. +3. If CPU stays high, run `sample 6`. `eventsSince` is the next suspect; + it filters on `ts` alone. diff --git a/src-tauri/src/dashboard_checks.rs b/src-tauri/src/dashboard_checks.rs index 1e65b3e..56cdd98 100644 --- a/src-tauri/src/dashboard_checks.rs +++ b/src-tauri/src/dashboard_checks.rs @@ -59,3 +59,28 @@ fn project_decisions_match_source_open_count_without_a_silent_cap() { } }); } + +#[test] +fn attention_event_reads_use_the_type_index() { + tauri::async_runtime::block_on(async { + let repo = include_str!("../../src/lib/repo.ts"); + let valid_events = repo + .split_once("WITH valid_events AS (").expect("valid_events moved").1 + .split_once("),\n outstanding_results").expect("outstanding_results moved").0; + let mut db = SqliteConnection::connect("sqlite::memory:").await.unwrap(); + sqlx::raw_sql("CREATE TABLE events (id INTEGER PRIMARY KEY, session_id TEXT NOT NULL, type TEXT NOT NULL, + payload_json TEXT NOT NULL, ts INTEGER NOT NULL, dedupe_key TEXT); + CREATE INDEX idx_events_session ON events(session_id, ts);") + .execute(&mut db).await.unwrap(); + sqlx::raw_sql(crate::EVENTS_TYPE_INDEX_SQL).execute(&mut db).await.unwrap(); + let sql = format!( + "EXPLAIN QUERY PLAN WITH valid_events AS ({valid_events}) + SELECT id FROM valid_events WHERE type = 'attention_state_observed'" + ); + let plan = sqlx::query(&sql).fetch_all(&mut db).await.unwrap(); + assert!( + plan.iter().any(|row| row.get::("detail").contains("idx_events_type_ts")), + "Attention reads fell back to a table scan" + ); + }); +} diff --git a/src-tauri/src/lib.rs b/src-tauri/src/lib.rs index 7d5a5ad..59dcb41 100644 --- a/src-tauri/src/lib.rs +++ b/src-tauri/src/lib.rs @@ -26,6 +26,11 @@ use tauri::menu::{MenuBuilder, MenuItem, SubmenuBuilder}; use tauri::Manager; use tauri_plugin_sql::{Migration, MigrationKind}; +/// Without this, reads filtered by `events.type` scan the whole table. The +/// Attention Inbox query runs after every hook, so those scans pile up until +/// every database worker is busy. See docs/LANDMINES.md. +const EVENTS_TYPE_INDEX_SQL: &str = "CREATE INDEX IF NOT EXISTS idx_events_type_ts ON events(type, ts);"; + #[cfg_attr(mobile, tauri::mobile_entry_point)] pub fn run() { let migrations = vec![Migration { @@ -240,6 +245,12 @@ pub fn run() { + CAST(substr(strftime('%f', 'now'), 4, 3) AS INTEGER), 'result_review_tracking_started:v1');"#, kind: MigrationKind::Up, + }, + Migration { + version: 15, + description: "index events by type and time", + sql: EVENTS_TYPE_INDEX_SQL, + kind: MigrationKind::Up, }]; tauri::Builder::default() From 1ac0ed04d0c3067dd953266b8438501e2b89e1ad Mon Sep 17 00:00:00 2001 From: Superlogicai Date: Fri, 6 Nov 2026 07:30:01 -1000 Subject: [PATCH 2/3] test(db): make the index check line-ending safe Windows checks repo.ts out with CRLF, so matching a literal newline failed the new test there. The migration itself was unaffected. Co-Authored-By: Claude Opus 5.5 --- src-tauri/src/dashboard_checks.rs | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/src-tauri/src/dashboard_checks.rs b/src-tauri/src/dashboard_checks.rs index 56cdd98..eb07600 100644 --- a/src-tauri/src/dashboard_checks.rs +++ b/src-tauri/src/dashboard_checks.rs @@ -66,7 +66,9 @@ fn attention_event_reads_use_the_type_index() { let repo = include_str!("../../src/lib/repo.ts"); let valid_events = repo .split_once("WITH valid_events AS (").expect("valid_events moved").1 - .split_once("),\n outstanding_results").expect("outstanding_results moved").0; + .split_once("outstanding_results AS").expect("outstanding_results moved").0 + .trim_end() + .trim_end_matches("),"); let mut db = SqliteConnection::connect("sqlite::memory:").await.unwrap(); sqlx::raw_sql("CREATE TABLE events (id INTEGER PRIMARY KEY, session_id TEXT NOT NULL, type TEXT NOT NULL, payload_json TEXT NOT NULL, ts INTEGER NOT NULL, dedupe_key TEXT); From 277e1e786123610d8434eb8234f7a6822302ebc7 Mon Sep 17 00:00:00 2001 From: Superlogicai Date: Fri, 6 Nov 2026 07:35:47 -1000 Subject: [PATCH 3/3] fix(db): index events by time for eventsSince With two agents running, CPU still reached 30-300% after migration 15. Spike samples showed pread under getOverflowPage with JSON parsing near zero: eventsSince filters on ts alone on every side-panel refresh, and ts is stored after payload_json, so each run walked every row's overflow pages. Migration 16 adds events(ts). On a clone, a 1-hour window drops from 919 ms to 8 ms with identical output. The index test now covers both reads and was confirmed to fail with the new index removed. Co-Authored-By: Claude Opus 5.5 --- docs/LANDMINES.md | 16 +++++++++++----- docs/TESTING.md | 32 +++++++++++++++++-------------- src-tauri/src/dashboard_checks.rs | 12 +++++++++++- src-tauri/src/lib.rs | 11 +++++++++++ 4 files changed, 51 insertions(+), 20 deletions(-) diff --git a/docs/LANDMINES.md b/docs/LANDMINES.md index 8187f51..254042d 100644 --- a/docs/LANDMINES.md +++ b/docs/LANDMINES.md @@ -534,8 +534,14 @@ fix is ever reverted or bypassed. Referenced from CLAUDE.md. roughly 100% per busy worker, which is why the top end is about 900%. Migration 15 adds `events(type, ts)`: 12.7 s down to 112 ms on a full clone, with identical output. An explicit `type` filter in the CTE only reached - 9.8 s, and the Phase 68 cleanup alone only 3.7 s. Triage next time: run - `sample 6` and count threads with `sqlite3` frames, plus - `jsonValidFunc` versus `jsonExtractFunc`. Any new read filtering `events` - without a usable index repeats this. `eventsSince` still filters on `ts` - alone and was not fixed here. + 9.8 s, and the Phase 68 cleanup alone only 3.7 s. That left 30-300% with two + agents running: spike samples showed `pread` under `accessPayload` and + `getOverflowPage`, with JSON parsing near zero. `ts` is stored after + `payload_json`, so `eventsSince`, which filters on `ts` alone on every + side-panel refresh, walked each row's overflow pages to reach it. Migration + 16 adds `events(ts)`: 919 ms down to 8 ms for a 1-hour window, with identical + output. Triage next time: run `sample 6` and count threads with + `sqlite3` frames, then compare `jsonValidFunc`, `jsonExtractFunc` and + `getOverflowPage`. CPU spikes are short, so trigger the sample when CPU + crosses a threshold. Any new read filtering `events` without a usable index + repeats this, and a column after `payload_json` is costlier than it looks. diff --git a/docs/TESTING.md b/docs/TESTING.md index 8ba2162..8f61953 100644 --- a/docs/TESTING.md +++ b/docs/TESTING.md @@ -7067,19 +7067,23 @@ with subagents and confirm no "transcript format doesn't match" banner appears. Not yet run; the banner isn't persisted, so the old false trip was only reproduced by replay. -### Events type index, migration 15 (2026-11-06) +### Events indexes, migrations 15 and 16 (2026-11-06) Automated: `cargo test --lib` pins that the Attention query's `valid_events` -read uses `idx_events_type_ts`. On an APFS clone of the maintainer database -(18 GB, warm cache, `node:sqlite`): `listAttentionEvidence` 12.7 s to 112 ms, -`listToolEvents` 1.4 s to 4 ms, `lastLeft` 235 ms to under 1 ms, identical -output hashes, index build 1.6 s. - -Manual, installed app after `npm run reinstall` (not yet run): - -1. Note first launch time; the migration builds on a cold database and may take - longer than 1.6 s. Terminals should appear normally. -2. With agents active, read CPU with `top -l 2 -s 2 -pid -stats cpu,th`. - Before this fix it sat at 500-900%. -3. If CPU stays high, run `sample 6`. `eventsSince` is the next suspect; - it filters on `ts` alone. +read uses `idx_events_type_ts` and that `eventsSince` uses `idx_events_ts`. On +an APFS clone of the maintainer database (18 GB, warm cache, `node:sqlite`): +`listAttentionEvidence` 12.7 s to 112 ms, `listToolEvents` 1.4 s to 4 ms, +`lastLeft` 235 ms to under 1 ms, `eventsSince` 919 ms to 8 ms for a 1-hour +window and 1,560 ms to 670 ms for 7 days. Output hashes were identical. Index +builds took 1.6 s and 1.0 s. + +Migration 15 on the installed app (maintainer, 2026-11-06): applied in 1.29 s on +the real database. CPU fell from 500-900% to 1-3% at idle and 30-300% with two +agents running. + +Manual, installed app after `npm run reinstall` (migration 16 not yet run): + +1. With two or more agents active, read CPU with + `top -l 0 -s 5 -pid -stats cpu,th`. Expect short spikes only. +2. If CPU holds high, run `sample 6` during a spike. CPU spikes are short, + so trigger the sample when CPU crosses a threshold. diff --git a/src-tauri/src/dashboard_checks.rs b/src-tauri/src/dashboard_checks.rs index eb07600..d30c54b 100644 --- a/src-tauri/src/dashboard_checks.rs +++ b/src-tauri/src/dashboard_checks.rs @@ -61,7 +61,7 @@ fn project_decisions_match_source_open_count_without_a_silent_cap() { } #[test] -fn attention_event_reads_use_the_type_index() { +fn hot_event_reads_use_their_indexes() { tauri::async_runtime::block_on(async { let repo = include_str!("../../src/lib/repo.ts"); let valid_events = repo @@ -69,12 +69,16 @@ fn attention_event_reads_use_the_type_index() { .split_once("outstanding_results AS").expect("outstanding_results moved").0 .trim_end() .trim_end_matches("),"); + let events_since = repo + .split_once("`SELECT id, ts, type, payload_json FROM events").expect("eventsSince moved").1 + .split_once('`').expect("eventsSince end missing").0; let mut db = SqliteConnection::connect("sqlite::memory:").await.unwrap(); sqlx::raw_sql("CREATE TABLE events (id INTEGER PRIMARY KEY, session_id TEXT NOT NULL, type TEXT NOT NULL, payload_json TEXT NOT NULL, ts INTEGER NOT NULL, dedupe_key TEXT); CREATE INDEX idx_events_session ON events(session_id, ts);") .execute(&mut db).await.unwrap(); sqlx::raw_sql(crate::EVENTS_TYPE_INDEX_SQL).execute(&mut db).await.unwrap(); + sqlx::raw_sql(crate::EVENTS_TS_INDEX_SQL).execute(&mut db).await.unwrap(); let sql = format!( "EXPLAIN QUERY PLAN WITH valid_events AS ({valid_events}) SELECT id FROM valid_events WHERE type = 'attention_state_observed'" @@ -84,5 +88,11 @@ fn attention_event_reads_use_the_type_index() { plan.iter().any(|row| row.get::("detail").contains("idx_events_type_ts")), "Attention reads fell back to a table scan" ); + let sql = format!("EXPLAIN QUERY PLAN SELECT id, ts, type, payload_json FROM events{events_since}"); + let plan = sqlx::query(&sql).bind(0_i64).bind("tab").bind("session").fetch_all(&mut db).await.unwrap(); + assert!( + plan.iter().any(|row| row.get::("detail").contains("idx_events_ts")), + "eventsSince fell back to a table scan" + ); }); } diff --git a/src-tauri/src/lib.rs b/src-tauri/src/lib.rs index 59dcb41..e278912 100644 --- a/src-tauri/src/lib.rs +++ b/src-tauri/src/lib.rs @@ -31,6 +31,11 @@ use tauri_plugin_sql::{Migration, MigrationKind}; /// every database worker is busy. See docs/LANDMINES.md. const EVENTS_TYPE_INDEX_SQL: &str = "CREATE INDEX IF NOT EXISTS idx_events_type_ts ON events(type, ts);"; +/// `ts` is stored after `payload_json`, so filtering on it without an index +/// walks every row's overflow pages. `eventsSince` does that on each side-panel +/// refresh. See docs/LANDMINES.md. +const EVENTS_TS_INDEX_SQL: &str = "CREATE INDEX IF NOT EXISTS idx_events_ts ON events(ts);"; + #[cfg_attr(mobile, tauri::mobile_entry_point)] pub fn run() { let migrations = vec![Migration { @@ -251,6 +256,12 @@ pub fn run() { description: "index events by type and time", sql: EVENTS_TYPE_INDEX_SQL, kind: MigrationKind::Up, + }, + Migration { + version: 16, + description: "index events by time", + sql: EVENTS_TS_INDEX_SQL, + kind: MigrationKind::Up, }]; tauri::Builder::default()