test(auditlog): hot-path latency budget for IAuditPayloadFilter (#23 M5)

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;
+
+/// <summary>
+/// Bundle D (M5-T9) hot-path latency budget for <see cref="IAuditPayloadFilter"/>.
+/// 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.
+/// </summary>
+/// <remarks>
+/// <para>
+/// Methodology: warm-up + N iterations, time each <see cref="IAuditPayloadFilter.Apply"/>
+/// with <see cref="Stopwatch"/>, sort, take p95, assert under threshold. Matches
+/// the simple-loop style of the existing <c>StaggeredStartupTests</c> /
+/// <c>HealthAggregationTests</c> in this project (no BenchmarkDotNet).
+/// </para>
+/// <para>
+/// 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.
+/// </para>
+/// </remarks>
+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<DefaultAuditPayloadFilter>.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,
+        };
+    }
+
+    /// <summary>
+    /// Run <paramref name="fn"/> N times, returning the p95 in microseconds.
+    /// Single-threaded; <see cref="Stopwatch.GetTimestamp"/> for high-res
+    /// timing.
+    /// </summary>
+    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<string>
+            {
+                "\"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<AuditLogOptions>
+    {
+        private readonly AuditLogOptions _value;
+        public StaticMonitor(AuditLogOptions value) => _value = value;
+        public AuditLogOptions CurrentValue => _value;
+        public AuditLogOptions Get(string? name) => _value;
+        public IDisposable? OnChange(Action<AuditLogOptions, string?> listener) => null;
+    }
+}

tests/ScadaLink.PerformanceTests/ScadaLink.PerformanceTests.csproj

@@ -21,6 +21,7 @@
   </ItemGroup>
 
   <ItemGroup>
+    <ProjectReference Include="../../src/ScadaLink.AuditLog/ScadaLink.AuditLog.csproj" />
     <ProjectReference Include="../../src/ScadaLink.Commons/ScadaLink.Commons.csproj" />
     <ProjectReference Include="../../src/ScadaLink.HealthMonitoring/ScadaLink.HealthMonitoring.csproj" />
     <ProjectReference Include="../../src/ScadaLink.StoreAndForward/ScadaLink.StoreAndForward.csproj" />