fix(audit): fail closed when a configured redactor is unavailable (#35)

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.
This commit is contained in:
Joseph Doherty
2026-08-12 03:04:50 -04:00
parent 7e594054e4
commit 006202f3c7
5 changed files with 654 additions and 17 deletions
@@ -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.
/// </summary>
/// <remarks>
/// A <c>false</c> 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
/// <see cref="ZB.MOM.WW.ScadaBridge.AuditLog.Redaction.ScadaBridgeAuditRedactor"/>.
/// </remarks>
/// <param name="pattern">The regex pattern string to look up or compile.</param>
/// <param name="regex">The compiled <see cref="Regex"/>, or <c>null</c> if the pattern is invalid.</param>
/// <returns><c>true</c> if the pattern compiled successfully; <c>false</c> if it is invalid or too slow to compile.</returns>
@@ -56,6 +62,52 @@ internal sealed class AuditRegexCache
return entry.Regex != null;
}
/// <summary>
/// Compile the supplied patterns up front so the 100 ms budget is measured
/// once, off the audit hot path.
/// </summary>
/// <remarks>
/// <para>
/// 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 <see cref="RegexOptions.Compiled"/> 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.
/// </para>
/// <para>
/// Warming is idempotent and cheap to repeat: already-cached patterns short
/// circuit in <see cref="ConcurrentDictionary{TKey,TValue}.GetOrAdd(TKey, Func{TKey, TValue})"/>.
/// 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.
/// </para>
/// </remarks>
/// <param name="patterns">Patterns to precompile; <c>null</c> entries are skipped.</param>
/// <returns>The number of supplied patterns that are unavailable (invalid or over budget).</returns>
public int Warm(IEnumerable<string?>? 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
@@ -46,7 +46,7 @@ namespace ZB.MOM.WW.ScadaBridge.AuditLog.Redaction;
/// <see cref="SafeDefaultAuditRedactor"/>.
/// </para>
/// </remarks>
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<ScadaBridgeAuditRedactor> _logger;
private readonly IAuditRedactionFailureCounter _failureCounter;
private readonly AuditRegexCache _regexCache;
private readonly IDisposable? _optionsReload;
/// <summary>
/// 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);
}
/// <summary>
/// Warm from the current options snapshot. Reading <c>CurrentValue</c> happens
/// INSIDE the try: an options provider that throws must not take the
/// constructor down — <see cref="Apply"/> owns that failure and answers it by
/// over-redacting, which is the behaviour
/// <c>OuterCatch_OptionsThrows_NeverLeaks_AllSensitiveFieldsOverRedacted</c>
/// pins.
/// </summary>
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");
}
}
/// <summary>
/// Compile every configured body / SQL-parameter redactor pattern so the
/// compile budget is spent once, off the audit hot path.
/// </summary>
/// <remarks>
/// 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.
/// </remarks>
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");
}
}
/// <inheritdoc />
public void Dispose() => _optionsReload?.Dispose();
/// <summary>
/// Applies the full redaction pipeline to <paramref name="rawEvent"/> 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;
}
/// <summary>
/// Fail-closed exit: a redactor the operator configured is unavailable, so the
/// payload is suppressed wholesale rather than emitted unredacted. Counted on
/// the same <see cref="IAuditRedactionFailureCounter"/> as other redaction
/// failures so a disabled redactor is observable, not just a log line.
/// </summary>
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<string> redactList)
=> AuditRedactionPrimitives.RedactHeaders(json, redactList, _logger, IncrementFailureCounter);
@@ -236,11 +349,20 @@ public sealed class ScadaBridgeAuditRedactor : IAuditRedactor
/// <summary>
/// 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.
/// </summary>
private IReadOnlyList<Regex> ResolveBodyRegexes(AuditLogOptions opts, string? target)
/// <remarks>
/// <paramref name="anyUnavailable"/> 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.
/// </remarks>
private IReadOnlyList<Regex> 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 <c>.</c> in
/// <paramref name="target"/>. Patterns are forced case-insensitive.
/// </summary>
private bool TryGetSqlParamRedactor(AuditLogOptions opts, string? target, out Regex? regex)
/// <remarks>
/// <paramref name="unavailable"/> 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 <c>false</c> is what let a configured redactor silently emit
/// parameter values verbatim.
/// </remarks>
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;
}
/// <summary>