using System.Diagnostics; using System.Text; using Microsoft.Extensions.Logging.Abstractions; using Microsoft.Extensions.Options; using ZB.MOM.WW.Audit; using ZB.MOM.WW.ScadaBridge.AuditLog.Configuration; using ZB.MOM.WW.ScadaBridge.AuditLog.Redaction; using ZB.MOM.WW.ScadaBridge.Commons.Types.Audit; using ZB.MOM.WW.ScadaBridge.Commons.Types.Enums; namespace ZB.MOM.WW.ScadaBridge.PerformanceTests.AuditLog; /// /// Bundle D (M5-T9) / C7 (Task 2.5) hot-path latency budget for /// . The redactor 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). /// /// /// C7 re-baseline rationale. The canonical /// works on a single DetailsJson bag (one JSON parse + one re-serialize per /// call) whereas the former typed-field approach touched many individual /// fields. Empirical calibration measurements on Apple M-series (2026-06-02, Release build; /// the CI test itself runs MeasureIterations=2 000 after WarmupIterations=200): /// /// 4 KB body (2 body-regex matches + truncation): p50 ≈ 13 µs, p95 ≈ 14 µs. /// Small DetailsJson, no redactors (JSON parse + rewrite only): p50 ≈ 1.5 µs, p95 ≈ 2 µs. /// True no-op (null DetailsJson, Target within cap — fast path): p50 ≈ 0 µs, p95 ≈ 0 µs. /// /// Thresholds are set conservatively to absorb a 15× CI-slowdown factor (shared, /// contested runners can be significantly slower than a dev laptop). The env-var /// override lets a still-slower runner pass without requiring a code change, while a /// true 50× regression still exceeds even the fallback ceiling. /// /// public class HotPathLatencyTests { private const int WarmupIterations = 200; private const int MeasureIterations = 2_000; // C3/C7 (Task 2.5): the hot-path redactor is the canonical // ScadaBridgeAuditRedactor (IAuditRedactor) operating on the canonical record. private static ScadaBridgeAuditRedactor Filter(AuditLogOptions opts) => new( new StaticMonitor(opts), NullLogger.Instance); private static AuditEvent NewEvent(string request) => ScadaBridgeAuditEventFactory.Create( 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]; } /// /// C7 re-baselined slow-path budget: 4 KiB DetailsJson with two global /// body-regex patterns and truncation. The canonical redactor deserializes /// DetailsJson, runs header → body-regex → truncation, then re-serializes. /// /// /// Empirical p95 ≈ 14 µs on an Apple M-series (Release build, 2026-06-02). /// Budget set to 200 µs (~15× headroom) so a contested shared CI runner does not /// produce a flaky red. Override via SCADABRIDGE_AUDIT_FILTER_4KB_P95_US /// when running on a known-slow machine without a code change. /// [Trait("Category", "Performance")] [Fact] public void Filter_Apply_4KB_DetailsJson_DefaultRedactors_P95_LessThan_200_Microseconds() { // 4 KiB request body inside DetailsJson, laced with a 16-digit token // + a `password` field so the body-regex stage matches twice and the // truncation stage fires (DetailsJson serialised form > DefaultCapBytes). 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: the request body we embed must be > 4 KiB so the truncate stage runs. Assert.True(Encoding.UTF8.GetByteCount(body) > 4096); var filter = Filter(opts); // NewEvent serialises requestSummary into DetailsJson via AuditDetailsCodec — // so the canonical JSON parse+rewrite cost IS measured, not elided. 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)); // C7 re-baseline: empirical p95 ≈ 14 µs; budget 200 µs (≈ 15× headroom for CI). // Old budget was 50 µs (pre-C3 typed-field path, no JSON parse). // Override: SCADABRIDGE_AUDIT_FILTER_4KB_P95_US (µs, positive double). var threshold = GetThresholdMicroseconds("SCADABRIDGE_AUDIT_FILTER_4KB_P95_US", 200d); Assert.True(p95Us < threshold, $"4KB DetailsJson slow-path p95 = {p95Us:F1} µs; threshold = {threshold:F1} µs " + $"(empirical baseline ≈ 14 µs; budget allows 15× CI headroom)"); } /// /// C7 re-baselined small-payload budget: small DetailsJson within the /// default cap, no redactors configured. The redactor still deserializes and /// re-serializes DetailsJson (target IS within cap so the check passes, but /// DetailsJson is non-empty so the slow path runs). /// /// /// Empirical p95 ≈ 2 µs on an Apple M-series (Release build, 2026-06-02). /// Budget set to 30 µs (~15× headroom). Override via /// SCADABRIDGE_AUDIT_FILTER_RAW_P95_US. /// [Trait("Category", "Performance")] [Fact] public void Filter_Apply_SmallDetailsJson_NoRedactors_P95_LessThan_30_Microseconds() { // No redactors configured — body-regex list is empty, SQL-param redactor is // gated on AuditChannel.DbOutbound (we're ApiOutbound), header redactor // short-circuits on non-object DetailsJson fields. Still goes through the // slow path because DetailsJson is non-empty (requestSummary was serialized // into it by NewEvent). Measures JSON parse + re-serialize baseline. var opts = new AuditLogOptions(); var filter = Filter(opts); // Small payload that fits well under the 8 KiB default cap. var evt = NewEvent("hello world"); for (var i = 0; i < WarmupIterations; i++) _ = filter.Apply(evt); var p95Us = MeasureP95Microseconds(MeasureIterations, () => _ = filter.Apply(evt)); // C7 re-baseline: empirical p95 ≈ 2 µs; budget 30 µs (≈ 15× headroom for CI). // Old budget was 10 µs (pre-C3 typed-field path, no JSON parse). // Override: SCADABRIDGE_AUDIT_FILTER_RAW_P95_US (µs, positive double). var threshold = GetThresholdMicroseconds("SCADABRIDGE_AUDIT_FILTER_RAW_P95_US", 30d); Assert.True(p95Us < threshold, $"Small-DetailsJson no-redactors p95 = {p95Us:F1} µs; threshold = {threshold:F1} µs " + $"(empirical baseline ≈ 2 µs; budget allows 15× CI headroom)"); } /// /// Fast-path budget: null/empty DetailsJson AND Target within cap — the /// redactor returns the input instance immediately without any JSON work. /// /// /// Empirical p95 ≈ 0.05 µs (effectively free) on an Apple M-series (Release /// build, 2026-06-02). Budget set to 5 µs — large headroom on an essentially /// zero-cost path. Override via SCADABRIDGE_AUDIT_FILTER_NOOP_P95_US. /// [Trait("Category", "Performance")] [Fact] public void Filter_Apply_NoDetailsJson_FastPath_P95_LessThan_5_Microseconds() { // Construct a minimal canonical event with no DetailsJson and a null Target // so BOTH fast-path conditions are met (detailsEmpty && targetWithinCap). // Apply() must return the same instance without deserializing anything. var opts = new AuditLogOptions(); var filter = Filter(opts); var evt = new AuditEvent { EventId = Guid.NewGuid(), OccurredAtUtc = DateTimeOffset.UtcNow, Actor = string.Empty, Action = "ApiOutbound.ApiCall", Category = "ApiOutbound", Outcome = AuditOutcome.Success, // DetailsJson intentionally null — exercises the true fast path. }; for (var i = 0; i < WarmupIterations; i++) _ = filter.Apply(evt); var p95Us = MeasureP95Microseconds(MeasureIterations, () => _ = filter.Apply(evt)); // Verify same-instance return (fast path must return the input unchanged). var result = filter.Apply(evt); Assert.Same(evt, result); // C7 baseline: empirical p95 ≈ 0 µs (branch + two null checks); budget 5 µs. // Override: SCADABRIDGE_AUDIT_FILTER_NOOP_P95_US (µs, positive double). var threshold = GetThresholdMicroseconds("SCADABRIDGE_AUDIT_FILTER_NOOP_P95_US", 5d); Assert.True(p95Us < threshold, $"No-op fast-path p95 = {p95Us:F1} µs; threshold = {threshold:F1} µs " + $"(empirical baseline ≈ 0 µs; fast path returns input unchanged)"); } 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; } }