Files
ScadaBridge/tests/ZB.MOM.WW.ScadaBridge.Host.Tests/LoggerConfigurationTests.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

209 lines
8.4 KiB
C#

using Microsoft.Extensions.Configuration;
using Serilog.Events;
namespace ZB.MOM.WW.ScadaBridge.Host.Tests;
/// <summary>
/// <c>ScadaBridge:Logging:MinimumLevel</c> must actually drive the Serilog
/// minimum level. Previously the value was bound into <see cref="LoggingOptions"/>
/// but never read, so editing it had no effect.
/// </summary>
public class LoggerConfigurationTests
{
private static IConfiguration BuildConfig(string? minimumLevel)
{
var values = new Dictionary<string, string?>();
if (minimumLevel != null)
values["ScadaBridge:Logging:MinimumLevel"] = minimumLevel;
return new ConfigurationBuilder().AddInMemoryCollection(values).Build();
}
/// <summary>Verifies that a Warning minimum level suppresses Information logs.</summary>
[Fact]
public void MinimumLevel_Warning_SuppressesInformationLogs()
{
var sink = new InMemorySink();
var logger = ScadaBridgeLogging.CreateLogger(
BuildConfig("Warning"), "Central", "central", "node1", new StringWriter(), lc => lc.WriteTo.Sink(sink));
logger.Information("info message");
logger.Warning("warning message");
Assert.Single(sink.LogEvents);
Assert.Equal(LogEventLevel.Warning, sink.LogEvents[0].Level);
}
/// <summary>Verifies the logger enriches events from the Serilog LogContext, so a run's pushed ExecutionId reaches the sink (ScadaBridge#56).</summary>
[Fact]
public void LogContextProperties_AreEnrichedOntoEvents()
{
var sink = new InMemorySink();
var logger = ScadaBridgeLogging.CreateLogger(
BuildConfig(null), "Site", "site-a", "node1", new StringWriter(), lc => lc.WriteTo.Sink(sink));
var id = Guid.NewGuid();
using (Serilog.Context.LogContext.PushProperty("ExecutionId", id))
{
logger.Information("inside");
}
logger.Information("outside");
Assert.Equal(2, sink.LogEvents.Count);
Assert.Equal(id.ToString(), sink.LogEvents[0].Properties["ExecutionId"].ToString().Trim('"'));
Assert.False(sink.LogEvents[1].Properties.ContainsKey("ExecutionId"));
}
/// <summary>Verifies that a Debug minimum level allows Debug logs.</summary>
[Fact]
public void MinimumLevel_Debug_AllowsDebugLogs()
{
var sink = new InMemorySink();
var logger = ScadaBridgeLogging.CreateLogger(
BuildConfig("Debug"), "Site", "site-a", "node1", new StringWriter(), lc => lc.WriteTo.Sink(sink));
logger.Debug("debug message");
Assert.Single(sink.LogEvents);
Assert.Equal(LogEventLevel.Debug, sink.LogEvents[0].Level);
}
/// <summary>Verifies that an absent minimum level defaults to Information.</summary>
[Fact]
public void MinimumLevel_Absent_DefaultsToInformation()
{
var sink = new InMemorySink();
var logger = ScadaBridgeLogging.CreateLogger(
BuildConfig(null), "Central", "central", "node1", new StringWriter(), lc => lc.WriteTo.Sink(sink));
logger.Debug("debug message");
logger.Information("info message");
Assert.Single(sink.LogEvents);
Assert.Equal(LogEventLevel.Information, sink.LogEvents[0].Level);
}
/// <summary>
/// An unrecognised <c>ScadaBridge:Logging:MinimumLevel</c> (e.g. a typo
/// like "Informaiton") must NOT abort startup but MUST emit a one-shot warning
/// naming the offending value and the fallback so the silent coercion is
/// visible. Null/blank is treated as "unset" and silently defaults.
/// </summary>
[Fact]
public void ParseLevel_UnrecognisedValue_FallsBackAndWarns()
{
var writer = new StringWriter();
var result = ScadaBridgeLogging.ParseLevel("Informaiton", writer);
Assert.Equal(LogEventLevel.Information, result);
var warning = writer.ToString();
Assert.Contains("warning", warning, StringComparison.OrdinalIgnoreCase);
Assert.Contains("Informaiton", warning);
Assert.Contains("Information", warning);
}
/// <summary>Verifies that a null or blank level falls back silently.</summary>
[Fact]
public void ParseLevel_NullOrBlank_FallsBackSilently()
{
var writer = new StringWriter();
var nullResult = ScadaBridgeLogging.ParseLevel(null, writer);
var blankResult = ScadaBridgeLogging.ParseLevel(" ", writer);
Assert.Equal(LogEventLevel.Information, nullResult);
Assert.Equal(LogEventLevel.Information, blankResult);
Assert.Empty(writer.ToString());
}
/// <summary>Verifies that a recognised level value produces no warning.</summary>
[Fact]
public void ParseLevel_RecognisedValue_NoWarning()
{
var writer = new StringWriter();
var result = ScadaBridgeLogging.ParseLevel("Warning", writer);
Assert.Equal(LogEventLevel.Warning, result);
Assert.Empty(writer.ToString());
}
/// <summary>
/// <c>ScadaBridge:Logging:MinimumLevel</c> is the documented source
/// of truth for the Serilog floor, and the explicit <c>MinimumLevel.Is</c>
/// call deliberately runs after <c>ReadFrom.Configuration(...)</c> so a
/// <c>Serilog:MinimumLevel</c> entry is overridden. To make that precedence
/// visible — instead of silently swallowed — <see cref="ScadaBridgeLogging.GovernMinimumLevel(IConfiguration,TextWriter)"/>
/// writes a one-shot warning when both keys are present. The warning must
/// name both values and point the operator at the documented key. When the
/// Serilog key is absent the warning is silent.
/// </summary>
[Fact]
public void Build_BothMinimumLevelKeysSet_WarnsAboutOverride()
{
var writer = new StringWriter();
var configuration = new ConfigurationBuilder()
.AddInMemoryCollection(new Dictionary<string, string?>
{
["ScadaBridge:Logging:MinimumLevel"] = "Warning",
["Serilog:MinimumLevel"] = "Debug",
})
.Build();
using var _ = ScadaBridgeLogging.CreateLogger(configuration, "Central", "central", "node1", writer, null);
var warning = writer.ToString();
Assert.Contains("warning", warning, StringComparison.OrdinalIgnoreCase);
Assert.Contains("Serilog:MinimumLevel", warning);
Assert.Contains("ScadaBridge:Logging:MinimumLevel", warning);
Assert.Contains("Debug", warning);
Assert.Contains("Warning", warning);
}
/// <summary>Verifies that setting only the ScadaBridge minimum level produces no override warning.</summary>
[Fact]
public void Build_OnlyScadaBridgeMinimumLevelSet_NoOverrideWarning()
{
var writer = new StringWriter();
var configuration = new ConfigurationBuilder()
.AddInMemoryCollection(new Dictionary<string, string?>
{
["ScadaBridge:Logging:MinimumLevel"] = "Warning",
})
.Build();
using var _ = ScadaBridgeLogging.CreateLogger(configuration, "Central", "central", "node1", writer, null);
// No Serilog override -> no override-warning. (The ScadaBridge value is
// a recognised level, so ParseLevel is silent too.)
Assert.Empty(writer.ToString());
}
private sealed class CollectingTarget : ZB.MOM.WW.ScadaBridge.Commons.Observability.IExecutionLogTarget
{
public List<ZB.MOM.WW.ScadaBridge.Commons.Observability.CapturedLogLine> Lines { get; } = new();
public void Capture(ZB.MOM.WW.ScadaBridge.Commons.Observability.CapturedLogLine line) => Lines.Add(line);
}
/// <summary>
/// ScadaBridge#56: the host pipeline carries the per-execution capture sink, so a line tagged with
/// a registered (traced) execution reaches that execution's step log.
/// </summary>
[Fact]
public void Build_IncludesTheExecutionCaptureSink()
{
var configuration = new ConfigurationBuilder().AddInMemoryCollection(new Dictionary<string, string?>()).Build();
using var logger = ScadaBridgeLogging.CreateLogger(configuration, "Site", "site-a", "node1", new StringWriter(), null);
var id = Guid.NewGuid();
var target = new CollectingTarget();
using (ZB.MOM.WW.ScadaBridge.Commons.Observability.ExecutionLogCapture.Register(id, target))
using (ZB.MOM.WW.ScadaBridge.Commons.Observability.ExecutionLogContext.Push(id))
{
logger.Warning("tagged line");
}
Assert.Equal("tagged line", Assert.Single(target.Lines).Message);
}
}