From 4eeda45f0e96df174c8264e80aa1bfab2e344346 Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Wed, 20 May 2026 17:36:29 -0400 Subject: [PATCH] test(auditlog): hot-path latency budget for IAuditPayloadFilter (#23 M5) --- .../AuditLog/HotPathLatencyTests.cs | 163 ++++++++++++++++++ .../ScadaLink.PerformanceTests.csproj | 1 + 2 files changed, 164 insertions(+) create mode 100644 tests/ScadaLink.PerformanceTests/AuditLog/HotPathLatencyTests.cs diff --git a/tests/ScadaLink.PerformanceTests/AuditLog/HotPathLatencyTests.cs b/tests/ScadaLink.PerformanceTests/AuditLog/HotPathLatencyTests.cs new file mode 100644 index 0000000..45b5134 --- /dev/null +++ b/tests/ScadaLink.PerformanceTests/AuditLog/HotPathLatencyTests.cs @@ -0,0 +1,163 @@ +using System.Diagnostics; +using System.Text; +using Microsoft.Extensions.Logging.Abstractions; +using Microsoft.Extensions.Options; +using ScadaLink.AuditLog.Configuration; +using ScadaLink.AuditLog.Payload; +using ScadaLink.Commons.Entities.Audit; +using ScadaLink.Commons.Types.Enums; + +namespace ScadaLink.PerformanceTests.AuditLog; + +/// +/// Bundle D (M5-T9) hot-path latency budget for . +/// The filter sits between event construction and persistence on every audit +/// row — site SQLite hot-path and central direct-write both — so it MUST stay +/// out of the way of script-thread latency. +/// +/// +/// +/// Methodology: warm-up + N iterations, time each +/// with , sort, take p95, assert under threshold. Matches +/// the simple-loop style of the existing StaggeredStartupTests / +/// HealthAggregationTests in this project (no BenchmarkDotNet). +/// +/// +/// Threshold note: the spec says "set during M5 brainstorm" — pick targets that +/// are an order of magnitude faster than the SQLite write they precede (the +/// site writer's bottleneck is the disk fsync, not the in-memory filter). +/// Reality may diverge on slow CI; the assertions include the empirical +/// fall-back the task brief calls for (p95 + 30% regression guard) wired +/// through environment-variable override so a slow shared runner doesn't +/// flake the build but a 10x regression still does. +/// +/// +public class HotPathLatencyTests +{ + private const int WarmupIterations = 200; + private const int MeasureIterations = 2_000; + + private static DefaultAuditPayloadFilter Filter(AuditLogOptions opts) => new( + new StaticMonitor(opts), + NullLogger.Instance); + + private static AuditEvent NewEvent(string request) + { + return new AuditEvent + { + EventId = Guid.NewGuid(), + OccurredAtUtc = DateTime.UtcNow, + Channel = AuditChannel.ApiOutbound, + Kind = AuditKind.ApiCall, + Status = AuditStatus.Delivered, + Target = "esg.target", + RequestSummary = request, + }; + } + + /// + /// Run N times, returning the p95 in microseconds. + /// Single-threaded; for high-res + /// timing. + /// + private static double MeasureP95Microseconds(int iterations, Action fn) + { + var samples = new double[iterations]; + var ticksToMicroseconds = 1_000_000d / Stopwatch.Frequency; + for (var i = 0; i < iterations; i++) + { + var start = Stopwatch.GetTimestamp(); + fn(); + var end = Stopwatch.GetTimestamp(); + samples[i] = (end - start) * ticksToMicroseconds; + } + Array.Sort(samples); + var p95Index = (int)Math.Ceiling(iterations * 0.95) - 1; + return samples[p95Index]; + } + + [Trait("Category", "Performance")] + [Fact] + public void Filter_Apply_4KB_Body_DefaultRedactors_P95_LessThan_50_Microseconds() + { + // 4 KiB body laced with a 16-digit token + a `password` field so the + // header-redact stage is a no-op (input isn't a JSON object with a + // headers field), the body regex stage matches twice, and the + // truncation stage runs after redaction. Mirrors a typical + // medium-sized HTTP POST body that an outbound API audit row would + // carry. + var opts = new AuditLogOptions + { + // Keep the cap modest so the truncation path actually fires. + DefaultCapBytes = 4096, + GlobalBodyRedactors = new List + { + "\"password\":\\s*\"[^\"]*\"", + "\\d{16}", + }, + }; + var pad = new string('x', 4 * 1024); + var body = "{\"user\":\"alice\",\"password\":\"hunter2\",\"card\":\"4111111111111111\",\"pad\":\"" + pad + "\"}"; + // Sanity: we actually want > 4 KiB so the truncate stage runs. + Assert.True(Encoding.UTF8.GetByteCount(body) > 4096); + + var filter = Filter(opts); + var evt = NewEvent(body); + + // Warm-up — JIT, regex compile, dictionary populate. + for (var i = 0; i < WarmupIterations; i++) _ = filter.Apply(evt); + + var p95Us = MeasureP95Microseconds(MeasureIterations, () => _ = filter.Apply(evt)); + + // Default budget 50 µs (spec target). Override via env for slow CI: + // SCADALINK_AUDIT_FILTER_4KB_P95_US — interpret as the regression + // guard threshold. Print the observed value so a missed budget gives + // useful telemetry on the test output. + var threshold = GetThresholdMicroseconds("SCADALINK_AUDIT_FILTER_4KB_P95_US", 50d); + Assert.True(p95Us < threshold, + $"4KB body filter p95 = {p95Us:F1} µs; threshold = {threshold:F1} µs"); + } + + [Trait("Category", "Performance")] + [Fact] + public void Filter_Apply_RawEvent_NoRedactors_P95_LessThan_10_Microseconds() + { + // No redactors configured — header redactor short-circuits on the + // non-JSON-object pre-check, body redactor list is empty, SQL param + // redactor is gated on AuditChannel.DbOutbound (we're ApiOutbound). + // Just the per-field truncation walk. Should be effectively free. + var opts = new AuditLogOptions(); + var filter = Filter(opts); + + // Small payload that fits under the 8 KiB default cap — no truncation, + // just the byte-count check per field. + var evt = NewEvent("hello world"); + + for (var i = 0; i < WarmupIterations; i++) _ = filter.Apply(evt); + + var p95Us = MeasureP95Microseconds(MeasureIterations, () => _ = filter.Apply(evt)); + + var threshold = GetThresholdMicroseconds("SCADALINK_AUDIT_FILTER_RAW_P95_US", 10d); + Assert.True(p95Us < threshold, + $"Raw-event filter p95 = {p95Us:F1} µs; threshold = {threshold:F1} µs"); + } + + private static double GetThresholdMicroseconds(string envVar, double defaultUs) + { + var raw = Environment.GetEnvironmentVariable(envVar); + if (raw != null && double.TryParse(raw, out var parsed) && parsed > 0) + { + return parsed; + } + return defaultUs; + } + + private sealed class StaticMonitor : IOptionsMonitor + { + private readonly AuditLogOptions _value; + public StaticMonitor(AuditLogOptions value) => _value = value; + public AuditLogOptions CurrentValue => _value; + public AuditLogOptions Get(string? name) => _value; + public IDisposable? OnChange(Action listener) => null; + } +} diff --git a/tests/ScadaLink.PerformanceTests/ScadaLink.PerformanceTests.csproj b/tests/ScadaLink.PerformanceTests/ScadaLink.PerformanceTests.csproj index fb6592c..659a59d 100644 --- a/tests/ScadaLink.PerformanceTests/ScadaLink.PerformanceTests.csproj +++ b/tests/ScadaLink.PerformanceTests/ScadaLink.PerformanceTests.csproj @@ -21,6 +21,7 @@ +