diff --git a/docs/LANDMINES.md b/docs/LANDMINES.md index 75ff7a4..254042d 100644 --- a/docs/LANDMINES.md +++ b/docs/LANDMINES.md @@ -525,3 +525,23 @@ 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. 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 153636b..8f61953 100644 --- a/docs/TESTING.md +++ b/docs/TESTING.md @@ -7066,3 +7066,24 @@ 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 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` 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 1e65b3e..d30c54b 100644 --- a/src-tauri/src/dashboard_checks.rs +++ b/src-tauri/src/dashboard_checks.rs @@ -59,3 +59,40 @@ fn project_decisions_match_source_open_count_without_a_silent_cap() { } }); } + +#[test] +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 + .split_once("WITH valid_events AS (").expect("valid_events moved").1 + .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'" + ); + 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" + ); + 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 7d5a5ad..e278912 100644 --- a/src-tauri/src/lib.rs +++ b/src-tauri/src/lib.rs @@ -26,6 +26,16 @@ 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);"; + +/// `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 { @@ -240,6 +250,18 @@ 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, + }, + Migration { + version: 16, + description: "index events by time", + sql: EVENTS_TS_INDEX_SQL, + kind: MigrationKind::Up, }]; tauri::Builder::default()