Joseph Doherty
5c8d6f6f98
The first form compared the publish's managed thread id with the caller's, which flaked (1 in 6): the evaluation pump may reuse the pooled thread the test released while awaiting the drain, so an id match proves nothing. It now sets a ThreadLocal flag for exactly the OnDependencyValue window, so 'published inline' is answered on the stack rather than by thread identity. Re-falsified by making SchedulePump run the pump synchronously (red immediately, reverted); 5 consecutive clean suite runs after.
286 lines
21 KiB
Markdown
286 lines
21 KiB
Markdown
# Code Review — Driver.Calculation
|
|
|
|
| Field | Value |
|
|
|---|---|
|
|
| Module | `src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.Calculation` |
|
|
| Reviewer | Claude (automated review agent) |
|
|
| Review date | 2026-08-10 |
|
|
| Commit reviewed | `b990adae` |
|
|
| Status | Reviewed |
|
|
| Open findings | 0 |
|
|
|
|
## Checklist coverage
|
|
|
|
| # | Category | Result |
|
|
|---|---|---|
|
|
| 1 | Correctness & logic bugs | 3 findings (Driver.Calculation-001, -002, -003), all Resolved |
|
|
| 2 | OtOpcUa conventions | No issues found. Galaxy/MXAccess-specific conventions do not apply to this pseudo-driver (no transport, no gateway). It correctly implements the capability-interface seams (IDriver, IDependencyConsumer, ISubscribable, IReadable, ISkippedTagReporter), .NET 10/AnyCPU, and authorization stays out of driver-level code. |
|
|
| 3 | Concurrency & thread safety | 1 finding (Driver.Calculation-005), Resolved |
|
|
| 4 | Error handling & resilience | Covered by Driver.Calculation-002 (script-evaluation faults never throw out of the driver; SkippedTagLedger tolerates a single bad tag without failing the whole rebuild). No further issues found. |
|
|
| 5 | Security | No issues found. No secrets, no I/O, no SQL; the sandboxed Roslyn evaluator (shared Core.Scripting sandbox) is the security boundary and lives outside this module. |
|
|
| 6 | Performance & resource management | Covered by Driver.Calculation-005 (blocking evaluation under a shared lock). CalculationTimerScheduler correctly bounds outstanding work to one tick per interval group (skip-if-in-flight) and CalculationEvaluator.ClearCompiledScripts() is invoked on every ReinitializeAsync, so compiled-script AssemblyLoadContexts do not accrete across script edits. No further issues found. |
|
|
| 7 | Design-document adherence | No issues found. The class-level XML docs cite the "mini-design" sections directly and the implementation matches them (change-gate, once-per-transition Bad, force-published recovery, GetHealth() per Gitea #517, ISkippedTagReporter per Gitea #541). |
|
|
| 8 | Code organization & conventions | 1 finding (Driver.Calculation-003, also an organization smell: three near-duplicate JsonSerializerOptions definitions across the module). Otherwise clean: one construction routine (RebuildTagTable) shared by the ctor and ReinitializeAsync so the two paths cannot drift. |
|
|
| 9 | Testing coverage | 1 finding (Driver.Calculation-004), Resolved (tests added). CalculationTimerScheduler.SkippedTickCount remains untested — see note under -004. |
|
|
| 10 | Documentation & comments | No issues found. XML docs are extensive, accurate, and were kept in sync with the fixes below. |
|
|
|
|
## Findings
|
|
|
|
### Driver.Calculation-001
|
|
|
|
| Field | Value |
|
|
|---|---|
|
|
| Severity | Medium |
|
|
| Category | Correctness & logic bugs |
|
|
| Location | `src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.Calculation/CalculationDriver.cs:103-106` (pre-fix), `CalculationEvaluator.cs:47,56-59` (pre-fix) |
|
|
| Status | Resolved |
|
|
|
|
**Description:** `CalculationDriver`'s constructor built the evaluator's logger as
|
|
`_logger is ILogger<CalculationEvaluator> el ? el : NullLogger<CalculationEvaluator>.Instance`, where
|
|
`_logger` is typed `ILogger<CalculationDriver>`. `ILogger<CalculationDriver>` and
|
|
`ILogger<CalculationEvaluator>` are unrelated closed generic interfaces (no inheritance relationship
|
|
between `CalculationDriver` and `CalculationEvaluator`), so the concrete logger instance the host injects
|
|
(a `Logger<CalculationDriver>` from `ILoggerFactory.CreateLogger<CalculationDriver>()`, or
|
|
`NullLogger<CalculationDriver>.Instance`) never actually implements `ILogger<CalculationEvaluator>`. The
|
|
`is` check was therefore **always false**, and every `CalculationEvaluator` silently ran with
|
|
`NullLogger<CalculationEvaluator>.Instance` regardless of what logger the driver itself was constructed
|
|
with — swallowing the evaluator's host-side diagnostics (Roslyn compile failures, sandbox violations,
|
|
unexpected execution throws, the single-tag `SetVirtualTag`-drop Debug line) with no way to route them to
|
|
the real host log sink. (The actual script-failure *reason* still reached the operator via the
|
|
`script-logs` DPS topic through `CalculationDriver.PublishScriptLog`, so this was a silent loss of
|
|
redundant host-side diagnostics rather than a loss of the primary operator signal — hence Medium, not
|
|
High.)
|
|
|
|
**Recommendation:** Have `CalculationEvaluator` accept the non-generic `ILogger` (every `ILogger<T>`
|
|
already implements it) instead of the closed generic `ILogger<CalculationEvaluator>`, and pass the
|
|
driver's own `_logger` straight through.
|
|
|
|
**Resolution:** Fixed 2026-08-10 (branch `review/calculation-session`). Changed
|
|
`CalculationEvaluator`'s constructor parameter/field from `ILogger<CalculationEvaluator>` to `ILogger`,
|
|
and `CalculationDriver`'s constructor now does `_evaluator = new CalculationEvaluator(_logger, _scriptRoot,
|
|
_options.RunTimeout);` with no type gymnastics. Regression test
|
|
`CalculationDriverTests.Evaluator_compile_diagnostics_flow_through_to_the_drivers_own_logger` (a
|
|
capturing `ILogger<CalculationDriver>` passed into the driver, a deliberately broken timer-triggered
|
|
script, asserting the capturing logger receives the "Roslyn compile failed" Warning) fails against the
|
|
pre-fix code and passes after.
|
|
|
|
---
|
|
|
|
### Driver.Calculation-002
|
|
|
|
| Field | Value |
|
|
|---|---|
|
|
| Severity | High |
|
|
| Category | Correctness & logic bugs |
|
|
| Location | `src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.Calculation/CalculationDriver.cs:374-410` (pre-fix `EvaluateTag`) |
|
|
| Status | Resolved |
|
|
|
|
**Description:** `EvaluateTag` computed the change-gate flag (`allArrived`) but only used it to decide
|
|
whether to *publish* the result — it called `_evaluator.Evaluate(...)` **before** checking `allArrived`,
|
|
against a dependency snapshot that only contains the deps that HAVE arrived. `VirtualTagContext.GetTag`
|
|
(shared with VirtualTag scripts) returns a Bad snapshot with `.Value == null` for a key not present in
|
|
the read cache. The idiomatic calc-tag script shape used throughout this module's own tests and comments —
|
|
`return (double)ctx.GetTag("src/a").Value + (double)ctx.GetTag("src/b").Value;` — casts that `null` to a
|
|
non-nullable value type, which throws `NullReferenceException` at the unboxing conversion. That exception
|
|
was caught by `CalculationEvaluator.Evaluate`'s generic `catch (Exception ex)` and reported as a
|
|
`Failure("script threw: Object reference not set to an instance of an object.")`, which
|
|
`OnEvaluationFailed` then unconditionally logged to the `script-logs` topic as a Warning — **on every
|
|
partial-dependency arrival**, for any multi-dependency change-triggered calc tag whose declared deps
|
|
don't all arrive on the same tick. This is not a corner case: it fires on ordinary warm-up (every deploy
|
|
and every driver restart) for the standard multi-input calc-tag shape, producing a false-positive
|
|
"script threw" warning that looks exactly like a real script bug even though nothing is wrong, plus a
|
|
wasted Roslyn/compiled-cache invocation per partial arrival.
|
|
|
|
**Recommendation:** Move the `allArrived` check before the call to `_evaluator.Evaluate` so the script
|
|
never runs against a snapshot it wasn't declared against, matching the class's own documented intent
|
|
("publish nothing until every declared dep has arrived at least once").
|
|
|
|
**Resolution:** Fixed 2026-08-10 (branch `review/calculation-session`). `EvaluateTag` now returns before
|
|
building the dependency snapshot / calling the evaluator when `!def.DependencyRefs.All(_arrivedDeps.Contains)`.
|
|
`OnEvaluationFailed`'s now-always-true `allArrived` parameter was removed (the caller only reaches it once
|
|
every dep has arrived). Regression test
|
|
`CalculationDriverTests.No_evaluation_or_script_log_while_a_declared_dep_is_still_missing` reproduces the
|
|
exact scenario from `No_publish_until_every_declared_dep_has_arrived` but also asserts `logs.ShouldBeEmpty()`;
|
|
it fails with the captured `"script threw: Object reference not set..."` entry against the pre-fix code
|
|
and passes after. The pre-existing `No_publish_until_every_declared_dep_has_arrived` and
|
|
`Failure_publishes_Bad_once_per_transition_emits_script_log_and_recovers` tests are unaffected (neither
|
|
exercises a multi-dep tag mid-warm-up while asserting on `logs`).
|
|
|
|
---
|
|
|
|
### Driver.Calculation-003
|
|
|
|
| Field | Value |
|
|
|---|---|
|
|
| Severity | Medium |
|
|
| Category | Correctness & logic bugs / Code organization & conventions |
|
|
| Location | `src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.Calculation/CalculationDriverProbe.cs:16-21` (pre-fix) |
|
|
| Status | Resolved |
|
|
|
|
**Description:** The module defines its config-parsing `JsonSerializerOptions` in three places —
|
|
`CalculationDriverFactoryExtensions.JsonOptions` (spawn), `CalculationDriver.ReinitJsonOptions` (in-place
|
|
ApplyDelta), and `CalculationDriverProbe.Opts` (Test-Connect) — and the first two both set
|
|
`ReadCommentHandling = JsonCommentHandling.Skip` and `AllowTrailingCommas = true` while the probe's did
|
|
not. A config blob the real spawn/reinit path tolerates (a trailing comma or a `//` comment, plausible for
|
|
a hand-edited config used during troubleshooting) could therefore fail Test-Connect with "Config JSON is
|
|
invalid" even though deploying the identical JSON would succeed — the probe was **stricter** than the path
|
|
it exists to stand in for, the opposite of its documented contract ("Never throws; returns Ok with
|
|
negligible latency" / parse-only parity with the real path).
|
|
|
|
**Recommendation:** Align `CalculationDriverProbe.Opts` with the other two option sets (or extract a
|
|
single shared `JsonSerializerOptions` constant the three call sites reuse, to remove the duplication risk
|
|
entirely for future changes).
|
|
|
|
**Resolution:** Fixed 2026-08-10 (branch `review/calculation-session`). Added
|
|
`ReadCommentHandling = JsonCommentHandling.Skip` and `AllowTrailingCommas = true` to `Opts`, with a
|
|
comment naming the two option sets it must stay in parity with. New test file
|
|
`CalculationDriverProbeTests.cs` (previously nonexistent — see Driver.Calculation-004) pins this with
|
|
`Tolerates_trailing_commas_like_the_real_spawn_and_reinit_paths` and
|
|
`Tolerates_comments_like_the_real_spawn_and_reinit_paths`, both of which fail against the pre-fix `Opts`
|
|
and pass after.
|
|
|
|
---
|
|
|
|
### Driver.Calculation-004
|
|
|
|
| Field | Value |
|
|
|---|---|
|
|
| Severity | Medium |
|
|
| Category | Testing coverage |
|
|
| Location | `src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.Calculation/CalculationDriverProbe.cs`, `CalculationDriver.cs` (`ISkippedTagReporter`/`GetSkippedTags()`), `CalculationTimerScheduler.cs` (`SkippedTickCount`) |
|
|
| Status | Resolved |
|
|
|
|
**Description:** Two behaviours in this module had zero test coverage before this review:
|
|
|
|
1. `CalculationDriverProbe` had no test file at all — the Test-Connect surface for this driver type was
|
|
completely unverified (and, per Driver.Calculation-003, was in fact wrong).
|
|
2. `CalculationDriver`'s implementation of `ISkippedTagReporter`/`GetSkippedTags()` (the Gitea #541
|
|
authored-vs-mapped-tag visibility feature — the exact class of bug that let a driver silently ignore
|
|
20 of 22 tags while still reporting Healthy) had no test verifying a raw tag with no `scriptId` is
|
|
actually reported skipped, that `AuthoredCount`/`SkippedCount`/`Sample` are correct, or that the report
|
|
is rebuilt (not stale) after `ReinitializeAsync`.
|
|
|
|
`CalculationTimerScheduler.SkippedTickCount` (the in-flight-tick-skip counter) remains untested — left
|
|
open rather than force-fitted, since reliably forcing a same-group timer overlap without a sleep-based
|
|
flaky test would need either an injectable clock/scheduler or an artificially slow evaluator hook, neither
|
|
of which exists yet in this module.
|
|
|
|
**Recommendation:** Add a dedicated `CalculationDriverProbeTests.cs`; add `GetSkippedTags()` coverage to
|
|
`CalculationDriverTests.cs`. For `SkippedTickCount`, a follow-up could add a test-only evaluator delay hook
|
|
if the counter ever needs to be pinned by a test rather than only exercised implicitly.
|
|
|
|
**Resolution:** Fixed 2026-08-10 (branch `review/calculation-session`). Added
|
|
`tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.Calculation.Tests/CalculationDriverProbeTests.cs` (6 tests,
|
|
including the two parity regressions from -003). Added to `CalculationDriverTests.cs`:
|
|
`GetSkippedTags_reports_a_raw_tag_with_no_scriptId_alongside_the_authored_total`,
|
|
`GetSkippedTags_has_no_skips_when_every_authored_tag_maps`, and
|
|
`GetSkippedTags_updates_after_reinitialize`. `SkippedTickCount` is intentionally left without a dedicated
|
|
test — noted above, not silently dropped.
|
|
|
|
---
|
|
|
|
### Driver.Calculation-005
|
|
|
|
| Field | Value |
|
|
|---|---|
|
|
| Severity | Medium |
|
|
| Category | Concurrency & thread safety |
|
|
| Location | `src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.Calculation/CalculationDriver.cs:300-314` (`OnDependencyValue`), `:374-410` (`EvaluateTag`); cross-module: `src/Server/ZB.MOM.WW.OtOpcUa.Runtime/VirtualTags/DependencyConsumerMuxAdapter.cs` |
|
|
| Status | Resolved |
|
|
|
|
**Description:** `OnDependencyValue` evaluates every change-triggered dependent tag **inline, under
|
|
`_lock`**, and `EvaluateTag`'s call into `CalculationEvaluator.Evaluate` ultimately runs
|
|
`TimedScriptEvaluator<...>.RunAsync(context).GetAwaiter().GetResult()` — a synchronous blocking wait bounded
|
|
by `RunTimeout` (default 2 s, configurable via `RunTimeoutMs`, with no enforced ceiling). `OnDependencyValue`
|
|
is invoked directly and synchronously from `DependencyConsumerMuxAdapter.OnDependencyValueChanged`
|
|
(`src/Server/ZB.MOM.WW.OtOpcUa.Runtime/VirtualTags/DependencyConsumerMuxAdapter.cs:66-70`), an Akka
|
|
`ReceiveActor`'s message handler — i.e. on the actor's dispatcher thread. A calc script that runs close to
|
|
its timeout budget therefore blocks that thread (and, transitively, that specific driver's dependency-value
|
|
mailbox) for up to `RunTimeout` on every dependency arrival, and — because `TimedScriptEvaluator` offloads
|
|
the actual run via `Task.Run` while the caller blocks synchronously waiting on it — occupies a pool thread
|
|
for the duration rather than yielding it, which is a known thread-pool-starvation risk under Akka's
|
|
fork-join dispatcher if enough calc drivers are evaluating slow scripts concurrently. The in-line comment
|
|
("the compile cache makes this a bounded method invocation — the same 'fast enough to run inline' contract
|
|
as the VT evaluator") is not actually enforced by anything faster than `RunTimeout` itself — the existence
|
|
of the timeout mechanism is evidence a script CAN run slow, not evidence it never will.
|
|
|
|
This exact pattern (`_evaluator.Evaluate(...)` called unconditionally, inline, from an Akka actor's
|
|
synchronous message handler, with the identical `GetAwaiter().GetResult()` blocking shape) is also present
|
|
in `VirtualTagActor.OnDependencyChanged` (`src/Server/ZB.MOM.WW.OtOpcUa.Runtime/VirtualTags/VirtualTagActor.cs:179-199`),
|
|
which `CalculationDriver`'s own docs explicitly say this module mirrors — so this is a systemic,
|
|
pre-existing trade-off in the scripting engine, not something introduced by the Calculation driver alone.
|
|
Recorded here because the blocking call itself lives in this module's code (`CalculationDriver.cs`), even
|
|
though a full fix spans `Core.Abstractions` (the synchronous `IDependencyConsumer.OnDependencyValue`
|
|
contract) and `Runtime` (the adapter actor) — both out of this review's module scope.
|
|
|
|
**Recommendation:** Not a fix for this review (cross-module: the synchronous `IDependencyConsumer` contract
|
|
lives in `Core.Abstractions`, and the actor calling it lives in `Runtime`). If this risk is judged worth
|
|
closing, options include: (a) giving `IDependencyConsumer.OnDependencyValue` an async signature so the actor
|
|
can `PipeTo` the result instead of blocking its own thread; (b) having `CalculationDriver` dispatch evaluation
|
|
onto a dedicated bounded scheduler (e.g. `Task.Run` from `OnDependencyValue` itself, publishing the result
|
|
asynchronously) so the actor thread returns immediately; or (c) tightening `RunTimeout`'s effective ceiling
|
|
independent of the `RunTimeoutMs` config knob. Any of these should be scoped and reviewed together with the
|
|
equivalent `VirtualTagActor` behaviour so the two mirrors do not diverge.
|
|
|
|
**Resolution (2026-08-10):** Fixed in `235e06a8` — **inside this module, with no change to the
|
|
`IDependencyConsumer` contract and none to `Runtime`.** The finding scoped a fix as necessarily
|
|
cross-module (option (a), an async `OnDependencyValue`), but option (b) — the driver owning its own
|
|
dispatch — closes both halves without touching a shared interface, which is the smaller change and leaves
|
|
the mirrored `VirtualTagActor` behaviour free to be addressed separately.
|
|
|
|
`OnDependencyValue` no longer evaluates anything. Under `_lock` it records the arrival and *prepares* each
|
|
change-triggered dependent — resolve the definition, apply the warm-up gate, snapshot that tag's declared
|
|
dependency values — into a `PendingEvaluation`, enqueues them, and returns; a single `Task.Run` **evaluation
|
|
pump** drains the queue in FIFO order. `_lock` is a short-held state lock again (dictionary work only, never
|
|
held across a script run); a new `_evalGate` carries the mutual exclusion `_lock` used to provide, and is
|
|
taken **only** by the two evaluation workers (the pump and `EvaluateTagFromTimer`), never by
|
|
`OnDependencyValue`, `ReadAsync` or `ReinitializeAsync` — which is what makes "no host thread can block on a
|
|
script" structural rather than incidental. Lock order is always `_evalGate` → `_lock`. `EvaluateTag` split
|
|
into `PrepareEvaluation` (under `_lock`) / `RunEvaluation` (script + apply, outside it) /
|
|
`MarkEvaluationSucceeded` + `MarkEvaluationFailed` (state decisions, under `_lock`, returning what to
|
|
publish); the script log and the `OnDataChange` fan-out now fire outside both locks.
|
|
|
|
**The guarantee the fix rests on: at most one evaluation runs at a time.** The pump is single (`_pumpScheduled`
|
|
is set and cleared under `_lock`, and the flag and the queue are always checked together, so an enqueue either
|
|
starts a pump or is seen by one that has not yet exited), and `_evalGate` serializes it against timer ticks —
|
|
so per-tag *and* cross-tag evaluation ordering is exactly what it was when the change path evaluated inline
|
|
under the state lock. Publishes follow evaluation order because they are issued by the same serialized worker.
|
|
|
|
Semantics deliberately preserved beyond ordering: the warm-up gate still runs BEFORE the evaluator
|
|
(Driver.Calculation-002 is not regressed — it moved into `PrepareEvaluation`, which is equivalent because
|
|
`_arrivedDeps` only ever grows and the arrival that completes the set queues its own evaluation); dedup,
|
|
once-per-transition Bad, and force-published recovery are unchanged. **The dependency snapshot is taken at
|
|
trigger time, not when the pump reaches the item** — without that, a burst of arrivals would collapse onto
|
|
whichever value happened to be current when the pump caught up, changing which intermediate values publish
|
|
(`Equal_result_is_deduped_and_a_changed_result_republishes` is the case that would have silently become
|
|
`[14.0]` instead of `[10.0, 14.0]`). The timer path keeps its own structure — a tick still evaluates on the
|
|
scheduler's pool thread under the scheduler's per-group in-flight guard, which is what bounds outstanding
|
|
timer work; routing ticks through the pump instead would have made `SkippedTickCount` dead and let ticks
|
|
queue without bound. `ReinitializeAsync`, `ShutdownAsync` and `Dispose` clear the queue (prepared items are
|
|
stale against a rebuilt tag table), and `RunEvaluation` re-looks-up the tag's state under `_lock` after the
|
|
run so a tag dropped mid-evaluation discards its result rather than publishing it.
|
|
|
|
RED first, two tests, both failing against the pre-fix code:
|
|
`A_dependency_arrival_does_not_run_the_script_on_the_callers_thread` (the publish — which can only happen
|
|
after the script ran — landed on the caller's own stack, inside the callback) and
|
|
`A_slow_script_blocks_neither_the_dependency_callback_nor_a_concurrent_read` (a 600 ms busy-wait script:
|
|
the callback took 1.21 s, and `ReadAsync`, which needs the same state lock, was stuck behind it). Both
|
|
carry a positive control asserting the value still computes and publishes, so neither can pass against a
|
|
driver that simply evaluates nothing. ⚠️ The first test's original form compared the publish's **thread id**
|
|
against the caller's and was itself flaky (1 failure in 6 runs): the pump is free to reuse the pooled thread
|
|
the test released while awaiting, so an id match means nothing. It asserts on a thread-local flag set for
|
|
exactly the callback window instead — which is exact, and was re-falsified by making `SchedulePump` run the
|
|
pump synchronously (red immediately, then reverted).
|
|
|
|
Known trade, documented rather than hidden: the pending queue is unbounded. Under sustained arrival
|
|
pressure the previous inline path applied backpressure by blocking the mux actor — which is the defect —
|
|
so the queue is the relief valve, and the tag-set is small and bounded by authored config. Five existing
|
|
tests that asserted on the line after `OnDependencyValue` now settle on a new internal `IsEvaluationIdle`
|
|
probe first (quiescence, not a sleep — the work is enqueued synchronously inside the callback, so idle
|
|
cannot be observed before it lands). Suites green: `Driver.Calculation.Tests` 53/53 (34 before this work),
|
|
`Runtime.Tests` 558 passed / 3 skipped.
|
|
|
|
The mirrored `VirtualTagActor.OnDependencyChanged` blocking shape this finding also names is **unchanged** —
|
|
it lives in `Runtime`, outside this module, and is left as the separate scoped change the finding's
|
|
recommendation asks for.
|