diff --git a/docs/requirements/Component-AuditLog.md b/docs/requirements/Component-AuditLog.md index 7dcad870..c36ef201 100644 --- a/docs/requirements/Component-AuditLog.md +++ b/docs/requirements/Component-AuditLog.md @@ -406,6 +406,31 @@ operational `SiteCalls` shape for the dispatcher and UI. - **Safety net** — if a configured redactor throws, the affected payload becomes `""` and `AuditRedactionFailure` increments. We over-redact, never under-redact, on configuration faults. +- **Unavailable redactors fail closed** — a configured pattern that will not + compile (malformed, or over the regex cache's 100 ms compile budget) makes the + whole payload over-redact for that row, exactly as a throwing redactor does. + It is NOT dropped from the redactor set. Dropping it published precisely the + values the operator configured it to suppress, on a row that looked entirely + normal downstream — a silent under-redaction, which this section has always + forbidden (Gitea #35). The distinction that matters is *configured but + unavailable* (suppress) versus *not configured at all* (capture as normal); + conflating the two is what caused the defect, so both cases are pinned by + `AuditRedactorFailClosedTests`. + +Redactor patterns are precompiled when the options snapshot is bound and again on +every reload, so the compile budget is spent off the audit hot path. Compiling +lazily on first event instead put a wall-clock budget on a hot path under +production load, where `RegexOptions.Compiled` IL emission can exceed it for a +perfectly valid pattern — and a rejection is cached for the process lifetime, so +one unlucky moment disabled that redactor until restart. A narrow window remains +between a reload and its warm-up; an event landing there compiles on the hot path +and, if rejected, fails closed, so the worst case is over-redaction. + +An unusable pattern does **not** fail the boot: the node degrades to +over-redaction (safe and loud via `AuditRedactionFailure` plus a startup warning +naming the count) rather than refusing to start. Operators should treat a +non-zero `AuditRedactionFailure` with over-redacted payloads as "fix the +pattern", not as a payload-capture problem. Redaction happens at the write site, before the row touches SQLite (or central MS SQL for direct-write events). Unredacted secrets never persist. diff --git a/src/ZB.MOM.WW.ScadaBridge.AuditLog/Payload/AuditRegexCache.cs b/src/ZB.MOM.WW.ScadaBridge.AuditLog/Payload/AuditRegexCache.cs index ae5fc452..eacdfd66 100644 --- a/src/ZB.MOM.WW.ScadaBridge.AuditLog/Payload/AuditRegexCache.cs +++ b/src/ZB.MOM.WW.ScadaBridge.AuditLog/Payload/AuditRegexCache.cs @@ -46,6 +46,12 @@ internal sealed class AuditRegexCache /// compile time "invalid"); the failure is logged once and the sentinel /// cache entry prevents repeat compile attempts. /// + /// + /// A false return for a pattern the operator actually configured means + /// "this redactor is unavailable", NOT "there is nothing to redact". The + /// caller MUST treat the two differently and fail closed — see + /// . + /// /// The regex pattern string to look up or compile. /// The compiled , or null if the pattern is invalid. /// true if the pattern compiled successfully; false if it is invalid or too slow to compile. @@ -56,6 +62,52 @@ internal sealed class AuditRegexCache return entry.Regex != null; } + /// + /// Compile the supplied patterns up front so the 100 ms budget is measured + /// once, off the audit hot path. + /// + /// + /// + /// The audit-log roadmap specifies these patterns are "precompiled at startup; + /// rejected if compile takes >100ms" and that catastrophic-backtracking + /// candidates are "rejected at startup". Compiling lazily on first event + /// instead measured a wall-clock budget on a hot path under production load, + /// where IL emission can exceed 100 ms for + /// a perfectly valid pattern — rejecting it, and (before the caller was made + /// to fail closed) silently emitting the payload unredacted. + /// + /// + /// Warming is idempotent and cheap to repeat: already-cached patterns short + /// circuit in . + /// Call it once at construction and again whenever the options snapshot + /// changes. Warming never throws — a pattern that fails here caches its + /// sentinel exactly as it would have on the hot path. + /// + /// + /// Patterns to precompile; null entries are skipped. + /// The number of supplied patterns that are unavailable (invalid or over budget). + public int Warm(IEnumerable? patterns) + { + if (patterns == null) + { + return 0; + } + + var unavailable = 0; + foreach (var pattern in patterns) + { + if (string.IsNullOrEmpty(pattern)) + { + continue; + } + if (!TryGet(pattern, out _)) + { + unavailable++; + } + } + return unavailable; + } + private CompiledRegex Compile(string pattern) { try diff --git a/src/ZB.MOM.WW.ScadaBridge.AuditLog/Redaction/ScadaBridgeAuditRedactor.cs b/src/ZB.MOM.WW.ScadaBridge.AuditLog/Redaction/ScadaBridgeAuditRedactor.cs index 20df75da..36435655 100644 --- a/src/ZB.MOM.WW.ScadaBridge.AuditLog/Redaction/ScadaBridgeAuditRedactor.cs +++ b/src/ZB.MOM.WW.ScadaBridge.AuditLog/Redaction/ScadaBridgeAuditRedactor.cs @@ -46,7 +46,7 @@ namespace ZB.MOM.WW.ScadaBridge.AuditLog.Redaction; /// . /// /// -public sealed class ScadaBridgeAuditRedactor : IAuditRedactor +public sealed class ScadaBridgeAuditRedactor : IAuditRedactor, IDisposable { private const string OverRedactedMarker = AuditRedactionPrimitives.OverRedactedEventMarker; @@ -54,6 +54,7 @@ public sealed class ScadaBridgeAuditRedactor : IAuditRedactor private readonly ILogger _logger; private readonly IAuditRedactionFailureCounter _failureCounter; private readonly AuditRegexCache _regexCache; + private readonly IDisposable? _optionsReload; /// /// Primary constructor used by DI — pulls the optional redaction-failure @@ -71,8 +72,87 @@ public sealed class ScadaBridgeAuditRedactor : IAuditRedactor _logger = logger ?? throw new ArgumentNullException(nameof(logger)); _failureCounter = failureCounter ?? new NoOpAuditRedactionFailureCounter(); _regexCache = new AuditRegexCache(_logger); + + // Precompile at construction and on every reload, per the audit-log + // roadmap ("patterns precompiled at startup; rejected if compile takes + // >100ms"). Compiling lazily on first event instead put a wall-clock + // budget on the hot path, where RegexOptions.Compiled IL emission can + // exceed it under load and reject a valid pattern. + WarmCurrentPatterns(); + _optionsReload = _options.OnChange(WarmRedactorPatterns); } + /// + /// Warm from the current options snapshot. Reading CurrentValue happens + /// INSIDE the try: an options provider that throws must not take the + /// constructor down — owns that failure and answers it by + /// over-redacting, which is the behaviour + /// OuterCatch_OptionsThrows_NeverLeaks_AllSensitiveFieldsOverRedacted + /// pins. + /// + private void WarmCurrentPatterns() + { + try + { + WarmRedactorPatterns(_options.CurrentValue); + } + catch (Exception ex) + { + _logger.LogWarning( + ex, "Could not read audit options to precompile redactor patterns; deferring to first use"); + } + } + + /// + /// Compile every configured body / SQL-parameter redactor pattern so the + /// compile budget is spent once, off the audit hot path. + /// + /// + /// Warming is best-effort and deliberately does NOT fail the boot: an + /// unusable pattern degrades that node to over-redaction (safe, loud) rather + /// than taking the node down. There is still a narrow window after a reload + /// where an event can beat the warm-up and compile on the hot path — that + /// path now fails closed, so the worst case is over-redaction, never a + /// silently unredacted payload. + /// + private void WarmRedactorPatterns(AuditLogOptions? opts) + { + if (opts == null) + { + return; + } + + try + { + var unavailable = _regexCache.Warm(opts.GlobalBodyRedactors); + foreach (var over in opts.PerTargetOverrides.Values) + { + unavailable += _regexCache.Warm(over.AdditionalBodyRedactors); + if (!string.IsNullOrEmpty(over.RedactSqlParamsMatching)) + { + unavailable += _regexCache.Warm(new[] { "(?i)" + over.RedactSqlParamsMatching }); + } + } + + if (unavailable > 0) + { + _logger.LogWarning( + "{Count} configured audit redactor pattern(s) are unavailable; audit payloads " + + "matching them will be over-redacted until the patterns are fixed.", + unavailable); + } + } + catch (Exception ex) + { + // Never let warm-up break construction or an options reload; the + // lazy path remains as the (fail-closed) fallback. + _logger.LogWarning(ex, "Audit redactor pattern warm-up failed; patterns will compile on first use"); + } + } + + /// + public void Dispose() => _optionsReload?.Dispose(); + /// /// Applies the full redaction pipeline to and returns a /// filtered copy; returns the same instance unchanged on the fast path. Never throws. @@ -116,7 +196,16 @@ public sealed class ScadaBridgeAuditRedactor : IAuditRedactor // --- Body-regex stage (also runs BEFORE truncation) ----------- // Per-target additions key on the canonical Target. - var bodyRegexes = ResolveBodyRegexes(opts, rawEvent.Target); + var bodyRegexes = ResolveBodyRegexes(opts, rawEvent.Target, out var bodyRedactorUnavailable); + + // FAIL CLOSED. A configured redactor that will not compile must never + // degrade to "emit the body raw" — that publishes precisely the values + // the operator asked to suppress, on a row that looks entirely normal. + if (bodyRedactorUnavailable) + { + return OverRedactUnavailable(rawEvent, "body"); + } + if (bodyRegexes.Count > 0) { request = RedactBody(request, bodyRegexes); @@ -128,10 +217,17 @@ public sealed class ScadaBridgeAuditRedactor : IAuditRedactor // --- SQL parameter redaction stage (DbOutbound only) ---------- // Channel-guarded on the canonical Category; connection key is the // Target prefix before the first '.'. - if (string.Equals(rawEvent.Category, nameof(AuditChannel.DbOutbound), StringComparison.Ordinal) - && TryGetSqlParamRedactor(opts, rawEvent.Target, out var sqlParamRegex)) + if (string.Equals(rawEvent.Category, nameof(AuditChannel.DbOutbound), StringComparison.Ordinal)) { - request = RedactSqlParameters(request, sqlParamRegex!); + if (TryGetSqlParamRedactor( + opts, rawEvent.Target, out var sqlParamRegex, out var sqlRedactorUnavailable)) + { + request = RedactSqlParameters(request, sqlParamRegex!); + } + else if (sqlRedactorUnavailable) + { + return OverRedactUnavailable(rawEvent, "SQL-parameter"); + } } // --- Truncation stage ----------------------------------------- @@ -219,6 +315,23 @@ public sealed class ScadaBridgeAuditRedactor : IAuditRedactor return outcome != AuditOutcome.Success; } + /// + /// Fail-closed exit: a redactor the operator configured is unavailable, so the + /// payload is suppressed wholesale rather than emitted unredacted. Counted on + /// the same as other redaction + /// failures so a disabled redactor is observable, not just a log line. + /// + private AuditEvent OverRedactUnavailable(AuditEvent rawEvent, string stage) + { + _logger.LogWarning( + "A configured {Stage} redactor is unavailable (invalid or over the compile budget); " + + "over-redacting DetailsJson rather than emitting it unredacted. " + + "Fix or remove the pattern — audit payloads stay suppressed until then.", + stage); + IncrementFailureCounter(); + return OverRedact(rawEvent); + } + private string? RedactHeaders(string? json, IList redactList) => AuditRedactionPrimitives.RedactHeaders(json, redactList, _logger, IncrementFailureCounter); @@ -236,11 +349,20 @@ public sealed class ScadaBridgeAuditRedactor : IAuditRedactor /// /// Combine the global and per-target body-redactor lists, returning the - /// compiled-regex set to apply. Patterns that failed compilation are - /// silently skipped. + /// compiled-regex set to apply. /// - private IReadOnlyList ResolveBodyRegexes(AuditLogOptions opts, string? target) + /// + /// is set when a pattern the operator + /// CONFIGURED could not be compiled (invalid, or over the cache's compile + /// budget). The caller must then fail closed — dropping the pattern and + /// emitting the body anyway would silently publish exactly the values the + /// operator asked to have redacted. + /// + private IReadOnlyList ResolveBodyRegexes( + AuditLogOptions opts, string? target, out bool anyUnavailable) { + anyUnavailable = false; + var hasGlobal = opts.GlobalBodyRedactors is { Count: > 0 }; var perTargetAdditions = (target != null && opts.PerTargetOverrides.TryGetValue(target, out var over) @@ -262,6 +384,10 @@ public sealed class ScadaBridgeAuditRedactor : IAuditRedactor { result.Add(rx!); } + else + { + anyUnavailable = true; + } } } if (perTargetAdditions != null) @@ -272,6 +398,10 @@ public sealed class ScadaBridgeAuditRedactor : IAuditRedactor { result.Add(rx!); } + else + { + anyUnavailable = true; + } } } return result; @@ -282,9 +412,18 @@ public sealed class ScadaBridgeAuditRedactor : IAuditRedactor /// target. Connection key = everything before the first . in /// . Patterns are forced case-insensitive. /// - private bool TryGetSqlParamRedactor(AuditLogOptions opts, string? target, out Regex? regex) + /// + /// separates "no SQL redactor is configured for + /// this connection" (fine — return false, capture parameters as normal) from + /// "one IS configured but will not compile" (fail closed). Collapsing the two + /// into a bare false is what let a configured redactor silently emit + /// parameter values verbatim. + /// + private bool TryGetSqlParamRedactor( + AuditLogOptions opts, string? target, out Regex? regex, out bool unavailable) { regex = null; + unavailable = false; if (string.IsNullOrEmpty(target)) { return false; @@ -300,7 +439,13 @@ public sealed class ScadaBridgeAuditRedactor : IAuditRedactor } var cacheKey = "(?i)" + over.RedactSqlParamsMatching; - return _regexCache.TryGet(cacheKey, out regex); + if (_regexCache.TryGet(cacheKey, out regex)) + { + return true; + } + + unavailable = true; + return false; } /// diff --git a/tests/ZB.MOM.WW.ScadaBridge.AuditLog.Tests/Redaction/AuditRedactorFailClosedTests.cs b/tests/ZB.MOM.WW.ScadaBridge.AuditLog.Tests/Redaction/AuditRedactorFailClosedTests.cs new file mode 100644 index 00000000..477de7a0 --- /dev/null +++ b/tests/ZB.MOM.WW.ScadaBridge.AuditLog.Tests/Redaction/AuditRedactorFailClosedTests.cs @@ -0,0 +1,332 @@ +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.Payload; +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.AuditLog.Tests.Redaction; + +/// +/// Guards the fail-closed contract for unavailable redactor patterns +/// (Gitea #35). +/// +/// +/// The defect. rejects a pattern that is +/// invalid OR whose compile exceeds a 100 ms budget, and caches that rejection +/// for the process lifetime. then dropped +/// the rejected pattern from its redactor list and emitted the payload anyway — +/// publishing exactly the values the operator configured it to suppress, on a +/// row that looks completely normal downstream. +/// +/// +/// +/// Why it hid. The budget is wall-clock timed and, before the warm-up +/// added alongside these tests, was measured on the audit hot path. +/// RegexOptions.Compiled emits IL during construction, so a busy node +/// could blow the budget on a perfectly valid pattern. It surfaced only as an +/// intermittent failure of +/// AuditLogOptionsBindingTests.Filter_PicksUp_NewBodyRedactor_OnConfigReload +/// under a loaded full-solution sweep, where it read as a flake. +/// +/// +/// +/// Why these tests use an invalid pattern. An unclosed character class +/// fails compilation deterministically and reaches the SAME rejection sentinel +/// as a timing rejection. Driving the 100 ms budget directly would require +/// making the machine slow on demand — the very nondeterminism that let the +/// defect through. The lever differs from production; the code path does not. +/// +/// +public class AuditRedactorFailClosedTests +{ + /// Unclosed character class — never compiles, on any machine, at any load. + private const string UncompilablePattern = "[unterminated"; + + private const string WorkingPattern = "\"password\":\\s*\"[^\"]*\""; + + private const string Secret = "hunter2"; + + private static AuditEvent NewEvent( + string? target = null, + AuditChannel channel = AuditChannel.ApiOutbound) + { + var details = new AuditDetails + { + RequestSummary = $"{{\"user\":\"alice\",\"password\":\"{Secret}\"}}", + Status = nameof(AuditStatus.Delivered), + }; + return new AuditEvent + { + EventId = Guid.NewGuid(), + OccurredAtUtc = DateTimeOffset.UtcNow, + Actor = "tester", + Action = AuditFieldBuilders.BuildAction(channel, AuditKind.ApiCall), + Category = AuditFieldBuilders.BuildCategory(channel), + Outcome = AuditOutcome.Success, + Target = target, + DetailsJson = AuditDetailsCodec.Serialize(details), + }; + } + + private static (ScadaBridgeAuditRedactor Redactor, CountingCounter Counter) Build(AuditLogOptions opts) + { + var counter = new CountingCounter(); + var redactor = new ScadaBridgeAuditRedactor( + new StaticMonitor(opts), NullLogger.Instance, counter); + return (redactor, counter); + } + + private static string? RequestOf(AuditEvent e) => + AuditDetailsCodec.Deserialize(e.DetailsJson).RequestSummary; + + /// + /// Positive control. Without it the "secret is absent" assertions below would + /// also pass if the redactor simply dropped every payload for any reason, and + /// would prove nothing about the fail-closed path specifically. + /// + [Fact] + public void Control_WorkingPattern_RedactsTheSecretAndKeepsTheRestOfTheBody() + { + var (redactor, counter) = Build(new AuditLogOptions + { + GlobalBodyRedactors = new List { WorkingPattern }, + }); + + var result = RequestOf(redactor.Apply(NewEvent())); + + Assert.DoesNotContain(Secret, result); + Assert.Contains("alice", result); // a working redactor is surgical, not wholesale + Assert.Equal(0, counter.Count); + } + + /// + /// Second control: with NO redactors configured the body is emitted verbatim. + /// This pins the distinction the fix turns on — "nothing to redact" must stay + /// permissive, and only "configured but unavailable" may suppress. + /// + [Fact] + public void Control_NoRedactorsConfigured_EmitsBodyUnchanged() + { + var (redactor, counter) = Build(new AuditLogOptions()); + + var result = RequestOf(redactor.Apply(NewEvent())); + + Assert.Contains(Secret, result); + Assert.Equal(0, counter.Count); + } + + [Fact] + public void UnavailableGlobalBodyRedactor_SuppressesPayload_RatherThanEmittingItRaw() + { + var (redactor, counter) = Build(new AuditLogOptions + { + GlobalBodyRedactors = new List { UncompilablePattern }, + }); + + var result = RequestOf(redactor.Apply(NewEvent())); + + Assert.DoesNotContain(Secret, result); + Assert.Equal(AuditRedactionPrimitives.OverRedactedEventMarker, result); + Assert.Equal(1, counter.Count); + } + + /// + /// The dangerous mixed case: one good pattern and one unusable one. Applying + /// only the good pattern looks like success while the unusable pattern's + /// target sails through, so the whole payload must still be suppressed. + /// + [Fact] + public void OneUnavailablePatternAmongWorkingOnes_StillSuppressesPayload() + { + var (redactor, counter) = Build(new AuditLogOptions + { + GlobalBodyRedactors = new List { WorkingPattern, UncompilablePattern }, + }); + + var result = RequestOf(redactor.Apply(NewEvent())); + + Assert.Equal(AuditRedactionPrimitives.OverRedactedEventMarker, result); + Assert.Equal(1, counter.Count); + } + + [Fact] + public void UnavailablePerTargetBodyRedactor_SuppressesPayload() + { + var opts = new AuditLogOptions(); + opts.PerTargetOverrides["svc"] = new PerTargetRedactionOverride + { + AdditionalBodyRedactors = new List { UncompilablePattern }, + }; + var (redactor, counter) = Build(opts); + + var result = RequestOf(redactor.Apply(NewEvent(target: "svc"))); + + Assert.Equal(AuditRedactionPrimitives.OverRedactedEventMarker, result); + Assert.Equal(1, counter.Count); + } + + /// + /// SQL-parameter redactors reach the cache by a separate path whose bare + /// false return conflated "not configured" with "will not compile". + /// CLAUDE.md records SQL parameter capture as on by default, so this path + /// leaks parameter values. + /// + [Fact] + public void UnavailableSqlParamRedactor_SuppressesPayload() + { + var opts = new AuditLogOptions(); + opts.PerTargetOverrides["conn"] = new PerTargetRedactionOverride + { + RedactSqlParamsMatching = UncompilablePattern, + }; + var (redactor, counter) = Build(opts); + + var result = RequestOf( + redactor.Apply(NewEvent(target: "conn.Table", channel: AuditChannel.DbOutbound))); + + Assert.Equal(AuditRedactionPrimitives.OverRedactedEventMarker, result); + Assert.Equal(1, counter.Count); + } + + /// + /// A SQL redactor configured for a DIFFERENT connection must not suppress + /// this row — otherwise fail-closed would over-reach into unrelated targets. + /// + [Fact] + public void UnavailableSqlParamRedactor_OnAnotherConnection_DoesNotSuppressThisRow() + { + var opts = new AuditLogOptions(); + opts.PerTargetOverrides["other"] = new PerTargetRedactionOverride + { + RedactSqlParamsMatching = UncompilablePattern, + }; + var (redactor, counter) = Build(opts); + + var result = RequestOf( + redactor.Apply(NewEvent(target: "conn.Table", channel: AuditChannel.DbOutbound))); + + Assert.Contains(Secret, result); + Assert.Equal(0, counter.Count); + } + + /// + /// The reload path: a pattern that becomes unavailable AFTER construction must + /// also fail closed. This is the shape that made the original defect a live + /// risk rather than a boot-time one. + /// + [Fact] + public void PatternThatBecomesUnavailableOnReload_FailsClosed() + { + var monitor = new MutableMonitor(new AuditLogOptions + { + GlobalBodyRedactors = new List { WorkingPattern }, + }); + var counter = new CountingCounter(); + using var redactor = new ScadaBridgeAuditRedactor( + monitor, NullLogger.Instance, counter); + + Assert.DoesNotContain(Secret, RequestOf(redactor.Apply(NewEvent()))); + + monitor.Set(new AuditLogOptions + { + GlobalBodyRedactors = new List { UncompilablePattern }, + }); + + Assert.Equal( + AuditRedactionPrimitives.OverRedactedEventMarker, + RequestOf(redactor.Apply(NewEvent()))); + } + + /// + /// Warm-up must happen at construction, so the compile budget is spent off the + /// hot path (audit-log roadmap: "patterns precompiled at startup"). Asserted + /// behaviourally: the FIRST event after construction must already be handled + /// by a compiled pattern. + /// + [Fact] + public void ConstructionWarmsPatterns_SoTheFirstEventIsNotTheOneThatCompiles() + { + var monitor = new MutableMonitor(new AuditLogOptions + { + GlobalBodyRedactors = new List { WorkingPattern }, + }); + + using var redactor = new ScadaBridgeAuditRedactor( + monitor, NullLogger.Instance, new CountingCounter()); + + // Construction alone must have read the options to warm them; a redactor + // that only compiled lazily would not have touched CurrentValue yet. + Assert.True( + monitor.CurrentValueReads > 0, + "the redactor must read its options at construction to precompile patterns"); + } + + private sealed class CountingCounter : IAuditRedactionFailureCounter + { + private int _count; + public int Count => Volatile.Read(ref _count); + public void Increment() => Interlocked.Increment(ref _count); + } + + 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; + } + + private sealed class MutableMonitor : IOptionsMonitor + { + private AuditLogOptions _value; + private readonly List> _listeners = new(); + private int _reads; + + public MutableMonitor(AuditLogOptions value) => _value = value; + + public int CurrentValueReads => Volatile.Read(ref _reads); + + public AuditLogOptions CurrentValue + { + get + { + Interlocked.Increment(ref _reads); + return _value; + } + } + + public AuditLogOptions Get(string? name) => CurrentValue; + + public IDisposable? OnChange(Action listener) + { + lock (_listeners) + { + _listeners.Add(listener); + } + return new Noop(); + } + + public void Set(AuditLogOptions value) + { + _value = value; + Action[] snapshot; + lock (_listeners) + { + snapshot = _listeners.ToArray(); + } + foreach (var l in snapshot) + { + l(value, Options.DefaultName); + } + } + + private sealed class Noop : IDisposable + { + public void Dispose() { } + } + } +} diff --git a/tests/ZB.MOM.WW.ScadaBridge.Host.Tests/GrpcCentralTransportTests.cs b/tests/ZB.MOM.WW.ScadaBridge.Host.Tests/GrpcCentralTransportTests.cs index 733829c0..3446bf90 100644 --- a/tests/ZB.MOM.WW.ScadaBridge.Host.Tests/GrpcCentralTransportTests.cs +++ b/tests/ZB.MOM.WW.ScadaBridge.Host.Tests/GrpcCentralTransportTests.cs @@ -64,8 +64,16 @@ public class GrpcCentralTransportTests : IAsyncLifetime backoffBase: TimeSpan.FromMilliseconds(50), backoffCap: TimeSpan.FromMilliseconds(200)); + /// + /// When set, node A's handler short-circuits every call with this gRPC status + /// instead of reaching its TestServer. See . + /// + private Grpc.Core.StatusCode? _nodeAForcedStatus; + private HttpMessageHandler HandlerFor(string endpoint) => endpoint == EndpointA - ? new ToggleHandler(_nodeA.Server.CreateHandler(), () => _nodeA.IsUp) + ? new GrpcStatusHandler( + new ToggleHandler(_nodeA.Server.CreateHandler(), () => _nodeA.IsUp), + () => _nodeAForcedStatus) : new ToggleHandler(_nodeB.Server.CreateHandler(), () => _nodeB.IsUp); private GrpcCentralTransport NewTransport(CentralChannelProvider provider, CommunicationOptions? options = null) @@ -182,10 +190,43 @@ public class GrpcCentralTransportTests : IAsyncLifetime [Fact] public async Task DeadlineExceeded_IsNotRetriedOnThePeer() { - // THE hard rule. Node A is UP but never replies, so the call deadlines. The transport must - // surface Status.Failure and must NOT try node B (the call may already have executed). + // THE hard rule: on DeadlineExceeded the call may ALREADY have executed, so the transport + // must surface Status.Failure and must NOT try node B. + // + // The status is injected rather than produced by black-holing node A behind a short + // deadline. That older setup was load-dependent and failed intermittently in full-solution + // sweeps: on a saturated machine the call could fail to even START, which IsConnectFailure + // correctly classifies as provably-unsent, so the transport failed over and node B's ack + // arrived instead of a Status.Failure. The test then read as a flake while actually + // reporting that its own premise had not held. Injecting the status makes the failure mode + // the test's subject rather than a race — see BlackHoledNode_DoesNotHang for the + // deadline-is-actually-applied half. + _nodeAForcedStatus = Grpc.Core.StatusCode.DeadlineExceeded; + + using var provider = NewProvider(); + var transport = NewTransport(provider); + var inbox = new Capture(_system); + + transport.SubmitNotification(NewSubmit("n1"), inbox.Ref); + + Assert.IsType(inbox.Receive(TimeSpan.FromSeconds(5))); + Assert.Equal(0, provider.CurrentIndex); // no failover on a deadline + Assert.Equal(0, _nodeB.SubmitCount); // peer never tried + } + + [Fact] + public async Task BlackHoledNode_DoesNotHang_APerCallDeadlineIsApplied() + { + // The other half of the split: a node that accepts the call and never replies must not + // hang the caller forever — a per-call deadline bounds it. Both nodes black-hole, so this + // holds whichever node the transport ends up on and the assertion cannot be perturbed by + // whether the machine was loaded enough to turn the stall into a connect failure. _nodeA.SetBlackHole(); - var shortDeadline = new CommunicationOptions { NotificationForwardTimeout = TimeSpan.FromMilliseconds(300) }; + _nodeB.SetBlackHole(); + var shortDeadline = new CommunicationOptions + { + NotificationForwardTimeout = TimeSpan.FromMilliseconds(300), + }; using var provider = NewProvider(); var transport = NewTransport(provider, shortDeadline); @@ -193,10 +234,9 @@ public class GrpcCentralTransportTests : IAsyncLifetime transport.SubmitNotification(NewSubmit("n1"), inbox.Ref); - // A per-call deadline is applied (the call returns fast instead of hanging on the black hole). + // Returns rather than hanging: the 5 s inbox wait is far longer than the 300 ms deadline, + // so a missing deadline shows up as a TimeoutException from Receive. Assert.IsType(inbox.Receive(TimeSpan.FromSeconds(5))); - Assert.Equal(0, provider.CurrentIndex); // no failover on a deadline - Assert.Equal(0, _nodeB.SubmitCount); // peer never tried } private static NotificationSubmit NewSubmit(string id) => new( @@ -250,6 +290,49 @@ public class GrpcCentralTransportTests : IAsyncLifetime } } + /// + /// Short-circuits a call with a chosen gRPC status, so a test can pick the exact failure class + /// the transport must classify instead of trying to provoke it with timing. + /// + /// + /// Emits a trailers-only response: HTTP 200 with grpc-status in the HEADERS and an empty + /// body, which is the shape gRPC defines for a call that fails before producing a message and + /// which Grpc.Net.Client surfaces as an RpcException carrying that status. + /// + private sealed class GrpcStatusHandler : DelegatingHandler + { + private readonly Func _forced; + + public GrpcStatusHandler(HttpMessageHandler inner, Func forced) + { + InnerHandler = inner; + _forced = forced; + } + + protected override async Task SendAsync( + HttpRequestMessage request, CancellationToken cancellationToken) + { + var forced = _forced(); + if (forced == null) + { + return await base.SendAsync(request, cancellationToken).ConfigureAwait(false); + } + + var response = new HttpResponseMessage(System.Net.HttpStatusCode.OK) + { + Version = new Version(2, 0), + Content = new ByteArrayContent(Array.Empty()), + RequestMessage = request, + }; + response.Content.Headers.ContentType = + new System.Net.Http.Headers.MediaTypeHeaderValue("application/grpc"); + response.Headers.TryAddWithoutValidation( + "grpc-status", ((int)forced.Value).ToString(System.Globalization.CultureInfo.InvariantCulture)); + response.Headers.TryAddWithoutValidation("grpc-message", "injected by GrpcStatusHandler"); + return response; + } + } + /// A gRPC channel handler that throws (a refused connection) while its node is "down". private sealed class ToggleHandler : DelegatingHandler {