fix(review): calc ReadOne reports an inputs-Bad publish; VT inputs-bad counter ticks only on a real report

This commit is contained in:
Joseph Doherty
2026-08-20 11:48:41 -04:00
parent 74794f4365
commit 886082fec7
6 changed files with 152 additions and 6 deletions
@@ -877,3 +877,34 @@ this plan each appended last:
fixture, and it is the only evidence that the identical-value recovery works end to end on a real
device. Recipe unchanged in §Live gate; the constant HR[5] vs auto-incrementing HR[100] pairing is what
makes it non-vacuous.
---
## Review outcome (verdict MERGE, two Low items applied)
Both were **real** — each is a place where a polled/observed surface disagreed with what the contract
says, i.e. the same class of bug this plan exists to close, one hop further out. Applied TDD, one commit.
1. **`CalculationDriver.ReadOne` guarded on `!st.HasValue`** — so a tag whose only publish was an
inputs-Bad report (no value of its own) read back `BadWaitingForInitialData` while its subscriber had
been told `BadNoCommunication`. The guard is now `!st.HasPublished`, which is the state that actually
means "nothing has ever been said about this tag".
- RED: new `ReadAsync_after_an_inputs_Bad_with_no_prior_value_reports_the_bad_status` ⇒
`Shouldly.ShouldAssertException : read[0].StatusCode should be 2150694912u`.
- The pre-existing `An_unevaluated_tag_still_reads_BadWaitingForInitialData` is the control for the
other side of the same guard and stayed green.
2. **`VirtualTagActor.OnInputsBad` metered `VirtualTagEval{outcome=inputs-bad}` above the
`AllDependenciesArrived()` return** — so ordinary cold start produced an "inputs bad" measurement per
trigger. The `Add` moved below **both** guards (readiness and transition-once), so the counter now
measures tags that actually report.
- RED: new `The_inputs_bad_counter_does_not_tick_during_warm_up` ⇒
`Shouldly.ShouldAssertException : meter.Count("inputs-bad") should be 0`.
- The absence half carries a **positive control in the same test** (completing the dep set ⇒ exactly
one measurement), so it cannot pass for want of a working `MeterListener`.
**Suites after the fixes:** `Driver.Calculation.Tests` **65/65**; `Runtime.Tests` `~VirtualTag`
**59/59**; `Core.ScriptedAlarms.Tests` **94/94**.
**STATUS.md corrected:** the anonymous Runtime.Tests flake is
`DriverHostActorNativeAlarmAckRoutingTests.RouteNativeAlarmAck_routes_to_driver_AcknowledgeAsync_with_principal`
— untouched by this branch, known #500 profile, 3× green in isolation per the reviewer.
+5 -3
View File
@@ -527,9 +527,11 @@ watchdog; calc tags and virtual tags **hold** while an input is Bad and report t
a script that relied on receiving `null` for a dead input no longer runs while it is Bad.
**Test-suite state at `62c5bc3a`:** full-solution unit sweep green. `Runtime.Tests` 672 passed / 3
skipped on four separate runs; one further run showed a **single** failure whose name was lost to an
output filter — consistent with the known #500 flake profile (~13 %/run) and not reproduced in four
subsequent full runs. No pre-existing red on the base commit.
skipped on four separate runs; one further run showed a single failure —
`DriverHostActorNativeAlarmAckRoutingTests.RouteNativeAlarmAck_routes_to_driver_AcknowledgeAsync_with_principal`
(named by the reviewer, who saw it once and then 3× green in isolation). It is untouched by this branch
and matches the known #500 flake profile (~13 %/run); not reproduced in four subsequent full runs. No
pre-existing red on the base commit.
**NOT done here — T19, the live gate**, which is the merge-blocking rig session (docker-dev + the Modbus
`standard` fixture: constant HR[5] proves the force-republish, HR[100] is the positive control; plus the
@@ -394,7 +394,11 @@ public sealed class CalculationDriver : IDriver, IDependencyConsumer, ISubscriba
var now = DateTime.UtcNow;
lock (_lock)
{
if (!_stateByRawPath.TryGetValue(reference, out var st) || !st.HasValue)
// Gated on HAS PUBLISHED, not on "has a value": a tag whose only publish was an inputs-Bad
// report has no value of its own, and answering BadWaitingForInitialData for it would tell a
// polled reader "never observed" while the subscriber on the same node had been told
// BadNoCommunication. Something HAS been observed about such a tag — that its input is dead.
if (!_stateByRawPath.TryGetValue(reference, out var st) || !st.HasPublished)
return new DataValueSnapshot(null, StatusBadWaitingForInitialData, null, now);
// Exactly what the subscriber was last told — including a propagated input sub-code. Deriving
// it from a two-state flag here would make a read disagree with the subscription over the
@@ -328,11 +328,14 @@ public sealed class VirtualTagActor : ReceiveActor
/// <param name="timestampUtc">The triggering change's timestamp, stamped on the result.</param>
private void OnInputsBad(uint worstInputStatus, DateTime timestampUtc)
{
OtOpcUaTelemetry.VirtualTagEval.Add(1, new KeyValuePair<string, object?>("outcome", "inputs-bad"));
if (!AllDependenciesArrived()) return;
if (_hasPublished && _lastPublishedStatus == worstInputStatus) return;
// Metered BELOW both guards, so the counter measures tags that actually REPORT Bad inputs. Above
// them it also counted every warm-up trigger — a dependency that has simply not arrived yet — which
// is ordinary cold start, and burying the real signal in it is how a counter stops being trusted.
OtOpcUaTelemetry.VirtualTagEval.Add(1, new KeyValuePair<string, object?>("outcome", "inputs-bad"));
_hasPublished = true;
_lastPublishedStatus = worstInputStatus;
Context.Parent.Tell(new EvaluationResult(
@@ -270,6 +270,38 @@ public sealed class CalculationDriverInputQualityTests
read[0].Value.ShouldBe(bad.Snapshot.Value);
}
/// <summary>
/// A tag whose ONLY publish was inputs-Bad — it never produced a value — must read back that Bad
/// status, not <c>BadWaitingForInitialData</c>. Guarding the read on "has a value" rather than
/// "has published" made a polled read say "never polled" while the subscriber on the same node had
/// been told <c>BadNoCommunication</c>: the two clients disagree, and the read is the one that
/// lies (something HAS been observed about this tag — that its input is dead).
/// </summary>
[Fact]
public async Task ReadAsync_after_an_inputs_Bad_with_no_prior_value_reports_the_bad_status()
{
var (driver, published, _) = Build(CalcTag(SumTag, SumScript));
await driver.InitializeAsync("{}", TestContext.Current.CancellationToken);
// The first thing that ever happens to this tag is a dead input — no successful evaluation, so
// there is no last value to carry.
driver.OnDependencyValue("src/a", null, StatusBadNoCommunication, DateTime.UtcNow);
driver.OnDependencyValue("src/b", 20.0, StatusGood, DateTime.UtcNow);
await Settle(driver);
published.Count.ShouldBe(1);
published.TryDequeue(out var bad).ShouldBeTrue();
bad!.Snapshot.StatusCode.ShouldBe(StatusBadNoCommunication);
bad.Snapshot.Value.ShouldBeNull();
var read = await driver.ReadAsync([SumTag], TestContext.Current.CancellationToken);
read[0].StatusCode.ShouldBe(StatusBadNoCommunication);
read[0].StatusCode.ShouldNotBe(StatusBadWaitingForInitialData,
"something HAS been observed about this tag — that its input is dead");
read[0].Value.ShouldBeNull();
}
/// <summary>A never-evaluated tag still reads BadWaitingForInitialData (regression).</summary>
[Fact]
public async Task An_unevaluated_tag_still_reads_BadWaitingForInitialData()
@@ -1,8 +1,10 @@
using System.Diagnostics.Metrics;
using Akka.Actor;
using Shouldly;
using Xunit;
using ZB.MOM.WW.OtOpcUa.Commons.Engines;
using ZB.MOM.WW.OtOpcUa.Commons.Messages.Logging;
using ZB.MOM.WW.OtOpcUa.Commons.Observability;
using ZB.MOM.WW.OtOpcUa.Commons.OpcUa;
using ZB.MOM.WW.OtOpcUa.Core.Abstractions;
using ZB.MOM.WW.OtOpcUa.Runtime.Tests.Harness;
@@ -149,6 +151,35 @@ public sealed class VirtualTagActorInputQualityTests : RuntimeActorTestBase
parent.ExpectNoMsg(TimeSpan.FromMilliseconds(400));
}
/// <summary>
/// The <c>inputs-bad</c> outcome counter must tick only when a tag actually <b>reports</b> Bad
/// inputs — not on every warm-up trigger, where a declared dependency simply has not arrived yet.
/// Metering above the readiness gate turns ordinary cold start into a stream of "inputs bad"
/// measurements, which is exactly the noise that makes an operator stop trusting the counter.
/// <para>The absence half is paired with a positive control in the same test — the counter DOES
/// tick once the tag reports — so "no measurements" can never pass for want of a working listener.</para>
/// </summary>
[Fact]
public void The_inputs_bad_counter_does_not_tick_during_warm_up()
{
var parent = CreateTestProbe();
var actor = parent.ChildActorOf(VirtualTagActor.Props(
"vt-1", "a + b", evaluator: new CountingSumEvaluator(), dependencyRefs: ["a", "b"]));
using var meter = new OutcomeRecorder();
// Warm-up: "b" has never arrived, so this is cold start, not a fault.
actor.Tell(new VirtualTagActor.DependencyValueChanged("a", null, DateTime.UtcNow, OpcUaStatus.BadNoCommunication));
parent.ExpectNoMsg(TimeSpan.FromMilliseconds(400));
meter.Count("inputs-bad").ShouldBe(0, "warm-up is not an inputs-bad report");
// Positive control: once every dep has arrived, the tag reports — and the counter ticks.
actor.Tell(new VirtualTagActor.DependencyValueChanged("b", 32, DateTime.UtcNow));
parent.ExpectMsg<VirtualTagActor.EvaluationResult>(PresenceBudget)
.StatusCode.ShouldBe(OpcUaStatus.BadNoCommunication);
AwaitCondition(() => meter.Count("inputs-bad") == 1, TimeSpan.FromSeconds(3));
}
/// <summary>
/// A deploy's <c>ReassertValue</c> re-emits the LAST PUBLISHED status, so a VT whose input is
/// comms-lost re-asserts <c>BadNoCommunication</c> onto the freshly-materialised node rather than
@@ -207,6 +238,49 @@ public sealed class VirtualTagActorInputQualityTests : RuntimeActorTestBase
evaluator.Calls.ShouldBe(callsBefore);
}
/// <summary>
/// Counts <c>otopcua.virtualtag.eval</c> measurements by their <c>outcome</c> tag.
/// <para>A <see cref="MeterListener"/> sees every measurement in the process, and this counter is
/// hot across the assembly — so the assertions above are scoped to the <c>inputs-bad</c> outcome,
/// which only this suite produces (nothing else drives a Bad dependency), and the absence
/// assertion is paired with a positive control rather than standing alone.</para>
/// </summary>
private sealed class OutcomeRecorder : IDisposable
{
private readonly MeterListener _listener;
private readonly List<string> _outcomes = new();
private readonly object _gate = new();
public OutcomeRecorder()
{
_listener = new MeterListener
{
InstrumentPublished = (instrument, listener) =>
{
if (instrument.Meter.Name == OtOpcUaTelemetry.MeterName
&& instrument.Name == "otopcua.virtualtag.eval")
listener.EnableMeasurementEvents(instrument);
},
};
_listener.SetMeasurementEventCallback<long>((_, _, tags, _) =>
{
foreach (var tag in tags)
{
if (tag.Key != "outcome" || tag.Value is not string outcome) continue;
lock (_gate) _outcomes.Add(outcome);
}
});
_listener.Start();
}
public int Count(string outcome)
{
lock (_gate) return _outcomes.Count(o => o == outcome);
}
public void Dispose() => _listener.Dispose();
}
/// <summary>
/// Sums the dependency values, counts its invocations, and records the status code the actor
/// handed it for "a" — so a test can assert both that the script did NOT run and that, when it