From e22ecea008c9b121e286d59a25146008f10c175c Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Mon, 17 Aug 2026 03:46:27 -0400 Subject: [PATCH] feat(drivers): per-driver poll-overrun meter on the shared OtOpcUa Meter; NoteOverrun + backoffCap doc notes --- .../Observability/OtOpcUaTelemetry.cs | 13 ++++++ .../PollGroupEngine.cs | 46 +++++++++++++++++-- .../AbCipDriver.cs | 8 +++- .../AbLegacyDriver.cs | 8 +++- .../FocasDriver.cs | 8 +++- .../ModbusDriver.cs | 8 +++- .../ZB.MOM.WW.OtOpcUa.Driver.S7/S7Driver.cs | 8 +++- .../ZB.MOM.WW.OtOpcUa.Driver.Sql/SqlDriver.cs | 8 +++- .../TwinCATDriver.cs | 8 +++- .../PollGroupEngineTests.cs | 44 ++++++++++++++++++ 10 files changed, 147 insertions(+), 12 deletions(-) diff --git a/src/Core/ZB.MOM.WW.OtOpcUa.Commons/Observability/OtOpcUaTelemetry.cs b/src/Core/ZB.MOM.WW.OtOpcUa.Commons/Observability/OtOpcUaTelemetry.cs index 7b9d7933..32043b0e 100644 --- a/src/Core/ZB.MOM.WW.OtOpcUa.Commons/Observability/OtOpcUaTelemetry.cs +++ b/src/Core/ZB.MOM.WW.OtOpcUa.Commons/Observability/OtOpcUaTelemetry.cs @@ -42,6 +42,19 @@ public static class OtOpcUaTelemetry Meter.CreateCounter("otopcua.driver.lifecycle", unit: "{event}", description: "DriverInstanceActor lifecycle transitions (event=spawn|stop|fault)."); + /// + /// Poll cycles that ran longer than their subscription's publishing interval, as counted by + /// PollGroupEngine.OverrunCount. Core.Abstractions deliberately carries no metrics + /// dependency, so each poll driver wires this counter to the engine's onOverrun callback; + /// this is the production consumer that surface was always missing. Tagged + /// driver.type (a DriverTypeNames constant) + driver.instance. + /// A non-zero and climbing rate means the device cannot sustain its configured poll rate — the + /// loop is already running flat out. + /// + public static readonly Counter PollOverruns = + Meter.CreateCounter("otopcua.driver.poll.overrun", unit: "{overrun}", + description: "Poll cycles that ran longer than the poll interval (slow success and slow failure both count — see PollGroupEngine.NoteOverrun)."); + // ---------------- VirtualTag / ScriptedAlarm engines ---------------- public static readonly Counter VirtualTagEval = diff --git a/src/Core/ZB.MOM.WW.OtOpcUa.Core.Abstractions/PollGroupEngine.cs b/src/Core/ZB.MOM.WW.OtOpcUa.Core.Abstractions/PollGroupEngine.cs index fd0e17bc..cdb64c92 100644 --- a/src/Core/ZB.MOM.WW.OtOpcUa.Core.Abstractions/PollGroupEngine.cs +++ b/src/Core/ZB.MOM.WW.OtOpcUa.Core.Abstractions/PollGroupEngine.cs @@ -44,10 +44,16 @@ namespace ZB.MOM.WW.OtOpcUa.Core.Abstractions; /// consecutiveFailures > 0 with a backoffCap configured, the capped-exponential /// schedule wins, because a failing device must not be hammered at fixed rate. /// -/// No Meter lives here. Core.Abstractions deliberately references -/// nothing, so plus the onOverrun callback ARE the -/// instrumentation surface — a driver that wants a metric wires its own meter to the callback. -/// (Driver-level meters are a recorded follow-up, not part of this type.) +/// No Meter lives here, and that is still deliberate. +/// Core.Abstractions references nothing, so plus the +/// onOverrun callback ARE the instrumentation surface — a driver that wants a metric +/// wires its own meter to the callback. The driver-level meter this note used to record as a +/// follow-up is delivered: every one of the seven poll drivers now passes an +/// onOverrun closure that bumps OtOpcUaTelemetry.PollOverruns +/// (otopcua.driver.poll.overrun) on the shared OtOpcUa Meter, tagged with the +/// driver's DriverTypeNames constant and its driver-instance id. The counter lives in +/// Commons.Observability, on the consumer side of the reference graph — this type still +/// owns no Meter and takes no metrics dependency. /// /// Programmer errors and obviously-fatal exceptions (, /// , , @@ -85,7 +91,27 @@ public sealed class PollGroupEngine : IAsyncDisposable /// (05/STAB-8). When supplied, sustained reader failures stretch the retry cadence /// (interval, 2×, 4×, … saturating at this cap) instead of hammering a dead device every /// tick; a successful poll resets to the base interval. null (default) keeps the - /// byte-identical fixed-interval cadence for consumers that have not opted in. + /// byte-identical fixed-interval cadence for consumers that have not opted in. + /// Units: a ceiling on the post-poll wait — the + /// longest gap the loop will ever leave between a failed poll and the next attempt. It is + /// not a count, a multiplier, or a total-outage budget: a device that stays down waits + /// backoffCap between every retry, forever. + /// Interaction with — it REPLACES the paced delay, + /// it does not add to it. The loop picks exactly one of two branches per cycle. With no + /// failures outstanding (or no cap configured) the wait is the fixed-RATE remainder + /// max(interval − pollDuration, 0). With a cap configured AND + /// consecutiveFailures > 0, the whole remainder computation is bypassed and the + /// wait becomes ConnectionBackoff.ComputeDelay(interval, failures, cap) — the poll's + /// own elapsed time is NOT subtracted, so the failure branch is a fixed DELAY (cycle = + /// poll + backoff), deliberately unlike the fixed-rate success branch. + /// The interval feeding that schedule is the per-subscription interval + /// already clamped to in , so + /// the first failure's wait equals the clamped interval (shift 0 → 1×) and the floor is + /// honoured for free. One asymmetry worth knowing: ComputeDelay saturates at the cap + /// unconditionally, so a set SMALLER than the clamped + /// interval makes failures retry FASTER than the interval floor — the cap outranks + /// on the failure branch. Configure it above the floor + /// (every driver here uses 30 s against a 100 ms floor). /// Optional per-cycle batch callback — invoked once per poll cycle that /// produced at least one change, carrying exactly that cycle's changed items in reader /// order, after all of the cycle's per-tag callbacks. The @@ -311,6 +337,16 @@ public sealed class PollGroupEngine : IAsyncDisposable /// Record a poll that took longer than its interval: bump and /// hand the measured duration to the optional onOverrun sink. Defensive against a /// sink that throws, for the same reason is. + /// Caveat — this CONFLATES a slow success with a slow failure. It is called + /// from the finally of both poll sites, so the only input is the measured elapsed + /// time; a device that answers in 300 ms on a 200 ms interval and one that throws (or times + /// out) after 300 ms both increment the counter and both raise onOverrun with the + /// same duration. A consumer reading otopcua.driver.poll.overrun therefore learns + /// "the loop cannot keep its cadence", NOT "the device is healthy but slow" — pair it with + /// the driver's health surface (which onError already feeds) to tell the two apart. + /// Disambiguating here would mean threading the cycle's outcome into this method and + /// splitting the counter/callback by it; no consumer needs that yet, so it is deliberately + /// not done. /// private void NoteOverrun(TimeSpan interval, TimeSpan elapsed) { diff --git a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbCip/AbCipDriver.cs b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbCip/AbCipDriver.cs index 510c245e..958f9c63 100644 --- a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbCip/AbCipDriver.cs +++ b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbCip/AbCipDriver.cs @@ -1,5 +1,6 @@ using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging.Abstractions; +using ZB.MOM.WW.OtOpcUa.Commons.Observability; using ZB.MOM.WW.OtOpcUa.Core.Abstractions; using ZB.MOM.WW.OtOpcUa.Driver.AbCip.PlcFamilies; @@ -161,7 +162,12 @@ public sealed class AbCipDriver : IDriver, IReadable, IWritable, ITagDiscovery, onError: HandlePollError, backoffCap: PollBackoffCap, onBatch: (handle, items) => - OnDataChangeBatch?.Invoke(this, new DataChangeBatchEventArgs(handle, items))); + OnDataChangeBatch?.Invoke(this, new DataChangeBatchEventArgs(handle, items)), + // The engine owns no Meter (Core.Abstractions takes no metrics dependency), so this + // closure IS the production consumer of its overrun signal. + onOverrun: _ => OtOpcUaTelemetry.PollOverruns.Add(1, + new KeyValuePair("driver.type", DriverTypeNames.AbCip), + new KeyValuePair("driver.instance", driverInstanceId))); _alarmProjection = new AbCipAlarmProjection(this, _options.AlarmPollInterval, _logger); } diff --git a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbLegacy/AbLegacyDriver.cs b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbLegacy/AbLegacyDriver.cs index 5767d489..9c3fa501 100644 --- a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbLegacy/AbLegacyDriver.cs +++ b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbLegacy/AbLegacyDriver.cs @@ -1,5 +1,6 @@ using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging.Abstractions; +using ZB.MOM.WW.OtOpcUa.Commons.Observability; using ZB.MOM.WW.OtOpcUa.Core.Abstractions; using ZB.MOM.WW.OtOpcUa.Driver.AbLegacy.PlcFamilies; @@ -76,7 +77,12 @@ public sealed class AbLegacyDriver : IDriver, IReadable, IWritable, ITagDiscover onChange: (handle, tagRef, snapshot) => OnDataChange?.Invoke(this, new DataChangeEventArgs(handle, tagRef, snapshot)), onError: HandlePollError, - backoffCap: PollBackoffCap); + backoffCap: PollBackoffCap, + // The engine owns no Meter (Core.Abstractions takes no metrics dependency), so this + // closure IS the production consumer of its overrun signal. + onOverrun: _ => OtOpcUaTelemetry.PollOverruns.Add(1, + new KeyValuePair("driver.type", DriverTypeNames.AbLegacy), + new KeyValuePair("driver.instance", driverInstanceId))); } /// Upper bound on the poll-loop failure backoff — adopts the S7-proven 30 s cap fleet-wide (05/STAB-8). diff --git a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.FOCAS/FocasDriver.cs b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.FOCAS/FocasDriver.cs index 8dc5b847..1db8be35 100644 --- a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.FOCAS/FocasDriver.cs +++ b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.FOCAS/FocasDriver.cs @@ -1,6 +1,7 @@ using System.Collections.Concurrent; using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging.Abstractions; +using ZB.MOM.WW.OtOpcUa.Commons.Observability; using ZB.MOM.WW.OtOpcUa.Core.Abstractions; namespace ZB.MOM.WW.OtOpcUa.Driver.FOCAS; @@ -121,7 +122,12 @@ public sealed class FocasDriver : IDriver, IReadable, IWritable, ITagDiscovery, onError: HandlePollError, backoffCap: PollBackoffCap, onBatch: (handle, items) => - OnDataChangeBatch?.Invoke(this, new DataChangeBatchEventArgs(handle, items))); + OnDataChangeBatch?.Invoke(this, new DataChangeBatchEventArgs(handle, items)), + // The engine owns no Meter (Core.Abstractions takes no metrics dependency), so this + // closure IS the production consumer of its overrun signal. + onOverrun: _ => OtOpcUaTelemetry.PollOverruns.Add(1, + new KeyValuePair("driver.type", DriverTypeNames.FOCAS), + new KeyValuePair("driver.instance", driverInstanceId))); } /// True when the supplied DriverConfig JSON carries a real body. The bootstrapper always passes diff --git a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.Modbus/ModbusDriver.cs b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.Modbus/ModbusDriver.cs index 0d34449c..b598f209 100644 --- a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.Modbus/ModbusDriver.cs +++ b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.Modbus/ModbusDriver.cs @@ -3,6 +3,7 @@ using System.Collections.Concurrent; using System.Text.Json; using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging.Abstractions; +using ZB.MOM.WW.OtOpcUa.Commons.Observability; using ZB.MOM.WW.OtOpcUa.Core.Abstractions; namespace ZB.MOM.WW.OtOpcUa.Driver.Modbus; @@ -187,7 +188,12 @@ public sealed class ModbusDriver { if (_cycleBatchItems.TryRemove(handle, out var published) && published.Count > 0) OnDataChangeBatch?.Invoke(this, new DataChangeBatchEventArgs(handle, published)); - }); + }, + // The engine owns no Meter (Core.Abstractions takes no metrics dependency), so this + // closure IS the production consumer of its overrun signal. + onOverrun: _ => OtOpcUaTelemetry.PollOverruns.Add(1, + new KeyValuePair("driver.type", DriverTypeNames.Modbus), + new KeyValuePair("driver.instance", driverInstanceId))); } /// Upper bound on the poll-loop failure backoff — adopts the S7-proven 30 s cap fleet-wide (05/STAB-8). diff --git a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7/S7Driver.cs b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7/S7Driver.cs index c93606ed..6fa90de0 100644 --- a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7/S7Driver.cs +++ b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7/S7Driver.cs @@ -3,6 +3,7 @@ using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging.Abstractions; using S7.Net; using S7NetDataType = global::S7.Net.DataType; +using ZB.MOM.WW.OtOpcUa.Commons.Observability; using ZB.MOM.WW.OtOpcUa.Core.Abstractions; namespace ZB.MOM.WW.OtOpcUa.Driver.S7; @@ -69,7 +70,12 @@ public sealed class S7Driver minInterval: TimeSpan.FromMilliseconds(100), onError: HandlePollError, backoffCap: TimeSpan.FromSeconds(30), - onBatch: (handle, items) => OnDataChangeBatch?.Invoke(this, new DataChangeBatchEventArgs(handle, items))); + onBatch: (handle, items) => OnDataChangeBatch?.Invoke(this, new DataChangeBatchEventArgs(handle, items)), + // The engine owns no Meter (Core.Abstractions takes no metrics dependency), so this + // closure IS the production consumer of its overrun signal. + onOverrun: _ => OtOpcUaTelemetry.PollOverruns.Add(1, + new KeyValuePair("driver.type", DriverTypeNames.S7), + new KeyValuePair("driver.instance", driverInstanceId))); } // ---- ISubscribable + IHostConnectivityProbe state ---- diff --git a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.Sql/SqlDriver.cs b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.Sql/SqlDriver.cs index 0c7b7631..89f39840 100644 --- a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.Sql/SqlDriver.cs +++ b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.Sql/SqlDriver.cs @@ -2,6 +2,7 @@ using System.Data.Common; using System.Diagnostics.CodeAnalysis; using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging.Abstractions; +using ZB.MOM.WW.OtOpcUa.Commons.Observability; using ZB.MOM.WW.OtOpcUa.Core.Abstractions; using ZB.MOM.WW.OtOpcUa.Driver.Sql.Contracts; @@ -228,7 +229,12 @@ public sealed class SqlDriver onChange: (handle, tagRef, snapshot) => OnDataChange?.Invoke(this, new DataChangeEventArgs(handle, tagRef, snapshot)), onError: HandlePollError, - backoffCap: PollBackoffCap); + backoffCap: PollBackoffCap, + // The engine owns no Meter (Core.Abstractions takes no metrics dependency), so this + // closure IS the production consumer of its overrun signal. + onOverrun: _ => OtOpcUaTelemetry.PollOverruns.Add(1, + new KeyValuePair("driver.type", DriverTypeNames.Sql), + new KeyValuePair("driver.instance", driverInstanceId))); } /// diff --git a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.TwinCAT/TwinCATDriver.cs b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.TwinCAT/TwinCATDriver.cs index 5e1d75c7..6e13e39c 100644 --- a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.TwinCAT/TwinCATDriver.cs +++ b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.TwinCAT/TwinCATDriver.cs @@ -1,6 +1,7 @@ using System.Collections.Concurrent; using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging.Abstractions; +using ZB.MOM.WW.OtOpcUa.Commons.Observability; using ZB.MOM.WW.OtOpcUa.Core.Abstractions; namespace ZB.MOM.WW.OtOpcUa.Driver.TwinCAT; @@ -78,7 +79,12 @@ public sealed class TwinCATDriver : IDriver, IReadable, IWritable, ITagDiscovery onChange: (handle, tagRef, snapshot) => OnDataChange?.Invoke(this, new DataChangeEventArgs(handle, tagRef, snapshot)), onError: HandlePollError, - backoffCap: PollBackoffCap); + backoffCap: PollBackoffCap, + // The engine owns no Meter (Core.Abstractions takes no metrics dependency), so this + // closure IS the production consumer of its overrun signal. + onOverrun: _ => OtOpcUaTelemetry.PollOverruns.Add(1, + new KeyValuePair("driver.type", DriverTypeNames.TwinCAT), + new KeyValuePair("driver.instance", driverInstanceId))); } /// Upper bound on the poll-loop failure backoff — adopts the S7-proven 30 s cap fleet-wide (05/STAB-8). diff --git a/tests/Core/ZB.MOM.WW.OtOpcUa.Core.Abstractions.Tests/PollGroupEngineTests.cs b/tests/Core/ZB.MOM.WW.OtOpcUa.Core.Abstractions.Tests/PollGroupEngineTests.cs index 547d1b29..fdd7ed59 100644 --- a/tests/Core/ZB.MOM.WW.OtOpcUa.Core.Abstractions.Tests/PollGroupEngineTests.cs +++ b/tests/Core/ZB.MOM.WW.OtOpcUa.Core.Abstractions.Tests/PollGroupEngineTests.cs @@ -670,6 +670,50 @@ public sealed class PollGroupEngineTests overruns.Count.ShouldBeLessThanOrEqualTo(1); } + /// + /// The counter and the callback must be the SAME signal, not two approximations of it: every + /// increment of is matched by exactly one + /// onOverrun invocation. This is what lets a driver's meter (the production consumer, + /// OtOpcUaTelemetry.PollOverruns) be read as the counter itself — a callback that + /// fired on only some increments, or twice on one, would silently mis-scale the metric. + /// + /// + /// The two existing pacing tests + /// ( / + /// ) assert each side against its own loose + /// threshold, so they would both still pass if the callback fired on, say, every other + /// increment. This one compares the two directly, and does so only AFTER + /// UnsubscribeAsync has drained the loop — while a poll is in flight the increment + /// and the callback are two separate statements, so a live read could legitimately catch + /// them one apart and the equality would be flaky rather than falsifiable. + /// + [Fact] + public async Task Every_overrun_increment_is_matched_by_exactly_one_onOverrun_callback() + { + async Task> Reader(IReadOnlyList refs, CancellationToken ct) + { + await Task.Delay(120, ct); + var now = DateTime.UtcNow; + // A fresh value every poll, so the change path runs on every cycle too. + return refs.Select(_ => new DataValueSnapshot(now.Ticks, 0u, now, now)).ToList(); + } + + var overruns = new ConcurrentQueue(); + await using var engine = new PollGroupEngine( + Reader, + (_, _, _) => { }, + minInterval: TimeSpan.FromMilliseconds(20), + onOverrun: e => overruns.Enqueue(e)); + + var handle = engine.Subscribe(["X"], TimeSpan.FromMilliseconds(40)); + await Task.Delay(1000, TestContext.Current.CancellationToken); + await engine.UnsubscribeAsync(handle); + + // Sanity: the scenario actually produced overruns, so the equality below is not vacuous. + engine.OverrunCount.ShouldBeGreaterThanOrEqualTo(3); + overruns.Count.ShouldBe((int)engine.OverrunCount); + } + /// /// The async teardown must be behaviourally identical to the sync one: the handle is known, /// the loop stops, and no further callback fires. Mirrors