diff --git a/src/ZB.MOM.WW.ScadaBridge.Commons/Observability/ScadaBridgeTelemetry.cs b/src/ZB.MOM.WW.ScadaBridge.Commons/Observability/ScadaBridgeTelemetry.cs index a28c16c8..d6b5bc54 100644 --- a/src/ZB.MOM.WW.ScadaBridge.Commons/Observability/ScadaBridgeTelemetry.cs +++ b/src/ZB.MOM.WW.ScadaBridge.Commons/Observability/ScadaBridgeTelemetry.cs @@ -37,6 +37,11 @@ public static class ScadaBridgeTelemetry Meter.CreateCounter("scadabridge.inbound_api.requests", unit: "1", description: "Inbound API requests, tagged by method."); + /// Incremented each time an inbound execution is abandoned (handler outlived its request), tagged with the API method. + private static readonly Counter _inboundAbandonedExecutions = + Meter.CreateCounter("scadabridge.inbound_api.abandoned_executions", unit: "1", + description: "Inbound API executions abandoned after timeout/abort (handler still running), tagged by method."); + /// Incremented each time an S&F buffer replication op fails to dispatch/deliver to the peer. private static readonly Counter _replicationFailures = Meter.CreateCounter("scadabridge.store_and_forward.replication.failures", unit: "1", @@ -75,6 +80,11 @@ public static class ScadaBridgeTelemetry public static void RecordInboundApiRequest(string method) => _inboundApiRequests.Add(1, new KeyValuePair("method", method)); + /// Records that an inbound execution was abandoned (handler outlived its request) for the given . + /// The API method whose execution was abandoned. + public static void RecordInboundAbandonedExecution(string method) => + _inboundAbandonedExecutions.Add(1, new KeyValuePair("method", method)); + /// Records one failed S&F replication dispatch. public static void RecordReplicationFailure() => _replicationFailures.Add(1); diff --git a/src/ZB.MOM.WW.ScadaBridge.InboundAPI/InboundScriptExecutor.cs b/src/ZB.MOM.WW.ScadaBridge.InboundAPI/InboundScriptExecutor.cs index 782db41a..86e9ab4b 100644 --- a/src/ZB.MOM.WW.ScadaBridge.InboundAPI/InboundScriptExecutor.cs +++ b/src/ZB.MOM.WW.ScadaBridge.InboundAPI/InboundScriptExecutor.cs @@ -8,6 +8,7 @@ using ZB.MOM.WW.ScadaBridge.Commons.Entities.InboundApi; using ZB.MOM.WW.ScadaBridge.Commons.Interfaces.Repositories; using ZB.MOM.WW.ScadaBridge.Commons.Interfaces.Services; using ZB.MOM.WW.ScadaBridge.Commons.Messages.InboundApi; +using ZB.MOM.WW.ScadaBridge.Commons.Observability; using ZB.MOM.WW.ScadaBridge.Commons.Types; namespace ZB.MOM.WW.ScadaBridge.InboundAPI; @@ -83,6 +84,21 @@ public class InboundScriptExecutor private readonly IServiceProvider _serviceProvider; + // Count of inbound executions whose handler outlived its request (timed out or + // client-aborted) and is still running with its DI scope disposal deferred. A + // non-cooperative script that ignores the cancellation token keeps running after + // WaitAsync returns; the scope is disposed by the handler's own completion + // continuation, not the request finally, and this gauge makes the pile-up visible. + private long _abandonedExecutions; + + /// + /// Diagnostic gauge — number of inbound executions currently orphaned (handler + /// still running after a timeout/abort, with DI-scope disposal deferred to the + /// handler's completion). Internal so the counter stays an implementation detail; + /// promote to public if a health surface needs it later. + /// + internal long AbandonedExecutionCount => Interlocked.Read(ref _abandonedExecutions); + /// /// Initializes a new instance of the InboundScriptExecutor. /// @@ -305,6 +321,11 @@ public class InboundScriptExecutor // no IServiceScopeFactory) is tolerated: the gateway is simply unavailable, so // a script not using Database still runs, while one that does fails on use. IServiceScope? scope = null; + // Hoisted out of the try so the finally can tell whether the handler task + // outlived the request. If it did (non-cooperative script after a timeout or + // client abort), disposing the scope underneath it would fault the still-running + // task with ObjectDisposedException — so the finally defers disposal instead. + Task? handlerTask = null; try { scope = _serviceProvider.CreateScope(); @@ -383,7 +404,8 @@ public class InboundScriptExecutor _scriptHandlers[method.Name] = cached; // last-write-wins; concurrent first-callers race benignly } - var result = await cached.Handler(context).WaitAsync(cts.Token); + handlerTask = cached.Handler(context); + var result = await handlerTask.WaitAsync(cts.Token); var resultJson = result != null ? JsonSerializer.Serialize(result) @@ -440,9 +462,28 @@ public class InboundScriptExecutor } finally { - // Dispose the per-execution DI scope (if one was created) only after the - // script handler has finished running and its result been serialized. - scope?.Dispose(); + if (handlerTask is null || handlerTask.IsCompleted) + { + scope?.Dispose(); + } + else + { + // The handler outlived the request (non-cooperative script after a + // timeout/client abort). Do NOT dispose the scope underneath it — + // defer cleanup to the task's own completion, and count the orphan + // so repeated timeouts of a slow method are visible. + Interlocked.Increment(ref _abandonedExecutions); + ScadaBridgeTelemetry.RecordInboundAbandonedExecution(method.Name); + _logger.LogWarning( + "Abandoned inbound execution for method {Method} is still running; DI scope disposal deferred", method.Name); + var abandonedScope = scope; + _ = handlerTask.ContinueWith(t => + { + _ = t.Exception; // observe the fault so it never surfaces as unobserved + abandonedScope?.Dispose(); + Interlocked.Decrement(ref _abandonedExecutions); + }, TaskScheduler.Default); + } } } } diff --git a/tests/ZB.MOM.WW.ScadaBridge.InboundAPI.Tests/InboundScriptExecutorTests.cs b/tests/ZB.MOM.WW.ScadaBridge.InboundAPI.Tests/InboundScriptExecutorTests.cs index 7e5d0c08..cb46895c 100644 --- a/tests/ZB.MOM.WW.ScadaBridge.InboundAPI.Tests/InboundScriptExecutorTests.cs +++ b/tests/ZB.MOM.WW.ScadaBridge.InboundAPI.Tests/InboundScriptExecutorTests.cs @@ -728,6 +728,26 @@ public class InboundScriptExecutorTests return new SqliteGateway("DataSource=file:movein-exec?mode=memory&cache=shared"); } + [Fact] + public async Task TimedOutScript_ScopeDisposalDeferred_NoOrphanLeak() + { + // Handler ignores the token and keeps running past the method timeout. + var release = new TaskCompletionSource(); + _executor.RegisterHandler("slow", async _ => { await release.Task; return 1; }); + var method = new ApiMethod("slow", "unused") { Id = 9, TimeoutSeconds = 1 }; + + var result = await _executor.ExecuteAsync( + method, new Dictionary(), _route, TimeSpan.FromMilliseconds(50)); + + Assert.False(result.Success); + Assert.Contains("timed out", result.ErrorMessage); + Assert.Equal(1, _executor.AbandonedExecutionCount); // orphan is COUNTED + + release.SetResult(); // orphan finishes; continuation cleans up + await Task.Delay(200); + Assert.Equal(0, _executor.AbandonedExecutionCount); // ...and DECREMENTED + } + private sealed class CompileLogCounter { public int CompilationFailures;