From ddb3c32e0654ada2876ef4f1ade94511b0b7ff24 Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Mon, 17 Aug 2026 03:58:41 -0400 Subject: [PATCH] fix(siteeventlog): scope the storage cap to site_events' own pages (register rows 81, 84) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Row 81 — the cap could not be enforced on a replicated node. MaxStorageMb was compared against page_count-freelist_count over the WHOLE consolidated LocalDb file, which since Phase 1/2 holds ten tables plus __localdb_oplog / __localdb_row_version / __localdb_snapshot_state. Every 1000-row trim batch freed ~390 KB of site_events pages and added ~1000 oplog rows + ~1000 tombstones to the same file, so the measured size did not fall, the "size did not decrease" guard fired, and the trim stopped 2.5x over a 64 MB cap with 226 k rows still present. A node whose peer was down could not enforce its cap at all, and the event log's budget was in practice shared with bookkeeping it does not own. The cap now measures site_events AND ITS FOUR INDEXES only, so replication bookkeeping can neither consume nor block the budget — and the cap stops being a function of the peer's health, which was the wrong direction of coupling: an inflated oplog is a replication fault, and letting it drive event deletion would destroy operational history in response to one. dbstat — the exact per-table measurement the register proposed — is NOT usable here, verified before implementing. It is a compile-time option and the bundled SQLitePCLRaw.lib.e_sqlite3 (SQLite 3.53.3) does not enable it: PRAGMA compile_options lists no ENABLE_DBSTAT_VTAB, pragma_module_list returns ten modules with neither dbstat nor sqlite_dbpage, and selecting from dbstat fails with "no such table". Switching SQLite builds was rejected — the provider is shared with ZB.MOM.WW.LocalDb and every other consumer, so it trades cap accuracy for fleet-wide version skew. The footprint is therefore modelled from sampled row width (500 rows each end, octet_length so multi-byte UTF-8 is not under-counted) through a page-layout model; whole pages rather than a flat rate, because page fill collapses once rows approach half a page and a linear model underestimates that by ~40%. Clamped by whole-file logical size, a true upper bound that can only correct an over-estimate and never binds on a replicated node. Index pages count against the cap deliberately: measured at ~34% of the table's footprint, and the 1 GB default was sized against a 393 B/row figure that already included them. Guard semantics restated — two backstops replace the single on-disk check: (1) row width unsampleable => refuse to trim (checked before the cap comparison, since a zero width makes "over cap" unanswerable rather than false; the old loop's answer to an unanswerable cap was to keep deleting); (2) estimated size not falling across a batch => stop. (2) is the old guard re-based onto the table-scoped metric, so it can no longer be tripped by replication bookkeeping and now means exactly one thing: events are arriving as fast as the trim removes them. For that to be observable the loop re-reads the row count each batch, while bytes-per-row is sampled once per tick and held fixed — re-sampling per batch would jitter the estimate as the trim eats the head of the table and could stall the loop through guard (2), the same self-defeating measurement as row 81 itself. Row 84 — LogReplicationBacklogNote moved from per-phase to once per tick, driven by the shared PurgeBudget. A tick where retention AND the cap trim both deleted used to emit two identical Information notes; the tick total is also the more useful number beside an oplog spike. Measured model error: -0.8% / +8.4% / +12.8% across representative workloads, biased high on purpose (an early cap forfeits budget; a low one fails at its only job). Independently cross-checks row 34's harness at 397.2 vs 393 B/row. Fail-before: reverting the estimator to whole-file semantics fails 5 of the new tests and reproduces the original signature exactly (remaining=2000 estimate=21725184 cap=11534336 — rows destroyed, cap still unmet); restoring per-phase notes fails the row-84 test with "collection contained 2 matching items". No config keys added or renamed, so no rig/deploy changes. Decision record: docs/plans/2026-08-17-site-event-log-cap-semantics-decision.md Tests: SiteEventLogging 104/104 (was 93), Host 520/520, solution build clean. --- CLAUDE.md | 2 +- docs/deployment/topology-guide.md | 34 ++ ...-15-site-events-purge-burst-measurement.md | 12 + ...7-site-event-log-cap-semantics-decision.md | 264 +++++++++++++ .../Component-SiteEventLogging.md | 50 ++- .../EventLogPurgeService.cs | 336 ++++++++++++++-- .../SiteEventLogOptions.cs | 29 +- .../EventLogPurgeServiceTests.cs | 41 ++ .../EventLogStorageCapScopeTests.cs | 365 ++++++++++++++++++ .../SqliteCapabilityTests.cs | 84 ++++ 10 files changed, 1171 insertions(+), 46 deletions(-) create mode 100644 docs/plans/2026-08-17-site-event-log-cap-semantics-decision.md create mode 100644 tests/ZB.MOM.WW.ScadaBridge.SiteEventLogging.Tests/EventLogStorageCapScopeTests.cs create mode 100644 tests/ZB.MOM.WW.ScadaBridge.SiteEventLogging.Tests/SqliteCapabilityTests.cs diff --git a/CLAUDE.md b/CLAUDE.md index 1a02e3b4..1f3252d4 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -190,7 +190,7 @@ spec for each is `docs/requirements/Component-.md`, and `README.md` carrie - Debug view: real-time streaming via DebugStreamBridgeActor + gRPC (events via `SiteStreamGrpcClient`, snapshot via the `SiteCommandService` query surface — `QueryReply.DebugViewSnapshot`). Health dashboard: 10s polling timer. Deployment status: real-time push via SignalR. - Health reports: 30s interval, 60s offline threshold, monotonic sequence numbers, raw error counts per interval. - Dead letter monitoring as a health metric. -- Site Event Logging: 30-day retention, 1GB storage cap, daily purge, paginated queries with keyword search. +- Site Event Logging: 30-day retention, 1GB storage cap, daily purge, paginated queries with keyword search. **The cap measures `site_events` + its four indexes, NOT the consolidated LocalDb file** (register row 81, 2026-08-17): whole-file measurement made the trim unwinnable on a replicated node — each batch freed event pages while adding an equal count of oplog rows + tombstones to the same file, so it stopped 2.5x over a 64 MB cap and a node with a down peer could not enforce the cap at all. `dbstat` (the exact per-table measurement) is **NOT compiled into the bundled `SQLitePCLRaw.lib.e_sqlite3`** — probed and pinned by `SqliteCapabilityTests`, so don't reach for it — the footprint is modelled from sampled row width instead (−0.8%…+12.8%, biased high). Consequence: `MaxStorageMb` no longer bounds the data volume alone; LocalDb bookkeeping is separate overhead bounded by `MaxOplogRows`/`TombstoneRetention` and is deliberately not this component's job. Decision: `docs/plans/2026-08-17-site-event-log-cap-semantics-decision.md`. - Notification Outbox KPIs are central-computed point-in-time from the `Notifications` table (global + per-source-site): queue depth, stuck count, parked count, delivered-last-interval, oldest-pending age. - Stuck = `Pending`/`Retrying` older than a configurable age threshold (default 10 min) — display-only (KPI count + row badge), no escalation/alerting. - Headline KPI tiles surface on the Health dashboard; a new Central UI Notification Outbox page offers a queryable list with Retry/Discard actions on parked notifications. diff --git a/docs/deployment/topology-guide.md b/docs/deployment/topology-guide.md index b2e69bff..127d8ea9 100644 --- a/docs/deployment/topology-guide.md +++ b/docs/deployment/topology-guide.md @@ -273,6 +273,13 @@ history had expired. An unreplicated node logs only the first line. If a backlog spike has no such line near it in the active node's log, the purge is *not* the explanation and the spike is worth investigating. +The second line is emitted **once per purge tick**, and its count covers the retention purge and +the storage-cap trim together. If you are comparing it against the `Purged N events older than…` +line above it, expect the two numbers to differ whenever the cap trim also ran — the note reports +the tick's whole contribution to the oplog, which is what a backlog spike is made of. (Through +2026-08-16 the note was emitted per phase, so a tick that ran both produced two near-identical +lines; register row 84.) + **A tick that hit the ceiling adds a Warning**, rate-limited to one line per 15 minutes so a converging backlog does not flood the log: @@ -513,6 +520,33 @@ hardening and needs no change to the key design. | Site node | 2 cores | 4 GB | 20 GB | SQLite databases grow with S&F | | SQL Server | 4 cores | 16 GB | 100 GB | Shared across central cluster | +#### Sizing a site's data volume — `MaxStorageMb` is not the whole story + +`ScadaBridge:SiteEventLog:MaxStorageMb` (default **1 GB**) bounds **`site_events` and its four +indexes**, and nothing else. It is deliberately *not* a cap on the consolidated LocalDb file +(register row 81 — decision record +`docs/plans/2026-08-17-site-event-log-cap-semantics-decision.md`). Before that change it did +measure the whole file, which on a replicated node made the cap unenforceable: the trim's own CDC +oplog rows and tombstones grew the file as fast as the deletes shrank it, and the trim stopped +2.5x over cap. Tying the event log's budget to the peer's liveness was the defect, not a feature +worth preserving. + +So budget the volume as the **sum** of: + +- **`MaxStorageMb`** — the event log proper. +- **LocalDb replication bookkeeping** — `__localdb_oplog` and `__localdb_row_version`, bounded + separately by `LocalDb:Replication:MaxOplogRows` (default 1 000 000) and `TombstoneRetention` + (default 7 days). This is transient: it drains as the peer acks and as tombstones expire, but it + is not small during a burst. Measured worst case (register row 34): purging a full 1 GB event log + left **707 MB** of bookkeeping in the file. Unreplicated sites carry none of this — they have no + capture triggers at all. +- **The other eight consolidated tables** plus the separate, unreplicated audit database at + `AuditLog:SiteWriter:DatabasePath`. + +The 20 GB figure above has ample headroom for all three at default settings. Raising +`MaxStorageMb` on a replicated site should be paired with a look at the oplog settings, not done +in isolation. + ### Network Bandwidth - Health reports: ~1 KB per site per 30 seconds = negligible diff --git a/docs/plans/2026-08-15-site-events-purge-burst-measurement.md b/docs/plans/2026-08-15-site-events-purge-burst-measurement.md index d8d72360..89658838 100644 --- a/docs/plans/2026-08-15-site-events-purge-burst-measurement.md +++ b/docs/plans/2026-08-15-site-events-purge-burst-measurement.md @@ -204,6 +204,18 @@ practice shared with replication bookkeeping that the event log does not own. A measure `site_events`' own pages (e.g. `dbstat`) rather than the file, which is a change to the cap's semantics and deserves its own decision. Reported for the register; no row added here. +> **Postscript (2026-08-17) — fixed; register row 81 closed.** The cap now measures `site_events` +> and its four indexes only. One correction to the suggestion above: **`dbstat` turned out to be +> unavailable.** It is a compile-time option and the bundled `SQLitePCLRaw.lib.e_sqlite3` +> (SQLite 3.53.3) does not enable it — `PRAGMA compile_options` lists no `ENABLE_DBSTAT_VTAB`, and +> neither `dbstat` nor `sqlite_dbpage` appears in `pragma_module_list`. The table's footprint is +> therefore *modelled* from sampled row width rather than measured, at −0.8 %…+12.8 % accuracy +> against the numbers in §3.4, biased high on purpose. The "size did not decrease" guard survives, +> re-based onto the table-scoped metric so replication bookkeeping can no longer trip it. Decision +> record, including the probe evidence and why a different SQLite build was rejected: +> `docs/plans/2026-08-17-site-event-log-cap-semantics-decision.md`. §3.4's replicated row is left +> as measured — it is the record of the defect, not of current behaviour. + ## 6. Verification - Fail-before: the new behavioural tests do not compile against pre-fix `EventLogPurgeService` diff --git a/docs/plans/2026-08-17-site-event-log-cap-semantics-decision.md b/docs/plans/2026-08-17-site-event-log-cap-semantics-decision.md new file mode 100644 index 00000000..357ebc6e --- /dev/null +++ b/docs/plans/2026-08-17-site-event-log-cap-semantics-decision.md @@ -0,0 +1,264 @@ +# `site_events` storage cap — what the cap measures (register row 81) + +**Date:** 2026-08-17 +**Row:** deferred-work register #81 — *"the storage cap fights its own oplog."* +**Outcome:** cap semantics changed. `ScadaBridge:SiteEventLog:MaxStorageMb` now bounds +**`site_events` and its four indexes**, not the whole consolidated LocalDb file. `dbstat` — the +exact measurement the register proposed — turned out to be **unavailable in the SQLite this +solution ships**, so the table's footprint is *modelled* from sampled row width. This memo records +the probe that ruled `dbstat` out, the model, its measured accuracy, and the new meaning of the +wipe-prevention guard. + +--- + +## 1. The defect + +Since LocalDb Phase 1/2 the site keeps ten tables in one SQLite file at `LocalDb:Path`, alongside +LocalDb's own `__localdb_oplog`, `__localdb_row_version` and `__localdb_snapshot_state` +bookkeeping. `EventLogPurgeService.GetDatabaseSizeBytes()` measured +`page_count − freelist_count` over **that whole file** and compared it to `MaxStorageMb`. + +On a replication-enabled node the cap trim therefore fought itself. Every 1000-row batch freed +~390 KB of `site_events` pages *and* pushed ~1000 rows into `__localdb_oplog` plus ~1000 +row-version tombstones into the same file. The measured size did not fall, the existing +"size did not decrease across an iteration" guard fired, and the trim stopped — with the cap +unmet. + +Measured 2026-08-16 during the row-34 work +(`docs/plans/2026-08-15-site-events-purge-burst-measurement.md` §3.4/§5), 64 MB cap, 400 000 rows: + +| Replicated? | Events deleted | Remaining | Size before → after | Reached the cap? | +| --- | ---: | ---: | --- | --- | +| no | 248 000 | 152 000 | 158.0 MB → 66.98 MB | **yes** (cap 67.11 MB) | +| yes | 174 000 | 226 000 | 203.6 MB → 167.7 MB | **no — stopped 2.5x over cap** | + +Two consequences, both real: + +1. **A node whose peer is down cannot enforce its event-log cap at all.** Nothing drains the + oplog, so the file never shrinks and the guard stops the trim every tick, forever. +2. **The "1 GB event log" budget was in practice shared with replication bookkeeping the event + log does not own.** Worse, the direction of the coupling is backwards: a *replication fault* + (peer down, oplog piling up) would, under a naive "just keep deleting" fix, cause operational + event history to be destroyed. The cap must not be a function of the peer's health. + +The old guard was not the bug — it was doing its job, preventing the table being wiped in pursuit +of an unreachable target. The bug is that the target was unreachable, because the metric was +wrong. + +## 2. `dbstat` is not available — the decision this memo turns on + +The register proposed `SELECT sum(pgsize) FROM dbstat WHERE name='site_events'`. `dbstat` is a +**compile-time option** (`SQLITE_ENABLE_DBSTAT_VTAB`), and it was verified before any +implementation was written. It is **not enabled** in the native library this solution ships +(`SQLitePCLRaw.lib.e_sqlite3`, the security-pinned 2.1.12 build referenced by both +`ZB.MOM.WW.ScadaBridge.SiteEventLogging` and its test project). + +Probed live against a real file, SQLite **3.53.3**: + +``` +PRAGMA compile_options -> no ENABLE_DBSTAT_VTAB + (ENABLE_FTS3/4/5, RTREE, GEOPOLY, SESSION, PREUPDATE_HOOK, … present) +pragma_module_list -> 10 modules: fts3, fts3tokenize, fts4, fts4aux, fts5, fts5vocab, + geopoly, pragma_module_list, rtree, rtree_i32 +SELECT sum(pgsize) FROM dbstat -> SQLite Error 1: 'no such table: dbstat' +SELECT … FROM dbstat('main') WHERE name=… -> SQLite Error 1: 'no such table: dbstat' +``` + +`sqlite_dbpage` — the other route to per-table page attribution — is absent for the same reason. +The module list is non-empty, so this is a genuine absence and not an empty-result artefact. + +**This is pinned by a committed test**, `SqliteCapabilityTests.DbStat_IsNotAvailable_…`, written to +fail if `dbstat` ever appears. If it does, the right move is to delete the model in §3 and measure +exactly; the test's own comment says so. + +Alternatives considered and rejected: + +- **Switch to a SQLite build that enables `dbstat`** (system `libsqlite3` via + `SQLitePCLRaw.bundle_sqlite3`, or a vendored native build). Rejected: the provider is shared with + `ZB.MOM.WW.LocalDb` and every other SQLite consumer in the product, so this trades a storage-cap + accuracy problem for fleet-wide version skew across macOS dev boxes and the Debian-based runtime + image — a disproportionate blast radius for a coarse safety valve. +- **Give `site_events` its own file again.** Reverses LocalDb Phase 1/2 consolidation and removes + the table from CDC replication. Out of the question. +- **Maintain a running byte counter in the writer, or via triggers.** The writer is not the only + thing that inserts into `site_events` (replication applies remote rows), a counter does not + survive a restart, and adding our own triggers to a `RegisterReplicated` table is hazardous — + LocalDb builds its capture triggers from the column list at registration time and extra triggers + would also fire on replicated applies. +- **Keep the whole-file metric and simply stop re-measuring mid-loop** (compute a delete plan once + and execute it). This makes the trim terminate, but it makes the *event log* pay for bookkeeping + bytes: an oplog inflated by a down peer would drive aggressive deletion of operational history. + That is consequence 2 above, made worse rather than fixed. + +## 3. What the cap measures now + +`EventLogPurgeService.EstimateSiteEventsSize()` returns the live row count and modelled bytes per +row. `MaxStorageMb` is compared against `rowCount × bytesPerRow`. + +Row width is **sampled** — `SizeSampleRows` (500) rows from each end of the table, head and tail. +The head is what the oldest-first trim will actually delete; the tail catches an event stream whose +shape has drifted. Widths are taken with `octet_length()` (SQLite 3.43+), not `length()`, which +counts characters and would under-size any multi-byte UTF-8 message; a second committed test pins +that function's availability. + +The table term is computed as **whole pages**, `ceil(rows / rowsPerPage) × pageSize`, rather than +as a flat bytes-per-row rate: + +``` +usablePerPage = (pageSize - 35) * 0.78 // max-local-payload rule × measured mean page fill +avgCellBytes = avgPayloadBytes + 16 // payload-length varint, rowid varint, cell pointer +rowsPerPage = max(1, floor(usablePerPage / avgCellBytes)) +tableBytes = ceil(rowCount / rowsPerPage) * pageSize +indexBytes = rowCount * (avgIndexedBytes + 8 * 4) / 0.75 +estimate = min(tableBytes + indexBytes, wholeFileLogicalBytes) +``` + +Whole pages rather than a rate because that term **dominates once rows approach half a page**: a +2 KB row cannot be packed two-to-a-page, so each one wastes the remainder. A linear model +underestimates that case by ~40 % (measured), and underestimating is the failure direction that +matters for a cap. + +**Index pages count against the cap — deliberately.** Measured, the four indexes are ~34 % of +`site_events`' total footprint (397.2 vs 260.9 bytes/row with and without them, same 200 000 rows), +and the 1 GB default was sized against the 393 bytes/row figure from row 34, which already included +them. Excluding index pages would silently raise real disk consumption by about a third at an +unchanged setting. The index term is driven by the *sampled* widths of the four indexed columns, so +an event stream that leaves `instance_id` null is charged less than one that fills it. + +**Clamped by the file.** The whole-file logical size is a true upper bound on any single table's +pages, so the model is capped by it. This can only ever correct an over-estimate downward, and it +cannot reintroduce the row-81 defect: on a replicated node the file is *larger* than +`site_events`, never smaller, so the clamp does not bind there. + +`GetDatabaseSizeBytes()` survives, renamed in meaning rather than in signature: it is the whole +consolidated file's logical size, used for the clamp and as a diagnostic. It is no longer what the +cap compares against. + +### 3.1 Measured accuracy + +Calibration seeded realistic rows into a real file and measured `page_count`/`freelist_count`/ +`page_size`. Two independent cross-checks against row 34's harness: the baseline workload came out +at **397.2 bytes/row** against row 34's independently measured **393**, and the row-count-at-1 GB +figure follows. + +| Workload | rows | actual bytes/row | payload bytes/row | +| --- | ---: | ---: | ---: | +| 1-in-10 details @200 B (baseline) | 200 000 | 397.2 | 187.9 | +| same, **no indexes** | 200 000 | 260.9 | 187.9 | +| no details at all | 200 000 | 373.5 | 167.7 | +| details on every row @200 B | 200 000 | 597.7 | 367.7 | +| details on every row @2 KB | 50 000 | 4295.2 | 2215.7 | +| 1-in-10 details @4 KB | 50 000 | 824.7 | 583.0 | +| small table | 5 000 | 396.5 | 189.6 | + +The shipped model, scored against a **differential** measurement of the table's real page cost +(file measured with ballast only, events added, growth attributed to `site_events`) — this is +`EstimateSiteEventsSize_TracksTheRealFootprint`, run on every build: + +| Workload | estimated | actual | error | +| --- | ---: | ---: | ---: | +| narrow rows, no details | 3 155 626 | 2 912 256 | **+8.4 %** | +| typical rows, 200 B details | 3 992 096 | 3 538 944 | **+12.8 %** | +| wide rows, 2 KB details | 12 748 048 | 12 845 056 | **−0.8 %** | + +The test asserts the band **−5 % … +25 %**. The bias is intentionally to the high side: a cap that +fires slightly early forfeits a slice of the budget, whereas one that reads low lets the log +overrun the disk allowance the cap exists to defend. Against the previous behaviour's **+250 %** +error on a replicated node this is not a close call. + +**Known limitation.** The model samples 1000 rows out of a table that may hold millions. An event +stream whose row width changes sharply *in the middle* of the history — neither at the head nor the +tail — is mis-sized until the trim reaches it. Self-correcting in practice, since the cap is +re-evaluated every tick and the head sample advances as the oldest rows go. + +## 4. The wipe-prevention guard, restated + +The register asked whether the "size did not decrease" guard should survive. It should, and it +does, but its meaning has changed and it has gained a sibling. There are now **two** backstops: + +1. **Unusable row width → refuse to trim.** Checked *before* the cap comparison, because a zero + bytes-per-row makes "is `site_events` over cap" unanswerable rather than false. Logs a Warning + naming the row count and deletes nothing. The old code had no analogue: its answer to an + unanswerable cap was to keep deleting until the file shrank, which is exactly how a cap that can + never be met empties a table. + +2. **Estimated size did not decrease across a batch → stop.** The old guard, re-based onto the + table-scoped metric. Crucially it **can no longer be tripped by replication bookkeeping** — the + metric excludes it — so when it fires it now means precisely one thing: the table is not + shrinking even though deletes are landing, i.e. **new events are arriving at least as fast as + the trim removes them.** That is a real operational condition and the Warning says so. + + For this to be observable rather than tautological, the loop re-reads the **row count** from the + database after each batch instead of decrementing a local counter, so concurrent recorder writes + are visible. Bytes-per-row, by contrast, is sampled **once per tick and held fixed** — re-sampling + every batch would make the estimate jitter as the trim consumes the head of the table, and a + sample that happened to widen could stall the loop through this very guard. That is the same + class of self-defeating measurement as row 81 itself, and it is deliberately avoided. + +Both backstops are covered by tests that pin a degenerate estimate through `internal virtual` +seams (`EstimateSiteEventsSize`, `GetSiteEventsRowCount`). + +## 5. Behaviour on an UNREPLICATED node + +Materially unchanged, as intended — but not bit-identical, and the delta is worth stating. + +On a node with no CDC triggers there is no oplog and no tombstone table, so whole-file logical size +was already ≈ `site_events` + the nine other (largely small) tables. The cap therefore used to fire +at roughly the right place, and the row-34 measurement confirms it: the unreplicated trim reached +66.98 MB against a 67.11 MB cap. + +What changes: + +- **Slightly more headroom.** The other nine tables no longer count against the event log's budget. + On a rig-shaped site those tables are small relative to a 1 GB event log, so the shift is a few + percent at most. +- **Model error replaces measurement error.** Where the old number was exact-but-wrong-scoped, the + new one is right-scoped but carries the +8 %/+13 % conservative bias of §3.1. Net effect on an + unreplicated node: the cap fires marginally earlier than before at the same setting. + +Neither warrants a config change. Sites that were happy with `MaxStorageMb: 1024` remain so. + +## 6. Explicitly out of scope: LocalDb's own bookkeeping + +This change makes the cap ignore `__localdb_oplog`, `__localdb_row_version` and +`__localdb_snapshot_state`. It does **not** attempt to manage them, and should not. + +Their size is governed by LocalDb's own machinery — `LocalDb:Replication:MaxOplogRows` (default +1 000 000) and `TombstoneRetention` (default 7 days) — and row 34's pacing +(`MaxPurgedRowsPerTick`) is what keeps a purge burst from blowing through the oplog cap and forcing +a snapshot resync. Those are the correct controls and they already exist. A second, competing +bound applied from the event log would only obscure which subsystem is responsible for a full disk. + +The honest statement of the budget is therefore: **`MaxStorageMb` bounds `site_events` and its +indexes; LocalDb replication bookkeeping is separate overhead on the same volume, bounded +separately.** Sizing a site's data volume means adding the two, and the topology guide now says so. +Row 34's measurement gives the scale — a 2.73 M-row purge left 707 MB of bookkeeping in the file +after deleting a 1 GB event log — and that overhead is transient, draining as the peer acks and as +tombstones expire. + +## 7. Verification + +- **`dbstat` unavailability probed before any implementation was written**, on a real file, with + the result recorded in §2 and pinned by `SqliteCapabilityTests`. +- **Fail-before, row 81.** With `EstimateSiteEventsSize` reverted to pre-row-81 semantics (whole + file attributed to `site_events`) and nothing else changed, **5 of the new tests fail** and all + 99 others pass. `PurgeByStorageCap_WithLargeBallastInTheSameFile_StillEnforces…` reproduces the + original signature exactly: `remaining=2000 estimate=21725184 cap=11534336` — 4000 of 6000 rows + destroyed and the cap **still unmet**. +- **Fail-before, row 84.** With per-phase emission restored, + `RunPurge_WhenBothPhasesDeleteRows_LogsTheBacklogNoteOnceForTheWholeTick` fails with + `Assert.Single() Failure: The collection contained 2 matching items`. +- `dotnet build ZB.MOM.WW.ScadaBridge.slnx` — clean, 0 warnings. +- `ZB.MOM.WW.ScadaBridge.SiteEventLogging.Tests`: **104 passed / 0 failed** (93 before this change). +- The docker rig was not touched. + +## 8. Register row 84, folded in + +`LogReplicationBacklogNote` was emitted by each purge phase, so a tick in which the retention purge +*and* the cap trim both deleted rows produced two identical Information notes. It is now emitted +once from `RunPurge`, driven by the tick's shared `PurgeBudget`. + +The budget is the natural source: it already holds exactly "rows this tick deleted", which is also +the more useful number to put next to an oplog spike — the tick's whole contribution rather than +one phase's share. `PurgeByRetention` keeps its own "Purged N events older than D days" line; only +the replication note moved. diff --git a/docs/requirements/Component-SiteEventLogging.md b/docs/requirements/Component-SiteEventLogging.md index 7a40c737..8c374e76 100644 --- a/docs/requirements/Component-SiteEventLogging.md +++ b/docs/requirements/Component-SiteEventLogging.md @@ -93,7 +93,50 @@ Each event entry contains: rig's site-b/site-c), the log stays node-local and a failover does start it fresh — the documented trade of not configuring a peer, unchanged by this policy. - **Retention**: 30 days. A **daily background job** runs on the active node and deletes all events older than 30 days. Hard delete — no archival. Deletes are sliced into bounded 1000-row batches per DELETE statement rather than one unbounded statement, so a large expired backlog does not hold the write lock (and every concurrent recorder flush) for the duration of the purge. -- **Storage cap**: A configurable maximum database size (default: 1 GB) is enforced. If the storage cap is reached before the 30-day retention window, the oldest events are purged first. This prevents disk exhaustion from alarm storms, script failure loops, or connection flapping. +- **Storage cap**: A configurable maximum size (default: 1 GB) is enforced. If the cap is reached + before the 30-day retention window, the oldest events are purged first. This prevents disk + exhaustion from alarm storms, script failure loops, or connection flapping. +- **The cap measures `site_events` and its four indexes — NOT the database file** (register row 81; + decision record `docs/plans/2026-08-17-site-event-log-cap-semantics-decision.md`). This matters + because the event log shares one SQLite file with nine other tables plus LocalDb's + `__localdb_oplog` / `__localdb_row_version` / `__localdb_snapshot_state` bookkeeping. The cap used + to compare `MaxStorageMb` against `page_count − freelist_count` over that whole file, which on a + replication-enabled node made the trim **unwinnable**: each 1000-row delete freed ~390 KB of event + pages while adding ~1000 oplog rows and ~1000 tombstones to the same file, the measured size did + not fall, and the progress guard stopped the trim — measured 2.5x over a 64 MB cap with 226 k rows + still present. A node whose peer was down could not enforce its cap at all. Two consequences of + the new scoping are worth internalising: + - **The cap is now independent of replication health.** It was previously a function of the + *peer's* liveness, and in the wrong direction — an inflated oplog is a replication fault, and + letting it drive event deletion would destroy operational history in response to one. + - **`MaxStorageMb` no longer bounds the data volume on its own.** LocalDb bookkeeping is separate + overhead on the same disk, bounded separately by `LocalDb:Replication:MaxOplogRows` and + `TombstoneRetention`; sizing a site's volume means adding the two. Managing that bookkeeping is + deliberately **not** this component's job — see the decision record §6. +- **The measurement is modelled, not exact.** SQLite can report per-table page usage precisely via + the `dbstat` virtual table, and that was the intended fix — but `dbstat` is a compile-time option + and the bundled `SQLitePCLRaw.lib.e_sqlite3` native library (SQLite 3.53.3) does **not** enable it; + neither `dbstat` nor `sqlite_dbpage` exists, verified by probe and pinned by + `SqliteCapabilityTests`. The table's footprint is therefore estimated from sampled row width + (500 rows from each end of the table, measured with `octet_length` so multi-byte UTF-8 is not + under-counted) fed into a page-layout model; index pages count against the cap, deliberately, + because they are ~34 % of the table's real footprint and the 1 GB default was sized against a + bytes/row figure that included them. Measured error is **−0.8 % to +12.8 %** across representative + workloads, biased high on purpose — a cap that fires slightly early forfeits budget, whereas one + that reads low fails at the only job it has. The estimate is additionally clamped by the + whole-file logical size, which is a true upper bound on any one table. +- **Two wipe-prevention backstops** guard the cap trim, replacing the single "on-disk size did not + decrease" check. (1) If row width cannot be sampled, the trim **refuses to run** and warns — + checked before the cap comparison, because a zero row width makes "are we over cap" unanswerable + rather than false, and the old loop's answer to an unanswerable cap was to keep deleting. (2) If + the *estimated table size* fails to fall across a batch, the trim stops and warns. Guard (2) is the + old check re-based onto the table-scoped metric, and its meaning is now unambiguous: replication + bookkeeping can no longer trip it, so it fires only when new events are arriving at least as fast + as the trim removes them. For that to be observable, the loop re-reads the row count from the + database after every batch, while bytes-per-row is sampled **once per tick and held fixed** — + re-sampling per batch would make the estimate jitter as the trim eats the head of the table and + could stall the loop through guard (2), which is the same self-defeating-measurement failure as + row 81 itself. - **Per-tick delete ceiling** (`MaxPurgedRowsPerTick`, default **250 000**; `0` = unlimited): one purge tick deletes at most this many rows, **shared** by the retention purge and the storage-cap trim — two independently-capped phases would let a tick emit twice the intended burst. A tick that @@ -128,7 +171,10 @@ Each event entry contains: replication fault and not the purge. The purge logs an Information line naming the row count and the expected transient backlog whenever it deletes rows on a replication-enabled node, so an operator can correlate a spike with the purge that caused it — a spike with no such line nearby is - not the purge. Node-local wiring: the Host supplies the replication predicate + not the purge. That line is emitted **once per tick**, carrying the retention purge's and the cap + trim's deletes combined (register row 84 — it used to fire once per phase, so a tick in which both + deleted produced two identical notes; the tick total is also the more useful number to put beside + an oplog spike). Node-local wiring: the Host supplies the replication predicate (`SiteLocalDbSetup.ReplicationIsConfigured` — the `PeerAddress`-OR-`ApiKey` rule) as `SiteEventLogReplicationCheck`; this component never reads LocalDb configuration itself, and with no predicate registered the note is suppressed. Operator detail — diff --git a/src/ZB.MOM.WW.ScadaBridge.SiteEventLogging/EventLogPurgeService.cs b/src/ZB.MOM.WW.ScadaBridge.SiteEventLogging/EventLogPurgeService.cs index fad27c36..3055c5df 100644 --- a/src/ZB.MOM.WW.ScadaBridge.SiteEventLogging/EventLogPurgeService.cs +++ b/src/ZB.MOM.WW.ScadaBridge.SiteEventLogging/EventLogPurgeService.cs @@ -1,3 +1,5 @@ +using System.Globalization; +using Microsoft.Data.Sqlite; using Microsoft.Extensions.Hosting; using Microsoft.Extensions.Logging; using Microsoft.Extensions.Options; @@ -60,6 +62,40 @@ public class EventLogPurgeService : BackgroundService /// Number of events deleted per retention-purge batch — same size as . private const int RetentionPurgeBatchSize = 1000; + /// + /// Rows sampled from each end of site_events when sizing an average row. See + /// . + /// + private const int SizeSampleRows = 500; + + /// + /// Per-row bookkeeping a table B-tree leaf spends on top of the row's own bytes: the + /// payload-length varint, the rowid varint and the 2-byte cell-pointer slot. + /// + private const int TableCellOverheadBytes = 16; + + /// + /// Bytes at the end of a page SQLite will not fill with local payload — the + /// pageSize - 35 maximum-local-payload rule for table leaves. + /// + private const int PageReservedBytes = 35; + + /// + /// Average proportion of a table leaf page that actually holds rows. B-tree splits leave + /// pages part-empty; 0.78 is the measured mean across the workloads in + /// docs/plans/2026-08-17-site-event-log-cap-semantics-decision.md §3. + /// + private const double TablePageFillFactor = 0.78; + + /// Number of indexes on site_events (timestamp, event_type, instance_id, severity). + private const int IndexedColumnCount = 4; + + /// Per-entry bookkeeping in an index B-tree leaf: key-length varint, rowid and cell pointer. + private const int IndexEntryOverheadBytes = 8; + + /// Average fill of an index leaf page; measured alongside . + private const double IndexPageFillFactor = 0.75; + /// Minimum spacing between ceiling-reached log lines; see . private static readonly TimeSpan CeilingLogInterval = TimeSpan.FromMinutes(15); @@ -186,6 +222,14 @@ public class EventLogPurgeService : BackgroundService PurgeByRetention(budget); PurgeByStorageCap(budget); + // Register row 84: emitted ONCE per tick, from the tick's shared budget, rather + // than once per phase. A tick in which both the retention purge and the cap trim + // deleted rows used to log two identical Information notes; the number an operator + // wants next to the oplog spike is the tick total anyway, which is exactly what + // the shared budget already holds. + if (budget.Deleted > 0) + LogReplicationBacklogNote(budget.Deleted); + if (!budget.StoppedAtCeiling) return false; @@ -290,10 +334,7 @@ public class EventLogPurgeService : BackgroundService } if (totalDeleted > 0) - { _logger.LogInformation("Purged {Count} events older than {Days} days", totalDeleted, _options.RetentionDays); - LogReplicationBacklogNote(totalDeleted); - } } /// @@ -318,9 +359,17 @@ public class EventLogPurgeService : BackgroundService /// /// Emits the operator breadcrumb that explains the oplog backlog spike a purge produces on a - /// replication-enabled node. No-op when this node has no replication peer. + /// replication-enabled node — once per purge tick. No-op when this node has no + /// replication peer. /// /// + /// + /// Called from rather than from each phase (register row 84). Both the + /// retention purge and the cap trim generate the same CDC cost, and a tick in which both + /// deleted rows used to emit two identical Information notes. One note carrying the tick's + /// combined total is what an operator correlating an oplog spike actually wants. + /// + /// /// site_events is a replicated table, and a retention/cap DELETE is captured by CDC /// exactly like an ordinary write — there is deliberately no purge-exemption path (LocalDb /// Phase 2: CDC does all three jobs). The daily purge therefore pushes one oplog row per @@ -329,8 +378,12 @@ public class EventLogPurgeService : BackgroundService /// on its own; without this line an operator correlating the spike has nothing in the log to /// tie it to. Information level because it is only interesting next to the purge line it /// follows — the spike itself is not a fault. + /// /// - /// Number of rows the purge just deleted; always > 0 at the call sites. + /// + /// Rows deleted by the WHOLE tick — retention purge and cap trim combined, read off the + /// shared . Always > 0 at the single call site. + /// private void LogReplicationBacklogNote(int deletedRows) { bool replicated; @@ -358,13 +411,52 @@ public class EventLogPurgeService : BackgroundService _options.MaxPurgedRowsPerTick > 0 ? _options.MaxPurgedRowsPerTick.ToString() : "unlimited"); } + /// + /// Trims the oldest events until site_events' own footprint is back under + /// . + /// + /// + /// + /// The cap is table-scoped as of register row 81. It used to compare + /// against the whole consolidated LocalDb + /// file, which on a replication-enabled node made the trim unwinnable: every batch freed + /// event pages and added an equal number of oplog rows and row-version tombstones to the + /// same file, so the measured size did not fall and the progress guard stopped the trim + /// 2.5x over cap with 226 k rows still present. The cap now measures + /// — site_events and its four indexes only — + /// so replication bookkeeping can no longer consume, or block, the event log's budget. + /// + /// + /// Bytes-per-row is sampled ONCE per tick and held fixed for the whole loop, while the row + /// count is re-read after each batch. That split is deliberate: re-sampling row width every + /// batch would make the estimate jitter as the trim consumes the head of the table, and a + /// sample that happened to widen could stall the loop through the progress guard below — + /// the same class of self-defeating measurement row 81 was about. + /// + /// /// The tick's shared delete budget, already drawn down by the retention purge. private void PurgeByStorageCap(PurgeBudget budget) { var capBytes = (long)_options.MaxStorageMb * 1024 * 1024; - var currentSizeBytes = GetDatabaseSizeBytes(); + var estimate = EstimateSiteEventsSize(); - if (currentSizeBytes <= capBytes) + if (estimate.RowCount <= 0) + return; + + // Wipe-prevention backstop, first of two — checked BEFORE the cap comparison, because a + // zero row width makes "site_events is over cap" unanswerable rather than false. An + // unusable width (empty sample, degenerate estimate) used to have no analogue: the old + // loop's answer to an unanswerable cap was to keep deleting. Refuse instead. + if (estimate.BytesPerRow <= 0) + { + _logger.LogWarning( + "Storage-cap trim skipped: site_events row width could not be sampled ({Rows} rows). " + + "No rows are deleted rather than trimming against an unusable size estimate.", + estimate.RowCount); + return; + } + + if (estimate.EstimatedBytes <= capBytes) return; // Over cap but out of budget: flag the catch-up tick and stay silent rather than logging @@ -378,14 +470,18 @@ public class EventLogPurgeService : BackgroundService } _logger.LogWarning( - "Event log size {Size:F1} MB exceeds cap {Cap} MB — purging oldest events", - currentSizeBytes / (1024.0 * 1024.0), _options.MaxStorageMb); + "site_events occupies about {Size:F1} MB across {Rows} rows — over the {Cap} MB cap. " + + "Trimming the oldest events. (The cap measures the event table and its indexes only, " + + "not the whole consolidated LocalDb file.)", + estimate.EstimatedBytes / (1024.0 * 1024.0), estimate.RowCount, _options.MaxStorageMb); - // Delete the oldest events in batches until the database is under the cap. - // The loop also stops if the on-disk size fails to decrease across an - // iteration (e.g. if vacuum cannot reclaim space), so a cap that can never - // be met does not silently empty the entire table. + // Delete the oldest events in batches until the ESTIMATED TABLE size is under the cap. + // Wipe-prevention backstop, second of two: the loop also stops if the estimate fails to + // fall across an iteration. Replication bookkeeping can no longer trip that — the metric + // excludes it — so it now means what it says: the table is not shrinking, because a batch + // deleted nothing or because concurrent recorder writes are outrunning the trim. var totalDeleted = 0; + var currentSizeBytes = estimate.EstimatedBytes; while (currentSizeBytes > capBytes) { @@ -430,57 +526,213 @@ public class EventLogPurgeService : BackgroundService totalDeleted += deleted; budget.Record(deleted); - currentSizeBytes = GetDatabaseSizeBytes(); + + // Row count re-read from the database, not decremented locally, so concurrent + // recorder writes are visible; row width stays fixed for the tick (see remarks). + currentSizeBytes = (long)(GetSiteEventsRowCount() * estimate.BytesPerRow); if (currentSizeBytes >= previousSizeBytes) { - // Size is not shrinking despite deletes — stop rather than wipe the - // whole table. This should not happen now that logical size is - // measured, but guards against any future regression. _logger.LogWarning( - "Event log size did not decrease after a cap-purge batch ({Size:F1} MB); " + - "stopping to avoid emptying the log", + "Estimated site_events size did not decrease after a cap-purge batch " + + "({Size:F1} MB); stopping to avoid emptying the log. Deletes are landing, so " + + "this means new events are arriving at least as fast as the trim removes them.", currentSizeBytes / (1024.0 * 1024.0)); break; } } - - // Same CDC cost as the retention purge above — a cap-driven trim is usually the - // larger of the two, so it gets the same operator breadcrumb. - if (totalDeleted > 0) - { - LogReplicationBacklogNote(totalDeleted); - } } /// - /// Returns the logical size of the database in bytes — only pages that hold live - /// data, excluding free pages on the freelist. Measuring logical size (rather than - /// the raw file size from page_count) means the storage-cap loop observes - /// space being reclaimed even if free pages have not yet been returned to the OS. + /// Returns the logical size of the WHOLE consolidated database file in bytes — only pages + /// that hold live data, excluding free pages on the freelist. /// - /// The logical database size in bytes (used pages × page size). + /// + /// + /// This is no longer what the storage cap measures (register row 81, + /// docs/plans/2026-08-17-site-event-log-cap-semantics-decision.md). Since LocalDb + /// Phase 1/2 the file holds ten tables plus __localdb_oplog, + /// __localdb_row_version and __localdb_snapshot_state, so a whole-file + /// number is not site_events' size: on a replication-enabled node each cap-trim + /// batch freed ~390 KB of event pages while adding ~1000 oplog rows and ~1000 tombstones + /// to the same file, and the trim fought itself to a standstill 2.5x over cap. + /// + /// + /// It survives for two narrow jobs: it is a true UPPER BOUND on site_events' own + /// pages, which uses to clamp an over-eager model, + /// and it remains a useful diagnostic for the file as a whole. + /// + /// + /// The logical size of the whole database file in bytes (used pages × page size). internal long GetDatabaseSizeBytes() + { + return _eventLogger.WithConnection(connection => ReadLogicalFileBytes(connection)); + } + + /// Logical size of the whole file, on an already-held connection. + /// An open connection to the consolidated database. + /// Used pages × page size, in bytes. + private static long ReadLogicalFileBytes(SqliteConnection connection) + { + var pageCount = ReadPragmaLong(connection, "PRAGMA page_count"); + var freeListCount = ReadPragmaLong(connection, "PRAGMA freelist_count"); + var pageSize = ReadPragmaLong(connection, "PRAGMA page_size"); + return Math.Max(0, pageCount - freeListCount) * pageSize; + } + + /// Reads a single-value PRAGMA as a 64-bit integer. + /// An open connection. + /// The PRAGMA statement to run. + /// The PRAGMA's value. + private static long ReadPragmaLong(SqliteConnection connection, string pragma) + { + using var cmd = connection.CreateCommand(); + cmd.CommandText = pragma; + return Convert.ToInt64(cmd.ExecuteScalar(), CultureInfo.InvariantCulture); + } + + /// + /// How many rows site_events currently holds, and how many bytes of the file one + /// average row occupies — the two numbers the storage cap is expressed in. + /// + /// Live row count at the time of the estimate. + /// + /// Modelled file bytes per row, table pages plus index pages. 0 when the table is + /// empty or the sample could not be sized, which the cap trim treats as "do not trim". + /// + internal readonly record struct SiteEventsSizeEstimate(long RowCount, double BytesPerRow) + { + /// Modelled total bytes site_events occupies in the file. + public long EstimatedBytes => (long)(RowCount * BytesPerRow); + } + + /// + /// Estimates how much of the consolidated file site_events — and only + /// site_events — occupies, by sampling average row width and modelling SQLite's + /// page layout. + /// + /// + /// + /// Why a model and not a measurement. SQLite can report per-table page usage + /// exactly through the dbstat virtual table, and that was the intended fix for + /// register row 81 — but dbstat is a compile-time option and the + /// SQLitePCLRaw.lib.e_sqlite3 native build this solution ships does NOT enable it. + /// Probed directly (SqliteCapabilityTests): PRAGMA compile_options on + /// SQLite 3.53.3 lists no ENABLE_DBSTAT_VTAB, pragma_module_list returns ten + /// modules (fts3/4/5, rtree, geopoly) with neither dbstat nor sqlite_dbpage + /// among them, and selecting from dbstat fails with "no such table". So an exact + /// per-table page count is not obtainable from this provider at all, and the cap is + /// modelled instead. That trade is recorded in + /// docs/plans/2026-08-17-site-event-log-cap-semantics-decision.md. + /// + /// + /// The model. Rows are sampled from both ends of the table ( + /// from each — the head is what the oldest-first trim will actually delete, the tail catches a + /// workload whose event shape has drifted) to get an average payload width and an average + /// width across the four indexed columns. Table cost is then computed as whole pages — + /// ceil(rows / rowsPerPage) × pageSize — rather than as a flat bytes-per-row rate, + /// because that is the term that dominates once rows approach half a page: rows too wide to + /// pack two-per-page waste the remainder, which a linear model underestimates by ~40 %. + /// Index cost is added per row from the sampled indexed-column widths, so an event stream + /// that leaves instance_id null is charged less than one that fills it. + /// + /// + /// Index pages count against the cap — deliberately. The four indexes are storage the + /// event log causes and owns (measured at ~34 % of the table's total footprint), and the + /// 1 GB default was sized against the 393 bytes/row figure that already included them. + /// Excluding them would silently raise real disk use by about a third at the same setting. + /// + /// + /// Clamped by the file. The whole-file logical size is a true upper bound on any one + /// table's pages, so the model is capped by it. That can only ever correct an + /// over-estimate downward; it cannot reintroduce the row-81 defect, because on a replicated + /// node the file is larger than site_events, not smaller, and so never binds. + /// + /// + /// Marked virtual so tests can substitute a degenerate estimate and exercise the + /// trim's backstops. + /// + /// + /// The current row count and modelled bytes per row. + internal virtual SiteEventsSizeEstimate EstimateSiteEventsSize() { return _eventLogger.WithConnection(connection => { - using var pageCountCmd = connection.CreateCommand(); - pageCountCmd.CommandText = "PRAGMA page_count"; - var pageCount = (long)pageCountCmd.ExecuteScalar()!; + var rowCount = ReadPragmaLong(connection, "SELECT COUNT(*) FROM site_events"); + if (rowCount <= 0) + return new SiteEventsSizeEstimate(0, 0); - using var freeListCmd = connection.CreateCommand(); - freeListCmd.CommandText = "PRAGMA freelist_count"; - var freeListCount = (long)freeListCmd.ExecuteScalar()!; + double avgPayloadBytes; + double avgIndexedBytes; + using (var sampleCmd = connection.CreateCommand()) + { + // octet_length (SQLite 3.43+) rather than length(), which counts CHARACTERS: + // a message with multi-byte UTF-8 would otherwise be under-sized. Pinned by + // SqliteCapabilityTests so a provider downgrade fails a test rather than + // silently shrinking every estimate. + sampleCmd.CommandText = $""" + SELECT AVG(payload_bytes), AVG(indexed_bytes) FROM ( + SELECT payload_bytes, indexed_bytes FROM ( + SELECT + octet_length(id) + octet_length(timestamp) + octet_length(event_type) + + octet_length(severity) + COALESCE(octet_length(instance_id), 0) + + octet_length(source) + octet_length(message) + + COALESCE(octet_length(details), 0) AS payload_bytes, + octet_length(timestamp) + octet_length(event_type) + + octet_length(severity) + COALESCE(octet_length(instance_id), 0) + AS indexed_bytes + FROM site_events LIMIT {SizeSampleRows} + ) + UNION ALL + SELECT payload_bytes, indexed_bytes FROM ( + SELECT + octet_length(id) + octet_length(timestamp) + octet_length(event_type) + + octet_length(severity) + COALESCE(octet_length(instance_id), 0) + + octet_length(source) + octet_length(message) + + COALESCE(octet_length(details), 0) AS payload_bytes, + octet_length(timestamp) + octet_length(event_type) + + octet_length(severity) + COALESCE(octet_length(instance_id), 0) + AS indexed_bytes + FROM site_events ORDER BY rowid DESC LIMIT {SizeSampleRows} + ) + ) + """; + using var reader = sampleCmd.ExecuteReader(); + if (!reader.Read() || reader.IsDBNull(0)) + return new SiteEventsSizeEstimate(rowCount, 0); - using var pageSizeCmd = connection.CreateCommand(); - pageSizeCmd.CommandText = "PRAGMA page_size"; - var pageSize = (long)pageSizeCmd.ExecuteScalar()!; + avgPayloadBytes = reader.GetDouble(0); + avgIndexedBytes = reader.IsDBNull(1) ? 0 : reader.GetDouble(1); + } - var usedPages = Math.Max(0, pageCount - freeListCount); - return usedPages * pageSize; + var pageSize = ReadPragmaLong(connection, "PRAGMA page_size"); + var usablePerPage = (pageSize - PageReservedBytes) * TablePageFillFactor; + var avgCellBytes = avgPayloadBytes + TableCellOverheadBytes; + + // At least one row per page: a row wider than a page spills to overflow pages, + // which this floor charges as a whole page each — close enough, and never under. + var rowsPerPage = Math.Max(1, (long)(usablePerPage / Math.Max(1, avgCellBytes))); + var tableBytes = (long)Math.Ceiling(rowCount / (double)rowsPerPage) * pageSize; + + var indexBytesPerRow = + (avgIndexedBytes + (IndexEntryOverheadBytes * IndexedColumnCount)) / IndexPageFillFactor; + + var modelled = tableBytes + (long)(rowCount * indexBytesPerRow); + var clamped = Math.Min(modelled, ReadLogicalFileBytes(connection)); + + return new SiteEventsSizeEstimate(rowCount, clamped / (double)rowCount); }); } + /// Live site_events row count. + /// + /// Re-read after every cap-trim batch so the trim's progress check sees concurrent + /// recorder writes, not just its own deletes. virtual for the backstop tests. + /// + /// Number of rows currently in site_events. + internal virtual long GetSiteEventsRowCount() => + _eventLogger.WithConnection(connection => ReadPragmaLong(connection, "SELECT COUNT(*) FROM site_events")); + /// /// One purge tick's shared delete allowance, drawn down by the retention purge and then the /// storage-cap trim. diff --git a/src/ZB.MOM.WW.ScadaBridge.SiteEventLogging/SiteEventLogOptions.cs b/src/ZB.MOM.WW.ScadaBridge.SiteEventLogging/SiteEventLogOptions.cs index 00c19ce9..1feeee3e 100644 --- a/src/ZB.MOM.WW.ScadaBridge.SiteEventLogging/SiteEventLogOptions.cs +++ b/src/ZB.MOM.WW.ScadaBridge.SiteEventLogging/SiteEventLogOptions.cs @@ -4,7 +4,34 @@ public class SiteEventLogOptions { /// Number of days to retain site event log entries before purge; default 30. public int RetentionDays { get; set; } = 30; - /// Maximum SQLite database size in megabytes before old entries are purged; default 1024 MB. + /// + /// Maximum size in megabytes of site_events AND ITS FOUR INDEXES before the oldest + /// entries are trimmed; default 1024 MB. + /// + /// + /// + /// This is not a cap on the database file (register row 81, decision record + /// docs/plans/2026-08-17-site-event-log-cap-semantics-decision.md). site_events + /// shares one SQLite file at LocalDb:Path with nine other tables plus LocalDb's + /// __localdb_oplog / __localdb_row_version bookkeeping. Measuring the whole file + /// made the trim unwinnable on a replication-enabled node — each batch of deletes generated + /// an equal number of oplog rows and tombstones in the same file, so the measured size never + /// fell and the trim stopped 2.5x over cap. Worse, it made the event log's budget a function + /// of the replication peer's health, in the direction where a replication fault destroys + /// operational history. + /// + /// + /// Consequence for sizing a site's data volume: this value alone does not bound it. LocalDb + /// replication bookkeeping is separate overhead on the same disk, bounded by + /// LocalDb:Replication:MaxOplogRows and TombstoneRetention. Budget the sum. + /// + /// + /// The footprint is MODELLED from sampled row width rather than measured exactly: SQLite's + /// dbstat virtual table would give an exact per-table page count but is not compiled + /// into the bundled native library. Measured accuracy is −0.8 % to +12.8 %, deliberately + /// biased high. See EventLogPurgeService.EstimateSiteEventsSize. + /// + /// public int MaxStorageMb { get; set; } = 1024; /// /// MIGRATION-ONLY as of LocalDb Phase 1. no longer reads diff --git a/tests/ZB.MOM.WW.ScadaBridge.SiteEventLogging.Tests/EventLogPurgeServiceTests.cs b/tests/ZB.MOM.WW.ScadaBridge.SiteEventLogging.Tests/EventLogPurgeServiceTests.cs index a26f7cdd..3d92bfa9 100644 --- a/tests/ZB.MOM.WW.ScadaBridge.SiteEventLogging.Tests/EventLogPurgeServiceTests.cs +++ b/tests/ZB.MOM.WW.ScadaBridge.SiteEventLogging.Tests/EventLogPurgeServiceTests.cs @@ -547,6 +547,47 @@ public class EventLogPurgeServiceTests : IDisposable Assert.Equal(LogLevel.Information, note.Level); } + [Fact] + public void RunPurge_WhenBothPhasesDeleteRows_LogsTheBacklogNoteOnceForTheWholeTick() + { + // Register row 84. The note used to be emitted by each phase, so a tick in which the + // retention purge AND the cap trim both deleted rows produced two identical Information + // lines. It is now emitted once, from the tick's shared delete budget — which also makes + // the number it reports the figure an operator actually wants next to an oplog spike: + // the whole tick's contribution, not one phase's. + const int expiredRows = 50; + const int recentRows = 50; + for (int i = 0; i < expiredRows; i++) + { + InsertEventWithTimestamp(DateTimeOffset.UtcNow.AddDays(-31)); + } + for (int i = 0; i < recentRows; i++) + { + InsertEventWithTimestamp(DateTimeOffset.UtcNow); + } + + var capOptions = new SiteEventLogOptions + { + DatabasePath = _dbPath, + RetentionDays = 30, + MaxStorageMb = 0 // retention takes the expired rows; the cap trim takes the rest + }; + + var logger = new CapturingLogger(); + var purge = CreatePurgeService(capOptions, isReplicationConfigured: () => true, logger: logger); + purge.RunPurge(); + + // Both phases really did delete — otherwise this would pass for the wrong reason. + Assert.Contains(logger.Entries, e => + e.Message.Contains($"Purged {expiredRows} events older than", StringComparison.Ordinal)); + Assert.Contains(logger.Entries, e => e.Message.Contains("over the 0 MB cap", StringComparison.Ordinal)); + Assert.Equal(0, GetEventCount()); + + var note = Assert.Single(logger.Entries, e => e.Message.Contains(BacklogNoteFragment, StringComparison.Ordinal)); + Assert.Equal(LogLevel.Information, note.Level); + Assert.Contains($"Purged {expiredRows + recentRows} site_events rows", note.Message, StringComparison.Ordinal); + } + [Fact] public void RunPurge_WhenReplicationCheckThrows_StillPurgesAndSwallows() { diff --git a/tests/ZB.MOM.WW.ScadaBridge.SiteEventLogging.Tests/EventLogStorageCapScopeTests.cs b/tests/ZB.MOM.WW.ScadaBridge.SiteEventLogging.Tests/EventLogStorageCapScopeTests.cs new file mode 100644 index 00000000..308be8d3 --- /dev/null +++ b/tests/ZB.MOM.WW.ScadaBridge.SiteEventLogging.Tests/EventLogStorageCapScopeTests.cs @@ -0,0 +1,365 @@ +using Microsoft.Data.Sqlite; +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Logging.Abstractions; +using Microsoft.Extensions.Options; +using Xunit.Abstractions; + +namespace ZB.MOM.WW.ScadaBridge.SiteEventLogging.Tests; + +/// +/// Register row 81 — the storage cap measures site_events' own pages, not the whole +/// consolidated LocalDb file. +/// +/// +/// +/// The defect these tests close: site_events shares one SQLite file with nine other +/// tables plus LocalDb's __localdb_oplog / __localdb_row_version bookkeeping, and +/// the cap used to compare MaxStorageMb against page_count - freelist_count over +/// that whole file. On a replication-enabled node the trim therefore fought itself — each +/// 1000-row delete freed ~390 KB of event pages while adding ~1000 oplog rows and ~1000 +/// tombstones to the same file — and stopped 2.5x over a 64 MB cap with 226 k rows still +/// present (docs/plans/2026-08-15-site-events-purge-burst-measurement.md §5). +/// +/// +/// A real replication pair is not needed to pin the semantics: what matters is that OTHER pages +/// in the same file neither consume nor block the event log's budget. A plain ballast table +/// stands in for the oplog, tombstones and the other nine tables alike. +/// +/// +public class EventLogStorageCapScopeTests : IDisposable +{ + private readonly ITestOutputHelper _output; + private readonly SiteEventLogger _eventLogger; + private readonly TestLocalDb _localDb; + private readonly string _dbPath; + + public EventLogStorageCapScopeTests(ITestOutputHelper output) + { + _output = output; + _dbPath = Path.Combine(Path.GetTempPath(), $"test_capscope_{Guid.NewGuid()}.db"); + _localDb = TestLocalDb.Create(_dbPath); + _eventLogger = new SiteEventLogger( + Options.Create(new SiteEventLogOptions { DatabasePath = _dbPath }), + NullLogger.Instance, + _localDb.Db); + } + + public void Dispose() + { + _eventLogger.Dispose(); + _localDb.Dispose(); + TestLocalDb.DeleteFiles(_dbPath); + GC.SuppressFinalize(this); + } + + private EventLogPurgeService CreatePurgeService(SiteEventLogOptions options, ILogger? logger = null) => + new(_eventLogger, Options.Create(options), logger ?? NullLogger.Instance); + + private SiteEventLogOptions CapOptions(int maxStorageMb) => new() + { + DatabasePath = _dbPath, + // Far enough in the past that the retention purge never fires — these tests are about + // the cap trim in isolation, and a shared tick budget would otherwise blur the two. + RetentionDays = 3650, + MaxStorageMb = maxStorageMb, + }; + + /// Seeds events, each ~256 bytes of payload. + private void SeedEvents(int count) + { + var details = new string('x', 200); + _eventLogger.WithConnection(connection => + { + using var tx = connection.BeginTransaction(); + using var cmd = connection.CreateCommand(); + cmd.Transaction = tx; + cmd.CommandText = """ + INSERT INTO site_events (id, timestamp, event_type, severity, instance_id, source, message, details) + VALUES ($id, $ts, 'script', 'Info', $inst, 'SiteRuntime', 'Bulk event', $details) + """; + var id = cmd.Parameters.Add("$id", SqliteType.Text); + var ts = cmd.Parameters.Add("$ts", SqliteType.Text); + var inst = cmd.Parameters.Add("$inst", SqliteType.Text); + var det = cmd.Parameters.Add("$details", SqliteType.Text); + var start = new DateTimeOffset(2026, 1, 1, 0, 0, 0, TimeSpan.Zero); + for (var i = 0; i < count; i++) + { + id.Value = Guid.NewGuid().ToString("N"); + ts.Value = start.AddSeconds(i).ToString("o"); + inst.Value = i % 3 == 0 ? DBNull.Value : Guid.NewGuid().ToString(); + det.Value = details; + cmd.ExecuteNonQuery(); + } + tx.Commit(); + }); + } + + /// + /// Fills a non-event table in the SAME file, standing in for LocalDb's oplog and + /// row-version tables and the nine other consolidated tables. + /// + private void SeedBallast(int rows, int bytesPerRow) + { + var payload = new string('b', bytesPerRow); + _eventLogger.WithConnection(connection => + { + using var create = connection.CreateCommand(); + create.CommandText = "CREATE TABLE IF NOT EXISTS test_ballast (seq INTEGER PRIMARY KEY, row_json TEXT)"; + create.ExecuteNonQuery(); + + using var tx = connection.BeginTransaction(); + using var cmd = connection.CreateCommand(); + cmd.Transaction = tx; + cmd.CommandText = "INSERT INTO test_ballast (row_json) VALUES ($p)"; + var p = cmd.Parameters.Add("$p", SqliteType.Text); + for (var i = 0; i < rows; i++) + { + p.Value = payload; + cmd.ExecuteNonQuery(); + } + tx.Commit(); + }); + } + + private long EventCount() => _eventLogger.WithConnection(connection => + { + using var cmd = connection.CreateCommand(); + cmd.CommandText = "SELECT COUNT(*) FROM site_events"; + return (long)cmd.ExecuteScalar()!; + }); + + [Fact] + public void EstimatedSize_ExcludesOtherTablesInTheSameFile() + { + // A small ballast is seeded up front so the whole-file clamp inside the estimator is + // slack in BOTH readings — otherwise the first would be pinned to the file size and the + // comparison would be measuring the clamp rather than the model. + SeedBallast(rows: 4_000, bytesPerRow: 400); + SeedEvents(4000); + + var purge = CreatePurgeService(CapOptions(1024)); + var eventsOnly = purge.EstimateSiteEventsSize().EstimatedBytes; + var fileBefore = purge.GetDatabaseSizeBytes(); + + SeedBallast(rows: 40_000, bytesPerRow: 500); + + var eventsAfterBallast = purge.EstimateSiteEventsSize().EstimatedBytes; + var fileAfter = purge.GetDatabaseSizeBytes(); + + _output.WriteLine($"site_events estimate {eventsOnly} -> {eventsAfterBallast}; file {fileBefore} -> {fileAfter}"); + + // The file grew several-fold; the event log's own measured footprint did not move at all. + Assert.True(fileAfter > fileBefore * 2, + $"Ballast must visibly grow the file ({fileBefore} -> {fileAfter})."); + Assert.Equal(eventsOnly, eventsAfterBallast); + } + + [Fact] + public void PurgeByStorageCap_WithLargeBallastInTheSameFile_DoesNotTrimAnUnderCapEventLog() + { + // The most direct expression of row 81: on a replicated node with an undrained oplog the + // file dwarfs site_events. Under the old whole-file cap the trim would run — and delete + // events — purely because of bytes the event log does not own. + SeedEvents(4000); + + var sizingProbe = CreatePurgeService(CapOptions(1024)); + var eventBytes = sizingProbe.EstimateSiteEventsSize().EstimatedBytes; + + SeedBallast(rows: 40_000, bytesPerRow: 500); + + // Cap comfortably above site_events but far BELOW the whole file. + var capMb = (int)Math.Max(1, (eventBytes * 2) / (1024 * 1024)); + var purge = CreatePurgeService(CapOptions(capMb)); + + Assert.True(purge.GetDatabaseSizeBytes() > (long)capMb * 1024 * 1024, + "Precondition: the whole file must exceed the cap, so a file-scoped cap would trim."); + + purge.RunPurge(); + + Assert.Equal(4000, EventCount()); + } + + [Fact] + public void PurgeByStorageCap_WithLargeBallastInTheSameFile_StillEnforcesTheCapOnEventsAndDoesNotEmptyTheTable() + { + // The other half: the cap must still be MET. Under the old whole-file measurement this + // was impossible with unreclaimable ballast present — the trim either emptied the table + // chasing a file size it could not reach, or (as measured) tripped the progress guard + // and left the log 2.5x over cap. + SeedEvents(6000); + SeedBallast(rows: 40_000, bytesPerRow: 500); + + var sizingProbe = CreatePurgeService(CapOptions(1024)); + var eventBytes = sizingProbe.EstimateSiteEventsSize().EstimatedBytes; + + var capBytes = eventBytes / 2; + var capMb = (int)Math.Max(1, capBytes / (1024 * 1024)); + var purge = CreatePurgeService(CapOptions(capMb)); + + purge.RunPurge(); + + var remaining = EventCount(); + var finalEstimate = purge.EstimateSiteEventsSize().EstimatedBytes; + var finalCapBytes = (long)capMb * 1024 * 1024; + + _output.WriteLine($"remaining={remaining} estimate={finalEstimate} cap={finalCapBytes} file={purge.GetDatabaseSizeBytes()}"); + + Assert.True(remaining > 0, "The cap trim must not empty the event table."); + Assert.True(remaining < 6000, "The cap trim must remove events when the event log is over cap."); + Assert.True(finalEstimate <= finalCapBytes, + $"site_events estimate {finalEstimate} must be at or below the cap {finalCapBytes}."); + + // And the proof that the cap is table-scoped: the FILE is still way over it, and that is + // correct — those bytes belong to LocalDb bookkeeping and the other consolidated tables. + Assert.True(purge.GetDatabaseSizeBytes() > finalCapBytes, + "The whole file is expected to stay over the cap — the cap no longer measures it."); + } + + // ── size-model accuracy ── + + public static TheoryData Workloads => new() + { + // name, rows, details length (0 = no details column), details on every row + { "narrow rows, no details", 8000, 0, 1.0 }, + { "typical rows, 200B details", 6000, 200, 1.0 }, + { "wide rows, 2KB details", 3000, 2048, 1.0 }, + }; + + [Theory] + [MemberData(nameof(Workloads))] + public void EstimateSiteEventsSize_TracksTheRealFootprint(string name, int rows, int detailsLength, double detailsFraction) + { + // Calibration guard for the modelled estimate. site_events' true page count is obtained + // DIFFERENTIALLY: the file is measured with ballast only, the events are then added, and + // the growth is what the table and its four indexes actually cost. Seeding the ballast + // first also keeps the estimator's whole-file clamp slack, so this scores the model + // itself rather than the clamp. + // + // The band is deliberately asymmetric. The model is tuned to run somewhat high, because + // a cap that fires early wastes a slice of the budget whereas one that reads low lets + // the log overrun the disk allowance the cap exists to defend. + SeedBallast(rows: 4_000, bytesPerRow: 400); + + var purge = CreatePurgeService(CapOptions(1024)); + var baselineBytes = purge.GetDatabaseSizeBytes(); + + var details = detailsLength > 0 ? new string('d', detailsLength) : null; + _eventLogger.WithConnection(connection => + { + using var tx = connection.BeginTransaction(); + using var cmd = connection.CreateCommand(); + cmd.Transaction = tx; + cmd.CommandText = """ + INSERT INTO site_events (id, timestamp, event_type, severity, instance_id, source, message, details) + VALUES ($id, $ts, 'ScriptExecution', 'Information', $inst, 'SiteRuntime', $msg, $details) + """; + var id = cmd.Parameters.Add("$id", SqliteType.Text); + var ts = cmd.Parameters.Add("$ts", SqliteType.Text); + var inst = cmd.Parameters.Add("$inst", SqliteType.Text); + var msg = cmd.Parameters.Add("$msg", SqliteType.Text); + var det = cmd.Parameters.Add("$details", SqliteType.Text); + var start = new DateTimeOffset(2026, 1, 1, 0, 0, 0, TimeSpan.Zero); + var rnd = new Random(7); + for (var i = 0; i < rows; i++) + { + id.Value = Guid.NewGuid().ToString(); + ts.Value = start.AddSeconds(i).ToString("o"); + inst.Value = i % 3 == 0 ? DBNull.Value : Guid.NewGuid().ToString(); + msg.Value = $"Script 'Recipe{i % 50}' completed in {rnd.Next(1, 900)} ms"; + det.Value = details is not null && rnd.NextDouble() < detailsFraction ? details : (object)DBNull.Value; + cmd.ExecuteNonQuery(); + } + tx.Commit(); + }); + + var estimated = purge.EstimateSiteEventsSize().EstimatedBytes; + var actual = purge.GetDatabaseSizeBytes() - baselineBytes; + var error = (estimated - (double)actual) / actual; + + _output.WriteLine($"{name}: rows={rows} estimated={estimated} actual={actual} error={error:P1}"); + + Assert.InRange(error, -0.05, 0.25); + } + + // ── wipe-prevention backstops ── + + /// Purge service whose size estimate and row count can be pinned by a test. + private sealed class StubbedEstimatePurgeService( + SiteEventLogger eventLogger, + IOptions options, + ILogger logger, + EventLogPurgeService.SiteEventsSizeEstimate? estimate, + long? frozenRowCount) + : EventLogPurgeService(eventLogger, options, logger) + { + internal override EventLogPurgeService.SiteEventsSizeEstimate EstimateSiteEventsSize() => + estimate ?? base.EstimateSiteEventsSize(); + + internal override long GetSiteEventsRowCount() => + frozenRowCount ?? base.GetSiteEventsRowCount(); + } + + [Fact] + public void PurgeByStorageCap_WhenRowWidthCannotBeSampled_DeletesNothingAndWarns() + { + // First backstop. A zero row width makes "how many rows put us under cap" unanswerable. + // The old loop's answer to an unanswerable cap was to keep deleting until the file + // shrank, which is precisely how a cap that can never be met empties a table. + SeedEvents(2000); + + var logger = new CapturingLogger(); + var purge = new StubbedEstimatePurgeService( + _eventLogger, + Options.Create(CapOptions(0)), + logger, + new EventLogPurgeService.SiteEventsSizeEstimate(RowCount: 2000, BytesPerRow: 0), + frozenRowCount: null); + + purge.RunPurge(); + + Assert.Equal(2000, EventCount()); + Assert.Contains(logger.Entries, e => + e.Level == LogLevel.Warning && e.Message.Contains("row width could not be sampled", StringComparison.Ordinal)); + } + + [Fact] + public void PurgeByStorageCap_WhenTheTableStopsShrinking_StopsRatherThanEmptyingTheLog() + { + // Second backstop, carried over from the old "size did not decrease" guard but re-based + // onto the table-scoped metric. It can no longer be tripped by replication bookkeeping; + // a frozen row count is what it now models — writers arriving as fast as the trim deletes. + SeedEvents(5000); + + var logger = new CapturingLogger(); + var purge = new StubbedEstimatePurgeService( + _eventLogger, + Options.Create(CapOptions(0)), // a 0 MB cap would otherwise delete every row + logger, + estimate: null, + frozenRowCount: 5000); + + purge.RunPurge(); + + var remaining = EventCount(); + Assert.True(remaining > 0, "The guard must stop the trim before the table is emptied."); + Assert.True(remaining >= 4000, $"Only one batch should have been deleted; {5000 - remaining} rows went."); + Assert.Contains(logger.Entries, e => + e.Level == LogLevel.Warning && e.Message.Contains("did not decrease", StringComparison.Ordinal)); + } + + private sealed record LogEntry(LogLevel Level, string Message); + + private sealed class CapturingLogger : ILogger + { + public List Entries { get; } = []; + + public IDisposable? BeginScope(TState state) where TState : notnull => null; + + public bool IsEnabled(LogLevel logLevel) => true; + + public void Log( + LogLevel logLevel, EventId eventId, TState state, Exception? exception, + Func formatter) => + Entries.Add(new LogEntry(logLevel, formatter(state, exception))); + } +} diff --git a/tests/ZB.MOM.WW.ScadaBridge.SiteEventLogging.Tests/SqliteCapabilityTests.cs b/tests/ZB.MOM.WW.ScadaBridge.SiteEventLogging.Tests/SqliteCapabilityTests.cs new file mode 100644 index 00000000..c46dc380 --- /dev/null +++ b/tests/ZB.MOM.WW.ScadaBridge.SiteEventLogging.Tests/SqliteCapabilityTests.cs @@ -0,0 +1,84 @@ +using Microsoft.Data.Sqlite; + +namespace ZB.MOM.WW.ScadaBridge.SiteEventLogging.Tests; + +/// +/// Pins the two SQLite provider capabilities the storage cap's size model depends on +/// (register row 81, docs/plans/2026-08-17-site-event-log-cap-semantics-decision.md). +/// +/// +/// The intended fix for row 81 was to measure site_events' own pages exactly through the +/// dbstat virtual table. These tests are the evidence that this is not possible with the +/// native SQLite this solution ships, and the tripwire that will tell us if that ever changes — +/// if dbstat appears, the modelled estimate in +/// should be replaced by a real +/// measurement. +/// +public class SqliteCapabilityTests +{ + private static SqliteConnection OpenMemory() + { + var connection = new SqliteConnection("Data Source=:memory:"); + connection.Open(); + return connection; + } + + [Fact] + public void DbStat_IsNotAvailable_SoThePerTablePageCountMustBeModelled() + { + // If this test starts FAILING, that is good news, not a regression: the bundled + // e_sqlite3 has gained SQLITE_ENABLE_DBSTAT_VTAB and the cap can measure + // `SELECT sum(pgsize) FROM dbstat WHERE name='site_events'` exactly instead of + // modelling it. Delete the model, not this expectation, if that day comes. + using var connection = OpenMemory(); + + using var compileOptions = connection.CreateCommand(); + compileOptions.CommandText = "PRAGMA compile_options"; + var options = new List(); + using (var reader = compileOptions.ExecuteReader()) + { + while (reader.Read()) + options.Add(reader.GetString(0)); + } + + Assert.DoesNotContain("ENABLE_DBSTAT_VTAB", options); + + using var modules = connection.CreateCommand(); + modules.CommandText = "SELECT name FROM pragma_module_list"; + var names = new List(); + using (var reader = modules.ExecuteReader()) + { + while (reader.Read()) + names.Add(reader.GetString(0)); + } + + // The list is non-empty (fts3/4/5, rtree, geopoly …) so an empty result is not being + // mistaken for "no dbstat". + Assert.NotEmpty(names); + Assert.DoesNotContain("dbstat", names); + Assert.DoesNotContain("sqlite_dbpage", names); + + using var query = connection.CreateCommand(); + query.CommandText = "SELECT sum(pgsize) FROM dbstat"; + var ex = Assert.Throws(() => query.ExecuteScalar()); + Assert.Contains("dbstat", ex.Message, StringComparison.OrdinalIgnoreCase); + } + + [Fact] + public void OctetLength_IsAvailable_SoRowWidthIsSampledInBytesNotCharacters() + { + // The size model samples row width with octet_length() (SQLite 3.43+). length() counts + // CHARACTERS, so a multi-byte UTF-8 message would be under-sized and the cap enforced + // late. A provider downgrade that drops octet_length must fail here rather than + // silently shrinking every estimate at runtime. + using var connection = OpenMemory(); + + using var cmd = connection.CreateCommand(); + cmd.CommandText = "SELECT octet_length('skål'), length('skål')"; + using var reader = cmd.ExecuteReader(); + + Assert.True(reader.Read()); + Assert.Equal(5, reader.GetInt32(0)); // 'å' is two bytes in UTF-8 + Assert.Equal(4, reader.GetInt32(1)); + } +}