006202f3c7
Component-AuditLog.md has always required "we over-redact, never under-redact, on configuration faults", but the body / SQL-parameter redactors violated it. AuditRegexCache rejects a pattern that is malformed OR whose compile exceeds a 100 ms budget, caching the rejection for the process lifetime. ScadaBridgeAuditRedactor then simply dropped the rejected pattern from its redactor set and emitted the payload anyway — publishing precisely the values the operator configured it to suppress, onto a row that looks entirely normal downstream. Recovery required a process restart and the only signal was one Warning line. The SQL path was worse: TryGetSqlParamRedactor returned a bare false for both "no redactor configured for this connection" and "the configured one will not compile", and CLAUDE.md records SQL parameter capture as on by default. Two changes: 1. Fail closed. A pattern that is CONFIGURED but unavailable now over-redacts the whole payload and increments AuditRedactionFailure, reusing the existing safety-net path. "Not configured at all" stays permissive — conflating those two states is the actual defect, so both are pinned by tests. 2. Precompile off the hot path. The audit-log roadmap specifies patterns are "precompiled at startup; rejected if compile takes >100ms"; the implementation had drifted to compiling lazily on first event, which put a wall-clock budget on a hot path under production load. RegexOptions.Compiled emits IL during construction, so a busy node could blow the budget on a perfectly valid pattern. Warm-up now runs at construction and on every options reload. The residual window between a reload and its warm-up is safe because that path now fails closed. Warm-up deliberately does not fail the boot — an unusable pattern degrades the node to over-redaction (safe, loud) rather than refusing to start. Reading CurrentValue happens inside the warm-up try so an options provider that throws still surfaces via Apply's over-redact path, not the constructor (OuterCatch_OptionsThrows_NeverLeaks_AllSensitiveFieldsOverRedacted). Also de-flakes GrpcCentralTransportTests.DeadlineExceeded_IsNotRetriedOnThePeer, which is how this was found. It black-holed node A behind a 300 ms deadline, but on a saturated machine the call could fail to even START — a genuinely-unsent failure that IsConnectFailure correctly fails over on, so node B's ack arrived instead of the expected Status.Failure. The test read as a flake while actually reporting that its own premise had not held. Split in two: the hard rule now injects an explicit DeadlineExceeded via a trailers-only response (deterministic, load-independent), and a new BlackHoledNode_DoesNotHang covers the deadline-is-actually-applied half with both nodes black-holed so no ack can arrive down any path. Verified: both fixes were confirmed to fail before they pass — reverting the fail-closed guard fails exactly the 5 fail-closed tests while the 4 controls still pass, and adding DeadlineExceeded to IsConnectFailure fails the rewritten transport test. AuditLog 367/367, Host.Tests GrpcCentralTransport 8/8, solution build clean. The previously-intermittent Filter_PicksUp_NewBodyRedactor_OnConfigReload is green in a full sweep for the first time. Not addressed here, and noted on #35: the 100 ms wall-clock budget remains a weak proxy for catastrophic backtracking (RegexOptions.Compiled defers JIT to first match, so construction time measures the wrong thing), and a rejection is still cached permanently. Both are now safe rather than dangerous, so they are hardening rather than a leak.
333 lines
12 KiB
C#
333 lines
12 KiB
C#
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;
|
|
|
|
/// <summary>
|
|
/// Guards the fail-closed contract for unavailable redactor patterns
|
|
/// (Gitea #35).
|
|
///
|
|
/// <para>
|
|
/// <b>The defect.</b> <see cref="AuditRegexCache"/> rejects a pattern that is
|
|
/// invalid OR whose compile exceeds a 100 ms budget, and caches that rejection
|
|
/// for the process lifetime. <see cref="ScadaBridgeAuditRedactor"/> 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.
|
|
/// </para>
|
|
///
|
|
/// <para>
|
|
/// <b>Why it hid.</b> The budget is wall-clock timed and, before the warm-up
|
|
/// added alongside these tests, was measured on the audit hot path.
|
|
/// <c>RegexOptions.Compiled</c> 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
|
|
/// <c>AuditLogOptionsBindingTests.Filter_PicksUp_NewBodyRedactor_OnConfigReload</c>
|
|
/// under a loaded full-solution sweep, where it read as a flake.
|
|
/// </para>
|
|
///
|
|
/// <para>
|
|
/// <b>Why these tests use an invalid pattern.</b> 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.
|
|
/// </para>
|
|
/// </summary>
|
|
public class AuditRedactorFailClosedTests
|
|
{
|
|
/// <summary>Unclosed character class — never compiles, on any machine, at any load.</summary>
|
|
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<ScadaBridgeAuditRedactor>.Instance, counter);
|
|
return (redactor, counter);
|
|
}
|
|
|
|
private static string? RequestOf(AuditEvent e) =>
|
|
AuditDetailsCodec.Deserialize(e.DetailsJson).RequestSummary;
|
|
|
|
/// <summary>
|
|
/// 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.
|
|
/// </summary>
|
|
[Fact]
|
|
public void Control_WorkingPattern_RedactsTheSecretAndKeepsTheRestOfTheBody()
|
|
{
|
|
var (redactor, counter) = Build(new AuditLogOptions
|
|
{
|
|
GlobalBodyRedactors = new List<string> { 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);
|
|
}
|
|
|
|
/// <summary>
|
|
/// 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.
|
|
/// </summary>
|
|
[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<string> { UncompilablePattern },
|
|
});
|
|
|
|
var result = RequestOf(redactor.Apply(NewEvent()));
|
|
|
|
Assert.DoesNotContain(Secret, result);
|
|
Assert.Equal(AuditRedactionPrimitives.OverRedactedEventMarker, result);
|
|
Assert.Equal(1, counter.Count);
|
|
}
|
|
|
|
/// <summary>
|
|
/// 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.
|
|
/// </summary>
|
|
[Fact]
|
|
public void OneUnavailablePatternAmongWorkingOnes_StillSuppressesPayload()
|
|
{
|
|
var (redactor, counter) = Build(new AuditLogOptions
|
|
{
|
|
GlobalBodyRedactors = new List<string> { 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<string> { UncompilablePattern },
|
|
};
|
|
var (redactor, counter) = Build(opts);
|
|
|
|
var result = RequestOf(redactor.Apply(NewEvent(target: "svc")));
|
|
|
|
Assert.Equal(AuditRedactionPrimitives.OverRedactedEventMarker, result);
|
|
Assert.Equal(1, counter.Count);
|
|
}
|
|
|
|
/// <summary>
|
|
/// SQL-parameter redactors reach the cache by a separate path whose bare
|
|
/// <c>false</c> return conflated "not configured" with "will not compile".
|
|
/// CLAUDE.md records SQL parameter capture as on by default, so this path
|
|
/// leaks parameter values.
|
|
/// </summary>
|
|
[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);
|
|
}
|
|
|
|
/// <summary>
|
|
/// A SQL redactor configured for a DIFFERENT connection must not suppress
|
|
/// this row — otherwise fail-closed would over-reach into unrelated targets.
|
|
/// </summary>
|
|
[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);
|
|
}
|
|
|
|
/// <summary>
|
|
/// 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.
|
|
/// </summary>
|
|
[Fact]
|
|
public void PatternThatBecomesUnavailableOnReload_FailsClosed()
|
|
{
|
|
var monitor = new MutableMonitor(new AuditLogOptions
|
|
{
|
|
GlobalBodyRedactors = new List<string> { WorkingPattern },
|
|
});
|
|
var counter = new CountingCounter();
|
|
using var redactor = new ScadaBridgeAuditRedactor(
|
|
monitor, NullLogger<ScadaBridgeAuditRedactor>.Instance, counter);
|
|
|
|
Assert.DoesNotContain(Secret, RequestOf(redactor.Apply(NewEvent())));
|
|
|
|
monitor.Set(new AuditLogOptions
|
|
{
|
|
GlobalBodyRedactors = new List<string> { UncompilablePattern },
|
|
});
|
|
|
|
Assert.Equal(
|
|
AuditRedactionPrimitives.OverRedactedEventMarker,
|
|
RequestOf(redactor.Apply(NewEvent())));
|
|
}
|
|
|
|
/// <summary>
|
|
/// 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.
|
|
/// </summary>
|
|
[Fact]
|
|
public void ConstructionWarmsPatterns_SoTheFirstEventIsNotTheOneThatCompiles()
|
|
{
|
|
var monitor = new MutableMonitor(new AuditLogOptions
|
|
{
|
|
GlobalBodyRedactors = new List<string> { WorkingPattern },
|
|
});
|
|
|
|
using var redactor = new ScadaBridgeAuditRedactor(
|
|
monitor, NullLogger<ScadaBridgeAuditRedactor>.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<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;
|
|
}
|
|
|
|
private sealed class MutableMonitor : IOptionsMonitor<AuditLogOptions>
|
|
{
|
|
private AuditLogOptions _value;
|
|
private readonly List<Action<AuditLogOptions, string?>> _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<AuditLogOptions, string?> listener)
|
|
{
|
|
lock (_listeners)
|
|
{
|
|
_listeners.Add(listener);
|
|
}
|
|
return new Noop();
|
|
}
|
|
|
|
public void Set(AuditLogOptions value)
|
|
{
|
|
_value = value;
|
|
Action<AuditLogOptions, string?>[] snapshot;
|
|
lock (_listeners)
|
|
{
|
|
snapshot = _listeners.ToArray();
|
|
}
|
|
foreach (var l in snapshot)
|
|
{
|
|
l(value, Options.DefaultName);
|
|
}
|
|
}
|
|
|
|
private sealed class Noop : IDisposable
|
|
{
|
|
public void Dispose() { }
|
|
}
|
|
}
|
|
}
|