test(auditlog): redaction safety net edge cases (#23 M5)
This commit is contained in:
Joseph Doherty
@@ -0,0 +1,270 @@
|
||||
using Microsoft.Extensions.Logging;
|
||||
using Microsoft.Extensions.Logging.Abstractions;
|
||||
using Microsoft.Extensions.Options;
|
||||
using ScadaLink.AuditLog.Configuration;
|
||||
using ScadaLink.AuditLog.Payload;
|
||||
using ScadaLink.Commons.Entities.Audit;
|
||||
using ScadaLink.Commons.Types.Enums;
|
||||
|
||||
namespace ScadaLink.AuditLog.Tests.Payload;
|
||||
|
||||
/// <summary>
|
||||
/// Bundle D (M5-T10) safety-net edge cases for
|
||||
/// <see cref="DefaultAuditPayloadFilter"/>. Bundle B already pinned the
|
||||
/// happy-path safety net (catastrophic-backtracking timeout →
|
||||
/// <c><redacted: redactor error></c> + counter bump); this fixture covers
|
||||
/// the pathological / config-mistake corners that production operators will
|
||||
/// hit when typoing a regex or shipping a half-baked redactor list.
|
||||
/// </summary>
|
||||
/// <remarks>
|
||||
/// <para>
|
||||
/// The invariants under test:
|
||||
/// </para>
|
||||
/// <list type="bullet">
|
||||
/// <item>An UNCOMPILABLE pattern (e.g. <c>[unclosed</c>) is logged at warning
|
||||
/// on first encounter and cached as invalid so it never throws again,
|
||||
/// but the redactor-failure COUNTER is not bumped at bind time —
|
||||
/// per the contract on <see cref="IAuditRedactionFailureCounter"/>
|
||||
/// the counter tracks RUNTIME redaction failures only.</item>
|
||||
/// <item>One throwing regex in the middle of a list does NOT poison the
|
||||
/// other patterns — the filter stops at the failing pattern,
|
||||
/// over-redacts the offending field, but lets every other field keep
|
||||
/// the prior cleanly-redacted state and lets the rest of the writer
|
||||
/// pipeline run.</item>
|
||||
/// <item>A live config change that introduces a broken pattern does not
|
||||
/// crash the filter — the bad pattern is silently dropped (logged once)
|
||||
/// and the still-valid patterns continue to redact normally.</item>
|
||||
/// </list>
|
||||
/// </remarks>
|
||||
public class RedactionSafetyNetTests
|
||||
{
|
||||
private static IOptionsMonitor<AuditLogOptions> Monitor(AuditLogOptions? opts = null) =>
|
||||
new StaticMonitor(opts ?? new AuditLogOptions());
|
||||
|
||||
private static AuditEvent NewEvent(
|
||||
AuditStatus status = AuditStatus.Delivered,
|
||||
string? request = null,
|
||||
string? response = null,
|
||||
string? errorDetail = null,
|
||||
string? extra = null,
|
||||
string? target = null) => new()
|
||||
{
|
||||
EventId = Guid.NewGuid(),
|
||||
OccurredAtUtc = DateTime.UtcNow,
|
||||
Channel = AuditChannel.ApiOutbound,
|
||||
Kind = AuditKind.ApiCall,
|
||||
Status = status,
|
||||
Target = target,
|
||||
RequestSummary = request,
|
||||
ResponseSummary = response,
|
||||
ErrorDetail = errorDetail,
|
||||
Extra = extra,
|
||||
};
|
||||
|
||||
[Fact]
|
||||
public void RegexNotCompilable_AtBindTime_LoggedAndSkipped()
|
||||
{
|
||||
// `[unclosed` is a structurally invalid character class — the .NET
|
||||
// regex engine throws ArgumentException at compile time. We assert:
|
||||
// * the filter does NOT throw,
|
||||
// * the OTHER (valid) pattern still redacts hunter2,
|
||||
// * the failure counter is NOT incremented at compile time
|
||||
// (it tracks runtime redaction failures only),
|
||||
// * a warning is logged exactly once.
|
||||
const string badPattern = "[unclosed";
|
||||
const string goodPattern = "\"password\":\\s*\"[^\"]*\"";
|
||||
var opts = new AuditLogOptions
|
||||
{
|
||||
GlobalBodyRedactors = new List<string> { badPattern, goodPattern },
|
||||
};
|
||||
var counter = new CountingRedactionFailureCounter();
|
||||
var spy = new SpyLogger<DefaultAuditPayloadFilter>();
|
||||
var filter = new DefaultAuditPayloadFilter(Monitor(opts), spy, counter);
|
||||
|
||||
var evt = NewEvent(request: "{\"user\":\"alice\",\"password\":\"hunter2\"}");
|
||||
|
||||
var result = filter.Apply(evt);
|
||||
|
||||
Assert.NotNull(result.RequestSummary);
|
||||
Assert.DoesNotContain("hunter2", result.RequestSummary);
|
||||
Assert.Contains("<redacted>", result.RequestSummary);
|
||||
Assert.Equal(0, counter.Count);
|
||||
// Apply twice — the invalid-pattern compile must run AT MOST once;
|
||||
// the sentinel-cache entry stops repeat compile attempts.
|
||||
_ = filter.Apply(evt);
|
||||
var badPatternWarnings = spy.Entries
|
||||
.Where(e => e.Level == LogLevel.Warning && e.Message.Contains(badPattern))
|
||||
.Count();
|
||||
Assert.Equal(1, badPatternWarnings);
|
||||
}
|
||||
|
||||
[Fact]
|
||||
public void MultipleRedactors_OneThrows_OthersStillApply_ToOtherFields()
|
||||
{
|
||||
// Pattern set: [valid-A, evil, valid-B]. The evil pattern is
|
||||
// catastrophic-backtracking on the RequestSummary input (all-'a's +
|
||||
// mismatching suffix) — that field is over-redacted with the error
|
||||
// marker as soon as evil throws. ResponseSummary is processed
|
||||
// INDEPENDENTLY; its input does not trigger evil's backtracking, so
|
||||
// valid-A and valid-B both still apply on that field. This proves a
|
||||
// per-field redactor failure does not poison the rest of the writer
|
||||
// call (the SQL-param stage, the truncation stage, and the other
|
||||
// fields all continue normally).
|
||||
const string validA = "SECRET-[A-Z0-9]+";
|
||||
const string evil = "^(a+)+$"; // catastrophic on long all-'a' string
|
||||
const string validB = "PIN-\\d{4}";
|
||||
var opts = new AuditLogOptions
|
||||
{
|
||||
GlobalBodyRedactors = new List<string> { validA, evil, validB },
|
||||
};
|
||||
var counter = new CountingRedactionFailureCounter();
|
||||
var filter = new DefaultAuditPayloadFilter(
|
||||
Monitor(opts),
|
||||
NullLogger<DefaultAuditPayloadFilter>.Instance,
|
||||
counter);
|
||||
|
||||
// Request: ALL 'a's + a non-'a' suffix character. valid-A does not
|
||||
// match (no SECRET-X prefix), so the buffer reaches `evil` untouched
|
||||
// and triggers the backtracking explosion.
|
||||
var request = new string('a', 30) + "!";
|
||||
// Response: short, mismatches the evil pattern cleanly (no
|
||||
// backtracking), so both valid-A and valid-B run and redact.
|
||||
const string response = "SECRET-ABC456 PIN-9999 other-text";
|
||||
|
||||
var result = filter.Apply(NewEvent(request: request, response: response));
|
||||
|
||||
// RequestSummary: over-redacted (evil pattern threw).
|
||||
Assert.Equal("<redacted: redactor error>", result.RequestSummary);
|
||||
Assert.True(counter.Count >= 1, $"expected counter >= 1, got {counter.Count}");
|
||||
|
||||
// ResponseSummary: clean — both valid regexes still applied; the evil
|
||||
// one ran without throwing on this short input.
|
||||
Assert.NotNull(result.ResponseSummary);
|
||||
Assert.DoesNotContain("SECRET-ABC456", result.ResponseSummary);
|
||||
Assert.DoesNotContain("PIN-9999", result.ResponseSummary);
|
||||
Assert.Contains("<redacted>", result.ResponseSummary);
|
||||
Assert.Contains("other-text", result.ResponseSummary);
|
||||
}
|
||||
|
||||
// Edge case 3 (RedactorReturnsNonStringExceptionType) intentionally
|
||||
// skipped — the brief permits dropping it: there is no portable way to
|
||||
// artificially trigger an OutOfMemoryException inside System.Text.RegularExpressions
|
||||
// from a unit test without writing native interop, and the existing
|
||||
// per-stage try/catch already covers Exception (which OOM and similar
|
||||
// would derive from). Bundle B's RegexThrowsTimeout coverage exercises
|
||||
// the same catch path with a deterministic trigger.
|
||||
|
||||
[Fact]
|
||||
public void ConfigChange_WithBadRegex_LiveTrafficKeepsApplyingValidRegexes()
|
||||
{
|
||||
// Initial config: one valid global redactor — hunter2 is redacted.
|
||||
// Reload: ADD a malformed pattern alongside the original. Per the
|
||||
// safety contract, the bad pattern is logged + skipped, the original
|
||||
// valid pattern keeps redacting, and the filter NEVER throws on the
|
||||
// hot path. The counter must not be bumped at reload time (the
|
||||
// CompiledRegex sentinel covers the bind error before runtime even
|
||||
// sees it).
|
||||
var monitor = new MutableMonitor(new AuditLogOptions
|
||||
{
|
||||
GlobalBodyRedactors = new List<string> { "\"password\":\\s*\"[^\"]*\"" },
|
||||
});
|
||||
var counter = new CountingRedactionFailureCounter();
|
||||
var spy = new SpyLogger<DefaultAuditPayloadFilter>();
|
||||
var filter = new DefaultAuditPayloadFilter(monitor, spy, counter);
|
||||
|
||||
var evt = NewEvent(request: "{\"user\":\"alice\",\"password\":\"hunter2\"}");
|
||||
|
||||
var before = filter.Apply(evt);
|
||||
Assert.DoesNotContain("hunter2", before.RequestSummary!);
|
||||
|
||||
// Reload: malformed pattern added to the list.
|
||||
monitor.Set(new AuditLogOptions
|
||||
{
|
||||
GlobalBodyRedactors = new List<string>
|
||||
{
|
||||
"\"password\":\\s*\"[^\"]*\"",
|
||||
"[unclosed",
|
||||
},
|
||||
});
|
||||
|
||||
var after = filter.Apply(evt);
|
||||
Assert.NotNull(after.RequestSummary);
|
||||
Assert.DoesNotContain("hunter2", after.RequestSummary);
|
||||
Assert.Contains("<redacted>", after.RequestSummary);
|
||||
Assert.Equal(0, counter.Count);
|
||||
// Compile-time warning logged for the broken pattern.
|
||||
Assert.Contains(
|
||||
spy.Entries,
|
||||
e => e.Level == LogLevel.Warning && e.Message.Contains("[unclosed"));
|
||||
}
|
||||
|
||||
/// <summary>Counts <see cref="IAuditRedactionFailureCounter.Increment"/> calls.</summary>
|
||||
private sealed class CountingRedactionFailureCounter : IAuditRedactionFailureCounter
|
||||
{
|
||||
private int _count;
|
||||
public int Count => _count;
|
||||
public void Increment() => System.Threading.Interlocked.Increment(ref _count);
|
||||
}
|
||||
|
||||
/// <summary>IOptionsMonitor test double — returns the same snapshot on every read.</summary>
|
||||
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;
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// IOptionsMonitor test double that supports a live <see cref="Set"/> —
|
||||
/// mirrors the helper used in
|
||||
/// <see cref="ScadaLink.AuditLog.Tests.Configuration.AuditLogOptionsBindingTests"/>;
|
||||
/// kept private here so the safety-net test file remains self-contained.
|
||||
/// </summary>
|
||||
private sealed class MutableMonitor : IOptionsMonitor<AuditLogOptions>
|
||||
{
|
||||
private AuditLogOptions _current;
|
||||
public MutableMonitor(AuditLogOptions initial) => _current = initial;
|
||||
public AuditLogOptions CurrentValue => _current;
|
||||
public AuditLogOptions Get(string? name) => _current;
|
||||
public IDisposable? OnChange(Action<AuditLogOptions, string?> listener) => null;
|
||||
public void Set(AuditLogOptions value) => _current = value;
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Minimal ILogger that records each formatted log line so tests can
|
||||
/// assert on the compile-time warning emission contract — counting
|
||||
/// warnings and grepping the message text.
|
||||
/// </summary>
|
||||
private sealed class SpyLogger<T> : ILogger<T>
|
||||
{
|
||||
private readonly List<LogEntry> _entries = new();
|
||||
|
||||
public IReadOnlyList<LogEntry> Entries
|
||||
{
|
||||
get { lock (_entries) return _entries.ToArray(); }
|
||||
}
|
||||
|
||||
public IDisposable BeginScope<TState>(TState state) where TState : notnull => NullScope.Instance;
|
||||
public bool IsEnabled(LogLevel logLevel) => true;
|
||||
public void Log<TState>(
|
||||
LogLevel logLevel,
|
||||
EventId eventId,
|
||||
TState state,
|
||||
Exception? exception,
|
||||
Func<TState, Exception?, string> formatter)
|
||||
{
|
||||
var msg = formatter(state, exception);
|
||||
lock (_entries) _entries.Add(new LogEntry(logLevel, msg));
|
||||
}
|
||||
|
||||
private sealed class NullScope : IDisposable
|
||||
{
|
||||
public static readonly NullScope Instance = new();
|
||||
public void Dispose() { }
|
||||
}
|
||||
}
|
||||
|
||||
public sealed record LogEntry(LogLevel Level, string Message);
|
||||
}
|
||||
Reference in New Issue
Block a user