Site event log: severity / event_type filters sort every matching row (slowest query on a full 1 GB log) #123

New Issue

2026-11-10T15:58:37-05:00

dohertj2 commented

2026-11-10 15:58:37 -05:00

Found by the #49 [xc-3] run (docs/plans/2026-11-10-wp4-residual-scope-results.md §3.3, ResidualBench eventlog).

On a full 1 GB / 30-day site_events table (2.36 M rows), equality filters on severity or event_type are the slowest event-log queries:

query (page 500)	first (cold)	warm P50
severity=Error, 30 d	2,287 ms	115 ms
severity=Error, last 24 h	117 ms	105 ms
event_type=alarm, last 24 h	216 ms	149 ms

Every other shape is ≤ 14 ms warm, including the time-window pages and the instance filter.

The cause is visible in EXPLAIN QUERY PLAN. With no ANALYZE statistics, SQLite picks the single-column idx_events_severity / idx_events_type, reads every matching row in the table, and then sorts them (USE TEMP B-TREE FOR ORDER BY) to return 500. So the cost grows with table size, not page size.

This is not a failure: everything is under 0.5 s warm. Possible fixes:

Composite (severity, timestamp) / (event_type, timestamp) indexes. These change the row model the storage-cap estimate is calibrated on, so SiteEventsSchemaCalibrationTests, the cap-semantics calibration and register row 93 would need re-calibrating in the same change.
Run ANALYZE / PRAGMA optimize so the planner prefers idx_events_timestamp with a filter.
Add an INDEXED BY hint when a time window is present.

Found by the #49 `[xc-3]` run (`docs/plans/2026-11-10-wp4-residual-scope-results.md` §3.3, `ResidualBench eventlog`). On a full 1 GB / 30-day `site_events` table (2.36 M rows), equality filters on `severity` or `event_type` are the slowest event-log queries: | query (page 500) | first (cold) | warm P50 | |---|---|---| | severity=Error, 30 d | 2,287 ms | 115 ms | | severity=Error, last 24 h | 117 ms | 105 ms | | event_type=alarm, last 24 h | 216 ms | 149 ms | Every other shape is ≤ 14 ms warm, including the time-window pages and the instance filter. The cause is visible in `EXPLAIN QUERY PLAN`. With no `ANALYZE` statistics, SQLite picks the single-column `idx_events_severity` / `idx_events_type`, reads every matching row in the table, and then sorts them (`USE TEMP B-TREE FOR ORDER BY`) to return 500. So the cost grows with table size, not page size. This is not a failure: everything is under 0.5 s warm. Possible fixes: - Composite `(severity, timestamp)` / `(event_type, timestamp)` indexes. These change the row model the storage-cap estimate is calibrated on, so `SiteEventsSchemaCalibrationTests`, the cap-semantics calibration and register row 93 would need re-calibrating in the same change. - Run `ANALYZE` / `PRAGMA optimize` so the planner prefers `idx_events_timestamp` with a filter. - Add an `INDEXED BY` hint when a time window is present.

dohertj2 added the priority:p3 type:followup labels 2026-11-10 15:58:54 -05:00

dohertj2 referenced this issue from a commit

2026-11-10 16:46:46 -05:00

test(perf): measure phase-8 WP-4 residual criteria xc-3/4/5/8 (#49)

dohertj2 referenced this issue from a commit

2026-11-10 16:46:46 -05:00

fix: outbox KPI per-status legs, composite event-log indexes, AuditLog ingest FORCESEEK (#122, #123, #124)

dohertj2 referenced this issue

2026-11-10 16:47:01 -05:00

Measure WP-4 residual load criteria (site-event-log retention, audit load vs central, large-template flatten, UI under load) #49

dohertj2 commented

2026-11-10 16:47:02 -05:00

Fixed in 424db155 with composite indexes, as decided: idx_events_type_timestamp (event_type, timestamp) and idx_events_severity_timestamp (severity, timestamp) replace the single-column indexes.

SiteEventLogSchema.Apply drops the old two in place on first boot; site-a's file on the rig migrated cleanly. Indexes are not in LocalDb's replicated-table digest, so this does not affect pair sync.

ResidualBench eventlog re-run (full 1 GB, 30 d, page 500):

query	before (cold / warm)	after (cold / warm)
severity=Error, 30 d	2,287 / 115 ms	15 / 1.6 ms
severity=Error, 24 h	117 / 105 ms	2.0 / 1.6 ms
event_type=alarm, 24 h	216 / 149 ms	1.2 / 1.1 ms

Plans now SEARCH … USING INDEX idx_events_severity_timestamp (severity=? AND timestamp>?) with only a last-term (tie) sort; pinned by SchemaIndexTests.

Cost (accepted): 454 → 530 B/row on disk. The 1 GB cap holds 2.03 M rows instead of 2.36 M, and 30 days fit only below 0.78 events/s per site (was 0.91). The CDC-on writer drains 8,760 events/s (was 10,535); the purge tick is unchanged (10.7 s).

Recalibration (register row 93): still four secondary indexes; the sampler now counts timestamp three times. EstimateSiteEventsSize_TracksTheRealFootprint errors are +8.7 % / +12.8 % / −0.5 % (were +8.4 / +12.8 / −0.8), inside the −5…+25 % band with constants unchanged. SiteEventsSchemaCalibrationTests re-pinned; memo §3.2 records it.

Fixed in 424db155 with composite indexes, as decided: `idx_events_type_timestamp (event_type, timestamp)` and `idx_events_severity_timestamp (severity, timestamp)` replace the single-column indexes. `SiteEventLogSchema.Apply` drops the old two in place on first boot; site-a's file on the rig migrated cleanly. Indexes are not in LocalDb's replicated-table digest, so this does not affect pair sync. **`ResidualBench eventlog` re-run (full 1 GB, 30 d, page 500):** | query | before (cold / warm) | after (cold / warm) | |---|---|---| | severity=Error, 30 d | 2,287 / 115 ms | 15 / 1.6 ms | | severity=Error, 24 h | 117 / 105 ms | 2.0 / 1.6 ms | | event_type=alarm, 24 h | 216 / 149 ms | 1.2 / 1.1 ms | Plans now `SEARCH … USING INDEX idx_events_severity_timestamp (severity=? AND timestamp>?)` with only a last-term (tie) sort; pinned by `SchemaIndexTests`. **Cost (accepted):** 454 → 530 B/row on disk. The 1 GB cap holds 2.03 M rows instead of 2.36 M, and 30 days fit only below 0.78 events/s per site (was 0.91). The CDC-on writer drains 8,760 events/s (was 10,535); the purge tick is unchanged (10.7 s). **Recalibration (register row 93):** still four secondary indexes; the sampler now counts `timestamp` three times. `EstimateSiteEventsSize_TracksTheRealFootprint` errors are +8.7 % / +12.8 % / −0.5 % (were +8.4 / +12.8 / −0.8), inside the −5…+25 % band with constants unchanged. `SiteEventsSchemaCalibrationTests` re-pinned; memo §3.2 records it.

dohertj2 closed this issue

2026-11-10 16:47:02 -05:00

Sign in to join this conversation.

1 Participants

Notifications

Due Date

No due date set.

Dependencies

No dependencies set.

Reference: dohertj2/ScadaBridge#123