74c7bd2fa8ed37c2e68ce4aeb7bb403e05505ddf
8 Commits
| Author | SHA1 | Message | Date | |
|---|---|---|---|---|
 Joseph Doherty
|
6c11362d9f |
fix(auditlog)+fix(siteeventlog): complete audit write tasks only after commit; run event-log retention on standby (arch-review 2026-08-19 P4-2 + P4-4)
P4-2: SqliteAuditWriter.FlushBatch completed each pending row's Task (TrySetResult) inside the per-row insert loop, before transaction.Commit() ran. A later failure in the same batch (another row's insert throwing, or the commit itself failing) rolled the whole transaction back, but the earlier rows' Tasks had already completed successfully -- the caller and FallbackAuditWriter (whose ring-buffer fallback exists precisely for this outage) both saw false success while the rows were actually gone from the database; the outer catch's TrySetException became a silent no-op against an already-completed TaskCompletionSource. Every row's Completion is now deferred and only resolved (TrySetResult for the whole batch, or TrySetException for the whole batch) after transaction.Commit() succeeds or the transaction rolls back, mirroring SiteEventLogger.FlushBatch. P4-4: EventLogPurgeService gated the daily site_events purge on the active-node check, early-exiting on the standby, on the stale premise that "the standby receives no writes". DataConnectionActor runs on both site nodes and writes site_events regardless of active/standby status (register rows 89/90/97), so an unreplicated standby (the rig's site-b/site-c posture) grew its site_events file forever with no retention and no cap. The gate is removed; every node now purges its own file every tick. Safe on a replicated pair because the retention/cap deletes are CDC-captured and converge under LWW regardless of which node issues them; required on an unreplicated pair because each node's file is independent. The active-node check is retained only to annotate the purge tick's log line. Tests: new SqliteAuditWriterCommitFailureTests forces a genuine non-swallowed mid-batch INSERT failure via a real SQLite trigger + custom scalar function on the writer's own connection (reflection seam), proving (a) a row whose own insert succeeded still faults when a later row in the same batch fails, and (b) FallbackAuditWriter rings every faulted row and increments the failure counter for each -- both assertions fail against the pre-fix code (proof-of-failure verified by temporarily reverting the fix). EventLogPurgeServiceTests' standby case is inverted to assert the purge now runs (not skips) on a standby node. |
||
|
Joseph Doherty
|
ddb3c32e06 |
fix(siteeventlog): scope the storage cap to site_events' own pages (register rows 81, 84)
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. |
||
|
Joseph Doherty
|
d9a35846d9 |
perf(siteeventlog): pace the site_events purge burst — per-tick delete ceiling + accelerated catch-up (row 34)
Measured the unbounded purge burst and found it can force a full ten-table
snapshot resync, then bounded it. No purge-exemption path was added — the
deletes are still CDC-captured like any other write, which stays ruled out
by design; what changed is how many a single tick performs.
MEASURED (harness: real EventLogPurgeService over a real LocalDb file with
site_events genuinely RegisterReplicated, plus a two-node loopback gRPC
replication pair; docker rig untouched):
393 bytes/row incl. indexes => a 1 GB event log holds ~2,731,947 rows.
Expiring all of them in ONE tick: 285 s, 2,731,947 oplog rows,
284 MB oplog payload, 2.73 M row-version tombstones (7-day retention),
i.e. 2.7x LocalDb's MaxOplogRows default of 1,000,000. Crossing that makes
the 60 s maintenance tick prune the oplog and set needs_snapshot — a FULL
snapshot of all ten replicated tables, bought by a routine retention purge.
The resident backlog is produced-minus-drained, so a healthy peer blunts it:
on loopback the same burst peaked at 391,424 and cleared in 6.0 min. That is
the problem, not the reassurance — the old safety margin was a function of
peer throughput and vanished with the peer down. A bounded tick is safe at
any peer speed.
Drain is not a bottleneck: 7.6k-19.8k tombstones/s (20k / 500k / 2.73M runs).
SHIPPED:
- SiteEventLogOptions.MaxPurgedRowsPerTick (default 250,000; 0 = unlimited
escape hatch, negatives rejected). One SHARED budget across the retention
purge and the cap trim — two independently-capped phases would let a tick
emit twice the intended burst. 4x margin under MaxOplogRows, which is also
shared with every other replicated table's ordinary traffic.
- SiteEventLogOptions.PurgeCatchUpInterval (default 5 min, validated > 0 and
<= PurgeInterval). Without it pacing would make retention converge in 11
DAYS at the daily cadence; with it the worst case converges in ~11 ticks
(~55 min), every burst bounded. 5 min rather than 1 so ticks cannot outrun
the peer's drain and re-accumulate the backlog.
- A ceiling is claimed only when work genuinely remains (bounded EXISTS probe),
so an expired set landing exactly on the budget does not arm a no-op retry.
- Visibility: rate-limited (15 min) Warning naming the ceiling and the
accelerated interval, plus an unthrottled counter
scadabridge.site.event_log.purge_ceiling_hits — its SHAPE distinguishes a
backlog converging from a site whose event rate outruns one paced tick.
- The purge loop is a delay loop rather than a PeriodicTimer, so its cadence
now anchors to the END of the previous purge. Documented.
ROW-33 INTERPLAY VERIFIED: pacing lowers each spike and lengthens total purge
duration, but a full 250k tick drains in ~23 s (~4 min even at 10x a real
link's penalty) against the 15-minute sustained dwell and a 5-minute gap to
the next tick. The UNPACED 2.73M burst had only 2.5x of margin (6.0 min), so
pacing makes the badge assumption robust rather than merely preserving it.
Docs travel together: Component-SiteEventLogging.md, topology-guide.md
("Reading the replication backlog" + the row-33 badge note), CLAUDE.md's
purge-burst sentence, and a dated measurement/decision note under docs/plans/.
Fail-before: the new behavioural tests do not compile against the pre-fix
service (RunPurge was void); with PurgeBudget neutralised to always-unlimited,
6 of the new tests fail and all 19 pre-existing ones pass.
Tests: SiteEventLogging 93/93, Commons 715/715, HealthMonitoring 115/115,
Host 505/505. Solution build clean.
|
||
|
Joseph Doherty
|
9d2834e30a |
docs+log(siteeventlogging): explain the site_events purge oplog-backlog burst (R7)
The daily site_events retention purge (and the storage-cap trim) is CDC-captured on a replication-enabled site node exactly like any other write — correct by design, since LocalDb Phase 2 deliberately has no purge-exemption path — so the backlog jumps by the deleted batch size at purge time. LocalDbOplogBacklog / localdb_oplog_depth spike, drain, and an operator watching the gauge with no context reads it as a replication fault. Documentation + one log line, no behaviour change: - topology-guide.md gains "Reading the replication backlog — the daily site_events purge burst": when it fires (PurgeInterval 24h, anchored to the active node's PROCESS START, not a wall-clock hour, so it moves after every failover), where it shows (replicated nodes only — not rig site-b/site-c), the healthy signature (LocalDbReplicationConnected stays true, backlog returns to ~0) and what a genuine fault looks like instead. - Component-SiteEventLogging.md Storage records the same under retention/purge; Component-HealthMonitoring.md gains the two previously-undocumented LocalDbReplicationConnected / LocalDbOplogBacklog metric rows carrying the caveat, with cross-references both ways. - EventLogPurgeService emits one Information line naming the row count and the expected transient backlog when a purge deleted rows on a replication-enabled node, so the spike is correlatable in the log. Replication-awareness comes in as a Host-supplied SiteEventLogReplicationCheck delegate, mirroring the existing SiteEventLogActiveNodeCheck seam: SiteLocalDbSetup.ReplicationIsConfigured goes internal so the PeerAddress-OR-ApiKey rule stays in one place and SiteEventLogging never learns to read LocalDb config. Unregistered ⇒ no note, matching the default that replication is opt-in and off. Both delete paths carry the note (a cap trim is usually the larger burst); the predicate is try/caught since a log-wording check must never break the purge. Tests: 5 new EventLogPurgeServiceTests cases (replicated logs it, unreplicated does not, zero-rows does not, cap purge logs it, throwing predicate still purges and swallows) via a local capturing ILogger. SiteEventLogging 81/81 green, Host 490/490 green, full solution build clean (0 warnings). |
||
|
Joseph Doherty
|
c254d0740e |
perf(sitelog): sampled per-run events; interval run summaries; site_events replication policy pinned
Implements WP3.2 stage (b) per docs/plans/2026-08-15-site-events-policy-design.md.
- Per-run instance-script Started/Completed Info site events are now off by
default (SiteRuntimeOptions.PerRunScriptEvents=false) instead of firing on
every run, closing the dominant site_events writer. Gated at the ScriptRunLauncher
call sites (moved there from ScriptExecutionActor by WP3.1). Error-level events
(timeout/failure/stuck-watchdog/recursion-limit) remain unconditional.
- ScriptRunSummaryRecorder accumulates per-(instance, script) run counters and a
new site-only ScriptRunSummaryFlushService emits one aggregate "script" Info
site event per ScriptRunSummaryIntervalSeconds (default 300s), top-50-script
breakdown with an "others" rollup, zero-activity intervals emit nothing.
- Per-script opt-in via PerRunScriptEventScripts ("Instance/Script" exact or
"Instance/*" wildcard), matched by the new pure ScriptRunEventPolicy. All three
options are read from IOptionsMonitor<SiteRuntimeOptions> per run, so the
policy is hot-togglable without a restart.
- Fixed the stale "event log is not replicated" comment at AkkaHostedService.cs
(~905): site_events IS registered in SiteLocalDbSetup.ReplicatedTables — the
singleton is what makes queries always hit the actively-written copy;
replication is what gives the singleton history to read after a failover
(memo Decision (b)). site_events replication itself is unchanged (still
registered) and already pinned by
tests/ZB.MOM.WW.ScadaBridge.Host.Tests/SiteLocalDbCdcRegistrationTests.cs.
- Updated Component-SiteEventLogging.md (Volume Policy section, corrected
Storage/replication rationale) and Component-SiteRuntime.md (Script Run
Launch + Error Handling sections).
|
||
|
Joseph Doherty
|
0dd3be0bd8 | docs(notification-outbox): trim Site Event Logging notification row, de-duplicate rationale | ||
|
Joseph Doherty
|
a59f5ec1ff | docs(notification-outbox): add Notification category to Site Event Logging | ||
|
Joseph Doherty
|
d91aa83665 |
refactor(docs): move requirements and test infra docs into docs/ subdirectories
Organize documentation by moving requirements (HighLevelReqs, Component-*, lmxproxy_protocol) to docs/requirements/ and test infrastructure docs to docs/test_infra/. Updates all cross-references in README, CLAUDE.md, infra/README, component docs, and 23 plan files. |