refactor(telemetry.serilog): review fixes (thread-safe redactor, bootstrap logger, minlevel ordering, test coverage)

2026-06-01 07:48:57 -04:00
parent 37fb84f477
commit f1240c0bd4
7 changed files with 140 additions and 48 deletions
@@ -9,22 +9,24 @@ namespace ZB.MOM.WW.Telemetry.Serilog;
 /// automatically by <see cref="ZbSerilogExtensions.AddZbSerilog"/>. The enricher resolves
 /// <see cref="ILogRedactor"/> from DI on first use (lazy, to avoid a circular-DI problem during
 /// Serilog's bootstrap); if none is registered it is permanently inert — no DI call per event.
+/// Resolution is thread-safe: <see cref="LazyThreadSafetyMode.ExecutionAndPublication"/> ensures
+/// exactly one DI lookup regardless of how many logging threads race to the first event.
 /// </summary>
 public sealed class RedactionEnricher : ILogEventEnricher
 {
-    private readonly IServiceProvider _serviceProvider;
-    private ILogRedactor? _redactor;
-    private bool _resolved;
+    private readonly Lazy<ILogRedactor?> _redactor;

    /// <summary>
    /// Creates the enricher bound to a service provider from which the project-supplied
-    /// <see cref="ILogRedactor"/> is resolved lazily on first use.
+    /// <see cref="ILogRedactor"/> is resolved lazily on first use (thread-safe).
    /// </summary>
    /// <param name="serviceProvider">Provider used to resolve a registered <see cref="ILogRedactor"/>.</param>
    public RedactionEnricher(IServiceProvider serviceProvider)
    {
        ArgumentNullException.ThrowIfNull(serviceProvider);
-        _serviceProvider = serviceProvider;
+        _redactor = new Lazy<ILogRedactor?>(
+            () => serviceProvider.GetService<ILogRedactor>(),
+            LazyThreadSafetyMode.ExecutionAndPublication);
    }

    /// <summary>
@@ -64,17 +66,7 @@ public sealed class RedactionEnricher : ILogEventEnricher
        }
    }

-    private ILogRedactor? ResolveRedactor()
-    {
-        if (_resolved)
-        {
-            return _redactor;
-        }
-
-        _redactor = _serviceProvider.GetService<ILogRedactor>();
-        _resolved = true;
-        return _redactor;
-    }
+    private ILogRedactor? ResolveRedactor() => _redactor.Value;

    private static bool HasChanged(LogEvent logEvent, string key, object? newValue)
    {
@@ -24,4 +24,10 @@
    <ProjectReference Include="..\ZB.MOM.WW.Telemetry\ZB.MOM.WW.Telemetry.csproj" />
  </ItemGroup>

+  <ItemGroup>
+    <AssemblyAttribute Include="System.Runtime.CompilerServices.InternalsVisibleTo">
+      <_Parameter1>ZB.MOM.WW.Telemetry.Serilog.Tests</_Parameter1>
+    </AssemblyAttribute>
+  </ItemGroup>
+
 </Project>
@@ -12,8 +12,10 @@ namespace ZB.MOM.WW.Telemetry.Serilog;
 /// trace-context correlation, redaction, and OTel log export) to a
 /// <see cref="LoggerConfiguration"/>. Shared by <see cref="ZbSerilogExtensions.AddZbSerilog"/>
 /// and unit tests so both exercise an identical enricher/sink set.
+/// Internal to keep the public NuGet surface minimal; exposed to the test assembly via
+/// <c>[assembly: InternalsVisibleTo("ZB.MOM.WW.Telemetry.Serilog.Tests")]</c>.
 /// </summary>
-public static class ZbSerilogConfig
+internal static class ZbSerilogConfig
 {
    /// <summary>
    /// Applies the shared identity enrichers — <see cref="ZbLogEnricherNames.SiteId"/> and
@@ -113,9 +115,10 @@ public static class ZbSerilogConfig

    /// <summary>
    /// Builds the OTLP Resource-attribute map mirroring <c>ZbResource</c>. Null/empty optional
-    /// attributes are omitted, matching the shared Resource's omission rules.
+    /// attributes are omitted, matching the shared Resource's omission rules. Internal so it can
+    /// be asserted by the test assembly without being part of the public NuGet API.
    /// </summary>
-    private static IDictionary<string, object> BuildResourceAttributes(ZbTelemetryOptions options)
+    internal static IDictionary<string, object> BuildResourceAttributes(ZbTelemetryOptions options)
    {
        var attributes = new Dictionary<string, object>
        {
@@ -1,5 +1,3 @@
-using Microsoft.Extensions.Configuration;
-using Microsoft.Extensions.DependencyInjection;
 using Microsoft.Extensions.Hosting;
 using Serilog;
 using Serilog.Events;
@@ -8,22 +6,46 @@ using ZB.MOM.WW.Telemetry;
 namespace ZB.MOM.WW.Telemetry.Serilog;

 /// <summary>
-/// Extension point for configuring the shared Serilog bootstrap on an
+/// Extension point for configuring the shared Serilog two-stage bootstrap on an
 /// <see cref="IHostApplicationBuilder"/>. Wires config-driven sinks
 /// (<c>ReadFrom.Configuration</c>), an explicit minimum level (<c>Serilog:MinimumLevel</c>,
 /// default <see cref="LogEventLevel.Information"/>), and the shared enricher/redaction/OTel-export
 /// set via <see cref="ZbSerilogConfig"/>. Does NOT configure OTel metrics/traces — call
 /// <c>AddZbTelemetry</c> in the core package for that.
+///
+/// <para>
+/// Stage 1 (bootstrap): sets <see cref="Log.Logger"/> to a console-only logger before
+/// <c>Build()</c> is called, capturing any startup exceptions that occur before the DI
+/// container is ready.
+/// </para>
+/// <para>
+/// Stage 2 (application): wires the full Serilog pipeline via
+/// <see cref="SerilogHostBuilderExtensions.UseSerilog(IHostBuilder,Action{HostBuilderContext,IServiceProvider,LoggerConfiguration},bool,bool)"/>
+/// once the host builds, replacing the bootstrap logger with the configuration-driven one.
+/// </para>
 /// </summary>
 public static class ZbSerilogExtensions
 {
    /// <summary>
-    /// Registers Serilog on the host with the shared ZB.MOM.WW configuration: sinks read from
-    /// <see cref="IConfiguration"/> (<c>ReadFrom.Configuration</c>), an explicit minimum level
-    /// (<c>Serilog:MinimumLevel</c>, default <see cref="LogEventLevel.Information"/>), and the
-    /// identity enrichers (<c>SiteId</c>/<c>NodeRole</c> from <paramref name="configure"/>,
-    /// <c>NodeHostname</c> = <see cref="System.Environment.MachineName"/>). The
-    /// <paramref name="configure"/> delegate receives the same <see cref="ZbTelemetryOptions"/>
+    /// Registers Serilog on the host with a two-stage bootstrap:
+    /// <list type="number">
+    /// <item>
+    ///   <description>
+    ///   Stage 1 — immediately sets <see cref="Log.Logger"/> to a console-only bootstrap logger
+    ///   so that startup exceptions before <c>Build()</c> are captured.
+    ///   </description>
+    /// </item>
+    /// <item>
+    ///   <description>
+    ///   Stage 2 — registers the full pipeline via <c>AddSerilog</c>: configuration-driven sinks
+    ///   (<c>ReadFrom.Configuration</c>), a code default of <see cref="LogEventLevel.Information"/>
+    ///   that config can override via <c>Serilog:MinimumLevel</c> or namespace overrides, plus
+    ///   the identity enrichers (<c>SiteId</c>/<c>NodeRole</c> from <paramref name="configure"/>,
+    ///   <c>NodeHostname</c> = <see cref="System.Environment.MachineName"/>).
+    ///   </description>
+    /// </item>
+    /// </list>
+    /// The <paramref name="configure"/> delegate receives the same <see cref="ZbTelemetryOptions"/>
    /// used by <c>AddZbTelemetry</c> — typically share one options-population lambda across both.
    /// </summary>
    /// <param name="builder">The host application builder.</param>
@@ -38,32 +60,21 @@ public static class ZbSerilogExtensions
        var options = new ZbTelemetryOptions();
        configure(options);

-        var minimumLevel = ReadMinimumLevel(builder.Configuration);
+        // Stage 1: bootstrap logger captures startup exceptions before Build().
+        Log.Logger = new LoggerConfiguration()
+            .WriteTo.Console()
+            .CreateBootstrapLogger();

+        // Stage 2: full application logger — code default first, then config overrides.
        builder.Services.AddSerilog((serviceProvider, loggerConfiguration) =>
        {
            loggerConfiguration
-                .ReadFrom.Configuration(builder.Configuration)
-                .MinimumLevel.Is(minimumLevel);
+                .MinimumLevel.Is(LogEventLevel.Information)
+                .ReadFrom.Configuration(builder.Configuration);

            ZbSerilogConfig.Apply(loggerConfiguration, options, serviceProvider);
        });

        return builder;
    }
-
-    /// <summary>
-    /// Reads <c>Serilog:MinimumLevel</c> (or the nested <c>Serilog:MinimumLevel:Default</c>) from
-    /// configuration, falling back to <see cref="LogEventLevel.Information"/> for missing or
-    /// unparseable values.
-    /// </summary>
-    private static LogEventLevel ReadMinimumLevel(IConfiguration configuration)
-    {
-        var raw = configuration["Serilog:MinimumLevel"]
-            ?? configuration["Serilog:MinimumLevel:Default"];
-
-        return Enum.TryParse<LogEventLevel>(raw, ignoreCase: true, out var parsed)
-            ? parsed
-            : LogEventLevel.Information;
-    }
 }
@@ -43,4 +43,33 @@ public sealed class EnricherTests
            Environment.MachineName,
            ScalarValue(logEvent, ZbLogEnricherNames.NodeHostname));
    }
+
+    [Fact]
+    public void Null_SiteId_and_NodeRole_are_suppressed_but_NodeHostname_is_always_present()
+    {
+        var sink = new InMemorySink();
+        var options = new ZbTelemetryOptions
+        {
+            ServiceName = "otopcua",
+            SiteId = null,
+            NodeRole = null,
+        };
+
+        var loggerConfig = new LoggerConfiguration();
+        ZbSerilogConfig.Apply(loggerConfig, options);
+        using var logger = loggerConfig
+            .WriteTo.Sink(sink)
+            .CreateLogger();
+
+        logger.Information("hello");
+
+        var logEvent = Assert.Single(sink.LogEvents);
+        Assert.False(logEvent.Properties.ContainsKey(ZbLogEnricherNames.SiteId),
+            "SiteId should be absent when null");
+        Assert.False(logEvent.Properties.ContainsKey(ZbLogEnricherNames.NodeRole),
+            "NodeRole should be absent when null");
+        Assert.Equal(
+            Environment.MachineName,
+            ScalarValue(logEvent, ZbLogEnricherNames.NodeHostname));
+    }
 }
@@ -84,7 +84,53 @@ public sealed class RedactionTests

        using var host = builder.Build();

+        // Serilog.ILogger is registered by AddSerilog — not Microsoft.Extensions.Logging.ILogger.
        var logger = host.Services.GetRequiredService<ILogger>();
        logger.Information("otlp wiring smoke test");
    }
+
+    [Fact]
+    public void BuildResourceAttributes_contains_required_keys_and_optional_keys_when_set()
+    {
+        var options = new ZbTelemetryOptions
+        {
+            ServiceName = "mxgateway",
+            ServiceNamespace = "ZB.MOM.WW",
+            SiteId = "site-a",
+            NodeRole = "central",
+        };
+
+        var attributes = ZbSerilogConfig.BuildResourceAttributes(options);
+
+        // Required keys always present.
+        Assert.True(attributes.ContainsKey("service.name"), "service.name must be present");
+        Assert.True(attributes.ContainsKey("service.namespace"), "service.namespace must be present");
+        Assert.True(attributes.ContainsKey("host.name"), "host.name must be present");
+
+        // Optional keys present when options supply them.
+        Assert.True(attributes.ContainsKey("site.id"), "site.id must be present when SiteId is set");
+        Assert.True(attributes.ContainsKey("node.role"), "node.role must be present when NodeRole is set");
+
+        Assert.Equal("mxgateway", attributes["service.name"]);
+        Assert.Equal("ZB.MOM.WW", attributes["service.namespace"]);
+        Assert.Equal(Environment.MachineName, attributes["host.name"]);
+        Assert.Equal("site-a", attributes["site.id"]);
+        Assert.Equal("central", attributes["node.role"]);
+    }
+
+    [Fact]
+    public void BuildResourceAttributes_omits_optional_keys_when_not_set()
+    {
+        var options = new ZbTelemetryOptions
+        {
+            ServiceName = "mxgateway",
+            SiteId = null,
+            NodeRole = null,
+        };
+
+        var attributes = ZbSerilogConfig.BuildResourceAttributes(options);
+
+        Assert.False(attributes.ContainsKey("site.id"), "site.id must be absent when SiteId is null");
+        Assert.False(attributes.ContainsKey("node.role"), "node.role must be absent when NodeRole is null");
+    }
 }
@@ -42,11 +42,16 @@ public sealed class TraceContextEnricherTests
        Assert.NotNull(activity);
        Assert.NotNull(Activity.Current);

+        // Capture IDs before the log call so assertions are not sensitive to activity
+        // lifecycle — Activity.Current may differ after the log call returns.
+        var expectedTraceId = activity.TraceId.ToString();
+        var expectedSpanId = activity.SpanId.ToString();
+
        logger.Information("traced");

        var logEvent = Assert.Single(sink.LogEvents);
-        Assert.Equal(Activity.Current!.TraceId.ToString(), ScalarOrNull(logEvent, "trace_id"));
-        Assert.Equal(Activity.Current!.SpanId.ToString(), ScalarOrNull(logEvent, "span_id"));
+        Assert.Equal(expectedTraceId, ScalarOrNull(logEvent, "trace_id"));
+        Assert.Equal(expectedSpanId, ScalarOrNull(logEvent, "span_id"));
    }

    [Fact]