fix(telemetry): redact after ConfigureLogger enrichers, keep colliding dictionary keys, require http(s) OTLP endpoint and validate the options overload; bump 0.2.1 (scadaproj#48)

Claude-Session: https://claude.ai/code/session_01GT67AEHd2Acv1YPwGfXEoV
2026-11-09 14:57:48 -05:00
parent 5bf2f2caf1
commit 1786bab0a0
12 changed files with 182 additions and 25 deletions
@@ -64,6 +64,13 @@ All test assemblies run offline:

 ## Status

+**`0.2.1` (2026-11-09, scadaproj#48) — built, NOT published.** P3 review fixes: `RedactionEnricher` is now registered
+AFTER `ConfigureLogger`, so enrichers added in the hook are redacted (009); dictionary keys that print identically are
+all kept (later ones get a `#n` suffix in the redactor's view; the original key is restored on rebuild) (010); the OTLP
+endpoint must be `http`/`https` with a host (`collector:4317` is now rejected) and the pre-built-options
+`AddZbTelemetry(services, options)` overload validates `ServiceName` + endpoint like the lambda overloads (011).
+**Behaviour change:** a scheme-less OTLP endpoint that previously passed validation now throws at startup.
+
 **`0.2.0` (2026-11-09, scadaproj#12) — built, NOT published** (feed carries `0.1.0` only). Additive:
 a new `AddZbSerilog(builder, configure, configureSerilog)` overload taking `ZbSerilogOptions` —
 `MinimumLevelGovernor` (`Func<IConfiguration, LogEventLevel?>`, applied with `MinimumLevel.Is`
@@ -5,7 +5,7 @@
    <Nullable>enable</Nullable>
    <ImplicitUsings>enable</ImplicitUsings>
    <LangVersion>latest</LangVersion>
-    <Version>0.2.0</Version>
+    <Version>0.2.1</Version>
    <ManagePackageVersionsCentrally>true</ManagePackageVersionsCentrally>
  </PropertyGroup>

@@ -136,6 +136,19 @@ public sealed class RedactionEnricher : ILogEventEnricher
                foreach (var pair in dictionary.Elements)
                {
                    var key = pair.Key.Value?.ToString() ?? NullKey;
+
+                    // Distinct keys can print identically (DateTime keys differing below one second,
+                    // a null key next to ""). Keep every entry: later collisions get a "#n" suffix in
+                    // the redactor's view, and OriginalKeys restores the real key on rebuild.
+                    if (projectedDictionary.ContainsKey(key))
+                    {
+                        var baseKey = key;
+                        for (var n = 2; projectedDictionary.ContainsKey(key); n++)
+                        {
+                            key = baseKey + "#" + n;
+                        }
+                    }
+
                    projectedDictionary[key] = Project(pair.Value);
                    projectedDictionary.OriginalKeys[key] = pair.Key;
                }
@@ -72,7 +72,7 @@ internal static class ZbSerilogConfig

        if (serviceProvider is not null)
        {
-            enrich.With(new RedactionEnricher(serviceProvider));
+            ApplyRedaction(loggerConfiguration, serviceProvider);
        }

        ApplyOpenTelemetryExport(loggerConfiguration, options);
@@ -80,6 +80,16 @@ internal static class ZbSerilogConfig
        return loggerConfiguration;
    }

+    /// <summary>
+    /// Registers the <see cref="RedactionEnricher"/>. Must be the LAST enricher registered so that
+    /// every other enricher (including ones a host adds through <c>ZbSerilogOptions.ConfigureLogger</c>)
+    /// has stamped its properties before redaction runs.
+    /// </summary>
+    /// <param name="loggerConfiguration">The Serilog configuration.</param>
+    /// <param name="serviceProvider">Provider used to lazily resolve <c>ILogRedactor</c>.</param>
+    internal static void ApplyRedaction(LoggerConfiguration loggerConfiguration, IServiceProvider serviceProvider) =>
+        loggerConfiguration.Enrich.With(new RedactionEnricher(serviceProvider));
+
    /// <summary>
    /// Adds a <c>WriteTo.OpenTelemetry</c> log sink when an OTLP exporter is explicitly
    /// selected (<see cref="ZbTelemetryOptions.Exporter"/> = <see cref="ZbExporter.Otlp"/>).
@@ -115,9 +115,15 @@ public static class ZbSerilogExtensions
                    loggerConfiguration.MinimumLevel.Is(governed);
                }

-                ZbSerilogConfig.Apply(loggerConfiguration, options, serviceProvider);
+                // Redaction is deliberately applied AFTER the hook (Telemetry-009): Serilog runs
+                // enrichers in registration order, so a RedactionEnricher registered before
+                // ConfigureLogger would let hook-added enrichers stamp properties that reach every
+                // sink unredacted. Apply() is told there is no provider so it skips redaction here.
+                ZbSerilogConfig.Apply(loggerConfiguration, options, serviceProvider: null);

                serilogOptions.ConfigureLogger?.Invoke(loggerConfiguration, serviceProvider);
+
+                ZbSerilogConfig.ApplyRedaction(loggerConfiguration, serviceProvider);
            },
            preserveStaticLogger: true);

@@ -41,7 +41,8 @@ public sealed class ZbSerilogOptions
    /// <summary>
    /// Final, app-specific adjustments to the <see cref="LoggerConfiguration"/> — filters,
    /// extra enrichers, extra sinks — run after the governed level and the shared
-    /// enricher/redaction/export set. Receives the application <see cref="IServiceProvider"/>.
+    /// enricher/export set. Redaction is registered after this hook, so properties stamped by enrichers
+    /// added here ARE passed through <c>ILogRedactor</c>. Receives the application <see cref="IServiceProvider"/>.
    /// </summary>
    public Action<LoggerConfiguration, IServiceProvider>? ConfigureLogger { get; set; }
 }
@@ -44,6 +44,10 @@ public static class ZbTelemetryExtensions
        ArgumentNullException.ThrowIfNull(services);
        ArgumentNullException.ThrowIfNull(options);

+        // The lambda overloads validate in BuildOptions; a caller-built options object must get the
+        // same fail-fast treatment (Telemetry-011).
+        ValidateRequired(options, nameof(options));
+
        services.AddOpenTelemetry()
            .ConfigureResource(rb => ZbResource.Configure(rb, options))
            .WithMetrics(metrics =>
@@ -95,14 +99,19 @@ public static class ZbTelemetryExtensions
        ArgumentNullException.ThrowIfNull(configure);
        var options = new ZbTelemetryOptions();
        configure(options);
+        ValidateRequired(options, nameof(configure));
+        return options;
+    }
+
+    private static void ValidateRequired(ZbTelemetryOptions options, string paramName)
+    {
        if (string.IsNullOrWhiteSpace(options.ServiceName))
        {
            throw new ArgumentException(
                "ZbTelemetryOptions.ServiceName is required (e.g. \"otopcua\").",
-                nameof(configure));
+                paramName);
        }
-        ZbTelemetryOptionsValidator.Validate(options, nameof(configure));
-        return options;
+        ZbTelemetryOptionsValidator.Validate(options, paramName);
    }

    private static void ApplyMetricsExporter(MeterProviderBuilder metrics, ZbTelemetryOptions options)
@@ -11,7 +11,7 @@ internal static class ZbTelemetryOptionsValidator
    /// <summary>
    /// Validates the OTLP configuration. When <see cref="ZbTelemetryOptions.Exporter"/> is
    /// <see cref="ZbExporter.Otlp"/>, <see cref="ZbTelemetryOptions.OtlpEndpoint"/> must be a
-    /// non-empty, well-formed absolute URI. Throws an <see cref="ArgumentException"/> (naming the
+    /// non-empty, well-formed absolute <c>http</c>/<c>https</c> URI with a host. Throws an <see cref="ArgumentException"/> (naming the
    /// option) otherwise. No-op for the Prometheus exporter — a stray endpoint is ignored there.
    /// </summary>
    /// <param name="options">The populated telemetry options to validate.</param>
@@ -33,10 +33,15 @@ internal static class ZbTelemetryOptionsValidator
                paramName);
        }

-        if (!Uri.TryCreate(options.OtlpEndpoint, UriKind.Absolute, out _))
+        // A scheme-less "host:port" (e.g. "collector:4317") parses as an absolute URI whose scheme
+        // is the host name, so TryCreate alone accepts the exact typo this check exists to catch
+        // (Telemetry-011). OTLP exporters speak http/https only.
+        if (!Uri.TryCreate(options.OtlpEndpoint, UriKind.Absolute, out var uri)
+            || (uri.Scheme != Uri.UriSchemeHttp && uri.Scheme != Uri.UriSchemeHttps)
+            || string.IsNullOrEmpty(uri.Host))
        {
            throw new ArgumentException(
-                $"ZbTelemetryOptions.OtlpEndpoint is not a well-formed absolute URI: " +
+                $"ZbTelemetryOptions.OtlpEndpoint is not a well-formed absolute http(s) URI: " +
                $"'{options.OtlpEndpoint}' (expected e.g. \"http://collector:4317\").",
                paramName);
        }
@@ -0,0 +1,72 @@
+using Microsoft.Extensions.Configuration;
+using Microsoft.Extensions.DependencyInjection;
+using Microsoft.Extensions.Hosting;
+using Serilog;
+using Serilog.Core;
+using Serilog.Events;
+
+namespace ZB.MOM.WW.Telemetry.Serilog.Tests;
+
+/// <summary>Regression tests for Telemetry-009 and Telemetry-010 (scadaproj#48).</summary>
+public sealed class ReviewP3Tests
+{
+    private sealed class MaskApiKey : ILogRedactor
+    {
+        public void Redact(IDictionary<string, object?> properties)
+        {
+            if (properties.ContainsKey("apiKey")) properties["apiKey"] = "***";
+        }
+    }
+
+    private sealed class NoOpRedactor : ILogRedactor
+    {
+        public void Redact(IDictionary<string, object?> properties) { }
+    }
+
+    private sealed class CaptureSink : ILogEventSink
+    {
+        public List<LogEvent> Events { get; } = [];
+        public void Emit(LogEvent logEvent) => Events.Add(logEvent);
+    }
+
+    [Fact]
+    public void Properties_stamped_by_ConfigureLogger_enrichers_are_redacted()
+    {
+        var builder = Host.CreateApplicationBuilder(new HostApplicationBuilderSettings { DisableDefaults = true });
+        builder.Services.AddSingleton<ILogRedactor>(new MaskApiKey());
+        var sink = new CaptureSink();
+        builder.AddZbSerilog(
+            o => o.ServiceName = "t",
+            s => s.ConfigureLogger = (lc, _) => lc.Enrich.WithProperty("apiKey", "s3cret").WriteTo.Sink(sink));
+
+        using var host = builder.Build();
+        host.Services.GetRequiredService<ILogger>().Information("hello");
+
+        var evt = Assert.Single(sink.Events);
+        Assert.Equal("***", ((ScalarValue)evt.Properties["apiKey"]).Value);
+    }
+
+    [Fact]
+    public void Dictionary_keys_that_print_identically_are_all_kept()
+    {
+        var provider = new ServiceCollection().AddSingleton<ILogRedactor>(new NoOpRedactor()).BuildServiceProvider();
+        var sink = new CaptureSink();
+        var cfg = new LoggerConfiguration();
+        ZbSerilogConfig.Apply(cfg, new ZbTelemetryOptions { ServiceName = "t" }, provider);
+        using var logger = cfg.WriteTo.Sink(sink).CreateLogger();
+
+        var map = new Dictionary<DateTime, string>
+        {
+            [new DateTime(2026, 1, 1, 12, 0, 0, 100)] = "first",
+            [new DateTime(2026, 1, 1, 12, 0, 0, 200)] = "second",
+        };
+        logger.Information("{Map}", map);
+
+        var dict = Assert.IsType<DictionaryValue>(Assert.Single(sink.Events).Properties["Map"]);
+        Assert.Equal(2, dict.Elements.Count);
+        Assert.Equal(
+            new[] { "first", "second" },
+            dict.Elements.Select(e => (string)((ScalarValue)e.Value).Value!).Order(StringComparer.Ordinal));
+        Assert.Equal(2, dict.Elements.Select(e => e.Key.Value).Distinct().Count());
+    }
+}
@@ -55,6 +55,43 @@ public sealed class AddZbTelemetryTests
        Assert.Contains("OtlpEndpoint", ex.Message);
    }

+    [Theory]
+    [InlineData("localhost:4317")]
+    [InlineData("otel-collector:4317")]
+    [InlineData("ftp://collector:4317")]
+    public void AddZbTelemetry_Throws_WhenOtlpEndpointIsSchemeLessOrNotHttp(string endpoint)
+    {
+        // Telemetry-011: "host:port" parses as an absolute URI whose scheme is the host name.
+        var builder = WebApplication.CreateBuilder();
+        var ex = Assert.Throws<ArgumentException>(() =>
+            builder.AddZbTelemetry(o =>
+            {
+                o.ServiceName = "telemetry-test";
+                o.Exporter = ZbExporter.Otlp;
+                o.OtlpEndpoint = endpoint;
+            }));
+        Assert.Contains("OtlpEndpoint", ex.Message);
+    }
+
+    [Fact]
+    public void AddZbTelemetry_PrebuiltOptionsOverload_ValidatesServiceNameAndOtlpEndpoint()
+    {
+        var services = new ServiceCollection();
+
+        Assert.Throws<ArgumentException>(() =>
+            services.AddZbTelemetry(new ZbTelemetryOptions()));
+
+        var ex = Assert.Throws<ArgumentException>(() =>
+            services.AddZbTelemetry(new ZbTelemetryOptions
+            {
+                ServiceName = "telemetry-test",
+                Exporter = ZbExporter.Otlp,
+                OtlpEndpoint = "collector:4317",
+            }));
+        Assert.Equal("options", ex.ParamName);
+        Assert.Contains("OtlpEndpoint", ex.Message);
+    }
+
    [Fact]
    public void AddZbTelemetry_Throws_WhenOtlpExporterHasNoEndpoint()
    {
@@ -40,7 +40,7 @@ code-reviews/

 ## Summary

-10 of 10 libraries reviewed. 33 pending findings across all libraries.
+10 of 10 libraries reviewed. 30 pending findings across all libraries.

 Coverage: Secrets, LocalDb, GalaxyRepository and Overview first reviewed, and Auth, Health,
 Theme, Audit, Configuration and Telemetry re-reviewed, on 2026-11-09 (#15). Each finding also
@@ -51,8 +51,8 @@ carries a P1/P2/P3 priority (P1 = Critical/High, P2 = Medium, P3 = Low).
 | Critical | 0 |
 | High | 0 |
 | Medium | 11 |
-| Low | 22 |
-| **Total** | **33** |
+| Low | 19 |
+| **Total** | **30** |

 ## Library Status

@@ -66,7 +66,7 @@ carries a P1/P2/P3 priority (P1 = Critical/High, P2 = Medium, P3 = Low).
 | [LocalDb](LocalDb/findings.md) | 2026-11-09 | `91fb2b4` | 0/0/4/3 | 7 | 7 |
 | [Overview](Overview/findings.md) | 2026-11-09 | `91fb2b4` | 0/0/0/0 | 0 | 5 |
 | [Secrets](Secrets/findings.md) | 2026-11-09 | `91fb2b4` | 0/0/6/13 | 19 | 19 |
-| [Telemetry](Telemetry/findings.md) | 2026-11-09 | `91fb2b4` | 0/0/0/3 | 3 | 11 |
+| [Telemetry](Telemetry/findings.md) | 2026-11-09 | `91fb2b4` | 0/0/0/0 | 0 | 11 |
 | [Theme](Theme/findings.md) | 2026-11-09 | `91fb2b4` | 0/0/0/0 | 0 | 8 |

 ## Pending Findings
@@ -100,7 +100,7 @@ _None open._
 | Secrets-013 | [Secrets](Secrets/findings.md) | UI add/rotate/delete: if the audit write throws after the store write succeeded, the change is reported and audited as a failure and the resolver cache is not evicted |
 | Secrets-017 | [Secrets](Secrets/findings.md) | `secret set`/`rotate` take the plaintext on argv; the host builder re-parses argv as configuration and can crash with the value in the error |

-### Low (22)
+### Low (19)

 | ID | Library | Title |
 |----|---------|-------|
@@ -123,6 +123,3 @@ _None open._
 | Secrets-016 | [Secrets](Secrets/findings.md) | The public UI components enforce no authorization of their own; gating relies entirely on the host rendering them inside `AuthorizeView` |
 | Secrets-018 | [Secrets](Secrets/findings.md) | Bundle import aborts mid-run on one bad entry, leaving earlier rows applied but reporting only "Import failed" |
 | Secrets-019 | [Secrets](Secrets/findings.md) | Hub-client cancellation surfaces as `RpcException(Cancelled)`, so shutdown is recorded as a failed sweep and the failover reader rotates through every endpoint with a cancelled token |
-| Telemetry-009 | [Telemetry](Telemetry/findings.md) | Enrichers added via `ZbSerilogOptions.ConfigureLogger` run after `RedactionEnricher`, so their properties are never redacted |
-| Telemetry-010 | [Telemetry](Telemetry/findings.md) | Redaction projection keys logged dictionaries by `ToString()`, silently dropping entries whose keys stringify identically |
-| Telemetry-011 | [Telemetry](Telemetry/findings.md) | OTLP fail-fast validation accepts scheme-less `host:port` and is skipped by the pre-built-options `AddZbTelemetry` overload |
@@ -10,7 +10,7 @@
 | Last reviewed | 2026-11-09 (re-review; baseline 2026-06-01 at `5f75cd4`) |
 | Reviewer | Claude (2026-11-09 re-review, scadaproj#15; baseline: Claude automated) |
 | Commit reviewed | `91fb2b4` |
-| Open findings | 3 |
+| Open findings | 0 |

 ## Summary

@@ -397,7 +397,7 @@ shared-contract summary.
 | Severity | Low |
 | Priority | P3 |
 | Category | Security & secret handling |
-| Status | Open |
+| Status | Resolved |
 | Location | `ZB.MOM.WW.Telemetry/src/ZB.MOM.WW.Telemetry.Serilog/ZbSerilogExtensions.cs:118-120`, `ZB.MOM.WW.Telemetry/src/ZB.MOM.WW.Telemetry.Serilog/ZbSerilogOptions.cs:41-46` |

 **Description**
@@ -431,7 +431,7 @@ asserts it is redacted.

 **Resolution**

-_Unresolved._
+Resolved 2026-11-09 in the commit tagged `(scadaproj#48)` (Telemetry `0.2.1`, unpublished) — `AddZbSerilogCore` now applies the shared enrichers with no provider, invokes `ConfigureLogger`, then registers `RedactionEnricher` last (new internal `ZbSerilogConfig.ApplyRedaction`; `Apply(…, sp)` still includes redaction for direct callers). Option doc updated. Test `Properties_stamped_by_ConfigureLogger_enrichers_are_redacted` (failed without the fix: `apiKey` reached the sink raw).

 ### Telemetry-010 — Redaction projection keys logged dictionaries by `ToString()`, silently dropping entries whose keys stringify identically

@@ -440,7 +440,7 @@ _Unresolved._
 | Severity | Low |
 | Priority | P3 |
 | Category | Correctness & logic bugs |
-| Status | Open |
+| Status | Resolved |
 | Location | `ZB.MOM.WW.Telemetry/src/ZB.MOM.WW.Telemetry.Serilog/RedactionEnricher.cs:134-143` (projection), `:163-173` (rebuild) |

 **Description**
@@ -470,7 +470,7 @@ colliding keys.

 **Resolution**

-_Unresolved._
+Resolved 2026-11-09 in the commit tagged `(scadaproj#48)` (Telemetry `0.2.1`, unpublished) — `RedactionEnricher.Project` keeps every dictionary entry: a key whose string form collides gets a `#n` suffix in the redactor's view and `OriginalKeys` restores the real key on rebuild. Test `Dictionary_keys_that_print_identically_are_all_kept` (two `DateTime` keys differing by milliseconds, no-op redactor; failed without the fix: one entry survived).

 ### Telemetry-011 — OTLP fail-fast validation accepts scheme-less `host:port` and is skipped by the pre-built-options `AddZbTelemetry` overload

@@ -479,7 +479,7 @@ _Unresolved._
 | Severity | Low |
 | Priority | P3 |
 | Category | Error handling & resilience |
-| Status | Open |
+| Status | Resolved |
 | Location | `ZB.MOM.WW.Telemetry/src/ZB.MOM.WW.Telemetry/ZbTelemetryOptionsValidator.cs:36`, `ZB.MOM.WW.Telemetry/src/ZB.MOM.WW.Telemetry/ZbTelemetryExtensions.cs:40-46` |

 **Description**
@@ -514,4 +514,4 @@ Require `uri.Scheme` to be `http` or `https` (the OTLP gRPC/HTTP schemes) and a

 **Resolution**

-_Unresolved._
+Resolved 2026-11-09 in the commit tagged `(scadaproj#48)` (Telemetry `0.2.1`, unpublished) — `ZbTelemetryOptionsValidator` now requires an absolute `http`/`https` URI with a host (`localhost:4317`, `otel-collector:4317`, `ftp://…` rejected); `AddZbTelemetry(IServiceCollection, ZbTelemetryOptions)` now runs the same ServiceName + OTLP validation as the lambda overloads (param name `options`). Tests `AddZbTelemetry_Throws_WhenOtlpEndpointIsSchemeLessOrNotHttp` and `AddZbTelemetry_PrebuiltOptionsOverload_ValidatesServiceNameAndOtlpEndpoint` (failed without the fix). Behaviour change: configs with a scheme-less endpoint now fail at startup, as Telemetry-006 intended.