fix(host): log a routine service stop as Information, not [FTL] (ScadaBridge#76)
An OperationCanceledException escaping RunAsync after ApplicationStopping has fired (WindowsServiceLifetime.StopAsync gets a cancelled token after shutdown finished) is a normal stop. Program.IsGracefulShutdown now routes it to an Information line; any other exception, or a cancellation with no shutdown requested, still logs Fatal and rethrows.
This commit is contained in:
@@ -151,6 +151,12 @@ Log.Logger = ZB.MOM.WW.ScadaBridge.Host.LoggerConfigurationFactory
|
|||||||
.Build(configuration, nodeRole, siteId, nodeHostname)
|
.Build(configuration, nodeRole, siteId, nodeHostname)
|
||||||
.CreateLogger();
|
.CreateLogger();
|
||||||
|
|
||||||
|
// The host's ApplicationStopping token, captured once the host is built. A normal Windows service
|
||||||
|
// stop (or SIGTERM) cancels it BEFORE RunAsync unwinds, and WindowsServiceLifetime.StopAsync can
|
||||||
|
// then surface an OperationCanceledException out of RunAsync after shutdown has already finished.
|
||||||
|
// The catch below uses it to tell that routine stop from a genuine fatal exit (ScadaBridge#76).
|
||||||
|
var hostStopping = CancellationToken.None;
|
||||||
|
|
||||||
try
|
try
|
||||||
{
|
{
|
||||||
Log.Information("Starting ScadaBridge host as {Role} on {Hostname}", nodeRole, nodeHostname);
|
Log.Information("Starting ScadaBridge host as {Role} on {Hostname}", nodeRole, nodeHostname);
|
||||||
@@ -639,6 +645,7 @@ try
|
|||||||
builder.Configuration.GetSection(ZB.MOM.WW.ScadaBridge.DeploymentManager.ServiceCollectionExtensions.OptionsSection));
|
builder.Configuration.GetSection(ZB.MOM.WW.ScadaBridge.DeploymentManager.ServiceCollectionExtensions.OptionsSection));
|
||||||
|
|
||||||
var app = builder.Build();
|
var app = builder.Build();
|
||||||
|
hostStopping = app.Lifetime.ApplicationStopping;
|
||||||
|
|
||||||
// Apply or validate database migrations (skip when running in test harness)
|
// Apply or validate database migrations (skip when running in test harness)
|
||||||
if (!string.Equals(configuration["ScadaBridge:Database:SkipMigrations"], "true", StringComparison.OrdinalIgnoreCase))
|
if (!string.Equals(configuration["ScadaBridge:Database:SkipMigrations"], "true", StringComparison.OrdinalIgnoreCase))
|
||||||
@@ -832,6 +839,7 @@ try
|
|||||||
SiteServiceRegistration.Configure(builder.Services, builder.Configuration);
|
SiteServiceRegistration.Configure(builder.Services, builder.Configuration);
|
||||||
|
|
||||||
var app = builder.Build();
|
var app = builder.Build();
|
||||||
|
hostStopping = app.Lifetime.ApplicationStopping;
|
||||||
|
|
||||||
// Endpoint routing middleware. The gRPC service mapping below and the
|
// Endpoint routing middleware. The gRPC service mapping below and the
|
||||||
// /metrics scrape endpoint both run on endpoint routing, so UseRouting()
|
// /metrics scrape endpoint both run on endpoint routing, so UseRouting()
|
||||||
@@ -890,6 +898,11 @@ try
|
|||||||
throw new InvalidOperationException($"Unknown role: {nodeRole}. Must be 'Central' or 'Site'.");
|
throw new InvalidOperationException($"Unknown role: {nodeRole}. Must be 'Central' or 'Site'.");
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
catch (Exception ex) when (Program.IsGracefulShutdown(ex, hostStopping))
|
||||||
|
{
|
||||||
|
// Routine stop: shutdown was requested and the host unwound with a cancellation. Not a fatal exit.
|
||||||
|
Log.Information("ScadaBridge host stopped (shutdown requested)");
|
||||||
|
}
|
||||||
catch (Exception ex)
|
catch (Exception ex)
|
||||||
{
|
{
|
||||||
Log.Fatal(ex, "ScadaBridge host terminated unexpectedly");
|
Log.Fatal(ex, "ScadaBridge host terminated unexpectedly");
|
||||||
@@ -905,6 +918,19 @@ finally
|
|||||||
/// </summary>
|
/// </summary>
|
||||||
public partial class Program
|
public partial class Program
|
||||||
{
|
{
|
||||||
|
/// <summary>
|
||||||
|
/// True when <paramref name="ex"/> is the cancellation a routine host stop produces: an
|
||||||
|
/// <see cref="OperationCanceledException"/> (incl. <see cref="TaskCanceledException"/>) escaping
|
||||||
|
/// <c>RunAsync</c> while the host's <c>ApplicationStopping</c> token is already cancelled
|
||||||
|
/// (ScadaBridge#76). Anything else - a non-cancellation exception, or a cancellation with no
|
||||||
|
/// shutdown requested - is still a genuine fatal exit and must keep logging <c>[FTL]</c>.
|
||||||
|
/// </summary>
|
||||||
|
/// <param name="ex">The exception that escaped the host run.</param>
|
||||||
|
/// <param name="hostStopping">The host's <c>ApplicationStopping</c> token (default if the host never built).</param>
|
||||||
|
/// <returns>True when the exception is the expected cancellation of a requested shutdown.</returns>
|
||||||
|
internal static bool IsGracefulShutdown(Exception ex, CancellationToken hostStopping) =>
|
||||||
|
ex is OperationCanceledException && hostStopping.IsCancellationRequested;
|
||||||
|
|
||||||
/// <summary>
|
/// <summary>
|
||||||
/// Extracts the distinct TCP ports from an ASP.NET Core server-URLs string (the
|
/// Extracts the distinct TCP ports from an ASP.NET Core server-URLs string (the
|
||||||
/// <c>ASPNETCORE_URLS</c> / <c>--urls</c> value, e.g. <c>"http://+:5000"</c> or a
|
/// <c>ASPNETCORE_URLS</c> / <c>--urls</c> value, e.g. <c>"http://+:5000"</c> or a
|
||||||
|
|||||||
@@ -0,0 +1,39 @@
|
|||||||
|
namespace ZB.MOM.WW.ScadaBridge.Host.Tests;
|
||||||
|
|
||||||
|
/// <summary>
|
||||||
|
/// ScadaBridge#76: a routine Windows service stop must not be logged as
|
||||||
|
/// <c>[FTL] host terminated unexpectedly</c>.
|
||||||
|
/// </summary>
|
||||||
|
public class GracefulShutdownTests
|
||||||
|
{
|
||||||
|
/// <summary>A cancellation escaping RunAsync after ApplicationStopping fired is a routine stop.</summary>
|
||||||
|
[Fact]
|
||||||
|
public void Cancellation_AfterStopRequested_IsGraceful()
|
||||||
|
{
|
||||||
|
using var cts = new CancellationTokenSource();
|
||||||
|
cts.Cancel();
|
||||||
|
|
||||||
|
Assert.True(Program.IsGracefulShutdown(new OperationCanceledException(), cts.Token));
|
||||||
|
Assert.True(Program.IsGracefulShutdown(new TaskCanceledException(), cts.Token));
|
||||||
|
}
|
||||||
|
|
||||||
|
/// <summary>A cancellation with no shutdown requested is still a genuine failure.</summary>
|
||||||
|
[Fact]
|
||||||
|
public void Cancellation_WithoutStopRequested_IsNotGraceful()
|
||||||
|
{
|
||||||
|
using var cts = new CancellationTokenSource();
|
||||||
|
|
||||||
|
Assert.False(Program.IsGracefulShutdown(new OperationCanceledException(), cts.Token));
|
||||||
|
Assert.False(Program.IsGracefulShutdown(new OperationCanceledException(), CancellationToken.None));
|
||||||
|
}
|
||||||
|
|
||||||
|
/// <summary>A real fault during shutdown must still be reported as fatal.</summary>
|
||||||
|
[Fact]
|
||||||
|
public void NonCancellationException_IsNeverGraceful()
|
||||||
|
{
|
||||||
|
using var cts = new CancellationTokenSource();
|
||||||
|
cts.Cancel();
|
||||||
|
|
||||||
|
Assert.False(Program.IsGracefulShutdown(new InvalidOperationException("boom"), cts.Token));
|
||||||
|
}
|
||||||
|
}
|
||||||
Reference in New Issue
Block a user