ScadaBridge/docs/plans/2026-11-09-auditlog-clustered-key-benchmark.md

AuditLog clustered key benchmark and P4 / P6 follow-ups (ScadaBridge#78)

Date: 2026-11-09. Status: benchmark record + recommendation. Implemented 2026-11-10 as migration FlipAuditLogClusteredKey (variant B2, #111) — script docs/plans/sql/FlipAuditLogClusteredKey.sql + .rollback.sql; the partition-switch staging table now follows the live key order (the "old binaries work on either shape" claim below is wrong for that one statement — binaries before the flip cannot switch a flipped table). Reduced re-run, SQL Server 2022 dev container, 300k rows / 631 MB: page 1 90,532 → 34 logical reads (plan: Clustered Index Scan … ORDERED BACKWARD under Top, no sort), keyset page 90,532 → 46, idempotency probe 14 → 14; FlipAuditLogClusteredKeyMigrationTests pins the same ratio on 20k rows (76 vs 7,420 / 274 vs 7,393).

P3 - flip dbo.AuditLog clustered key (EventId, OccurredAtUtc) -> (OccurredAtUtc, EventId)?

Facts from the code

• Clustered PK today: PK_AuditLog (EventId, OccurredAtUtc) on ps_AuditLog_Month(OccurredAtUtc) (monthly RANGE RIGHT partitions); 12 partition-aligned NC indexes (see AuditLogEntityTypeConfiguration, migrations CollapseAuditLogToCanonical, AlignAuditLogEventIdUniqueness, ReviewRemediationIndexes, AddAuditLogHashChain).
• EventId is Guid.NewGuid() (ScadaBridgeAuditEventFactory, minted at the emitting site): fully random, so the current clustered key inserts at random positions inside the active month partition. Every NC index also carries the clustered key as row locator.
• Idempotency (InsertIfNotExists, InsertChunkAsync, reconciliation) probes WHERE EventId = @id - today the clustered key's leading column. Since AlignAuditLogEventIdUniqueness there is no separate EventId index.
• Query shapes that range-scan or fetch rows: Audit Log page (QueryAsync: ORDER BY OccurredAtUtc DESC, EventId DESC, keyset cursor on the same pair, filters on channel/kind/status/site/node/target/actor/execution/correlation + time range), KPI snapshot (GetKpiSnapshotAsync, covered by IX_AuditLog_OccurredAtUtc INCLUDE (Status)), execution tree/trace (IX_AuditLog_Execution + window), hash-chain job (AuditLogHashChain: WHERE ChainSeq IS NULL AND month ORDER BY OccurredAtUtc, EventId, then UPDATE joined on (EventId, OccurredAtUtc), verification ORDER BY ChainSeq), per-channel purge (DELETE TOP (n) WHERE Category=@c AND OccurredAtUtc<@t), month archive read, partition-switch purge (metadata only, unaffected).

Method

Throwaway SQL Server 2022 (RTM-CU22, Developer, amd64 image under emulation on an Apple-silicon Mac, 6 GB cap, SIMPLE recovery) container, removed afterwards. Table recreated with the production DDL: partition function/scheme, 10 canonical columns, the persisted computed columns, ChainSeq/RowHash, all 12 NC indexes (+ variant-specific). 3,000,000 rows, ~1.9 KB/row (JSON DetailsJson ~480 chars), spread over 2026-07-01..2026-11-01, loaded in 3000 chronological batches of 1000 (each row 0-120 s older than its batch, imitating site telemetry delay), random NEWID() EventIds, using the production idempotent pattern INSERT ... WHERE NOT EXISTS (EventId). Variants:

• A current: clustered (EventId, OccurredAtUtc).
• B clustered (OccurredAtUtc, EventId), no EventId index (plain insert, no probe) - shows the pure clustered-key effect.
• B2 clustered (OccurredAtUtc, EventId) + aligned UNIQUE (EventId, OccurredAtUtc) NC index - the only variant that keeps cheap idempotency probes and a real EventId uniqueness guarantee. Queries measured cold (DROPCLEANBUFFERS) and warm with SET STATISTICS IO, TIME. Absolute times are inflated by emulation; compare ratios and logical reads. Single run each, no repetition - treat small differences as noise.

Insert, size, fragmentation (3M rows)

Variant	Insert rows/s	Page splits (counter delta)	Clustered pages / MB	Clustered fragmentation	Clustered page fill
A (current)	4,022	1,122,830	735,066 / 5,743	99.2%	64.0%
B (no EventId index)	7,631	816,961	500,001 / 3,906	0.6%	94.2%
B2 (B + unique EventId NC)	4,065	1,141,726	735,769 / 5,748	99.1%	63.9%

B2's clustered index ended up as fragmented as A's even though its key is time-ordered. The most likely cause (plan not inspected) is that the NOT EXISTS (EventId) probe against the new EventId index makes the optimizer feed the insert in EventId order, so the clustered inserts become random again; the unique EventId index itself is 16,099 pages / 99.2% fragmented. The NC indexes keyed on site/target/channel etc. fragment in every variant because their leading columns are not time-ordered.

Query shapes (logical reads, warm elapsed ms; cold in brackets)

Shape	A	B	B2
Q1 Audit Log page 1, newest 50, no filter	739,300 reads / 2,313 ms [3,855]	54 / 14 [22]	51 / 15 [25]
Q2 channel IN (..) + 1 day, top 50	55,217 / 80 [171]	58 / 12 [12]	70 / 16 [18]
Q3 site + 1 week, top 100	199,502 / 732 [793]	212 / 14 [15]	287 / 20 [21]
Q4 deep keyset page (cursor in Sept)	739,300 / 2,750 [1,862]	70 / 13 [14]	72 / 18 [20]
Q5 KPI last hour (covered)	7 / 0	7 / 0	8 / 0
Q6 actor filter, top 50	281,077 / 329 [548]	432 / 1 [13]	642 / 6 [21]
Q9 idempotency probe, 1000 new ids	24,988 / 159	15,444 / 62 (scans a narrow NC index - no EventId index)	16,204 / 101
Q10 idempotency probe, 1000 existing ids	24,988 / 85	15,444 / 47	16,204 / 85
Q11 hash-chain select 5000 unchained	24,574 / 313	1,195 / 290	1,678 / 306
Q12 hash-chain stamp 5000 rows	66,468 / 125	66,460 / 107	66,466 / 109
Q13 month ordered read (window row_number)	6,515 / 71	3,982 / 56	4,108 / 67
Q14 chain verify read, 50k by ChainSeq	196,306 / 1,213 [1,010]	136,131 / 153 [688]	200,724 / 185 [964]
Q15 per-channel purge batch 5000 (rolled back)	195,129 / 458 [654]	195,140 / 361 [1,592]	210,211 / 383 [540]
Q7/Q8 (execution/correlation lookups) returned 0 rows in this synthetic data (id not found) and are not reported; they are NC seeks whose key-lookup locality would favour B slightly.

Important side finding: in variant A the unfiltered/time-range Audit Log queries (Q1, Q4) read the entire table (739k pages at 3M rows) because the ORDER BY (OccurredAtUtc DESC, EventId DESC) cannot be satisfied by IX_AuditLog_OccurredAtUtc (its implicit trailing key is EventId ASC) over a partitioned table. This is a latent performance bug that grows linearly with table size, independent of the flip. A follow-up test adding IX_alt (OccurredAtUtc DESC, EventId DESC) INCLUDE (Status) to variant A did NOT fix Q1/Q4 (still 739k reads; forced with a hint it was worse at 12.6M reads), though it cut Q3 from 199k to 4k reads. So an index tweak is not a cheap substitute; the clustered-key flip is what makes the partitioned ordered TOP-N work.

Findings

1. The flip is a large, real win for read paths, orders of magnitude on the Audit Log page (the default view) and on every time-range query, plus ~13x fewer reads for the hash-chain job's selection, and sequential month reads.
2. The flip alone (B) roughly halves insert cost and removes clustered fragmentation (0.6% vs 99.2%, fill 94% vs 64%, 32% smaller table) because the clustered insert becomes append-only - but B is not viable without an EventId index (finding 3).
3. But without an EventId index, idempotent ingest (WHERE NOT EXISTS (EventId)) degrades to scanning a narrow NC index (B) - the cost grows with table size, and the table loses its uniqueness guarantee. Restoring it with a unique aligned (EventId, OccurredAtUtc) index (B2) re-introduces a random-GUID B-tree, and in this test also made the clustered inserts random: insert throughput, size and fragmentation matched A. So with B2 the flip does not help ingest (no regression either). Whether an insert path that does not sort by EventId (e.g. skipping the NOT EXISTS probe and catching 2627) would keep the clustered side append-only was not tested.
4. Chain stamp (Q12) and purge (Q15) are unchanged within noise; the chain verify read is better in B, equal in B2.

Recommendation

Flip: yes, as B2 (clustered (OccurredAtUtc, EventId) + aligned unique NC (EventId, OccurredAtUtc)), but schedule it deliberately - it is a priority-appropriate (P3) performance fix, not an urgent one, and the read win (default Audit Log page doing a full-table scan) justifies it as table size grows. B alone is not recommended (no cheap idempotency probe, no uniqueness guard). Ingest stays at today's cost under B2 (no regression), reads improve by 2-4 orders of magnitude. An optional later experiment: drop the pre-insert probe on the hot telemetry path in favour of catching 2627, which might recover B's insert win - not benchmarked.

Migration cost, risk and compatibility (not implemented)

• Rebuild is an offline-ish data move of the whole table (DROP/CREATE clustered index, or the CollapseAuditLogToCanonical-style new-table-and-copy pattern on the preserved partition scheme). Every one of the 12 NC indexes is rebuilt too (locator changes). On a large table that is hours of I/O and log, and a write outage for the audit path unless ONLINE = ON (Enterprise/Developer only; the deployment does not guarantee it - see AlignAuditLogEventIdUniqueness). Prefer a maintenance window or per-partition copy while draining ingest (site buffers retain unforwarded rows, so a window is tolerable).
• The hash chain, tombstones, partition-switch purge staging table (SwitchOutPartitionAsync hard-codes a byte-identical column list and must declare the same clustered key; a staging-table key mismatch fails SWITCH), the append-only role grants (DENY UPDATE/DELETE, GRANT UPDATE (ChainSeq, RowHash)), and AuditLogPartitionArchive must be re-verified; grants on the table survive an index-only rebuild but not a drop/rename table swap (re-grant as CollapseAuditLogToCanonical did).
• Code: the repository queries need no change (all predicates are on columns, not the key); the EF model declares HasKey(EventId, OccurredAtUtc) - EF does not manage the physical clustering (raw SQL), so only the model comment/index declaration should be adjusted. The hash-chain UPDATE join on (EventId, OccurredAtUtc) seeks via the unique NC index.
• Mixed-version / rollback: old binaries only issue SQL by column name, so a flipped table works with both old and new binaries, and the flip can be applied before or after an app upgrade; the new-table swap must run with all central nodes stopped or ingest paused. Rollback is the inverse rebuild (same cost) - the migration is reversible in principle, unlike CollapseAuditLogToCanonical. Take a backup first. QA/prod must not be touched without the usual deployment gate.

P4 - per-node KPI sampling cadence

Verified in code: KpiHistoryOptions.SampleInterval (default 60 s, KpiHistoryRecorderActor timer at lines ~218-223) is the single cadence; all IKpiSampleSources (including the per-site/per-node scoped series of the Notification Outbox and Site Call Audit sources) are enumerated once per pass and stamped with one shared tick time, with SourceTimeout (10 s) bounding each source. No per-node or per-source cadence exists and no requirement document asks for one (Component-KpiHistory.md, Component-HealthMonitoring.md). Nothing is actually open beyond an optional design preference ("should per-node series sample on a different interval?") - recommend closing the P4 item as not-a-defect unless someone supplies a use case. The stale "tracked follow-up" text in Component-ConfigurationDatabase.md has been replaced.

P6 - stale spec line

Component-ConfigurationDatabase.md claimed central still sent a bare sinceUtc on AuditLog reconciliation pulls. In fact SiteAuditReconciliationActor keeps a (Since, AfterId) cursor per site and GrpcPullAuditEventsClient sends AfterId; the site's ReadPendingSinceAsync serves strictly-after rows when it is set. The spec line is corrected (same commit as this record).