From f569d537d1d99136da82965d1ea6dadd74d96eef Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Mon, 1 Jun 2026 08:13:35 -0400 Subject: [PATCH] fix(telemetry.serilog): don't set process-global Log.Logger in AddZbSerilog (multi-host safe) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Remove the Stage-1 bootstrap-logger line (Log.Logger = new LoggerConfiguration() .WriteTo.Console().CreateBootstrapLogger()) from AddZbSerilog. A shared library must not mutate process-global state: when multiple hosts are built in one process (integration tests, Aspire multi-host, parallel test runs) the second call throws "The logger is already frozen". AddSerilog is now called with preserveStaticLogger: true so Serilog.Extensions.Hosting leaves the static Log.Logger entirely untouched. The DI-registered application logger is the only artifact AddZbSerilog produces. Apps that want a pre-Build() bootstrap logger should set Log.Logger themselves in Program.cs before calling AddZbSerilog — that decision belongs to the application. Three new regression tests in MultiHostTests verify: two hosts build in the same process without throwing; Log.Logger is not mutated; each host gets its own independent DI ILogger. Docs (SPEC.md §5 and shared-contract ZB.MOM.WW.Telemetry.md) updated: the "two-stage bootstrap" framing is replaced with the correct description — library registers only the DI application logger; optional Stage-1 bootstrap is the app's responsibility. --- .../ZbSerilogExtensions.cs | 84 ++++++++------- .../MultiHostTests.cs | 102 ++++++++++++++++++ .../shared-contract/ZB.MOM.WW.Telemetry.md | 34 +++--- components/observability/spec/SPEC.md | 25 +++-- 4 files changed, 186 insertions(+), 59 deletions(-) create mode 100644 ZB.MOM.WW.Telemetry/tests/ZB.MOM.WW.Telemetry.Serilog.Tests/MultiHostTests.cs diff --git a/ZB.MOM.WW.Telemetry/src/ZB.MOM.WW.Telemetry.Serilog/ZbSerilogExtensions.cs b/ZB.MOM.WW.Telemetry/src/ZB.MOM.WW.Telemetry.Serilog/ZbSerilogExtensions.cs index 11b850a..8150434 100644 --- a/ZB.MOM.WW.Telemetry/src/ZB.MOM.WW.Telemetry.Serilog/ZbSerilogExtensions.cs +++ b/ZB.MOM.WW.Telemetry/src/ZB.MOM.WW.Telemetry.Serilog/ZbSerilogExtensions.cs @@ -6,7 +6,7 @@ using ZB.MOM.WW.Telemetry; namespace ZB.MOM.WW.Telemetry.Serilog; /// -/// Extension point for configuring the shared Serilog two-stage bootstrap on an +/// Extension point for configuring the shared Serilog application logger on an /// . Wires config-driven sinks /// (ReadFrom.Configuration), an explicit minimum level (Serilog:MinimumLevel, /// default ), and the shared enricher/redaction/OTel-export @@ -14,39 +14,44 @@ namespace ZB.MOM.WW.Telemetry.Serilog; /// AddZbTelemetry in the core package for that. /// /// -/// Stage 1 (bootstrap): sets to a console-only logger before -/// Build() is called, capturing any startup exceptions that occur before the DI -/// container is ready. +/// This method intentionally does not set the process-global +/// (via CreateBootstrapLogger or otherwise). Mutating +/// process-global state in a shared library causes "logger is already frozen" exceptions +/// when multiple hosts are built in the same process (integration tests, multi-host apps). /// /// -/// Stage 2 (application): wires the full Serilog pipeline via -/// -/// once the host builds, replacing the bootstrap logger with the configuration-driven one. +/// Apps that need a pre-Build() bootstrap logger to capture early startup exceptions +/// should set themselves in Program.cs before calling +/// AddZbSerilog: +/// +/// Log.Logger = new LoggerConfiguration().WriteTo.Console().CreateBootstrapLogger(); +/// // ... then build the host ... +/// builder.AddZbSerilog(o => { ... }); +/// +/// This keeps global-state mutation firmly in the application, not the library. /// /// public static class ZbSerilogExtensions { /// - /// Registers Serilog on the host with a two-stage bootstrap: - /// - /// - /// - /// Stage 1 — immediately sets to a console-only bootstrap logger - /// so that startup exceptions before Build() are captured. - /// - /// - /// - /// - /// Stage 2 — registers the full pipeline via AddSerilog: configuration-driven sinks - /// (ReadFrom.Configuration), a code default of - /// that config can override via Serilog:MinimumLevel or namespace overrides, plus - /// the identity enrichers (SiteId/NodeRole from , - /// NodeHostname = ). - /// - /// - /// - /// The delegate receives the same - /// used by AddZbTelemetry — typically share one options-population lambda across both. + /// Registers the Serilog application logger in DI. Wires configuration-driven sinks + /// (ReadFrom.Configuration), a code default of + /// that config can override via Serilog:MinimumLevel or namespace overrides, plus + /// the identity enrichers (SiteId/NodeRole from , + /// NodeHostname = ). + /// + /// + /// This method does not set the process-global . + /// preserveStaticLogger: true is passed to AddSerilog so the static logger + /// is left entirely untouched — safe to call multiple times in the same process (integration + /// tests, multi-host scenarios) without hitting "logger is already frozen". + /// + /// + /// If early-startup bootstrap logging is required (before Build()), set + /// Log.Logger = new LoggerConfiguration().WriteTo.Console().CreateBootstrapLogger(); + /// in Program.cs before calling this method. That decision belongs to the + /// application, not the shared library. + /// /// /// The host application builder. /// Populates the . @@ -60,20 +65,19 @@ public static class ZbSerilogExtensions var options = new ZbTelemetryOptions(); configure(options); - // Stage 1: bootstrap logger captures startup exceptions before Build(). - Log.Logger = new LoggerConfiguration() - .WriteTo.Console() - .CreateBootstrapLogger(); + // Register the application logger in DI only. preserveStaticLogger: true ensures + // AddSerilog does NOT freeze or replace Log.Logger — critical for multi-host + // processes (integration tests etc.) where AddZbSerilog may be called more than once. + builder.Services.AddSerilog( + (serviceProvider, loggerConfiguration) => + { + loggerConfiguration + .MinimumLevel.Is(LogEventLevel.Information) + .ReadFrom.Configuration(builder.Configuration); - // Stage 2: full application logger — code default first, then config overrides. - builder.Services.AddSerilog((serviceProvider, loggerConfiguration) => - { - loggerConfiguration - .MinimumLevel.Is(LogEventLevel.Information) - .ReadFrom.Configuration(builder.Configuration); - - ZbSerilogConfig.Apply(loggerConfiguration, options, serviceProvider); - }); + ZbSerilogConfig.Apply(loggerConfiguration, options, serviceProvider); + }, + preserveStaticLogger: true); return builder; } diff --git a/ZB.MOM.WW.Telemetry/tests/ZB.MOM.WW.Telemetry.Serilog.Tests/MultiHostTests.cs b/ZB.MOM.WW.Telemetry/tests/ZB.MOM.WW.Telemetry.Serilog.Tests/MultiHostTests.cs new file mode 100644 index 0000000..faa84d5 --- /dev/null +++ b/ZB.MOM.WW.Telemetry/tests/ZB.MOM.WW.Telemetry.Serilog.Tests/MultiHostTests.cs @@ -0,0 +1,102 @@ +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Hosting; +using Serilog; +using ZB.MOM.WW.Telemetry; +using ZB.MOM.WW.Telemetry.Serilog; + +namespace ZB.MOM.WW.Telemetry.Serilog.Tests; + +/// +/// Regression tests for the process-global-state hazard: AddZbSerilog must not set or +/// freeze Log.Logger. When multiple hosts are built in the same process (integration +/// tests, multi-host apps) AddZbSerilog must be callable repeatedly without throwing +/// "The logger is already frozen". +/// +public sealed class MultiHostTests +{ + [Fact] + public void AddZbSerilog_called_twice_in_same_process_does_not_throw() + { + // Arrange + Act: build two completely independent hosts in the same test process. + // Prior to the fix, the second call to AddZbSerilog would crash with + // "The logger is already frozen" because Stage-1 set the process-global Log.Logger. + var exception = Record.Exception(() => + { + var builder1 = Host.CreateApplicationBuilder(); + builder1.AddZbSerilog(o => + { + o.ServiceName = "host-one"; + o.SiteId = "s1"; + o.NodeRole = "central"; + }); + using var host1 = builder1.Build(); + + var builder2 = Host.CreateApplicationBuilder(); + builder2.AddZbSerilog(o => + { + o.ServiceName = "host-two"; + o.SiteId = "s2"; + o.NodeRole = "site"; + }); + using var host2 = builder2.Build(); + }); + + Assert.Null(exception); + } + + [Fact] + public void AddZbSerilog_does_not_mutate_global_Log_Logger() + { + // Capture whatever the static logger is before calling AddZbSerilog. + var loggerBefore = Log.Logger; + + var builder = Host.CreateApplicationBuilder(); + builder.AddZbSerilog(o => + { + o.ServiceName = "no-global-state"; + }); + using var host = builder.Build(); + + // AddZbSerilog must leave Log.Logger exactly as it was found. + // (ReferenceEquals is the right check — it must be the *same* instance, not + // just an equivalent one, so we know the library never touched the static field.) + Assert.True( + ReferenceEquals(loggerBefore, Log.Logger), + "AddZbSerilog must not replace or freeze the global Log.Logger"); + } + + [Fact] + public void AddZbSerilog_each_host_resolves_its_own_DI_ILogger() + { + // Both hosts must resolve a working Serilog ILogger from DI independently — + // neither host's logger is the process-global Log.Logger. + var builder1 = Host.CreateApplicationBuilder(); + builder1.AddZbSerilog(o => { o.ServiceName = "host-a"; }); + using var host1 = builder1.Build(); + + var builder2 = Host.CreateApplicationBuilder(); + builder2.AddZbSerilog(o => { o.ServiceName = "host-b"; }); + using var host2 = builder2.Build(); + + var logger1 = host1.Services.GetRequiredService(); + var logger2 = host2.Services.GetRequiredService(); + + // Both are non-null and independently functional. + Assert.NotNull(logger1); + Assert.NotNull(logger2); + + // They are distinct instances (each host has its own application logger). + Assert.False( + ReferenceEquals(logger1, logger2), + "each host must have its own DI-registered ILogger instance"); + + // Neither matches the global Log.Logger — the library must not have promoted + // a DI logger to process-global state. + Assert.False( + ReferenceEquals(logger1, Log.Logger), + "host-a's DI logger must not be the global Log.Logger"); + Assert.False( + ReferenceEquals(logger2, Log.Logger), + "host-b's DI logger must not be the global Log.Logger"); + } +} diff --git a/components/observability/shared-contract/ZB.MOM.WW.Telemetry.md b/components/observability/shared-contract/ZB.MOM.WW.Telemetry.md index f0a9604..bd5c6ff 100644 --- a/components/observability/shared-contract/ZB.MOM.WW.Telemetry.md +++ b/components/observability/shared-contract/ZB.MOM.WW.Telemetry.md @@ -148,22 +148,30 @@ public static class ZbMetricsEndpointExtensions ```csharp namespace ZB.MOM.WW.Telemetry.Serilog; -/// Extension point for configuring the Serilog two-stage bootstrap on an IHostApplicationBuilder. +/// Extension point for registering the Serilog application logger in DI on an IHostApplicationBuilder. public static class ZbSerilogExtensions { - /// Two-stage Serilog bootstrap: - /// Stage 1 — minimal console-only bootstrap logger (for startup errors before IConfiguration). - /// Stage 2 — application logger wired from IConfiguration (ReadFrom.Configuration reads - /// Serilog:WriteTo sinks + Serilog:MinimumLevel from "Serilog:MinimumLevel") with - /// fixed enrichers: SiteId + NodeRole from ZbTelemetryOptions; NodeHostname from - /// Environment.MachineName (auto — not a caller-supplied option); TraceContextEnricher; - /// and RedactionEnricher (applied only when ILogRedactor is registered). + /// Registers the Serilog application logger in DI. Wires configuration-driven sinks + /// (ReadFrom.Configuration reads Serilog:WriteTo sinks + Serilog:MinimumLevel) with + /// fixed enrichers: SiteId + NodeRole from ZbTelemetryOptions; NodeHostname from + /// Environment.MachineName (auto — not a caller-supplied option); TraceContextEnricher; + /// and RedactionEnricher (applied only when ILogRedactor is registered). /// /// MinimumLevel: AddZbSerilog reads "Serilog:MinimumLevel" from IConfiguration. Callers that /// bind MinimumLevel from a different config key (e.g. ScadaBridge's /// "ScadaBridge:Logging:MinimumLevel") apply that override themselves before or after /// calling AddZbSerilog — this remains per-project and AddZbSerilog does not read it. /// + /// IMPORTANT — no process-global state: AddZbSerilog does NOT set Log.Logger. It passes + /// preserveStaticLogger: true to AddSerilog so the static logger is left untouched. + /// This makes AddZbSerilog safe to call multiple times in one process (integration tests, + /// multi-host apps) without hitting "The logger is already frozen". + /// + /// Apps that need a pre-Build() bootstrap logger (for startup exceptions before IConfiguration + /// is available) should set Log.Logger themselves in Program.cs: + /// Log.Logger = new LoggerConfiguration().WriteTo.Console().CreateBootstrapLogger(); + /// That is an application-level decision — not done by this library. + /// /// OTel log export is wired automatically: logs flow through the OTel pipeline with the same /// Resource as the metrics and traces (all three signals correlated in a backend). /// @@ -247,10 +255,12 @@ The net48 x86 mxaccessgw worker is excluded from both packages. Its `IWorkerLogg (`Directory.Packages.props`). 3. **`RedactionEnricher` DI timing:** `RedactionEnricher` resolves `ILogRedactor` from - `IServiceProvider` on first use (lazy, to avoid a circular-DI problem during Serilog's - two-stage bootstrap). Validate that the service provider is fully built by the time the - first post-startup log event fires. If MxGateway's `GatewayLogRedactor` has dependencies - that are not available at stage-1 bootstrap time, the lazy-resolve pattern protects it. + `IServiceProvider` on first use (lazy, to avoid a circular-DI problem at host-build time). + Validate that the service provider is fully built by the time the first post-startup log + event fires. If MxGateway's `GatewayLogRedactor` has dependencies that are not yet + available when the DI container is being composed, the lazy-resolve pattern protects it. + (Note: the library no longer sets a Stage-1 bootstrap logger, so there is no Stage-1 vs. + Stage-2 logger lifetime to reason about — only the single DI-registered application logger.) 4. **`SiteId` / `NodeRole` null handling:** `AddZbTelemetry` and `AddZbSerilog` silently omit null `SiteId`/`NodeRole` from the Resource and enricher set. Confirm this is the diff --git a/components/observability/spec/SPEC.md b/components/observability/spec/SPEC.md index f86bfab..208cc9b 100644 --- a/components/observability/spec/SPEC.md +++ b/components/observability/spec/SPEC.md @@ -108,13 +108,24 @@ three apps currently use or aspire to. ## 5. Serilog logging stack -`AddZbSerilog` is a companion extension in the `.Serilog` package. It replaces each -project's bespoke logging bootstrap with a shared two-stage pattern: +`AddZbSerilog` is a companion extension in the `.Serilog` package. It registers the +Serilog application logger in DI and applies a set of fixed enrichers: -**Stage 1 (bootstrap logger):** a minimal `Log.Logger` for startup errors before the -`IConfiguration` is available. Writes to console only. +> **No process-global state.** `AddZbSerilog` does NOT set or freeze the static +> `Log.Logger`. It passes `preserveStaticLogger: true` to `AddSerilog` so the global +> logger is left entirely untouched. This keeps the library safe for multi-host processes +> (integration tests, Aspire, test suites) — calling `AddZbSerilog` twice in the same +> process must never throw "The logger is already frozen". +> +> The optional Stage-1 **bootstrap logger** (`CreateBootstrapLogger`) — a minimal +> console-only `Log.Logger` for capturing startup exceptions before `IConfiguration` is +> available — is the **application's responsibility**, not the library's. Apps that need +> it should add this to `Program.cs` before calling `AddZbSerilog`: +> ```csharp +> Log.Logger = new LoggerConfiguration().WriteTo.Console().CreateBootstrapLogger(); +> ``` -**Stage 2 (application logger):** reads sinks and overrides from `IConfiguration` +**Application logger (DI):** reads sinks and overrides from `IConfiguration` (`ReadFrom.Configuration`) and applies a set of fixed enrichers: | Enricher | Property name | Source | @@ -170,9 +181,9 @@ process in log events) while making the plumbing reusable. | Project | Current state | Primary gaps | What normalizes | |---|---|---|---| -| **OtOpcUa** | Full OTel SDK (`WithMetrics` + `WithTracing`); Prometheus `/metrics`; Serilog bootstrap; 7 instruments + 2 spans. | No `Resource` / `service.name` anywhere; no trace↔log correlation; no `SiteId`/`NodeRole` enrichers. | Call `AddZbTelemetry` (adds Resource; consolidates standard instrumentation); call `AddZbSerilog` (adds `TraceContextEnricher` + identity enrichers); migrate existing Serilog bootstrap to shared two-stage pattern. | +| **OtOpcUa** | Full OTel SDK (`WithMetrics` + `WithTracing`); Prometheus `/metrics`; Serilog bootstrap; 7 instruments + 2 spans. | No `Resource` / `service.name` anywhere; no trace↔log correlation; no `SiteId`/`NodeRole` enrichers. | Call `AddZbTelemetry` (adds Resource; consolidates standard instrumentation); call `AddZbSerilog` (adds `TraceContextEnricher` + identity enrichers); remove bespoke Serilog bootstrap (if a pre-Build bootstrap logger is wanted, add `Log.Logger = new LoggerConfiguration()...CreateBootstrapLogger();` in `Program.cs`). | | **MxGateway** | Hand-rolled `GatewayMetrics` (13 counters / 3 histograms `ms` / 4 gauges); in-memory snapshot only — no export; MEL logging with `GatewayLogScope` correlation + `GatewayLogRedactor`; no OTel SDK. | No OTel SDK; no export; `ms` histograms diverge from OTel semconv (`s`); MEL → Serilog migration; no Resource. | Call `AddZbTelemetry` (wires OTel SDK around existing `GatewayMetrics` — finally exports); call `AddZbSerilog` (replaces MEL; re-expresses `GatewayLogScope` as `LogContext.PushProperty`; moves `GatewayLogRedactor` behind `ILogRedactor`). Duration unit convergence (`ms`→`s`) tracked in GAPS. **This is the one adoption done now.** | -| **ScadaBridge** | `OpenTelemetry.Api` ref only (dangling — CVE-patch origin, zero usage); Serilog bootstrap (`LoggerConfigurationFactory`) with `SiteId`/`NodeRole`/`NodeHostname` enrichers. | No OTel SDK; no metrics; no tracing; no export; no trace↔log correlation. ScadaBridge's enricher property names are already the target names — migration is additive. | Call `AddZbTelemetry` (adds OTel SDK + metrics + traces + export); call `AddZbSerilog` (consolidates `LoggerConfigurationFactory`; adds `TraceContextEnricher`). | +| **ScadaBridge** | `OpenTelemetry.Api` ref only (dangling — CVE-patch origin, zero usage); Serilog bootstrap (`LoggerConfigurationFactory`) with `SiteId`/`NodeRole`/`NodeHostname` enrichers. | No OTel SDK; no metrics; no tracing; no export; no trace↔log correlation. ScadaBridge's enricher property names are already the target names — migration is additive. | Call `AddZbTelemetry` (adds OTel SDK + metrics + traces + export); call `AddZbSerilog` (consolidates `LoggerConfigurationFactory`; adds `TraceContextEnricher`); if a pre-Build bootstrap logger is wanted, set `Log.Logger = new LoggerConfiguration()...CreateBootstrapLogger();` in `Program.cs`. | > The MxGateway logging migration (`MEL → Serilog`, re-expressing `GatewayLogRedactor` > behind `ILogRedactor`) is the **only sister-repo touch in scope for this release**. OtOpcUa