Files
ScadaBridge/tests/ZB.MOM.WW.ScadaBridge.Host.Tests/ScadaBridgeLoggingParityTests.cs
T
Joseph Doherty 2d2e9f35c5 feat(host): build the process logger through the shared AddZbSerilog bootstrap (#94)
Switch ScadaBridge from its own LoggerConfigurationFactory to AddZbSerilog
(ZB.MOM.WW.Telemetry(.Serilog) 0.1.0 -> 0.2.0) using the two 0.2.0 hooks:

- MinimumLevelGovernor: ScadaBridge:Logging:MinimumLevel, applied after
  ReadFrom.Configuration so it outranks Serilog:MinimumLevel (never null, so the
  floor never defers to the Serilog key; Override:* namespace entries still apply;
  the one-shot conflict / unparseable-value warnings are unchanged).
- ConfigureLogger: the standby active-node exclusion filter (register row 71),
  the configured node identity (the shared bootstrap stamps NodeHostname from
  the machine name and skips empty values; an overwriting enricher keeps the
  configured ScadaBridge:Node values verbatim), Enrich.FromLogContext and the
  ExecutionLogCaptureSink.

ScadaBridgeLogging runs AddZbSerilog on a small pre-host builder and Program
installs the result as the static Log.Logger; both web hosts keep UseSerilog()
over it. One logger and one file-sink handle per process, usable before the
host is built (startup banner, warnings, pre-host Fatal), by SerilogAkkaLogger,
and after the host is disposed (shutdown line, unexpected-termination Fatal) —
AddZbSerilog's own DI registration would leave Log.Logger alone and have the
host dispose the logger.

LoggerConfigurationFactory is deleted (nothing else used it). Tests: existing
logging/standby/sink tests now run through the new pipeline, plus
ScadaBridgeLoggingParityTests (level precedence, Override:* still applies,
one-shot warning, configured identity incl. NodeHostname != MachineName and empty
SiteId, exact property set of a plain line, trace_id/span_id). Mutation-checked:
governor deferring, filter removed, identity enricher removed, FromLogContext
removed, capture sink removed each fail tests.

Claude-Session: https://claude.ai/code/session_01GT67ACmpMR7b9LGRPLijMi
2026-11-12 14:43:19 -05:00

182 lines
7.2 KiB
C#

using System.Diagnostics;
using Microsoft.Extensions.Configuration;
using Serilog;
using Serilog.Core;
using Serilog.Events;
namespace ZB.MOM.WW.ScadaBridge.Host.Tests;
/// <summary>
/// ScadaBridge#94: the host logger moved from ScadaBridge's own <c>LoggerConfigurationFactory</c>
/// onto the shared <c>AddZbSerilog</c> bootstrap (Telemetry.Serilog 0.2.0) with a minimum-level
/// governor and a final <c>ConfigureLogger</c> hook. These tests pin the behaviour the old factory
/// had, through the real pipeline: level governance (the ScadaBridge key outranks the Serilog key,
/// namespace overrides still apply), the exact node-identity enrichers, trace correlation and the
/// property set of a plain line. The standby filter is pinned in
/// <see cref="StandbyHealthCheckLogNoiseTests"/> and the configured file sink in
/// <see cref="SerilogSinkConfigTests"/>, both through the same pipeline.
/// </summary>
public class ScadaBridgeLoggingParityTests
{
private static IConfiguration Config(params (string Key, string Value)[] values) =>
new ConfigurationBuilder()
.AddInMemoryCollection(values.ToDictionary(v => v.Key, v => (string?)v.Value))
.Build();
private static Logger Create(
IConfiguration configuration,
InMemorySink sink,
string nodeRole = "Site",
string siteId = "site-a",
string nodeHostname = "configured-node-hostname",
TextWriter? writer = null) =>
ScadaBridgeLogging.CreateLogger(
configuration, nodeRole, siteId, nodeHostname, writer ?? new StringWriter(), lc => lc.WriteTo.Sink(sink));
/// <summary>
/// Host-011: <c>ScadaBridge:Logging:MinimumLevel</c> is the floor even when
/// <c>Serilog:MinimumLevel</c> asks for something more verbose. Fails if the governor stops
/// running after <c>ReadFrom.Configuration</c> (the shared default ordering).
/// </summary>
[Fact]
public void ScadaBridgeLevel_OutranksAMoreVerboseSerilogLevel()
{
var sink = new InMemorySink();
using var logger = Create(
Config(("ScadaBridge:Logging:MinimumLevel", "Warning"), ("Serilog:MinimumLevel", "Verbose")),
sink);
logger.Debug("debug");
logger.Information("info");
logger.Warning("warning");
var evt = Assert.Single(sink.LogEvents);
Assert.Equal(LogEventLevel.Warning, evt.Level);
}
/// <summary>
/// The governor never defers to the Serilog key: with the ScadaBridge key absent the floor is
/// Information (the <see cref="LoggingOptions"/> default), not the configured Serilog Error.
/// </summary>
[Fact]
public void ScadaBridgeKeyAbsent_FloorIsInformation_NotTheSerilogKey()
{
var sink = new InMemorySink();
using var logger = Create(Config(("Serilog:MinimumLevel:Default", "Error")), sink);
logger.Debug("debug");
logger.Information("info");
var evt = Assert.Single(sink.LogEvents);
Assert.Equal(LogEventLevel.Information, evt.Level);
}
/// <summary>
/// Only the DEFAULT level is governed: a <c>Serilog:MinimumLevel:Override:*</c> namespace entry
/// still raises that namespace's floor, as it did under the old factory.
/// </summary>
[Fact]
public void NamespaceOverrides_StillApply()
{
var sink = new InMemorySink();
using var logger = Create(
Config(
("ScadaBridge:Logging:MinimumLevel", "Debug"),
("Serilog:MinimumLevel:Override:Noisy.Namespace", "Error")),
sink);
logger.ForContext(Constants.SourceContextPropertyName, "Noisy.Namespace.Thing").Warning("noisy warning");
logger.ForContext(Constants.SourceContextPropertyName, "Quiet.Namespace.Thing").Debug("quiet debug");
var evt = Assert.Single(sink.LogEvents);
Assert.Equal("quiet debug", evt.RenderMessage());
}
/// <summary>The override warning is written once per logger build, not per line.</summary>
[Fact]
public void OverrideWarning_IsOneShot()
{
var sink = new InMemorySink();
var writer = new StringWriter();
using var logger = Create(
Config(("ScadaBridge:Logging:MinimumLevel", "Warning"), ("Serilog:MinimumLevel", "Debug")),
sink,
writer: writer);
logger.Warning("one");
logger.Warning("two");
var lines = writer.ToString().Split(Environment.NewLine, StringSplitOptions.RemoveEmptyEntries);
Assert.Single(lines);
}
/// <summary>
/// <c>NodeHostname</c> is the CONFIGURED <c>ScadaBridge:Node:NodeHostname</c>, not the machine
/// name the shared bootstrap stamps, and <c>SiteId</c>/<c>NodeRole</c> are the configured values.
/// </summary>
[Fact]
public void IdentityEnrichers_AreTheConfiguredValues()
{
var sink = new InMemorySink();
const string hostname = "configured-node-hostname";
Assert.NotEqual(hostname, Environment.MachineName); // positive control: the two differ
using var logger = Create(Config(), sink, nodeRole: "Central", siteId: "central", nodeHostname: hostname);
logger.Information("line");
var evt = Assert.Single(sink.LogEvents);
Assert.Equal("central", Scalar(evt, "SiteId"));
Assert.Equal("Central", Scalar(evt, "NodeRole"));
Assert.Equal(hostname, Scalar(evt, "NodeHostname"));
}
/// <summary>
/// The old factory stamped an empty <c>SiteId</c> verbatim; the shared bootstrap skips empty
/// identity values. ScadaBridge keeps stamping it.
/// </summary>
[Fact]
public void EmptySiteId_IsStillStamped()
{
var sink = new InMemorySink();
using var logger = Create(Config(), sink, siteId: "");
logger.Information("line");
Assert.Equal("", Scalar(Assert.Single(sink.LogEvents), "SiteId"));
}
/// <summary>
/// A plain line carries exactly the three identity properties — no enricher was added or lost
/// in the move (the trace enricher adds nothing outside an Activity, the redaction seam is inert).
/// </summary>
[Fact]
public void PlainLine_CarriesExactlyTheIdentityProperties()
{
var sink = new InMemorySink();
using var logger = Create(Config(), sink);
logger.Information("plain");
var keys = Assert.Single(sink.LogEvents).Properties.Keys.OrderBy(k => k, StringComparer.Ordinal);
Assert.Equal(new[] { "NodeHostname", "NodeRole", "SiteId" }, keys);
}
/// <summary>Inside an Activity the shared <c>TraceContextEnricher</c> stamps trace_id/span_id.</summary>
[Fact]
public void InsideAnActivity_TraceContextIsStamped()
{
var sink = new InMemorySink();
using var logger = Create(Config(), sink);
using var activity = new Activity("parity-test").SetIdFormat(ActivityIdFormat.W3C).Start();
logger.Information("traced");
var evt = Assert.Single(sink.LogEvents);
Assert.Equal(activity.TraceId.ToHexString(), Scalar(evt, "trace_id"));
Assert.Equal(activity.SpanId.ToHexString(), Scalar(evt, "span_id"));
}
private static string? Scalar(LogEvent evt, string name) =>
evt.Properties.TryGetValue(name, out var value) && value is ScalarValue { Value: var v } ? v?.ToString() : null;
}