From 96ec751a0bf0a96612432855c2105906a3ae2d79 Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Fri, 9 Oct 2026 14:23:42 -0400 Subject: [PATCH] fix(historian): latch the recorder's dropped-kind Debug log per run; pin the outbox.unreadable gauge The DroppedUnsupportedKind counter still counts every value; only the Debug line is latched (cleared by the next captured value), so a Gateway-backend comms loss no longer logs one line per tag. Claude-Session: https://claude.ai/code/session_01Ef2ozxS7QPanGT8uoATbTe --- .../ContinuousHistorizationRecorder.cs | 16 ++++- .../ContinuousHistorizationMetricsTests.cs | 58 +++++++++++++++++++ 2 files changed, 73 insertions(+), 1 deletion(-) create mode 100644 tests/Server/ZB.MOM.WW.OtOpcUa.Runtime.Tests/Historian/ContinuousHistorizationMetricsTests.cs diff --git a/src/Server/ZB.MOM.WW.OtOpcUa.Runtime/Historian/ContinuousHistorizationRecorder.cs b/src/Server/ZB.MOM.WW.OtOpcUa.Runtime/Historian/ContinuousHistorizationRecorder.cs index 3eb35004..cd97e90a 100644 --- a/src/Server/ZB.MOM.WW.OtOpcUa.Runtime/Historian/ContinuousHistorizationRecorder.cs +++ b/src/Server/ZB.MOM.WW.OtOpcUa.Runtime/Historian/ContinuousHistorizationRecorder.cs @@ -196,6 +196,12 @@ public sealed class ContinuousHistorizationRecorder : ReceiveActor, IWithTimers /// the first item that ingests cleanly — see . private bool _ingestFaultLogged; + /// Whether the current run of unsupported-kind drops has already been logged, so a backend that + /// drops a whole class of value (every comms-loss marker on the Gateway backend, say) logs once per run rather + /// than once per value. The counter still counts every value. Cleared by + /// the next value that is captured. + private bool _droppedKindLogged; + /// Last observed state of , so a change is logged once rather /// than on every value. Seeded open: a gate that starts closed logs its first suppression. private bool _captureGateOpen = true; @@ -553,10 +559,18 @@ public sealed class ContinuousHistorizationRecorder : ReceiveActor, IWithTimers // (e.g. String/Empty on the gateway's numeric-only SQL analog path) — drop and meter. No value // content is logged. _droppedUnsupportedKind++; - _log.Debug("ContinuousHistorization: dropped a value of a kind the historian backend does not support."); + if (!_droppedKindLogged) + { + _droppedKindLogged = true; + _log.Debug("ContinuousHistorization: dropped a value of a kind the historian backend does not support. " + + "Further drops are only counted (DroppedUnsupportedKind) until a value is captured."); + } + return; } + _droppedKindLogged = false; + var timestampUtc = DateTime.SpecifyKind(msg.TimestampUtc, DateTimeKind.Utc); entries ??= new List(); diff --git a/tests/Server/ZB.MOM.WW.OtOpcUa.Runtime.Tests/Historian/ContinuousHistorizationMetricsTests.cs b/tests/Server/ZB.MOM.WW.OtOpcUa.Runtime.Tests/Historian/ContinuousHistorizationMetricsTests.cs new file mode 100644 index 00000000..044d82c1 --- /dev/null +++ b/tests/Server/ZB.MOM.WW.OtOpcUa.Runtime.Tests/Historian/ContinuousHistorizationMetricsTests.cs @@ -0,0 +1,58 @@ +using System.Diagnostics.Metrics; +using Shouldly; +using Xunit; +using ZB.MOM.WW.OtOpcUa.Commons.Observability; +using ZB.MOM.WW.OtOpcUa.Core.Abstractions; +using ZB.MOM.WW.OtOpcUa.Runtime.Historian; + +namespace ZB.MOM.WW.OtOpcUa.Runtime.Tests.Historian; + +/// +/// The otopcua.historian.outbox.unreadable gauge reports the bound outbox's +/// . The listener is filtered by the instrument INSTANCE (the +/// shared object plus the instrument name), never by meter name alone, so a +/// parallel test's measurements on another meter of the same name cannot reach it; and the bound outbox reports a +/// distinctive count, so the asserted value can only have come from this test's outbox. +/// +public sealed class ContinuousHistorizationMetricsTests +{ + private const string GaugeName = "otopcua.historian.outbox.unreadable"; + + [Fact] + public void The_unreadable_gauge_reports_the_bound_outboxs_unreadable_count() + { + const long distinctive = 7_331_919L; + ContinuousHistorizationMetrics.BindOutbox(new UnreadableOutbox(distinctive)); + + var observed = new List(); + using var listener = new MeterListener + { + InstrumentPublished = (instrument, l) => + { + if (ReferenceEquals(instrument.Meter, OtOpcUaTelemetry.Meter) && instrument.Name == GaugeName) + l.EnableMeasurementEvents(instrument); + }, + }; + listener.SetMeasurementEventCallback((instrument, value, _, _) => + { + if (instrument.Name == GaugeName) observed.Add(value); + }); + listener.Start(); + listener.RecordObservableInstruments(); + + observed.ShouldBe([distinctive]); + } + + private sealed class UnreadableOutbox(long unreadable) : IHistorizationOutbox + { + public long DroppedCount => 0; + public long UnreadableCount => unreadable; + public ValueTask AppendAsync(HistorizationOutboxEntry entry, CancellationToken ct) => ValueTask.CompletedTask; + public ValueTask AppendBatchAsync(IReadOnlyList entries, CancellationToken ct) => ValueTask.CompletedTask; + public ValueTask> PeekBatchAsync(int max, CancellationToken ct) => + ValueTask.FromResult>([]); + public ValueTask RemoveAsync(Guid id, CancellationToken ct) => ValueTask.CompletedTask; + public ValueTask CountAsync(CancellationToken ct) => ValueTask.FromResult(0); + public void Dispose() { } + } +}