audit: body-redactor compile budget fails OPEN — a valid pattern rejected under load disables redaction for the process lifetime #35

New Issue

2026-08-12T02:45:10-04:00

dohertj2 commented

2026-08-12 02:45:10 -04:00

Summary

AuditRegexCache rejects any body/SQL-parameter redaction pattern whose compilation exceeds a 100 ms wall-clock budget, and caches that rejection permanently. A rejected pattern is silently dropped from the redactor list, so the audit row is written unredacted. Because RegexOptions.Compiled emits IL during construction, a perfectly valid pattern can blow the budget purely because the node was busy at the moment it was first used.

The result: a correctly-configured password redactor can stop redacting for the entire process lifetime, writing plaintext secrets into the audit log, with a single Warning line as the only signal.

The code

src/ZB.MOM.WW.ScadaBridge.AuditLog/Payload/AuditRegexCache.cs:60-84

var swStart = Stopwatch.GetTimestamp();
var rx = new Regex(pattern, RegexOptions.Compiled, RegexMatchTimeout);
var elapsedMs = (Stopwatch.GetTimestamp() - swStart) * 1000d / Stopwatch.Frequency;
if (elapsedMs > 100)
{
    _logger.LogWarning(
        "Body redactor pattern compiled in {Elapsed}ms (> 100ms cap); rejecting '{Pattern}'",
        elapsedMs, pattern);
    return CompiledRegex.Invalid;   // cached forever
}

The Invalid sentinel is stored in the ConcurrentDictionary keyed by pattern string, so the pattern is never retried for the life of the process.

Why it fails open

ScadaBridgeAuditRedactor treats a cache miss as "no such redactor", not as an error:

src/ZB.MOM.WW.ScadaBridge.AuditLog/Redaction/ScadaBridgeAuditRedactor.cs:258-274

foreach (var pattern in opts.GlobalBodyRedactors)
{
    if (_regexCache.TryGet(pattern, out var rx))
    {
        result.Add(rx!);      // rejected patterns are simply absent
    }
}

TryGetSqlParamRedactor (line 303) has the same shape — a rejected pattern means SQL parameter values are captured verbatim.

Note the asymmetry. The per-match 50 ms timeout is handled correctly: AuditRedactionPrimitives catches RegexMatchTimeoutException and over-redacts the field, i.e. fails closed. Only the compile-budget path fails open. Two guards on the same control, opposite polarities.

How it was found

AuditLogOptionsBindingTests.Filter_PicksUp_NewBodyRedactor_OnConfigReload failed during a full solution sweep on 2026-08-12:

Assert.DoesNotContain() Failure: Sub-string found
String: "{"user":"alice","password":"hunter2"}"
Found:  "hunter2"

It passes 3/3 in isolation and fails only under a loaded sweep. The test is fully synchronous — there is no config-reload race — so the load sensitivity is the compile budget, not the binding. The test is doing its job; it just looks like a flake.

This surfaced incidentally while validating the ZB.MOM.WW.Auth / MxGateway 0.2.0 bump (7e594054) and is unrelated to it — the code predates that change.

Why this matters beyond the test

The budget is wall-clock timed on the audit hot path, so it is most likely to trip exactly when the node is under load — which is when audit coverage matters most. Failure is silent at the row level: the row is written and looks normal, so nothing downstream can distinguish "no secrets present" from "redactor was disabled". Recovery requires a process restart, and nothing reports the degraded state on the health snapshot.

Suggested directions

Validate patterns at config-bind time, not on the hot path. A slow or invalid pattern then becomes an operator-visible options-validation failure at startup (consistent with the eager-ValidateOnStart convention used across the other 12 components) rather than a silent runtime drop.
If a runtime budget is kept, fail closed. Reuse the existing match-timeout behaviour: over-redact the field rather than emitting it raw.
Don't cache the rejection permanently. A one-off compile stall under load should not disable a redactor until restart; re-validate, or cache success only.
Consider RegexOptions.NonBacktracking instead of Compiled — it bounds match cost structurally, which is what the 50 ms match timeout is approximating, and removes the IL-emission cost that makes construction time load-sensitive in the first place.
Surface the degraded state — a counter or health-snapshot field for "redactors rejected", so a disabled redactor is observable without grepping for one Warning line.

Option 1 plus 2 addresses the security property; 3-5 are hardening.

## Summary `AuditRegexCache` rejects any body/SQL-parameter redaction pattern whose **compilation** exceeds a 100 ms wall-clock budget, and caches that rejection permanently. A rejected pattern is silently dropped from the redactor list, so the audit row is written **unredacted**. Because `RegexOptions.Compiled` emits IL during construction, a perfectly valid pattern can blow the budget purely because the node was busy at the moment it was first used. The result: a correctly-configured password redactor can stop redacting for the entire process lifetime, writing plaintext secrets into the audit log, with a single Warning line as the only signal. ## The code `src/ZB.MOM.WW.ScadaBridge.AuditLog/Payload/AuditRegexCache.cs:60-84` ```csharp var swStart = Stopwatch.GetTimestamp(); var rx = new Regex(pattern, RegexOptions.Compiled, RegexMatchTimeout); var elapsedMs = (Stopwatch.GetTimestamp() - swStart) * 1000d / Stopwatch.Frequency; if (elapsedMs > 100) { _logger.LogWarning( "Body redactor pattern compiled in {Elapsed}ms (> 100ms cap); rejecting '{Pattern}'", elapsedMs, pattern); return CompiledRegex.Invalid; // cached forever } ``` The `Invalid` sentinel is stored in the `ConcurrentDictionary` keyed by pattern string, so the pattern is never retried for the life of the process. ## Why it fails open `ScadaBridgeAuditRedactor` treats a cache miss as "no such redactor", not as an error: `src/ZB.MOM.WW.ScadaBridge.AuditLog/Redaction/ScadaBridgeAuditRedactor.cs:258-274` ```csharp foreach (var pattern in opts.GlobalBodyRedactors) { if (_regexCache.TryGet(pattern, out var rx)) { result.Add(rx!); // rejected patterns are simply absent } } ``` `TryGetSqlParamRedactor` (line 303) has the same shape — a rejected pattern means SQL parameter values are captured verbatim. **Note the asymmetry.** The per-match 50 ms timeout is handled correctly: `AuditRedactionPrimitives` catches `RegexMatchTimeoutException` and **over-redacts** the field, i.e. fails closed. Only the compile-budget path fails open. Two guards on the same control, opposite polarities. ## How it was found `AuditLogOptionsBindingTests.Filter_PicksUp_NewBodyRedactor_OnConfigReload` failed during a full solution sweep on 2026-08-12: ``` Assert.DoesNotContain() Failure: Sub-string found String: "{"user":"alice","password":"hunter2"}" Found: "hunter2" ``` It passes 3/3 in isolation and fails only under a loaded sweep. The test is fully synchronous — there is no config-reload race — so the load sensitivity is the compile budget, not the binding. The test is doing its job; it just looks like a flake. This surfaced incidentally while validating the `ZB.MOM.WW.Auth` / `MxGateway` 0.2.0 bump (`7e594054`) and is unrelated to it — the code predates that change. ## Why this matters beyond the test The budget is wall-clock timed on the audit hot path, so it is most likely to trip exactly when the node is under load — which is when audit coverage matters most. Failure is silent at the row level: the row is written and looks normal, so nothing downstream can distinguish "no secrets present" from "redactor was disabled". Recovery requires a process restart, and nothing reports the degraded state on the health snapshot. ## Suggested directions 1. **Validate patterns at config-bind time, not on the hot path.** A slow or invalid pattern then becomes an operator-visible options-validation failure at startup (consistent with the eager-`ValidateOnStart` convention used across the other 12 components) rather than a silent runtime drop. 2. **If a runtime budget is kept, fail closed.** Reuse the existing match-timeout behaviour: over-redact the field rather than emitting it raw. 3. **Don't cache the rejection permanently.** A one-off compile stall under load should not disable a redactor until restart; re-validate, or cache success only. 4. **Consider `RegexOptions.NonBacktracking` instead of `Compiled`** — it bounds match cost structurally, which is what the 50 ms match timeout is approximating, and removes the IL-emission cost that makes construction time load-sensitive in the first place. 5. **Surface the degraded state** — a counter or health-snapshot field for "redactors rejected", so a disabled redactor is observable without grepping for one Warning line. Option 1 plus 2 addresses the security property; 3-5 are hardening.

dohertj2 commented

2026-08-12 03:07:16 -04:00

Fixed in 006202f3.

What shipped

1. Fail closed (the security property). 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 was the actual defect, so both are pinned by tests.

This also covers the SQL path, which was worse than the original report described: 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.

2. Precompile off the hot path. This turned out to be implementation drift, not a design choice — the audit-log roadmap specifies patterns are "precompiled at startup; rejected if compile takes >100ms" and that backtracking candidates are "rejected at startup", in three separate places. The implementation had drifted to lazy first-event compilation, which is what put a wall-clock budget on a hot path under production load. Warm-up now runs at construction and on every options reload.

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 through Apply's over-redact path rather than the constructor.

Component-AuditLog.md gains the rule explicitly. Worth noting it already required "we over-redact, never under-redact, on configuration faults" — so this was a violation of a documented invariant, not an undefined case.

Verification

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.
Adding DeadlineExceeded to IsConnectFailure fails the rewritten transport test.

AuditLog 367/367. Filter_PicksUp_NewBodyRedactor_OnConfigReload — the intermittent failure that exposed this — is green in a full sweep for the first time.

The tests use an invalid pattern (unclosed character class) rather than trying to provoke the 100 ms budget, since driving the budget directly would require making the machine slow on demand. The lever differs from production; the rejection code path is identical.

Deliberately not addressed

Directions 3 and 4 from the original report are not done, and are now hardening rather than a leak:

The 100 ms budget is still a weak proxy for catastrophic backtracking. RegexOptions.Compiled defers JIT to first match, so construction time measures the wrong thing. Moving it to startup makes it deterministic-ish and safe, but it is still not a real backtracking check. RegexOptions.NonBacktracking would bound match cost structurally.
A rejection is still cached permanently. Kept because the sentinel prevents hot-path recompile storms, and a mis-fire is now safe (over-redaction) rather than dangerous.

Leaving this open for those two, or close it and file a follow-up — no leak remains either way.

Fixed in `006202f3`. ## What shipped **1. Fail closed (the security property).** 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 was the actual defect, so both are pinned by tests. This also covers the SQL path, which was worse than the original report described: `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. **2. Precompile off the hot path.** This turned out to be implementation drift, not a design choice — the audit-log roadmap specifies patterns are "precompiled at startup; rejected if compile takes >100ms" and that backtracking candidates are "rejected at startup", in three separate places. The implementation had drifted to lazy first-event compilation, which is what put a wall-clock budget on a hot path under production load. Warm-up now runs at construction and on every options reload. 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 through `Apply`'s over-redact path rather than the constructor. `Component-AuditLog.md` gains the rule explicitly. Worth noting it already required *"we over-redact, never under-redact, on configuration faults"* — so this was a violation of a documented invariant, not an undefined case. ## Verification 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. - Adding `DeadlineExceeded` to `IsConnectFailure` fails the rewritten transport test. AuditLog 367/367. `Filter_PicksUp_NewBodyRedactor_OnConfigReload` — the intermittent failure that exposed this — is green in a full sweep for the first time. The tests use an invalid pattern (unclosed character class) rather than trying to provoke the 100 ms budget, since driving the budget directly would require making the machine slow on demand. The lever differs from production; the rejection code path is identical. ## Deliberately not addressed Directions 3 and 4 from the original report are **not** done, and are now hardening rather than a leak: - **The 100 ms budget is still a weak proxy for catastrophic backtracking.** `RegexOptions.Compiled` defers JIT to first match, so construction time measures the wrong thing. Moving it to startup makes it deterministic-ish and safe, but it is still not a real backtracking check. `RegexOptions.NonBacktracking` would bound match cost structurally. - **A rejection is still cached permanently.** Kept because the sentinel prevents hot-path recompile storms, and a mis-fire is now safe (over-redaction) rather than dangerous. Leaving this open for those two, or close it and file a follow-up — no leak remains either way.

dohertj2 referenced this issue from a commit

2026-08-12 03:09:31 -04:00

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

Sign in to join this conversation.

1 Participants

Notifications

Due Date

No due date set.

Dependencies

No dependencies set.

Reference: dohertj2/ScadaBridge#35