From 1ab5ca026baf42a708e11487dcf0654bed747bcc Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Mon, 9 Nov 2026 13:39:06 -0500 Subject: [PATCH] feat(telemetry): AddZbSerilog minimum-level governance hook; bump to 0.2.0 (scadaproj#12) Adds an additive AddZbSerilog(builder, configure, configureSerilog) overload taking ZbSerilogOptions: - MinimumLevelGovernor: Func applied with MinimumLevel.Is AFTER ReadFrom.Configuration, so an app-owned key (e.g. ScadaBridge:Logging:MinimumLevel) outranks Serilog:MinimumLevel; null defers to config; Serilog:MinimumLevel:Override:* entries still apply. - ConfigureLogger: runs last, for app filters/enrichers/sinks (ScadaBridge's standby active-node exclusion). The two-argument overload is unchanged. 8 new tests (4 fail with the hook neutralized). Telemetry + Telemetry.Serilog 0.1.0 -> 0.2.0, not published. Claude-Session: https://claude.ai/code/session_01GT67AEHd2Acv1YPwGfXEoV --- ZB.MOM.WW.Telemetry/CLAUDE.md | 19 +- ZB.MOM.WW.Telemetry/Directory.Build.props | 2 +- ZB.MOM.WW.Telemetry/README.md | 25 ++- .../ZbSerilogExtensions.cs | 40 ++++- .../ZbSerilogOptions.cs | 47 +++++ .../MinimumLevelGovernanceTests.cs | 162 ++++++++++++++++++ components/observability/GAPS.md | 5 +- 7 files changed, 288 insertions(+), 12 deletions(-) create mode 100644 ZB.MOM.WW.Telemetry/src/ZB.MOM.WW.Telemetry.Serilog/ZbSerilogOptions.cs create mode 100644 ZB.MOM.WW.Telemetry/tests/ZB.MOM.WW.Telemetry.Serilog.Tests/MinimumLevelGovernanceTests.cs diff --git a/ZB.MOM.WW.Telemetry/CLAUDE.md b/ZB.MOM.WW.Telemetry/CLAUDE.md index 078ac35..e8d67d4 100644 --- a/ZB.MOM.WW.Telemetry/CLAUDE.md +++ b/ZB.MOM.WW.Telemetry/CLAUDE.md @@ -2,7 +2,7 @@ Observability libraries for the **ZB.MOM.WW SCADA family** (OtOpcUa, MxAccessGateway, ScadaBridge). These are **libraries, not a service** — each package is linked directly into the consuming application at build time. There is no central telemetry process; instrumentation runs in-process alongside the application. -**Backlog / open work:** lives in Gitea issues on `dohertj2/scadaproj` (`tea issues list --repo dohertj2/scadaproj`) — currently #12 (`AddZbSerilog` min-level governance hook), #13 (OTel collector / OTLP end to end), #17 (stale README text). The history below is a record, not a status tracker; file new follow-ups as issues. +**Backlog / open work:** lives in Gitea issues on `dohertj2/scadaproj` (`tea issues list --repo dohertj2/scadaproj`) — currently #13 (OTel collector / OTLP end to end), #17 (stale README text). The history below is a record, not a status tracker; file new follow-ups as issues. The library normalizes the three-project observability surface: a shared OpenTelemetry Resource driven by a single identity triple (`service.name` / `site.id` / `node.role`), standard instrumentation wiring, Prometheus and OTLP export, and a Serilog bootstrap with enrichers and `TraceContextEnricher` for trace↔log correlation. @@ -15,7 +15,7 @@ The library normalizes the three-project observability surface: a shared OpenTel | Package | Responsibilities | Key Dependencies | |---|---|---| | `ZB.MOM.WW.Telemetry` | `AddZbTelemetry` — wires OTel SDK (metrics + tracing), populates shared Resource (`service.name`, `service.namespace`, `service.version`, `site.id`, `node.role`, `host.name`), registers caller-supplied Meters/ActivitySources, adds standard instrumentation (ASP.NET Core, HttpClient, gRPC client, runtime, process), Prometheus always-on exporter, OTLP additive overlay. `app.MapZbMetrics()` — mounts `/metrics`. `ZbTelemetryOptions` — the single options object shared by both packages. | `Microsoft.AspNetCore.App` (framework ref), `OpenTelemetry.*` stack | -| `ZB.MOM.WW.Telemetry.Serilog` | `AddZbSerilog` — shared two-stage Serilog bootstrap: `ReadFrom.Configuration`-driven sinks, `MinimumLevel.Is(Information)` default (config-overridable), `SiteId`/`NodeRole`/`NodeHostname` enrichers from `ZbTelemetryOptions`, `TraceContextEnricher` (writes `trace_id`/`span_id` from `Activity.Current`), `ILogRedactor` seam (per-project sensitive-field redaction via `RedactionEnricher`). Does NOT freeze `Log.Logger` — safe for multi-host/test scenarios. | `ZB.MOM.WW.Telemetry`, `Serilog.*` stack | +| `ZB.MOM.WW.Telemetry.Serilog` | `AddZbSerilog` — shared two-stage Serilog bootstrap: `ReadFrom.Configuration`-driven sinks, `MinimumLevel.Is(Information)` default (config-overridable), `SiteId`/`NodeRole`/`NodeHostname` enrichers from `ZbTelemetryOptions`, `TraceContextEnricher` (writes `trace_id`/`span_id` from `Activity.Current`), `ILogRedactor` seam (per-project sensitive-field redaction via `RedactionEnricher`). **0.2.0:** optional `ZbSerilogOptions` overload — `MinimumLevelGovernor` (app key outranks `Serilog:MinimumLevel`) + `ConfigureLogger` (final filters/enrichers/sinks). Does NOT freeze `Log.Logger` — safe for multi-host/test scenarios. | `ZB.MOM.WW.Telemetry`, `Serilog.*` stack | --- @@ -53,9 +53,9 @@ All test assemblies run offline: | Assembly | Tests | |---|---| -| `ZB.MOM.WW.Telemetry.Tests` | 7 | -| `ZB.MOM.WW.Telemetry.Serilog.Tests` | 12 | -| **Total** | **19** | +| `ZB.MOM.WW.Telemetry.Tests` | 12 | +| `ZB.MOM.WW.Telemetry.Serilog.Tests` | 30 | +| **Total** | **42** | `GeneratePackageOnBuild` is off — pack explicitly with the command above. @@ -63,6 +63,15 @@ All test assemblies run offline: ## Status +**`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`, applied with `MinimumLevel.Is` +AFTER `ReadFrom.Configuration`, so an app-owned key outranks `Serilog:MinimumLevel`; `null` defers to +config; namespace `Override:*` entries still apply) and `ConfigureLogger` (runs last, for filters such +as ScadaBridge's standby `active-node` exclusion). The two-argument overload is unchanged. This is +the library half of ScadaBridge's `AddZbSerilog` adoption; the app-side switch is a follow-on in +that repo. + Built at **0.1.0**, published to the Gitea NuGet feed, and **adopted across all three apps on 2026-06-01** (branch `feat/adopt-zb-telemetry` per repo, behaviour-preserving). MxAccessGateway's MEL→Serilog migration and metrics export both landed in this pass (not beforehand, despite the diff --git a/ZB.MOM.WW.Telemetry/Directory.Build.props b/ZB.MOM.WW.Telemetry/Directory.Build.props index c4755a6..f03af92 100644 --- a/ZB.MOM.WW.Telemetry/Directory.Build.props +++ b/ZB.MOM.WW.Telemetry/Directory.Build.props @@ -5,7 +5,7 @@ enable enable latest - 0.1.0 + 0.2.0 true diff --git a/ZB.MOM.WW.Telemetry/README.md b/ZB.MOM.WW.Telemetry/README.md index b449a21..f918eb1 100644 --- a/ZB.MOM.WW.Telemetry/README.md +++ b/ZB.MOM.WW.Telemetry/README.md @@ -112,6 +112,23 @@ builder.AddZbSerilog(o => }); ``` +```csharp +// 0.2.0+: optional hooks for apps whose OWN key governs the minimum level (e.g. ScadaBridge's +// ScadaBridge:Logging:MinimumLevel, which must outrank Serilog:MinimumLevel). The governor runs +// AFTER ReadFrom.Configuration, so a non-null result overrides Serilog:MinimumLevel[:Default]; +// null defers to config. Serilog:MinimumLevel:Override:* namespace entries still apply. +// ConfigureLogger runs last (filters, extra enrichers/sinks). Both default to null, in which +// case this is identical to the two-argument overload. +builder.AddZbSerilog( + o => { o.ServiceName = "scadabridge"; o.SiteId = siteId; o.NodeRole = nodeRole; }, + s => + { + s.MinimumLevelGovernor = cfg => + Enum.TryParse(cfg["ScadaBridge:Logging:MinimumLevel"], true, out var l) ? l : null; + s.ConfigureLogger = (lc, sp) => lc.Filter.ByExcluding(MyFilter); + }); +``` + --- ## Building and testing @@ -128,8 +145,8 @@ backend): | Assembly | Tests | |---|---| | `ZB.MOM.WW.Telemetry.Tests` | 12 | -| `ZB.MOM.WW.Telemetry.Serilog.Tests` | 17 | -| **Total** | **29** | +| `ZB.MOM.WW.Telemetry.Serilog.Tests` | 30 | +| **Total** | **42** | --- @@ -142,8 +159,8 @@ dotnet pack ZB.MOM.WW.Telemetry.slnx -c Release -o ./artifacts Produces two `.nupkg` files in `artifacts/`: ``` -ZB.MOM.WW.Telemetry.0.1.0.nupkg -ZB.MOM.WW.Telemetry.Serilog.0.1.0.nupkg +ZB.MOM.WW.Telemetry.0.2.0.nupkg +ZB.MOM.WW.Telemetry.Serilog.0.2.0.nupkg ``` `GeneratePackageOnBuild` is off — pack explicitly as above. Both packages are versioned 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 b259b87..2b6b77c 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 @@ -57,7 +57,35 @@ public static class ZbSerilogExtensions /// Populates the . public static IHostApplicationBuilder AddZbSerilog( this IHostApplicationBuilder builder, - Action configure) + Action configure) => + AddZbSerilogCore(builder, configure, new ZbSerilogOptions()); + + /// + /// Overload of + /// that additionally accepts caller-supplied hooks (): a + /// minimum-level governor that has the last word on the default floor (it runs AFTER + /// ReadFrom.Configuration, so it overrides Serilog:MinimumLevel), and a final + /// callback for app-specific filters/enrichers/sinks. + /// With every hook left null this is identical to the two-argument overload. + /// + /// The host application builder. + /// Populates the . + /// Populates the hooks. + public static IHostApplicationBuilder AddZbSerilog( + this IHostApplicationBuilder builder, + Action configure, + Action configureSerilog) + { + ArgumentNullException.ThrowIfNull(configureSerilog); + var serilogOptions = new ZbSerilogOptions(); + configureSerilog(serilogOptions); + return AddZbSerilogCore(builder, configure, serilogOptions); + } + + private static IHostApplicationBuilder AddZbSerilogCore( + IHostApplicationBuilder builder, + Action configure, + ZbSerilogOptions serilogOptions) { ArgumentNullException.ThrowIfNull(builder); ArgumentNullException.ThrowIfNull(configure); @@ -79,7 +107,17 @@ public static class ZbSerilogExtensions .MinimumLevel.Is(LogEventLevel.Information) .ReadFrom.Configuration(builder.Configuration); + // The governor runs AFTER ReadFrom.Configuration on purpose: that ordering is what + // lets an app-owned key outrank Serilog:MinimumLevel. Namespace overrides read from + // configuration are untouched — MinimumLevel.Is only sets the default floor. + if (serilogOptions.MinimumLevelGovernor?.Invoke(builder.Configuration) is { } governed) + { + loggerConfiguration.MinimumLevel.Is(governed); + } + ZbSerilogConfig.Apply(loggerConfiguration, options, serviceProvider); + + serilogOptions.ConfigureLogger?.Invoke(loggerConfiguration, serviceProvider); }, preserveStaticLogger: true); diff --git a/ZB.MOM.WW.Telemetry/src/ZB.MOM.WW.Telemetry.Serilog/ZbSerilogOptions.cs b/ZB.MOM.WW.Telemetry/src/ZB.MOM.WW.Telemetry.Serilog/ZbSerilogOptions.cs new file mode 100644 index 0000000..03b661d --- /dev/null +++ b/ZB.MOM.WW.Telemetry/src/ZB.MOM.WW.Telemetry.Serilog/ZbSerilogOptions.cs @@ -0,0 +1,47 @@ +using Microsoft.Extensions.Configuration; +using Serilog; +using Serilog.Events; + +namespace ZB.MOM.WW.Telemetry.Serilog; + +/// +/// Optional, caller-supplied hooks for . +/// Every member defaults to , and with all of them null the bootstrap is +/// byte-for-byte the two-argument AddZbSerilog. +/// +/// +/// +/// Why this exists. The default bootstrap pins a code floor of +/// and then lets ReadFrom.Configuration override it, +/// so Serilog:MinimumLevel is the source of truth. An app whose documented contract puts the +/// floor somewhere else (ScadaBridge: ScadaBridge:Logging:MinimumLevel wins over +/// Serilog:MinimumLevel) cannot express that with the default ordering — it needs to have +/// the LAST word on the floor. is that last word. +/// +/// +public sealed class ZbSerilogOptions +{ + /// + /// Governs the default minimum level. Invoked with the host's + /// each time the logger is built; a non-null result is applied with + /// MinimumLevel.Is(level) after ReadFrom.Configuration, so it overrides + /// Serilog:MinimumLevel / Serilog:MinimumLevel:Default. Returning + /// defers to the default behaviour (code floor Information, config wins). + /// + /// + /// Only the DEFAULT level is governed: per-namespace Serilog:MinimumLevel:Override:* + /// entries read from configuration still apply on top of it, exactly as they do when the app + /// builds its own and calls MinimumLevel.Is after + /// ReadFrom.Configuration. The governor is the place for any operator-facing warning + /// (unparseable value, conflicting Serilog:MinimumLevel key): it runs before the logger + /// exists, so it should write to its own sink (e.g. ). + /// + public Func? MinimumLevelGovernor { get; set; } + + /// + /// Final, app-specific adjustments to the — filters, + /// extra enrichers, extra sinks — run after the governed level and the shared + /// enricher/redaction/export set. Receives the application . + /// + public Action? ConfigureLogger { get; set; } +} diff --git a/ZB.MOM.WW.Telemetry/tests/ZB.MOM.WW.Telemetry.Serilog.Tests/MinimumLevelGovernanceTests.cs b/ZB.MOM.WW.Telemetry/tests/ZB.MOM.WW.Telemetry.Serilog.Tests/MinimumLevelGovernanceTests.cs new file mode 100644 index 0000000..0574950 --- /dev/null +++ b/ZB.MOM.WW.Telemetry/tests/ZB.MOM.WW.Telemetry.Serilog.Tests/MinimumLevelGovernanceTests.cs @@ -0,0 +1,162 @@ +using Microsoft.Extensions.Configuration; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Hosting; +using Serilog; +using Serilog.Core; +using Serilog.Events; +using ZB.MOM.WW.Telemetry.Serilog; + +namespace ZB.MOM.WW.Telemetry.Serilog.Tests; + +/// +/// scadaproj#12: the caller-supplied minimum-level governor on AddZbSerilog. The contract +/// being pinned is ScadaBridge's (REQ-HOST-8 / Host-011): an app-owned key is the floor and +/// OVERRIDES Serilog:MinimumLevel, while per-namespace overrides from config still apply. +/// +public sealed class MinimumLevelGovernanceTests +{ + private const string AppLevelKey = "App:Logging:MinimumLevel"; + + private static IHost Build( + Dictionary config, + Action? configureSerilog) + { + var builder = Host.CreateApplicationBuilder(new HostApplicationBuilderSettings + { + DisableDefaults = true, + }); + builder.Configuration.AddInMemoryCollection(config); + + if (configureSerilog is null) + builder.AddZbSerilog(o => o.ServiceName = "governance-test"); + else + builder.AddZbSerilog(o => o.ServiceName = "governance-test", configureSerilog); + + return builder.Build(); + } + + private static ILogger Logger(IHost host) => host.Services.GetRequiredService(); + + private static LogEventLevel? FromAppKey(IConfiguration c) => + Enum.TryParse(c[AppLevelKey], ignoreCase: true, out var level) ? level : null; + + [Fact] + public void Without_a_governor_Serilog_MinimumLevel_from_config_wins() + { + // Backward-compat pin: the two-argument overload keeps "config overrides the code floor". + using var host = Build( + new() { ["Serilog:MinimumLevel:Default"] = "Warning", [AppLevelKey] = "Debug" }, + configureSerilog: null); + + var log = Logger(host); + Assert.False(log.IsEnabled(LogEventLevel.Information)); + Assert.True(log.IsEnabled(LogEventLevel.Warning)); + } + + [Fact] + public void Governor_overrides_Serilog_MinimumLevel_downward() + { + using var host = Build( + new() { ["Serilog:MinimumLevel:Default"] = "Warning", [AppLevelKey] = "Debug" }, + o => o.MinimumLevelGovernor = FromAppKey); + + var log = Logger(host); + Assert.True(log.IsEnabled(LogEventLevel.Debug)); + Assert.False(log.IsEnabled(LogEventLevel.Verbose)); + } + + [Fact] + public void Governor_overrides_Serilog_MinimumLevel_upward_including_the_scalar_form() + { + // "Serilog:MinimumLevel": "Verbose" (scalar, not :Default) is the other shape config takes. + using var host = Build( + new() { ["Serilog:MinimumLevel"] = "Verbose", [AppLevelKey] = "Error" }, + o => o.MinimumLevelGovernor = FromAppKey); + + var log = Logger(host); + Assert.False(log.IsEnabled(LogEventLevel.Warning)); + Assert.True(log.IsEnabled(LogEventLevel.Error)); + } + + [Fact] + public void Governor_returning_null_defers_to_config() + { + using var host = Build( + new() { ["Serilog:MinimumLevel:Default"] = "Warning" }, + o => o.MinimumLevelGovernor = FromAppKey); + + var log = Logger(host); + Assert.False(log.IsEnabled(LogEventLevel.Information)); + Assert.True(log.IsEnabled(LogEventLevel.Warning)); + } + + [Fact] + public void Governor_receives_the_host_configuration() + { + IConfiguration? seen = null; + using var host = Build( + new() { [AppLevelKey] = "Fatal" }, + o => o.MinimumLevelGovernor = c => { seen = c; return null; }); + + Assert.NotNull(seen); + Assert.Equal("Fatal", seen![AppLevelKey]); + } + + [Fact] + public void Namespace_overrides_from_config_still_apply_under_a_governor() + { + using var host = Build( + new() + { + [AppLevelKey] = "Debug", + ["Serilog:MinimumLevel:Override:Noisy.Namespace"] = "Error", + }, + o => o.MinimumLevelGovernor = FromAppKey); + + var log = Logger(host); + var noisy = log.ForContext(Constants.SourceContextPropertyName, "Noisy.Namespace.Thing"); + Assert.True(log.IsEnabled(LogEventLevel.Debug)); + Assert.False(noisy.IsEnabled(LogEventLevel.Warning)); + Assert.True(noisy.IsEnabled(LogEventLevel.Error)); + } + + [Fact] + public void ConfigureLogger_runs_last_and_can_add_a_filter() + { + using var host = Build( + new() { [AppLevelKey] = "Information" }, + o => + { + o.MinimumLevelGovernor = FromAppKey; + o.ConfigureLogger = (lc, sp) => + { + Assert.NotNull(sp); + lc.Filter.ByExcluding(e => e.MessageTemplate.Text == "drop me") + .WriteTo.Sink(CapturingSink.Instance); + }; + }); + + CapturingSink.Instance.Events.Clear(); + var log = Logger(host); + log.Information("drop me"); + log.Information("keep me"); + + var texts = CapturingSink.Instance.Events.Select(e => e.MessageTemplate.Text).ToList(); + Assert.Equal(["keep me"], texts); + } + + [Fact] + public void Null_hook_configurator_is_rejected() + { + var builder = Host.CreateApplicationBuilder(); + Assert.Throws(() => + builder.AddZbSerilog(o => o.ServiceName = "x", configureSerilog: null!)); + } + + private sealed class CapturingSink : ILogEventSink + { + public static readonly CapturingSink Instance = new(); + public List Events { get; } = []; + public void Emit(LogEvent logEvent) => Events.Add(logEvent); + } +} diff --git a/components/observability/GAPS.md b/components/observability/GAPS.md index 5e719c3..4fd8e4d 100644 --- a/components/observability/GAPS.md +++ b/components/observability/GAPS.md @@ -230,7 +230,10 @@ sister apps in one pass, behaviour-preserving. Each adoption landed on a per-rep precedence and silently drop the knob. So ScadaBridge keeps the factory and only **adds the shared `TraceContextEnricher`** to it — gaining trace↔log correlation without regressing the contract. Full `AddZbSerilog` adoption for ScadaBridge would first require teaching the shared bootstrap to accept a - caller-supplied minimum-level governance hook (→ #12). + caller-supplied minimum-level governance hook (→ #12). **Library half landed in Telemetry `0.2.0` (unpublished, 2026-11-09):** `AddZbSerilog(builder, + configure, s => { s.MinimumLevelGovernor = …; s.ConfigureLogger = …; })` — the governor runs after + `ReadFrom.Configuration`, `ConfigureLogger` carries the standby `active-node` filter. ScadaBridge's switch is + the remaining follow-on in that repo. - **MxGateway keeps `GatewayLogScope` + request-logging middleware as-is.** The Serilog MEL provider captures MEL `BeginScope` dictionaries as structured properties, so the scope/correlation code keeps producing the same properties under Serilog. Only the provider swap + the `ILogRedactor` adapter were