Merge branch 'fix/r3-03-restart-resubscribe-watchdog' — R3-03: SpawnChild always sends the desired set (operator Restart + supervision restart re-provision, stale-alarm-set re-subscribe, incarnation check, 10 s backoff); watchdog grace = max(LastSuccessfulRead, connectedSince) (archreview 03/S16, S17, U6)

This commit is contained in:
Joseph Doherty
2026-08-20 10:40:11 -04:00
9 changed files with 1699 additions and 46 deletions
@@ -452,3 +452,321 @@ T8 anytime; T9 last (after T3/T5/T6/T7 merge-ready)
```
Overall effort: **~0.75–1 dev-day code+unit, plus the rig session.** The one HIGH-RISK production slice (T3, which changes what every child receives at spawn) lands behind the full 25-suite `DriverHostActor` regression before any new test stacks on it, and behind T2's explicitly behaviour-preserving refactor.
---
## Execution notes
Branch `fix/r3-03-restart-resubscribe-watchdog`, worktree
`.claude/worktrees/agent-a5bcdd61bfba22e10`, off master `5fd65d19`. TDD throughout: every
behaviour task's test was written first, RUN, and observed red for the predicted reason before the
production edit landed. Red observations are recorded per task below.
### T1 — 03/S17 watchdog grace (`??` → max)
**RED observed (as predicted).** With the two new tests in place against unmodified
`DriverInstanceActor`:
```
DriverInstanceActorCommsLossWatchdogTests.A_reconnected_driver_gets_a_full_grace_window_before_the_watchdog_trips_again [FAIL]
Failed: Expected no messages during 00:00:00.4000000, instead we received
<ConnectivityChanged { DriverInstanceId = stub-driver-1, Connected = False }> after 00:00:00.0496590
Failed! - Failed: 1, Passed: 9, Total: 10
```
The re-trip landed **49.7 ms** after the reconnect — one health tick (`FastPoll` = 50 ms) — against a
`Grace` of 1500 ms, i.e. exactly the "churn at health-tick cadence instead of the designed grace"
the finding describes. `A_half_broken_device_is_still_declared_lost_once_the_grace_elapses` passed
in the same run, which is what makes it the anti-vacuity control: it cannot distinguish the fix from
the bug, so the delay assertion is the one carrying the finding.
**GREEN after the one-line max at `:574`** (plus the "grace is per connection" remarks paragraph and
the reciprocal falsification-partner xmldoc on the existing
`A_degraded_driver_that_is_still_reading_successfully_is_left_alone`): 10/10 passed, 20 s.
`A_reconnect_attempt_tears_the_dead_transport_down_before_re_initialising` stayed green — as the plan
anticipated, each of its trip cycles now costs a full `FastTimeout` (250 ms) instead of one 50 ms
tick, and its `AwaitCondition(InitializeCount >= 2, 5 s)` still has ample headroom. No budget change
was needed.
### T2 — desired-subscription payload authority
Behaviour-preserving refactor, so there is no red observation to record by design — the gate is that
**no test moves**. `--filter "FullyQualifiedName~DriverHostActor"` → **114/114 passed**, unchanged
from the base commit.
⚠️ One run of that filter reported `DriverHostActorNativeAlarmAckRoutingTests.RouteNativeAlarmAck_on_non_primary_is_dropped`
failing on an `AwaitAssert`. Re-run in isolation: **3/3 passed**; re-run of the whole 114-test filter:
**114/114 passed**. Treated as the known #500 flake set for this assembly (~13 %/run), not a
regression — it touches none of the code this task edits (the alarm-ack Primary gate is a different
method entirely).
Deviation from the plan's literal step text (cosmetic, recorded for the reviewer): the plan's Finding-1
step 1 says `_desiredByDriver` *replaces* `_lastComposition` at `:347-349` while T3 step 2 says T3
deletes `_lastComposition`. Keeping T2 compilable means the two fields coexist for one commit;
`_lastComposition` and its assignment are deleted in T3 as T3's own step text specifies.
### T3 — `SpawnChild` always sends the desired set; `_lastComposition` deleted
The falsification for this production slice is **T5**, written and observed red afterwards (below) —
T3 lands the fix first because the plan sequences it that way and the ordering guard needs the whole
25-suite regression before any new test is trusted on top of it.
**HIGH-RISK regression gate (every child's spawn-time state changes, deploy path included):** the
FULL `Runtime.Tests` project, not just the `DriverHostActor` filter —
**639 passed, 3 skipped, 0 failed, 55 s**. The 3 skips are pre-existing (`DeploymentArtifact*` parity
tests, skipped on the base commit too).
`_lastComposition` is gone: `grep -c _lastComposition DriverHostActor.cs` → **0**. Its xmldoc had also
drifted (it claimed the field was set at the end of `PushDesiredSubscriptions`; the assignment was in
`ApplyDesiredSubscriptions`) — deleted with the field rather than corrected. The stale
"dropped-driver fallback" comment on the old `SendAuthoredOnly` local function was rewritten as the
`SendDesiredSubscriptions` remarks naming the three real consumers.
### T4 — test harness (seeder `enabled` flag + recording driver factory)
Test-only, additive, source-compatible: every pre-existing `SeedV3Deployment` / `SpawnHostAndApply`
call site compiles and behaves identically (the new parameters are trailing and default to today's
values). Gate: `--filter "…~DriverHostActor|…~DriverInstanceActor"` → **179/179 passed** (the plan
named `--filter "…~V3"`, which matches nothing — the seeder's four consumers are all `DriverHostActor*`
classes; the wider filter is the same set plus more).
**Deviation (recorded).** The plan lists one new seeder parameter (`enabled`); a second was needed and
added: `IReadOnlyDictionary<string, string>? tagConfigByTag = null`. The seeder hard-codes
`TagConfig = "{}"` on every tag, and a raw tag's alarm is derived *only* from `TagConfig.alarm` via
`TagConfigIntent.Parse` (`AddressSpaceComposer.cs:769-772`) — so without it there is no way to seed the
alarm-bearing raw tag that `Operator_restart_re_subscribes_alarm_refs_too` (a test the plan itself
specifies) requires. It is trailing and optional, so it is the same source-compatible shape as
`enabled`.
### T5 — `DriverHostActorRestartTests` (operator-restart falsification, 03/U6's first half)
**RED observed against a T3-reverted build** (the `SendDesiredSubscriptions(child, …)` call in
`SpawnChild` commented out, everything else on the branch): **all 4 FAILED, 0 passed**, each at the
bar the plan predicts —
```
Operator_restart_re_subscribes_the_respawned_child [FAIL]
factory.Created[1].SubscribeCount should be greater than or equal to 1 but was 0
Operator_restart_re_subscribes_alarm_refs_too [FAIL]
factory.Created[1].SubscribeAlarmsCount should be greater than or equal to 1 but was 0
Restart_of_a_driver_with_an_empty_value_set_still_sends_the_set [FAIL]
respawned.SubscribeAlarmsCount should be greater than or equal to 1 but was 0
A_child_spawned_by_a_fresh_deploy_ends_with_the_NEW_refs [FAIL]
factory.Created[2].LastSubscribedRefs should be ["Plant/Modbus/dev1/temp"] but was null
```
The call was then restored; **4/4 pass**, and the class was run **20× in isolation, 20/20 green** (#500
discipline for this assembly).
**Two deviations, both found by running the tests rather than by reading:**
1. ⚠️ **The plan's claim that the transient spawn-time set "is never acted on" is FALSE, and the
production comment that repeated it has been corrected.** The plan reasons that the child is still
`Connecting` when the stale set arrives, so it is only stored. But the child runs **concurrently**
with the rest of `HandleArtifactForApply` — `Context.ActorOf` returns and the child starts
processing while the host is still building `refsByDriver` — so a driver whose `InitializeAsync`
completes instantly reaches Connected and subscribes the stale set *before* the bulk push arrives.
Measured directly: `SubscribeCount == 2` on the respawned child, first with revision A's ref and
then with B's. What Akka's per-pair ordering does guarantee is **convergence**, and
`HandleSubscribeAsync` drops the prior subscription before establishing the new one, so the cost is
one extra subscribe round-trip on a *respawning* deploy — a real device driver, whose initialise
opens a socket, rarely wins that race. Accepted rather than "fixed": withholding the spawn-time send
is the 03/S16 defect, and the operator-Restart and supervision paths have no bulk push coming at
all. The `SpawnChild` comment now states this instead of the plan's claim, and the test asserts
convergence (the plan's own stated acceptance — "the child's live subscription carries the NEW
refs") rather than pinning the race.
2. **`A_child_spawned_by_a_fresh_deploy_ends_with_the_NEW_refs` had to be re-shaped.** The plan
describes revision B as one "which respawns nothing but re-pushes". It respawns: the raw tags are
folded into the merged `DriverConfig`, so a tag-set edit changes the `DriverInstanceSpec` and trips
the #516 config respawn. That is the *stronger* arrangement for this test's subject (a brand-new
child spawned while the authority still holds A), so the test keeps the same name and asserts the
respawned child converges on B — plus a subsequent operator Restart, which pins that the authority
is repopulated **whole** per apply rather than accumulated.
3. **`Restart_of_a_driver_with_no_authored_tags_sends_an_empty_set_not_nothing` was renamed
`Restart_of_a_driver_with_an_empty_value_set_still_sends_the_set`, with a real positive control.**
The seeder derives `DriverInstances` from the raw-tag rows, so a driver with *zero* tags is not
expressible, and — more importantly — an all-empty set has **no driver-side observable at all**
(the child stores it and, having no handle, does nothing), which would have made the test vacuous:
"it did not subscribe" passes equally against a build that sends the respawned child nothing, i.e.
against the defect itself. The subject is therefore a driver whose only raw tag is alarm-bearing:
its value half is genuinely empty while its alarm half is not, and **both halves ride in one
message** — so `SubscribeAlarmsCount >= 1` proves the message ARRIVED and `SubscribeCount == 0`
then proves the empty value half was honoured. The falsification run above confirms the control
works: with T3 reverted this test fails on the *positive control*, not on the absence.
**Not covered, and worth a reviewer's eye:** the `_desiredByDriver` union's `_children.Keys` arm
(a running child absent from BOTH ref maps) is not reachable through this seeder and is untested.
### T6 — supervision reprovision hook
`DriverInstanceActor.PostRestart` (calling `base.PostRestart(reason)` first, so `PreStart` re-attaches
the rediscovery / host-status sources and restarts the health timer) → `ReprovisionRequested` →
`DriverHostActor.HandleReprovisionRequested`, registered in **all three** `Receive` blocks that already
accept `RestartDriver`. The falsification is T7, below.
Gate: `--filter "…~DriverHostActor|…~DriverInstanceActor"` → **183/183 passed** (179 before this task
plus T5's four), no test moved.
### T7 — first supervision-restart test + the force-reconnect verified negative (03/U6)
**Crash seam that landed: the planned one** — `RecordingSubscribableDriver.FireMalformedDataChange`
raises `OnDataChange` with a null `Snapshot`; `DriverInstanceActor.OnDataChangeForward` dereferences
`msg.Snapshot.SourceTimestampUtc` on the actor thread and NREs; Akka's default decider Restarts. No
fallback (`OneForOneStrategy` + an internal test message) was needed, so no production surface was
added for the test.
**RED observed against a T6-reverted build** (the `Context.Parent.Tell(new ReprovisionRequested(…))`
in `PostRestart` commented out):
```
Supervision_restart_reinitialises_and_re_subscribes_the_child [FAIL]
driver.InitializeCount should be 2 but was 1
"the restarted child was never re-initialised — it is sitting in Connecting around a driver
its own PostStop already shut down (03/S6, the worse half of 03/S16)"
```
**Deviation, and the reason for it — the first red run was AMBIGUOUS and the test was strengthened.**
`InitializeCount == 1` is equally consistent with "the child restarted and was not re-provisioned"
and with "the child never crashed at all", so a seam that silently stopped working would read as a
passing regression test forever. A preceding `AwaitAssert(ShutdownCount >= 1)` was added — `PreRestart`
runs `PostStop`, which calls `ShutdownAsync`, so that is the evidence a restart genuinely happened.
On the re-run of the falsification that assertion **passed** and the failure landed squarely on the
re-initialise, which is what makes the red observation above meaningful.
`Force_reconnect_keeps_the_desired_set_and_re_subscribes` passed in **both** the red and green runs —
correct, and the point: it is the verified negative (`ForceReconnect` reaches the same live actor, so
`_desiredRefs` survive and the reconnect's Connected entry re-applies them). It carries a 30 s budget
rather than `PresenceBudget`, because `SpawnChild` gives the child the production
`DefaultReconnectInterval` (10 s) and the retry is a periodic timer, so the reconnect cannot land
sooner; a budget is only spent on failure.
After restoring the hook: **6/6 pass**, and the class was run **20× in isolation, 20/20 green**.
### T8 — docs
`docs/DriverLifecycle.md`:
- New §"What a (re)spawn re-provisions" (placed before §IDriverHealthPublisher): `_desiredByDriver` as
the single authority, a table of the three incarnation routes plus the verified-negative Force
Reconnect, the supervision route's invisibility, why replacing the default decider is out of scope,
the respawning-deploy ordering **with the measured caveat that the transient is not inert**, and the
assert-a-function-not-existence rule naming the weaker existing test.
- §"The comms-loss watchdog": conjunct 2 restated as the max, plus a new paragraph on the
per-connection grace — why `??` was wrong, that it **paces** rather than ends the half-broken-device
cycle, that the watchdog is not disabled by the change, and the two tests that pin each half.
### Final verification
- `dotnet build ZB.MOM.WW.OtOpcUa.slnx` → **0 errors** (904 warnings, all pre-existing analyzer
`OTOPCUA0001` noise in unrelated driver test projects).
- **Full `Runtime.Tests`: 645 passed, 3 skipped, 0 failed** (1 m 9 s). Baseline on the branch point was
637 + 3 skipped; the +8 are this plan's new tests (T1 ×2, T5 ×4, T7 ×2). The 3 skips are pre-existing
`DeploymentArtifact*` parity tests.
- The two other test projects that reference `ZB.MOM.WW.OtOpcUa.Runtime` were run as well, since T3
changes what every driver child receives at spawn: `ControlPlane.Tests` **262/262**, `Host.Tests`
**106/106**.
- T9 (live gate) deliberately left **pending** — run by the orchestrator.
### Summary of deviations (for the reviewer)
1. **The plan's "the transient spawn-time set is never acted on" is false** — measured, corrected in
both the production comment and the docs, and accepted with its cost stated (T5, deviation 1). This
is the one behavioural claim in the plan that did not survive contact with the code.
2. `A_child_spawned_by_a_fresh_deploy_ends_with_the_NEW_refs` re-shaped — revision B *does* respawn the
child (raw tags fold into the merged `DriverConfig`) (T5, deviation 2).
3. `Restart_of_a_driver_with_no_authored_tags_sends_an_empty_set_not_nothing` renamed +
re-based on an alarm-only driver, because an all-empty set has no driver-side observable and the
planned test would have been vacuous; the `_children.Keys` union arm remains untested (T5,
deviation 3).
4. Seeder gained a second optional parameter (`tagConfigByTag`) — the only way to seed an alarm-bearing
raw tag, which one of the plan's own tests needs (T4).
5. The supervision test gained a preceding `ShutdownCount >= 1` assertion, because the plan's red
observation was ambiguous with "the child never crashed" (T7).
6. `Force_reconnect_keeps_the_desired_set_and_re_subscribes` uses a 30 s budget, not `PresenceBudget` —
`SpawnChild` gives the child the production 10 s `DefaultReconnectInterval` (T7).
7. `_lastComposition` and `_desiredByDriver` coexist for one commit (T2) so T2 stays compilable; the
deletion lands in T3, as T3's own step text specifies.
---
## Review outcome
Verdict **FIX-FIRST**, 3 items. All three confirmed against the code, fixed TDD (test first, seen red
for the predicted reason, then fixed), one commit each.
### F1 [HIGH regression] — a changed alarm set latched (`edd01fcc`)
**Confirmed.** `SubscribeDesiredAlarms` and `HandleSubscribeAlarmsAsync` both gated on
`_alarmSubscriptionHandle is not null`, which is the right guard for an idempotent re-push and the wrong
one for a deploy that changes the set. The value side converges by construction
(`StoreDesiredSubscriptions` is a full replace; `HandleSubscribeAsync` drops the prior subscription
first) — the alarm side did not. **T3 is what made it reachable**: a tag-set edit forces a respawn, and
a fast-initialising driver subscribes the transient spawn-time set before the bulk push, so the
PREVIOUS revision's alarm refs latched for the connection's life. `sourceNodeIds`-filtering drivers
(OPC UA Client, AB CIP, FOCAS) would silently never deliver the newly-added alarm.
**RED:** `A_deploy_that_widens_the_alarm_set_re_subscribes_the_new_refs` — after deploying
alarm `{alarmX}` then `{alarmX, alarmY}`, `LastSubscribedAlarmRefs` was still `["Plant/Modbus/dev1/alarmX"]`.
**Fix:** new `_subscribedAlarmRefs` records what the live handle was established with;
`AlarmSubscriptionIsStale()` (no handle **or** the desired refs differ) replaces the bare null check in
both places; a stale handle is **released before** re-subscribing so a filtering driver cannot
accumulate two overlapping subscriptions. The release clears the handle *first*, so a throwing
unsubscribe cannot leave the staleness check treating a dead handle as live, and it is best-effort
(logged, non-fatal — the re-subscribe is what matters). Unsubscribe-on-**empty** is still deliberately
absent, unchanged. Two notes: the release had to be wrapped in `_invoker.ExecuteAsync` or the repo's
`OTOPCUA0001` analyzer fails the build; and the Connected-handler comment that stated the
value-only convergence claim was corrected, as was the matching bullet in `docs/DriverLifecycle.md`.
### F2 [MEDIUM] — reprovision routed by id, not incarnation (`2b7100cf`)
**Confirmed.** Fixed with `if (!Equals(Sender, entry.Actor)) return;` (plus a Debug line naming the
superseded ref).
⚠️ **The first version of the test PASSED against the unfixed code — the arrangement mattered.** With
the child already **Connected**, `InitializeRequested` is unhandled, so the stale reprovision was
swallowed for the wrong reason and the test was vacuous. The defect only bites a child in
`Connecting`, which is exactly where `InitializeRequested` *is* handled. `RecordingSubscribableDriver`
therefore gained an `InitializeGate` (a `TaskCompletionSource` its `InitializeAsync` awaits) so the
test can hold the child in `Connecting`. **RED with that arrangement:** `InitializeCount == 2` — the
second concurrent `InitializeAsync` racing the #527 dispose-before-overwrite. The absence assertion
carries a positive control (the child is proven alive at `InitializeCount == 1` first) and a
`GetDiagnostics` round-trip so the dropped message is provably processed before the absence is read.
### F3 [IMPORTANT] — no backoff on the reprovision (`0793b0cb`)
**Confirmed.** Added `DefaultReprovisionBackoff` (10 s, matched to
`DriverInstanceActor.DefaultReconnectInterval` because the reprovision drives the same connect work),
a per-driver `_lastReprovisionUtc` stamp, and a `reprovisionBackoff` Props parameter following the
existing `applyWedgeTimeout` precedent so a test need not wait the production window.
A held request is **deferred, not dropped**: one `StartSingleTimer` per driver re-delivers a
`ReprovisionDeferred` carrying the **original incarnation ref**, so F2's identity check still applies
on re-delivery, and a burst collapses to a single pending reprovision rather than a queue. Each
deferral logs a Warning naming the crash type, so a crash loop is visible rather than quiet.
**RED** (backoff disabled): `InitializeCount == 3` where the test requires 2-then-3 — i.e. the second
reprovision applied immediately. The test drives **two genuine supervision restarts** (not synthetic
messages), waits for the re-subscribe before arming the second crash, and asserts `ShutdownCount >= 2`
so "the second crash tripped supervision" is proven before the backoff is read.
### Optional adds (both done)
- `A_running_driver_with_no_authored_tags_is_handed_an_empty_set` — the `_children.Keys` union arm,
previously untested and called out as a gap in the T5 notes. It needed a driver with no tags at all,
which the seeder could not express, so `SeedV3Deployment` gained `taglessDrivers`. The tagless child
is asserted initialised-but-never-subscribed, with its tag-owning sibling's subscribe as the positive
control that the push pass ran.
- `_desiredByDriver` xmldoc now records that it is rebuilt only by a **successful** apply, so it
lingers on the last-known-good composition after a failed one — consistent with the address space,
drivers and subscriptions that also keep serving (#485/#486).
### Verification after the three fixes
- `dotnet build ZB.MOM.WW.OtOpcUa.slnx` → **0 errors**.
- **Full `Runtime.Tests`: 649 passed, 3 skipped, 0 failed** (up 4 from 645 — F1, F2, F3 and the
union-arm test).
- **`ControlPlane.Tests`: 262/262.**
- `DriverHostActorRestartTests` (now 10 cases) run **10× in isolation, 10/10 green**.
- T9 (live gate) still **pending** — the orchestrator runs it. Worth noting for that session: F1 is
directly observable on the rig, by deploying a second alarm-bearing raw tag to a driver that already
has one and confirming a transition on the NEW tag reaches `/alerts`.
@@ -5,19 +5,19 @@
{
"id": "T1",
"subject": "Comms-loss grace is per connection: ?? -> max(LastSuccessfulRead, _connectedSinceUtc) + falsification pair (03/S17)",
"status": "pending",
"status": "done",
"blockedBy": []
},
{
"id": "T2",
"subject": "Desired-subscription payload authority: _desiredByDriver + SendDesiredSubscriptions (behaviour-preserving refactor)",
"status": "pending",
"status": "done",
"blockedBy": []
},
{
"id": "T3",
"subject": "SpawnChild always sends the desired set; delete the write-only _lastComposition (03/S16)",
"status": "pending",
"status": "done",
"blockedBy": [
"T2"
]
@@ -25,13 +25,13 @@
{
"id": "T4",
"subject": "Test harness: V3ArtifactSeeder enabled flag + RecordingSubscribableDriver(Factory) with a crash seam",
"status": "pending",
"status": "done",
"blockedBy": []
},
{
"id": "T5",
"subject": "DriverHostActorRestartTests: operator restart re-subscribes the respawned child (falsifiable; 03/S16, U6)",
"status": "pending",
"status": "done",
"blockedBy": [
"T3",
"T4"
@@ -40,7 +40,7 @@
{
"id": "T6",
"subject": "Supervision reprovision hook: DriverInstanceActor.PostRestart -> ReprovisionRequested -> host re-init + re-subscribe (03/S6, S16)",
"status": "pending",
"status": "done",
"blockedBy": [
"T3"
]
@@ -48,7 +48,7 @@
{
"id": "T7",
"subject": "First real supervision-restart test + force-reconnect verified-negative regression (03/U6)",
"status": "pending",
"status": "done",
"blockedBy": [
"T4",
"T6"
@@ -57,7 +57,7 @@
{
"id": "T8",
"subject": "docs/DriverLifecycle.md: what a (re)spawn re-provisions + per-connection watchdog grace",
"status": "pending",
"status": "done",
"blockedBy": []
},
{