feat(api): a two-stage Serilog pipeline so every sink can be wrapped

src/Cluckwork.Api/Logging/ExceptionRedactingSink.cs

@@ -0,0 +1,99 @@
+namespace Cluckwork.Api.Logging;
+
+using Serilog.Core;
+using Serilog.Events;
+
+// The structural gap a property-mutating ILogEventEnricher cannot close, split
+// out of #273's log-redaction work as its own reviewable unit (codex review
+// round 2, P1b).
+//
+// An ILogEventEnricher only ever sees `logEvent.Properties`. `LogEvent.Exception`
+// is a get-only property with no mutator and no Serilog API to replace it, and
+// Serilog renders it SEPARATELY from the properties (the `{Exception}` output
+// token calls `Exception.ToString()`; `Serilog.Formatting.Compact` writes the
+// same text as `@x`). So an ordinary `logger.LogError(ex, ...)` sends the
+// exception's message and stack text to every sink completely unredacted —
+// including Npgsql's, whose messages routinely carry the connection string.
+//
+// The only place in Serilog's pipeline where an event can be REPLACED rather
+// than merely mutated is a sink. This wrapper therefore sits between the logger
+// and the real sinks: it rebuilds the LogEvent with a redacted stand-in
+// exception and forwards. RedactingLoggerPipeline is what guarantees it wraps
+// EVERY sink (config-declared and DI-registered alike) rather than one of them
+// — see that class for the coverage argument, and
+// docs/security/log-redaction-policy.md for what is and is not covered.
+//
+// The original event is forwarded untouched whenever redaction changed nothing,
+// which is the overwhelmingly common case: an ordinary exception keeps its real
+// CLR type, stack trace and inner-exception chain, and only an exception whose
+// rendered text actually contains something sensitive is substituted.
+//
+// `redactText` is injected rather than calling SensitiveDataRedactionEnricher
+// directly: this sink and RedactingLoggerPipeline are the generic "every sink
+// sees a chance to rewrite the exception" MECHANISM, reviewable on its own
+// terms (wiring, level semantics, sink coverage) independent of what any
+// particular redaction function actually does. What runs through the delegate
+// is the caller's decision — see CluckworkTelemetryServiceCollectionExtensions
+// for the real one.
+public sealed class ExceptionRedactingSink(ILogEventSink inner, Func<string, string> redactText) : ILogEventSink, IDisposable
+{
+    public void Emit(LogEvent logEvent)
+    {
+        var replacement = RedactedException.For(logEvent.Exception, redactText);
+        inner.Emit(ReferenceEquals(replacement, logEvent.Exception)
+            ? logEvent
+            : new LogEvent(
+                logEvent.Timestamp,
+                logEvent.Level,
+                replacement,
+                logEvent.MessageTemplate,
+                logEvent.Properties.Select(p => new LogEventProperty(p.Key, p.Value)),
+                logEvent.TraceId ?? default,
+                logEvent.SpanId ?? default));
+    }
+
+    // `inner` is the stage-two sub-logger `LoggerSinkConfiguration.Wrap` built
+    // (a `SecondaryLoggerSink`, disposable). Serilog's root `AggregateSink` only
+    // disposes sinks it directly holds — this wrapper, not what it wraps — so
+    // without delegating here, stage two (and any buffered/disposable sink
+    // inside it) never gets disposed and shutdown can drop unflushed events
+    // (codex review of #426).
+    public void Dispose() => (inner as IDisposable)?.Dispose();
+}
+
+// Stand-in for an exception whose rendered text carried something sensitive.
+//
+// A real exception's `StackTrace` is set by the runtime at throw time and its
+// `Message` is fixed at construction, so a redacted copy cannot be produced by
+// mutating the original — it has to be a different object. What matters is that
+// every way a sink can render an exception yields the redacted text:
+// `ToString()` (the `{Exception}` output token and Compact JSON's `@x`),
+// `Message` (structured formatters that project it), and `StackTrace` (which is
+// already contained in, and therefore only duplicated by, the rendered detail).
+public sealed class RedactedException : Exception
+{
+    private readonly string detail;
+
+    private RedactedException(string message, string detail)
+        : base(message) => this.detail = detail;
+
+    // Returns the ORIGINAL instance when redaction changed nothing, so callers
+    // can use reference equality to decide whether the event needs rebuilding.
+    public static Exception? For(Exception? exception, Func<string, string> redactText)
+    {
+        if (exception is null) return null;
+
+        var rendered = exception.ToString();
+        var redacted = redactText(rendered);
+        return string.Equals(rendered, redacted, StringComparison.Ordinal)
+            ? exception
+            : new RedactedException(redactText(exception.Message), redacted);
+    }
+
+    public override string ToString() => detail;
+
+    // The redacted stack text is already part of `detail`; exposing it a second
+    // time here would only give a formatter a second, unredacted-looking place
+    // to read from.
+    public override string? StackTrace => null;
+}

src/Cluckwork.Api/Logging/RedactingLoggerPipeline.cs

@@ -0,0 +1,173 @@
+namespace Cluckwork.Api.Logging;
+
+using Microsoft.Extensions.Primitives;
+using Serilog;
+using Serilog.Configuration;
+using Serilog.Core;
+using Serilog.Events;
+
+// #273 codex review (round 2, P1b) — builds this host's Serilog pipeline so
+// that NO sink can be reached except through ExceptionRedactingSink.
+//
+// Why two stages rather than "add another enricher". Property redaction can be
+// an enricher (it mutates `logEvent.Properties` in place), but `LogEvent.
+// Exception` is get-only and Serilog offers no way for an enricher or an
+// ILogEventFilter to SUBSTITUTE an event. The only pipeline element that
+// receives an event and decides what the next element sees is a sink. So the
+// exception redactor has to be a sink wrapper — and a wrapper is only a
+// security control if it is impossible to register a sink beside it.
+//
+// This class is deliberately just the WIRING: it takes an enricher and a
+// text-redaction function as parameters rather than referencing any specific
+// redaction implementation, so the pipeline mechanism (sink coverage, level
+// semantics) is reviewable and testable independent of what actually gets
+// redacted — see ExceptionRedactingSink. Split out of #273's log-redaction work
+// so this mechanism gets reviewed on its own terms; NOT YET WIRED into
+// CluckworkTelemetryServiceCollectionExtensions.AddCluckworkTelemetry, which
+// still builds a single-stage logger — that swap, plus the real redaction
+// content (SensitiveDataRedactionEnricher + RedactText), is the follow-up PR.
+//
+// Hence:
+//
+//   stage 1 (the logger callers hold)
+//     · minimum levels + per-source overrides + destructuring, read from the
+//       app's own `Serilog:` settings. These are the settings that must be
+//       evaluated where the event is CREATED: `ILogger.IsEnabled` and the
+//       `MinimumLevel.Override` map are consulted before an event exists at
+//       all, and destructuring policies run in the message-template processor
+//       of the logger the caller is holding. Keeping them here is what stops
+//       this restructure from turning `Serilog:MinimumLevel` into a no-op and
+//       materialising every EF Core Debug event in Production.
+//     · exactly ONE sink: ExceptionRedactingSink wrapping stage 2.
+//
+//   stage 2 (a sub-logger, reachable only through that wrapper)
+//     · every sink, from BOTH sources: `Serilog:WriteTo` in configuration and
+//       `ILogEventSink` registrations in DI (`ReadFrom.Services`, the #214 tap).
+//     · the configured enrichers (`Serilog:Enrich`, e.g. FromLogContext) and
+//       then the caller's `propertyEnricher`, in that order — it must run
+//       AFTER FromLogContext so that log-context properties are covered too,
+//       which is only true if it is appended last.
+//     · `MinimumLevel.Verbose()`, applied after the configuration is read: a
+//       sub-logger re-checks a forwarded event against its own flat minimum
+//       level and, unlike stage 1, does NOT re-apply the per-source override
+//       map — so anything but "pass everything stage 1 already allowed" would
+//       silently drop events that an override had deliberately enabled.
+//
+// The consequence worth stating plainly: an operator who adds a sink via
+// `Serilog:WriteTo`, and a test or future component that registers an
+// `ILogEventSink` in DI, both land inside the wrapper automatically. There is
+// no supported way to attach a sink to stage 1.
+public static class RedactingLoggerPipeline
+{
+    // The `Serilog:` settings that must be applied to stage 1 because they are
+    // consulted at event-CREATION time. Everything not listed here (WriteTo,
+    // AuditTo, Enrich, Filter, Properties) is applied to stage 2 instead —
+    // deliberately, so that no `WriteTo` entry can ever be attached to the
+    // outer logger. `Using` rides along because `Destructure` entries may name
+    // a type from an assembly it lists.
+    private static readonly string[] EventCreationSettings =
+        ["MinimumLevel", "LevelSwitches", "Destructure", "Using"];
+
+    // `propertyEnricher` and `redactExceptionText` are the caller's redaction
+    // CONTENT; this method is only the wiring that guarantees every sink sees
+    // it. Keeping the two separate is what lets the pipeline mechanism be
+    // reviewed (and tested) independently of what gets redacted — see
+    // ExceptionRedactingSink.
+    public static LoggerConfiguration Configure(
+        LoggerConfiguration loggerConfiguration,
+        IConfiguration configuration,
+        IServiceProvider services,
+        ILogEventEnricher propertyEnricher,
+        Func<string, string> redactExceptionText)
+    {
+        loggerConfiguration.ReadFrom.Configuration(EventCreationSettingsOf(configuration));
+
+        // LoggerSinkConfiguration.Wrap builds (and owns the disposal of) the
+        // wrapped sink chain; WriteTo.Sink then attaches the wrapper — and only
+        // the wrapper — as stage 1's single sink.
+        var redactedSinks = LoggerSinkConfiguration.Wrap(
+            inner => new ExceptionRedactingSink(inner, redactExceptionText),
+            sinks => sinks.Logger(stageTwo => stageTwo
+                .ReadFrom.Configuration(configuration)
+                .ReadFrom.Services(services)
+                .MinimumLevel.Verbose()
+                .Enrich.With(propertyEnricher)));
+
+        return loggerConfiguration.WriteTo.Sink(redactedSinks, LevelAlias.Minimum);
+    }
+
+    // A `Serilog:` settings view holding only the event-creation-time keys
+    // above. Built by re-keying the app's own configuration entries rather than
+    // by re-implementing Serilog.Settings.Configuration's parsing, so the
+    // meaning of `MinimumLevel` / `Destructure` stays whatever the library says
+    // it is, from whichever provider (file, env var, test `UseSetting`) supplied
+    // it.
+    //
+    // Wrapped in a reload-token-preserving view rather than handed back as a
+    // one-shot in-memory snapshot: Serilog.Settings.Configuration's dynamic
+    // MinimumLevel reload watches the RELOAD TOKEN of the exact `IConfiguration`
+    // instance passed to `ReadFrom.Configuration`, not `configuration`'s. A
+    // plain snapshot severs that token, so a running host would keep stage 1's
+    // startup levels forever — an `appsettings.json` edit under
+    // `reloadOnChange: true` could no longer raise verbosity, silently, with no
+    // error (codex review of #426).
+    // internal rather than private: RedactingLoggerPipelineTests asserts the
+    // reload-token behavior directly, since Configure()'s public surface has no
+    // other way to observe it.
+    internal static IConfiguration EventCreationSettingsOf(IConfiguration configuration) =>
+        new ReloadableFilteredConfiguration(configuration, EventCreationEntriesOf);
+
+    private static IEnumerable<KeyValuePair<string, string?>> EventCreationEntriesOf(IConfiguration configuration) =>
+        configuration.GetSection("Serilog")
+            .AsEnumerable(makePathsRelative: true)
+            .Where(entry => entry.Value is not null
+                && EventCreationSettings.Any(setting =>
+                    entry.Key.StartsWith(setting, StringComparison.OrdinalIgnoreCase)))
+            .Select(entry => new KeyValuePair<string, string?>($"Serilog:{entry.Key}", entry.Value));
+
+    // A read-only `IConfigurationRoot` holding a filtered snapshot of `source`,
+    // rebuilt and re-signaled on `source`'s own reload token so a consumer that
+    // (like Serilog.Settings.Configuration) subscribes to THIS instance's
+    // reload token still observes `source` changing. `ChangeToken.OnChange`
+    // re-subscribes after every fire, so this keeps working across repeated
+    // reloads, not just the first.
+    private sealed class ReloadableFilteredConfiguration : IConfigurationRoot, IDisposable
+    {
+        private readonly IConfiguration source;
+        private readonly Func<IConfiguration, IEnumerable<KeyValuePair<string, string?>>> filter;
+        private readonly IDisposable subscription;
+        private IConfigurationRoot snapshot;
+        private ConfigurationReloadToken reloadToken = new();
+
+        public ReloadableFilteredConfiguration(
+            IConfiguration source,
+            Func<IConfiguration, IEnumerable<KeyValuePair<string, string?>>> filter)
+        {
+            this.source = source;
+            this.filter = filter;
+            snapshot = BuildSnapshot();
+            subscription = ChangeToken.OnChange(source.GetReloadToken, Reload);
+        }
+
+        public void Reload()
+        {
+            snapshot = BuildSnapshot();
+            Interlocked.Exchange(ref reloadToken, new ConfigurationReloadToken()).OnReload();
+        }
+
+        private IConfigurationRoot BuildSnapshot() =>
+            new ConfigurationBuilder().AddInMemoryCollection(filter(source)).Build();
+
+        public string? this[string key]
+        {
+            get => snapshot[key];
+            set => snapshot[key] = value;
+        }
+
+        public IEnumerable<IConfigurationSection> GetChildren() => snapshot.GetChildren();
+        public IConfigurationSection GetSection(string key) => snapshot.GetSection(key);
+        public IChangeToken GetReloadToken() => reloadToken;
+        public IEnumerable<IConfigurationProvider> Providers => snapshot.Providers;
+        public void Dispose() => subscription.Dispose();
+    }
+}