Merge branch 'perf/followups-r3' — r2 register closed (ACL CAS loop, S7 worst-state-wins health, 404 mechanism named) + ScadaBridge rows 38/39 (Roslyn test de-flake, LocalDb conditional registration) + four live gates (FetchAndCache, alarm ratchet, ACL-enabled enforcement, 404 catch)
v2-ci / build (push) Successful in 5m49s
v2-ci / unit-tests (push) Failing after 3h1m31s

This commit is contained in:
Joseph Doherty
2026-08-18 09:11:23 -04:00
22 changed files with 2429 additions and 171 deletions
+46 -18
View File
@@ -550,8 +550,9 @@ fail-closed). Things worth knowing before touching it:
is Phase 4 — resist folding it in, or the "no SQL" scope becomes unprovable-in-parts.
On the docker-dev rig the central pair carries `ConfigServe` (`:4055`, committed dev key) and stays
`Direct`; the four site nodes carry `ConfigSource` (endpoints + matching key) defaulting to `Direct`.
Flip only the site nodes with `OTOPCUA_CONFIG_MODE=FetchAndCache` at `docker compose up`. See
hardcoded `Direct` via its admin role; the four site nodes carry `ConfigSource` (endpoints + matching
key) hardcoded `FetchAndCache` — mandatory for driver-only nodes since Phase 4, not a flip. There is
no `OTOPCUA_CONFIG_MODE` env var in the compose file. See
`docs/Configuration.md` §`ConfigSource` / `ConfigServe`, `docs/Redundancy.md` §"Command transport", and
`docs/plans/2026-07-22-mesh-phase3-config-fetch-and-cache.md`.
@@ -649,7 +650,9 @@ deliberately unresolvable gateway endpoint, so the buffer is always a live, non-
`.Replication`), bumped from `0.1.3` on 2026-08-15. It was a **pure pin bump — no code change**:
`RegisterReplicated(string)` is unchanged, everything 0.2.x added is additive, the wire protocol is
untouched (0.1.x peers still sync), and the on-disk bookkeeping schema v1 → v2 upgrades in place on
open, so no rig or volume action was needed. Three things about it are worth knowing:
open, so no rig or volume action was needed. **Its two new APIs — `DeregisterReplicated` and
`RegisterReplicated(table, baselineExistingRows:)` — are now both used** (2026-08-18); the bullets
below are the shape that landed, not the bump itself. Two things are worth knowing:
- **`MaxBatchSize` no longer means what the rig's `16` was chosen to mean.** 0.2.0 made batching
**byte-budgeted** — `LocalDb:Replication:MaxBatchBytes` (2 MB default, left unset here, sized
@@ -659,21 +662,46 @@ open, so no rig or volume action was needed. Three things about it are worth kno
`16` — it now bounds that transient allocation (≈2.7 MB at ≈171 KB artifact chunk rows), not the
message size. Every comment and doc row that called it "row-count-only against gRPC's 4 MB cap"
was corrected with the bump; do not restore that rationale.
- **`DeregisterReplicated` exists and this repo deliberately does not call it.** `LocalDbSetup.OnReady`
registers all four tables **unconditionally**, on every driver node, replicating or not — a
replication-configured node and a default-OFF one (central, site-b) carry identical CDC triggers.
ScadaBridge went the other way (conditional registration + a boot-time deregister self-heal), so
do not read that pattern across as settled here: it would be a behaviour change, and
`LocalDbSetupTests` pins the registered-table set and the DDL→register ordering exactly. The
cost of the current shape is three unused triggers per table on an unreplicated node; the
benefit is that turning replication on is a config change that needs no re-registration pass.
- **Consequently, `baselineExistingRows` is not used either.** Rows written on a node *before*
replication is enabled are not in `__localdb_row_version`, so enabling replication on a
long-running default-OFF node (central, site-b) converges on subsequent **writes**, not on the
rows already in the file. Passing `RegisterReplicated(table, baselineExistingRows: true)` is the
library's answer, but it flags a snapshot resync and is only correct when gated on replication
actually being configured — which the unconditional registration above cannot express. Enable
replication on a fresh pair, or accept the gap and let the next deploy re-cache.
- **Registration FOLLOWS the replication config — it is no longer unconditional (2026-08-18).**
`LocalDbSetup.OnReady` reads one predicate, `LocalDbSetup.ReplicationIsConfigured`:
**`LocalDb:Replication:PeerAddress` OR `LocalDb:Replication:ApiKey` is non-blank.** The **OR is
not belt-and-braces** — only the dialling half of a pair sets `PeerAddress`, so keying on it
alone would strip capture from every *passive* node (site-a-2 carries `ApiKey` +
`LocalDb:SyncListenPort` and nothing else) and the pair would converge in one direction only,
silently. ⚠️ **`SyncListenPort` deliberately does NOT join the OR:** the passive endpoint is
fail-closed on the key, so a port without an `ApiKey` rejects every inbound stream and has
nothing to capture for.
- **Configured ⇒ `RegisterReplicated(table, baselineExistingRows: true)`**, per table, in the
same load-bearing DDL→register order. Baselining is what makes enabling replication on a node
that has been running *without* it actually converge: capture is CDC and the snapshot streamer
pages from `__localdb_row_version`, so pre-registration rows were in neither and a late opt-in
used to replicate only writes made after the restart. It seeds the ledger at the LWW floor
(HLC `0`, this node's id) and flags a resync — a baselined row loses to any genuine remote
write of the same key and wins only where the peer has no version at all. It is idempotent, so
it is free on every boot after the first. ⚠️ On the pinned **0.2.1** the snapshot flag is
per-**database**, not per-table, so baselining anything streams *every* registered table in
full, in both directions at once — trim `alarm_sf_events` before enabling replication on a node
that has been buffering alarm history for months, and expect one slow first sync.
- **Not configured ⇒ `DeregisterReplicated(table)` per table**, an idempotent boot-time
self-heal: it drops the capture triggers an earlier (unconditional) build left in the file and
prunes that table's oplog + row-version rows. Merely declining to register would leave every
pre-2026-08-18 file capturing forever — two INSERTs plus a `json_object` of the whole row
inside every write transaction — on precisely the node that has no peer to capture for. The
call returns `true` when it removed something, so the Information line fires **once, and only
when it actually cleaned**; a default-OFF node's ordinary boot stays silent. The logger is
Serilog's static `Log.Logger` (this runs inside the `AddZbLocalDb` singleton factory, where
resolving one from DI would nest a resolution inside a singleton construction; `Program.cs`
assigns it before anything resolves `ILocalDb`), with an optional parameter so tests observe
the line rather than infer it.
- ⚠️ **PAIR SYMMETRY: flipping registration is a BOTH-NODES-TOGETHER change.** The sync handshake
compares registered-table digests **fail-closed**, so a node that deregisters a table its peer
still replicates stops syncing with a schema mismatch. Enabling replication on an established
pair means setting the config and **restarting both nodes** — do it on both, or on neither.
- **Rollout note:** the only replicating pair in the fleet is docker-dev **site-a**, and it was
enabled from a fresh pair, so the impact of the old gap was low — central and site-b are
default-OFF and simply shed their unused triggers on their next boot. `LocalDbSetupTests`
pins both branches (registered-table set on a configured node, empty set + zero triggers +
the HLC-0 baseline ledger entry on the other) and the DDL→register ordering, unchanged.
See `docs/Configuration.md` (`LocalDb` section), `docs/Redundancy.md` (pair-local config
cache), `docs/AlarmHistorian.md`, and the runbook
+35 -9
View File
@@ -95,7 +95,14 @@ issues the single, un-retried `POST http://localhost:9200/api/deployments` with
`X-Api-Key: docker-dev-deploy-key`. Override the URL / key / timeout via `OTOPCUA_ADMIN_URL`,
`OTOPCUA_DEPLOY_API_KEY`, `OTOPCUA_READY_TIMEOUT_SECONDS`.
### First-POST 404
The body is optional and the no-body form is fully supported (verified on this rig 2026-08-18):
the minimal-API `DeployRequest?` parameter binds a missing body *and* a `Content-Length: 0` body
as **null** — it does not 400 — and the handler defaults the audit field to
`CreatedBy = "rest-api"`. A bare `./docker-dev/deploy.sh` answers `202 Accepted` with the new
`deploymentId` + `revisionHash`, `200` when there is nothing to deploy, and `409` while another
deployment is still in flight.
### First-POST 404 — mechanism CONFIRMED (2026-08-18)
The first headless POST after `up -d` was seen answering **404** ~40 s into boot (2026-08-17 live
gate), clearing on retry. Neither end can produce it: the AdminUI maps every route synchronously
@@ -104,14 +111,33 @@ failure modes are 503 / 401 / 422 / 409 / 500 — it has no 404 path; and Traefi
router whose servers are all down with **503 "no available server"** (the checked-in
`traefik-dynamic.yml` router is `PathPrefix(/)` → `otopcua-admin` with a `/health/active`
healthCheck). Traefik's `api@internal` router (`PathPrefix(/api)`) is bound to the `:8080`
entrypoint (host 8089), not `web`/`:9200`, so it does not shadow `/api/deployments` either. So a
404 from `:9200` is Go's default "404 page not found" — **no router matched at that instant**;
the mechanism is unconfirmed. The `--accesslog=true --accesslog.fields.defaultmode=keep` flags on
the `traefik` service exist to diagnose the next occurrence: `docker compose -f
docker-dev/docker-compose.yml logs traefik` and look for the request with an empty `RouterName`.
The readiness gate in `deploy.sh` avoids the race (a 200 through `:9200` proves both a matched
router and a live backend), so a 404 *after* the gate is new evidence and the script fails loudly
saying so.
entrypoint (host 8089), not `web`/`:9200`, so it does not shadow `/api/deployments` either.
**The mechanism is the window between Traefik binding the `web` entrypoint and loading the
dynamic file-provider config** (`--providers.file.filename=/etc/traefik/dynamic.yml`). The
entrypoint accepts connections *before* the router table exists, and until it does, every request
gets Go's default `http.NotFound` handler. Reproduced 2026-08-18 by rapid-polling `:9200` across a
`docker restart otopcua-dev-traefik-1`: the port goes from connection-refused straight to **404 for
~65–160 ms**, then 200. The response body is exactly `404 page not found` (19 bytes), and the
access log — with the `--accesslog=true --accesslog.fields.defaultmode=keep` flags this service
carries for precisely this purpose — records it as:
```
192.168.97.1 - - [18/Aug/2026:11:58:26 +0000] "GET /health/ready HTTP/1.1" 404 19 "-" "-" 1 "-" "-" 0ms
```
**Empty `RouterName`, empty `ServiceName`, `0ms`** — nothing matched and no backend was dialled.
The competing candidate is **excluded**: a healthCheck'd service with no healthy server yet would
be a *matched* router (`otopcua-admin@file`) answering **503**, and zero 503s appear anywhere in
the log. Note the window has two sub-phases — the earliest 404s are not access-logged at all
(the accesslog handler is itself part of the not-yet-built dynamic chain), later ones are; both are
the same client-visible 404, so **absence from the access log does not mean absence of the 404**.
The readiness gate in `deploy.sh` closes the race (it loops on any non-200, and a 200 through
`:9200` proves both a matched router and a live backend), so a 404 *after* the gate is new evidence
and the script fails loudly saying so. A plain `docker compose up -d` also hides the window on this
rig without the gate helping: `up -d` blocks on the `depends_on: service_healthy` conditions and
returns ~30 s *after* Traefik starts, by which time the router table is long loaded.
## Tear down
+20 -7
View File
@@ -8,23 +8,36 @@
# end of the request: the AdminUI maps every route synchronously before RunAsync and
# the deploy endpoint has no 404 path (503/401/422/409/500 only), and Traefik answers
# a matched-router-with-all-servers-down as 503 "no available server". So the 404 means
# no Traefik router matched at that instant. Polling /health/ready through :9200 until
# it answers 200 proves both halves are in place — the router table carries the
# otopcua-admin router AND a backend is up — before the single, un-retried POST.
# no Traefik router matched at that instant.
#
# CONFIRMED 2026-08-18: the window is between Traefik binding the `web` entrypoint and
# loading its dynamic file-provider config — the port accepts connections before the
# router table exists, so requests get Go's default `404 page not found` (19 bytes),
# access-logged with an EMPTY RouterName/ServiceName and 0ms. Measured at ~65-160 ms
# across a `docker restart` of the traefik container. See docker-dev/README.md
# §"First-POST 404". Polling /health/ready through :9200 until it answers 200 proves
# both halves are in place — the router table carries the otopcua-admin router AND a
# backend is up — before the single, un-retried POST.
#
# A 404 AFTER the gate is therefore new evidence, not the known boot race: it should be
# investigated against the Traefik access log (`--accesslog=true` on the traefik service;
# `docker compose -f docker-dev/docker-compose.yml logs traefik`), which records the
# RouterName (empty on an unmatched request) for the failing call.
# RouterName (empty on an unmatched request) for the failing call. Caveat: the earliest
# 404s of the window predate the accesslog handler itself and are NOT logged at all, so
# an empty access log does not prove the 404 did not happen.
#
# Usage:
# ./deploy.sh # no body (matches the bare README snippet)
# ./deploy.sh artifact.json # send that file as the JSON request body
# cat artifact.json | ./deploy.sh
#
# NOTE (unverified against a live rig): the no-body invocation sends
# `Content-Type: application/json` with an empty body. Whether the minimal-API
# `DeployRequest?` parameter binds that as null or answers 400 has not been confirmed.
# NOTE (verified on the docker-dev rig 2026-08-18): the no-body invocation sends
# `Content-Type: application/json` with no body (or `Content-Length: 0` when stdin is a
# redirected-but-empty non-tty, which takes the `--data-binary @-` branch below). The
# minimal-API `DeployRequest?` parameter binds BOTH shapes as null — it does NOT 400 —
# and the handler falls back to `createdBy = "rest-api"` (DeployApiEndpoints.cs). Confirmed
# end to end: a bare `./deploy.sh` returned `HTTP 202 {"outcome":"Accepted",...}` and the
# resulting Deployment row carried `CreatedBy = rest-api`.
#
set -euo pipefail
+13 -1
View File
@@ -250,7 +250,7 @@ from the bytes emitted at compose time and never re-derived from the JSON, so an
costs at most one spurious "changed" revision after a runtime upgrade. Snapshot determinism is
unaffected — compression wraps the final bytes and reorders nothing.)
On the docker-dev rig the central pair carries `ConfigServe` (port `4055`, dev key) and stays `Direct`; the four site nodes carry `ConfigSource` (endpoints + matching key) defaulting to `Direct`. Flip only the site nodes with `OTOPCUA_CONFIG_MODE=FetchAndCache` at `docker compose up` — central keeps SQL and models the target topology.
On the docker-dev rig the central pair carries `ConfigServe` (port `4055`, dev key) and stays hardcoded `Direct` via its admin role; the four site nodes carry `ConfigSource` (endpoints + matching key) hardcoded `FetchAndCache` — mandatory for driver-only nodes since Phase 4, not a flip. There is no `OTOPCUA_CONFIG_MODE` env var in the compose file; central keeps SQL and models the target topology.
**`FetchAndCache` is mandatory on a driver-only node — per-cluster mesh Phase 4.** `Program.cs` now
registers `AddOtOpcUaConfigDb` only when the node carries the `admin` role, so a **driver-only**
@@ -418,6 +418,18 @@ replication stays inert until the sync port + peer are set.
| `LocalDb:Replication:MaxBatchSize` | `500` (library) | **Secondary** row-count cap on a batch — *and* the DB read-page size. `16` on the replicating pair. Since LocalDb 0.2.0 the wire message is bounded by `MaxBatchBytes`, not by this, so it is no longer the hand-tuned byte proxy the 4 MB cap once forced. It still matters because `OplogStore.ReadBatchAboveAsync`/`SnapshotStreamer` materialise a whole read page **before** the byte-budget split runs — `16` bounds that transient allocation at ≈2.7 MB for ≈171 KB artifact chunk rows. |
| `LocalDb:Replication:MaxBatchBytes` | `2 MB` (library) | **Primary** cap on one outbound delta/snapshot message: the summed serialized size of its entries, sized under gRPC's 4 MB receive limit. Left unset across the fleet. A single row larger than the budget is sent **alone** rather than stalling the stream. Added in LocalDb 0.2.0; needs no wire change, so a node on this version interoperates with any earlier peer in both directions. |
**These two keys also decide whether the node captures at all.** `LocalDbSetup.ReplicationIsConfigured` is
`PeerAddress` **OR** `ApiKey` non-blank — the OR because only the *dialling* half sets `PeerAddress`, so
keying on it alone would strip change capture from every passive node and leave the pair converging in one
direction only. `SyncListenPort` is deliberately **not** part of it (a port with no `ApiKey` is fail-closed
and syncs with nobody). A configured node registers all four tables with `baselineExistingRows: true`, so
turning replication on converges the rows **already in the file** and not merely subsequent writes; an
unconfigured node **deregisters** them at boot, dropping capture triggers an earlier build installed. ⚠️ The
sync handshake compares registered-table digests **fail-closed**, so flipping either key is a
both-nodes-together change: set it on both and restart both. On LocalDb 0.2.1 baselining flags a
**per-database** snapshot resync (every registered table, in full, both directions), so trim a long-running
`alarm_sf_events` buffer before enabling replication late.
Replication is **default-OFF** across the fleet; it is enabled per-pair as an opt-in. See
[`docs/operations/2026-07-20-localdb-pair-replication.md`](operations/2026-07-20-localdb-pair-replication.md)
for the enablement runbook (ApiKey handling, stop/start-together rule, tombstone-retention window, and the
@@ -82,8 +82,28 @@ Replication has two knobs, both under `LocalDb`:
> wire protocol is unchanged (0.1.x peers still sync), and the on-disk bookkeeping schema v1 → v2
> is upgraded **in place on open**, so an existing node's database file needs no operator action.
> Two behaviours changed that an operator should know: batching is now byte-budgeted (the two rows
> above), and `DeregisterReplicated` exists — this repo never calls it, so the deregistration
> symmetry rule and the HLC-anchor fix 0.2.1 shipped for it do not apply to an OtOpcUa node.
> above), and **both of 0.2.x's lifecycle APIs are now used** (2026-08-18) — see the box below.
> **⚠️ Registration follows this config, and flipping it is a BOTH-NODES change.** Since
> 2026-08-18 `LocalDbSetup.OnReady` installs the change-capture triggers only when the node is
> configured to replicate — the predicate is **`PeerAddress` OR `ApiKey` non-blank** (the OR because
> the passive node has no `PeerAddress`; `SyncListenPort` is deliberately not part of it, since a
> port with no key is fail-closed and syncs with nobody). Consequences at enablement time:
>
> - A configured node registers with **`baselineExistingRows: true`**, so the rows **already in the
> file** are seeded into the row-version ledger at the LWW floor (HLC `0`) and actually travel.
> Before this, enabling replication on a node that had been running converged on *subsequent
> writes only*. ⚠️ On 0.2.1 the snapshot flag is **per-database**: baselining streams *every*
> registered table in full, in both directions at once. **Trim a long-standing `alarm_sf_events`
> backlog before enabling replication late**, and expect one slow first sync.
> - An unconfigured node **deregisters** at boot — the capture triggers a pre-2026-08-18 build left
> behind are dropped and that table's oplog/row-version rows pruned. It logs one Information line
> naming the table count, and stays silent when there was nothing to clean.
> - The sync handshake compares **registered-table digests, fail-closed**, so a node that
> deregisters a table its peer still replicates stops syncing with a schema mismatch. **Set the
> keys on both nodes and restart both** — never one. (0.2.1's HLC-anchor fix now matters here:
> the clock is flushed inside the deregistration transaction, so a crash right after a
> deregister boot cannot bring the clock below stamps the peer already holds.)
Example (site-a-1 initiator, site-a-2 passive):
@@ -564,22 +564,41 @@ closed on the round-1 register. **None blocks the branch.**
one call. **Pre-existing and benign** — it self-heals on the next call and **no verdict is
affected** (a deferred stamp cannot serve a stale grant; the generation gate on `TryGet` is what
decides that, and it is unaffected). Recorded so the next reader does not re-derive it as a bug.
- **Closed by `441b34a3` (r3).** `InvalidateIfStale` is now a monotonic-max CAS **loop** with
the `<=` guard re-read inside each attempt, so a straggler that loses the CAS retries against
the moved stamp instead of falling out unpublished.
**S7**
- **Per-item decode health is last-writer-wins.** Pre-existing; now **pinned and documented**
rather than fixed, because changing it is a behaviour change to how a mixed-outcome chunk
reports driver health, not a test gap.
- **Closed by `4c161181` + `b35e423c` + `1765e300` (r3), for the READ path.** One
worst-state-wins accumulator per `ReadAsync` pass, one end-of-pass `_health` write, with
`LastSuccessfulRead` advanced whenever *any* item succeeded. ⚠️ **Modbus (all paths) and the
S7 WRITE path deliberately keep last-writer-wins** — recorded as a known asymmetry on the r3
register, not an oversight.
- **TM/CT decode at a non-zero device number still needs a real CPU.** The test exists and the
env var (`S7_TIMER_NUMBER_ADDRESSING=1`) is ready; python-snap7 cannot serve it (see the
BIT-address quirk above).
- **Carried (r3).** Unchanged — still blocked on hardware; explicitly out of scope in the r3
plan.
**docker-dev**
- **The first-POST 404's mechanism is unconfirmed** until the new access log catches an
occurrence. The gate prevents the symptom; the cause is still open.
- **Closed by `3f04a4d4` (r3).** Mechanism: the window between Traefik binding the `web`
entrypoint and loading the dynamic file-provider config — the listener accepts before the
router table exists (~65–160 ms on the rig; empty `RouterName`/`ServiceName`, `0ms`, Go's
`404 page not found`). The 503 candidate is excluded on evidence. ⚠️ **Not all 404s are
access-logged** — the accesslog handler is itself part of the not-yet-built dynamic chain, so
an empty log does not prove absence.
- **The no-body `POST` `Content-Type` binding is unverified against a live rig** — carried as a
header NOTE in `deploy.sh` rather than silently assumed correct.
- **Closed by `3f04a4d4` (r3).** Verified live across four request shapes: `DeployRequest?`
**binds null** (no 400, no 415), the request returns **202 Accepted**, and the handler's
fallback puts `CreatedBy = rest-api` — confirmed in the ConfigDb.
**SQL test infrastructure**
@@ -587,3 +606,4 @@ closed on the round-1 register. **None blocks the branch.**
**accepted**: two test processes racing on the same instance can have one reap what the other
just planted. The 24 h age floor makes it vanishingly unlikely in practice, and the alternative
(a lock table on a shared dev server) costs more than it buys.
- **Carried (r3).** Still accepted, unchanged; explicitly out of scope in the r3 plan.
+883
View File
@@ -0,0 +1,883 @@
# Perf Follow-ups Round 3 Implementation Plan
> **For Claude:** REQUIRED SUB-SKILL: Use superpowers-extended-cc:subagent-driven-development
> to implement this plan task-by-task (per the standing preference: Opus implementers,
> classification-driven review chains).
**Goal:** Close the actionable items in the round-2 follow-up register
(`docs/plans/2026-08-17-perf-followups-r2.md` §"Follow-up register") and run the
still-unexercised local live gates (FetchAndCache legs, alarm-bearing surgical ratchet,
ACL-enabled enforcement, docker-dev first-POST-404 catch), on branch `perf/followups-r3`
off master merge `49d05bc2`.
**Architecture:** Two surgical code fixes in already-reviewed code (the ACL cache's
single-shot CAS becomes a monotonic-max loop; S7 read-pass health becomes worst-state-wins
aggregation), one doc-staleness fix found during exploration, and four live gates on the
local docker-dev rig (OrbStack) sequenced on one rig session. No new subsystems.
**Tech Stack:** .NET 10 / C#, xUnit + Shouldly, docker-dev rig (OrbStack), Traefik v3.1
access log, Client.CLI, Chrome browser automation for AdminUI authoring.
**Out of scope (recorded, deliberately not here):**
- **TM/CT decode at a non-zero device number** — needs a real S7 CPU; the test exists and
is env-gated on `S7_TIMER_NUMBER_ADDRESSING=1`. Nothing to do until hardware exists.
- **Cross-process plant-vs-reap race on the shared SQL server** — accepted in r2; the 24 h
age floor is the mitigation. No work.
- **Modbus per-tag health last-writer-wins** — Task 2 fixes S7 only (the recorded item).
Modbus has the same shape (`ModbusDriver.ReadAsync:493/511/518` + the coalesced path);
fixing it here doubles the blast radius of a watchdog-adjacent change. Recorded in this
round's register as a deliberate asymmetry.
- **S7 write-path per-item health** (`S7Driver.cs:1575/1633/1645/1654`) — same
last-writer-wins shape on `WriteAsync`; out of scope for the same reason, recorded.
- Historian end-to-end live gate — needs the `wonder-sql-vd03` VPN (user-driven).
- HistorianGateway batch `WriteLiveValues` RPC — cross-repo.
- Load-scale throughput — needs a load harness; not defined enough to gate.
**Execution rules (unchanged from prior rounds):** shared checkout — explicit-pathspec
`git add`/`git commit -- <files>` only (never a bare commit); never checkout/switch/reset/
stash/clean; retry on `index.lock` and CS2012/MSB3030 build races; reviewers judge commits
via `git show`; falsification mutations applied AND reverted via Edit (never git), run
against a freshly built binary (never `--no-build` after a mutation), and labeled honestly
("pin, not red-first" where the behaviour predates the test; "probabilistic red" where the
mutation trips a race). Live-gate rig work is serial — one rig session, Tasks 4→5→6→7 in
that order, images built from the branch tip AFTER Tasks 1–3 land so the gates also
regression the new code.
---
### Task 1: ACL `InvalidateIfStale` — monotonic-max CAS loop (publication never deferred)
**Classification:** high-risk
**Estimated implement time:** ~4 min
**Parallelizable with:** Tasks 2, 3
**Files:**
- Modify: `src/Server/ZB.MOM.WW.OtOpcUa.OpcUaServer/Security/SessionAclDecisionCache.cs:453-461`
(+ the XML remarks block `:430-452`)
- Test: `tests/Server/ZB.MOM.WW.OtOpcUa.OpcUaServer.Tests/SessionAclDecisionCacheTests.cs`
**Context.** The r2 register records: the single-shot CAS in `InvalidateIfStale` can defer
stamp publication by one call. Two callers read the same `seen` baseline; gen-N wins the
CAS, gen-N+1's CAS fails against the moved stamp and falls out with **no retry** — N+1 is
not published on that call, so its `TryGet` misses and its `Set` is dropped at `:223`.
Benign (verdict safety lives in the per-shard generation gate), but it costs a lost store
exactly in the post-deploy window. Current code:
```csharp
private void InvalidateIfStale(long generation)
{
var seen = Interlocked.Read(ref _generation);
if (generation <= seen) return;
if (Interlocked.CompareExchange(ref _generation, generation, seen) == seen) ClearAll();
}
```
**Step 1: Write the racing pin (red against current code — probabilistic red, say so).**
```csharp
[Fact]
public void Concurrent_lookups_at_mixed_generations_always_publish_the_highest()
{
// The single-shot CAS defect: when gen-1 wins the shared-baseline race, gen-2's CAS
// fails and is never retried, leaving Generation == 1. Red is probabilistic per
// round; 200 barrier-synchronised rounds make it effectively certain.
for (var round = 0; round < 200; round++)
{
var cache = /* fresh cache, generation seed -1 */;
using var barrier = new Barrier(2);
var low = Task.Run(() => { barrier.SignalAndWait(); /* TryGet at generation 1 */ });
var high = Task.Run(() => { barrier.SignalAndWait(); /* TryGet at generation 2 */ });
Task.WaitAll(low, high);
cache.Generation.ShouldBe(2L,
$"round {round}: the newer generation must publish even when it loses the CAS race");
}
}
```
Use the ordinary `TryGet` lookup path (as the straggler test at `:286` does), NOT
`AdvanceGenerationForTest` — the defect lives in the lookup path's invalidation.
**Step 2: Run it, observe red.** `dotnet test tests/Server/ZB.MOM.WW.OtOpcUa.OpcUaServer.Tests --filter "FullyQualifiedName~Concurrent_lookups_at_mixed_generations"` — expect FAIL within a few rounds. If 200 rounds pass green against unmodified code, the test is not exercising the race — fix the test, do not proceed.
**Step 3: Implement the monotonic-max loop.**
```csharp
private void InvalidateIfStale(long generation)
{
while (true)
{
var seen = Interlocked.Read(ref _generation);
if (generation <= seen) return; // guard re-checked per attempt
if (Interlocked.CompareExchange(ref _generation, generation, seen) == seen)
{
ClearAll();
return;
}
}
}
```
Invariants (update the XML remarks `:430-452` to say all of this):
- The `<=` guard is INSIDE the loop against a fresh read — a straggler that lost a CAS
re-reads the newer stamp and exits; hoisting the guard reintroduces the 98d6a190 defect.
- Only the thread whose CAS moved the stamp clears (elected clear preserved). A rollover
now legitimately clears once per distinct generation (N then N+1) — bounded by
generations, not request volume.
- The loop self-terminates: each iteration exits via the guard or CASes against a strictly
larger `seen`, and `_generation` only rises.
- The `-1` seed still admits generation 0.
**Step 4: Run the new test + the full cache suite.** All 18 green (17 existing + 1 new),
especially `A_straggler_from_an_older_generation_neither_clears_nor_rolls_the_stamp_back`
(`:286`) and `No_hit_ever_returns_a_verdict_from_another_generation` (`:363`).
**Step 5: Falsify.** Via Edit, revert the loop to the single-shot form (fresh build, not
`--no-build`) → the new test must go red (probabilistic; report the failing round). Revert
via Edit. Separately, move the `<=` guard outside the loop → the straggler test at `:286`
must go red. Revert.
**Step 6: Commit.**
```bash
git add -- src/Server/ZB.MOM.WW.OtOpcUa.OpcUaServer/Security/SessionAclDecisionCache.cs \
tests/Server/ZB.MOM.WW.OtOpcUa.OpcUaServer.Tests/SessionAclDecisionCacheTests.cs
git commit -m "fix(acl): make InvalidateIfStale a monotonic-max CAS loop — stamp publication is never deferred" -- <same paths>
```
---
### Task 2: S7 read-pass health — worst-state-wins aggregation
**Classification:** high-risk
**Estimated implement time:** ~5 min
**Parallelizable with:** Tasks 1, 3
**Files:**
- Modify: `src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7/S7Driver.cs` — per-item health sites
`:647` (per-tag loop), `:828` (multi-var decode loop), `:941` (span member loop),
`RecordReadFailure:1010-1046`, plus one end-of-pass write in `ReadAsync`
- Test: `tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests/S7SpanReadParityTests.cs`
(flip the `:423` pin; doc-comment `:389-393` rewritten; new tests)
**Context.** The r2 register records: per-item decode health is last-writer-wins — a mixed
chunk reports whatever the LAST item's outcome was, so `Healthy` can be reported for a
pass that had failures (pinned at `:396-423`), and the `:1023` access-denied `Faulted` can
be overwritten by a later good item. Fix = aggregate one outcome per `ReadAsync` pass.
**Watchdog contract (MUST hold — CLAUDE.md comms-loss section):** `Degraded` means
connected-but-some-bad; `LastSuccessfulRead` advances on ANY success and is preserved on
failure. The aggregate write must advance `LastSuccessfulRead` when ANY item succeeded,
even when the state lands `Degraded`/`Faulted` — gating it on `Healthy` turns the fix into
a false-positive reconnect storm.
**Step 1: Red tests first** (the flip IS red-first; the rest are new):
1. Flip `:423`: `One_undecodable_multi_var_item...` now expects `Degraded` (rename to say
worst-state-wins; rewrite doc-comment `:389-393` — the last-writer-wins pin is being
deliberately retired).
2. New: a mixed multi-var pass reports `Degraded` AND `LastSuccessfulRead` is advanced
(non-null / newer than the pre-pass value).
3. New: span path — one bad member decode then a good member ⇒ `Degraded` (today: Healthy).
4. New: an access-denied `PlcException` on one tag followed by a success ⇒ state stays
`Faulted` (ordering `Healthy < Degraded < Faulted`), `LastSuccessfulRead` advanced.
Use the per-tag path if the multi-var fake can't produce a per-item PlcException.
5. Must-stay-green: `:326` (`A_failing_multi_var_chunk_falls_back...`, asserts Healthy at
`:346`) and `:432` (short answer, Healthy at `:447`) — a multi-var REQUEST fault whose
tags are re-served Good by the per-tag tail is NOT a failed outcome. The chunk-fault
catch (`:806-814`) stays outside the aggregate.
**Step 2: Run, observe red on 1–4** (each for its own reason; report per-test).
**Step 3: Implement.** A small per-pass accumulator threaded through the pass:
```csharp
private sealed class ReadPassOutcome
{
public bool AnySuccess;
public DriverState WorstFailure = DriverState.Healthy; // Healthy = none recorded
public string? FirstError; // first failure is causal
public void RecordSuccess() => AnySuccess = true;
public void RecordFailure(DriverState state, string message)
{
if (Rank(state) > Rank(WorstFailure)) WorstFailure = state;
FirstError ??= message;
static int Rank(DriverState s) => s switch
{
DriverState.Faulted => 2, DriverState.Degraded => 1, _ => 0
};
}
}
```
- The three success sites (`:647`, `:828`, `:941`) call `outcome.RecordSuccess()` instead
of assigning `_health`.
- `RecordReadFailure` takes the outcome, records `(Degraded|Faulted, message)` into it
instead of assigning `_health`, and KEEPS its `_plcDead` / `MarkConnectionDeadIfFatal`
side effects immediate. It still returns the per-item status code.
- One `_health` write at the end of the `ReadAsync` try body (NOT `finally` — the OCE
arms at `:649`/`:801`/`:920` rethrow and must skip it):
```csharp
_health = new DriverHealth(
outcome.WorstFailure == DriverState.Healthy
? DriverState.Healthy : outcome.WorstFailure,
outcome.AnySuccess ? now : _health.LastSuccessfulRead,
outcome.WorstFailure == DriverState.Healthy ? null : outcome.FirstError);
```
- Untouched: the `:567` connect-failure early return; `HandlePollError` (`:1980`); the
entire write path; init/shutdown sites. `ReadSpanAsync` / `ReadLeftoversByMultiVarAsync`
gain an outcome parameter — signature changes, no logic movement.
**Step 4: Run the full S7 suite** (`dotnet test tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests`)
— all green including the parity anchor `:202` (all-members-fail ⇒ Degraded both paths).
**Step 5: Falsify.** Via Edit: (a) make the end-of-pass write use the LAST recorded state
instead of the worst → tests 1/3/4 red; (b) gate `LastSuccessfulRead` advancement on the
state being Healthy → test 2 red. Fresh builds. Revert via Edit.
**Step 6: Commit** (explicit pathspec, message
`fix(s7): read-pass health is worst-state-wins — a mixed pass can no longer report Healthy`).
---
### Task 3: Fix stale `OTOPCUA_CONFIG_MODE` docs
**Classification:** trivial
**Estimated implement time:** ~2 min
**Parallelizable with:** Tasks 1, 2
**Files:**
- Modify: `docs/Configuration.md` (~line 253) — "Flip only the site nodes with
`OTOPCUA_CONFIG_MODE=FetchAndCache` at `docker compose up`" is stale
- Modify: `CLAUDE.md` — same sentence in the `ConfigSource`/`ConfigServe` section
- Check-and-fix if matched: `grep -rn "OTOPCUA_CONFIG_MODE" docs/ docker-dev/ CLAUDE.md`
**Spec.** Phase 4 made `FetchAndCache` mandatory on driver-only nodes
(`ConfigSourceOptionsValidator` fails host start on `Direct`), and the rig's four site
nodes are hardcoded `ConfigSource__Mode: "FetchAndCache"` in
`docker-dev/docker-compose.yml:572-579/691-696/787-792/858-863`. The env var appears
nowhere in the compose file; setting it is a no-op. Rewrite both sentences to state: the
site nodes run `FetchAndCache` unconditionally (mandatory for driver-only nodes since
Phase 4); central stays `Direct` via its admin role. No review (doc-only). Commit with
explicit pathspec, message `docs(config): OTOPCUA_CONFIG_MODE is gone — site nodes are hardcoded FetchAndCache (Phase 4)`.
---
### Task 4: Live gate — docker-dev first-POST-404 catch + no-body POST binding
**Classification:** live-gate (rig session step 1 — FRESH BOOT window)
**Estimated implement time:** ~10 min wall (mostly rig boot)
**Parallelizable with:** none (rig serial; runs after Tasks 1–3 land, images built from branch tip)
**Files:**
- Possibly modify: `docker-dev/deploy.sh` (the header NOTE about no-body binding),
`docker-dev/README.md` (§"First-POST 404" — mechanism note if caught)
- Evidence: write to the scratchpad; Task 8 folds it into the plan's Outcomes
**Procedure:**
1. Fresh rig: `docker compose -f docker-dev/docker-compose.yml down -v` then
`up -d --build` (build mandatory — the branch tip must be in the images).
2. IMMEDIATELY run `./docker-dev/deploy.sh` (no body). Its 2 s `/health/ready` poll rides
through Traefik during the boot window — every poll is access-logged with
`defaultmode=keep`, and an unmatched request shows an EMPTY `RouterName`.
3. After the deploy completes (or fails), capture
`docker compose -f docker-dev/docker-compose.yml logs traefik` and extract every
non-2xx access-log line from the boot window. **If any 404 appears:** name the
mechanism from `RouterName`/`ServiceName`/timing (the r2 elimination says: AdminUI
cannot 404 that path; backend-down is 503; so 404 = no router matched at that instant
— presumably the window before the dynamic-config file provider loads or before the
health-checked service has a server). Update `docker-dev/README.md` §"First-POST 404"
with the observed mechanism. **If it does not reproduce:** record that honestly —
"did not reproduce under the readiness gate; register item stays open" — do NOT
invent a mechanism.
4. No-body POST binding: with the rig ready, run `./docker-dev/deploy.sh` bare and record
the HTTP status + response body. Determine whether the minimal-API `DeployRequest?`
binds null (and what the endpoint then does) or 400s. Update the header NOTE in
`deploy.sh` from "unverified" to the observed behaviour, and `README.md` if wrong.
5. Leave the rig UP for Task 5.
Commit any `deploy.sh`/`README.md` edits (explicit pathspec). Report: the access-log
excerpt, the no-body verdict, and whether the 404 reproduced.
---
### Task 5: Live gate — FetchAndCache legs on the running rig
**Classification:** live-gate (rig session step 2)
**Estimated implement time:** ~8 min wall
**Parallelizable with:** none (rig serial, after Task 4)
**Procedure** (rig already up from Task 4; a deploy already ran):
1. **Fetch + verify:** `docker compose -f docker-dev/docker-compose.yml logs site-a-1 |
grep -E "Fetched \+ verified artifact"` — expect
`Fetched + verified artifact for {DeploymentId} from http://central-… ({Bytes} bytes).`
2. **Served (central side):** `logs central-1 central-2 | grep "Served artifact"` —
`Served artifact for {DeploymentId} ({Bytes} bytes, {Chunks} chunks)`.
3. **Applied-from-fetch + cached:** `logs site-a-1 | grep -E "applied fetched deployment|cached applied deployment"` — both lines must appear (the `fetched` variant, NOT the
Direct `applied deployment` form).
4. **Boot-from-cache:** `docker compose restart site-a-1`, wait for boot, then
`logs site-a-1 | grep "FetchAndCache boot"` — expect
`restored served state for deployment {Id} (rev {Rev}) from the LocalDb pointer.`
5. **Absence proof:** on site-a-1 logs, assert NO occurrence of `entering Stale`,
`ConfigDb back`, or the Direct-form `applied deployment {Id} (rev` (without
`fetched`). A FetchAndCache node must never reach Stale.
6. Evidence excerpts to the scratchpad for Task 8. Rig stays UP for Task 6.
No commit expected. If any leg fails, STOP and report — that is a real regression, not a
gate formality.
---
### Task 6: Live gate — alarm-bearing surgical ratchet
**Classification:** live-gate (rig session step 3)
**Estimated implement time:** ~12 min wall
**Parallelizable with:** none (rig serial, after Task 5)
**Context.** The surgical-deploys classifier routes an alarm-bearing raw-tag delta
(`Alarm != null` on EITHER side) to `Rebuild`; a whitelisted non-alarm attribute delta
(`Writable` among them) is surgical. Never observed live. The ONLY seam is the applier
summary line (`AddressSpaceApplier.cs:322-326`):
`applied plan (kind={Kind}, …, surgicalRawTags={SurgicalRaw}, …, rebuild={Rebuild})`.
**Procedure:**
1. Pick TWO alarm-free raw tags in the rig's seeded config (browse `/raw` via AdminUI at
`http://localhost:9200`, login disabled — or read the ConfigDb `Tag` rows). Call them
TagS (surgical lever) and TagA (alarm lever).
2. **Surgical control first:** toggle TagS's Access level (Read ↔ ReadWrite) — via the
RawTagModal in the browser, or a direct ConfigDb UPDATE of the tag row (the rig's DB
on `10.100.0.35,14330`; acceptable for a classifier gate, note which route was used).
Deploy via `./docker-dev/deploy.sh`. Expect on central-1:
`kind=AttributeOnly, … surgicalRawTags=1, … rebuild=False`.
3. **Alarm add ⇒ rebuild:** add `"alarm": {"alarmType": "OffNormalAlarm", "severity": 500}`
to TagA's `TagConfig` JSON (raw-JSON textarea — available because the seeded device is
a Galaxy driver, which has no typed editor — or the same direct-DB route). Deploy.
Expect `kind=Rebuild, … surgicalRawTags=0, … rebuild=True`.
4. **Alarm remove ⇒ rebuild:** remove the `alarm` object, deploy, expect `rebuild=True`
again (Alarm != null on the PREVIOUS side also disqualifies).
5. **Restore:** revert TagS's access level, deploy once more (surgical again — also
re-proves the ratchet is per-deploy, not latched).
6. Evidence: the four applier lines (grep `docker compose logs central-1 site-a-1 |
grep "applied plan (kind="` — note which nodes applied). Scratchpad for Task 8. Rig
stays UP for Task 7.
No commit expected. Failure of the expected routing = STOP and report.
---
### Task 7: Live gate — ACL-enabled enforcement on site-a (re-shaped cache)
**Classification:** live-gate (rig session step 4)
**Estimated implement time:** ~20 min wall
**Parallelizable with:** none (rig serial, after Task 6)
**Context.** `Security:Acl:Enabled` has never been exercised live since the r1/r2 cache
re-shape (per-key shards, generation stamp, Task 1's CAS loop). Site-a is the env-gated
demo pair: `OTOPCUA_ACL_ENABLED=true` reaches site-a-1/-2 only
(`docker-compose.yml:585/:702`); site-b stays off as the A/B control. Site-a OPC UA:
host ports 4842/4843; site-b: 4844/4845. Keys/grants reach driver-only site nodes ONLY
via the deployment artifact — every authoring step needs a deploy after it.
**Procedure:**
1. Restart site-a gated: `OTOPCUA_ACL_ENABLED=true docker compose -f docker-dev/docker-compose.yml up -d site-a-1 site-a-2`. Confirm the boot Warning on both:
`node ACL enforcement is ENABLED — EVERY data-plane operation … requires a matching NodeAcl grant`.
2. Mint a key: AdminUI `/apikeys` (Chrome automation; login disabled) — Name
`r3-acl-gate`, Principal `r3gate`. COPY the one-time `otua_…` credential immediately.
3. Author a grant: `/clusters/{site-a cluster id}/acls/new` — Principal `r3gate`, scope
picked via the AclScopePickerModal on a WRITABLE raw tag (or its device — inheritance
covers the tag), permissions: the Operator bundle (must include Browse/Read/
WriteOperate). Save; expect no "authorizes nobody" warning.
4. Deploy (`./docker-dev/deploy.sh`) so the key + grant ride the artifact to site-a.
Confirm on site-a-1: `data-plane authority generation {G} installed (… keys=…, grants=…)`.
5. **The load-bearing ALLOW:** Client.CLI write through the grant —
`dotnet run --project src/Client/ZB.MOM.WW.OtOpcUa.Client.CLI -- write -u opc.tcp://localhost:4842 -n "<granted raw tag NodeId>" -v <value> -U apikey -P otua_…`
Expect success (the session carries NO server-wide role; the grant alone authorizes —
a deny-only gate would pass against a build where the ACL is never consulted).
Note: the rig's Galaxy driver has no live gateway, so the DEVICE write may fail
downstream — the gate is that the request passes the ACL (not `BadUserAccessDenied`);
any downstream Bad status is fine and should be reported as such.
6. **Deny controls:** (a) same write WITHOUT credentials (anonymous) ⇒ denied; (b) a
read/browse on a node OUTSIDE the granted scope with the key ⇒ withheld (grep
site-a-1 for `AclGate: denied {Operation} on {NodeId} for principal r3gate`).
7. **Revocation reaches the artifact path:** disable the key on `/apikeys`, deploy,
confirm a NEW `data-plane authority generation {G+1} installed` on site-a-1, and the
same CLI write now fails auth (`ApiKeyAuth: denied — no enabled, unexpired key`).
8. **Teardown:** restore site-a ungated (`docker compose up -d site-a-1 site-a-2` without
the env), optionally delete the gate key/grant, and `docker compose down` the rig
unless Task 8 needs it. Evidence excerpts to the scratchpad.
No commit expected. If Chrome automation of the scope picker proves impractical, direct
ConfigDb inserts for `ApiKey`/`NodeAcl` rows are acceptable ONLY as a fallback — say so,
and keep the key's peppered HMAC consistent with the rig pepper
(`docker-dev-apikey-pepper-not-for-production`); minting via the UI is strongly preferred
because it exercises the real authoring path.
---
### Task 9: Roslyn evaluator racing test — remove the timing assumption
**Classification:** standard
**Estimated implement time:** ~5 min
**Parallelizable with:** Task 10 (disjoint files); independent of the rig tasks
**Origin:** ScadaBridge deferred-work register row 38, relayed cross-session 2026-08-18
(coordinated by the ScadaBridge session on Joe's behalf).
**Files:**
- Modify: `tests/Server/ZB.MOM.WW.OtOpcUa.Host.IntegrationTests/RoslynVirtualTagEvaluatorTests.cs`
(`Evaluate_racing_ClearCompiledScripts_never_fails_with_disposed`, ~:391 — renamed by
the implementation to `Evaluate_racing_ClearCompiledScripts_never_leaks_a_raw_disposed_failure`)
**Spec.** The test is load-fragile: it fails under full-solution parallel test load but
passes 3/3 in isolation. Its design assumes at most ONE `ClearCompiledScripts` lands
inside a single evaluation (so the product's one-shot retry suffices); under contention
two can land and the retry legitimately exhausts. Test-design issue, NOT a product bug.
Fix by removing the timing assumption while keeping the original intent (no
disposed-script failure ever ESCAPES the retry): either bound the clear cadence relative
to observed evaluation latency, or assert on retry-exhaustion behaviour instead of zero
failures — implementer picks whichever preserves intent with less machinery, documents
the choice in the test doc-comment, and demonstrates the test survives a
full-parallel-load run (run the containing suite alongside another heavy suite, or
repeat-run the suite ≥5×; report what was actually run).
---
### Task 10: LocalDb conditional registration + baseline + deregister self-heal
**Classification:** high-risk
**Estimated implement time:** ~8 min
**Parallelizable with:** Task 9 (disjoint files)
**Origin:** ScadaBridge deferred-work register row 39, relayed cross-session 2026-08-18.
ScadaBridge closed the same class with conditional registration + boot-time self-heal
(`Host/SiteLocalDbSetup.cs`, arch-review WP1.3/WP3.3); port that pattern here.
**Files:**
- Modify: `src/Server/ZB.MOM.WW.OtOpcUa.Host/Configuration/LocalDbSetup.cs` (`OnReady`,
registration at :63-66)
- Read for the predicate: `src/Server/ZB.MOM.WW.OtOpcUa.Host/Configuration/LocalDbRegistration.cs`
(`LocalDb:SyncListenPort`, `LocalDb:Replication:*` keys)
- Modify: `tests/Server/ZB.MOM.WW.OtOpcUa.Host.IntegrationTests/LocalDbSetupTests.cs`
(the registered-table-set + ordering pins — update DELIBERATELY, say so in the diff)
- Modify: `CLAUDE.md` LocalDb section — the two bullets recording unconditional
registration as deliberate ("DeregisterReplicated exists and this repo deliberately
does not call it" / "Consequently, baselineExistingRows is not used either") must be
rewritten to record the new conditional shape and why it changed.
**Spec.**
- "Replication configured" = `PeerAddress` OR `ApiKey` present (OR, because only the
dialling half sets PeerAddress while the passive half carries just the key + listen
port — verify the exact key names against `LocalDbRegistration`).
- Configured ⇒ `RegisterReplicated(table, baselineExistingRows: true)` per table, in the
existing DDL→register order (the ordering is load-bearing and pinned) — seeds
row-versions at the LWW floor and flags snapshot resync, so late-enabled replication
on an established node converges on EXISTING rows, not just subsequent writes.
- NOT configured ⇒ `DeregisterReplicated` on every table at boot — idempotent self-heal:
drops stale triggers, prunes oplog/row-version rows, logs once at Information when it
actually cleaned something (and stays silent when there was nothing to clean).
- Registration stays per-table in a loop (0.3.0 made the snapshot flag per-table; the
loop preserves that granularity if the pin ever moves).
- **Pin note:** this repo is on `ZB.MOM.WW.LocalDb 0.2.1`, which has both
`baselineExistingRows` and `DeregisterReplicated`. Do NOT bump the pin unless a needed
API is genuinely absent at 0.2.1 — if it is, stop and report before bumping.
- **Traps (both hit by ScadaBridge):** the registered-table set is pinned by
`LocalDbSetupTests` — update the pins deliberately with the behaviour change named in
the test doc-comment; and deregistration must be pair-symmetric — the sync handshake
compares registered-table digests fail-closed, so flipping registration is a
both-nodes-together change. Record the pair-symmetry consequence in CLAUDE.md and in
the rollout note (docker-dev site-a has replication ON and was enabled from fresh, so
current impact is low; the change is correctness-before-someone-enables-late).
- Tests: pin the new predicate both ways (configured ⇒ registered with baseline;
unconfigured ⇒ deregistered/self-healed) and keep the DDL→register ordering pin green.
---
### Task 8: Close-out — sweep + Outcomes + register annotations
**Classification:** close-out (blockedBy: all)
**Estimated implement time:** ~15 min
1. Full build (`dotnet build ZB.MOM.WW.OtOpcUa.slnx`) — 0 errors; warning count vs r2's
904 explained.
2. Full unit sweep, every `*.Tests` project, per-project; reconcile the passed-count
delta against Tasks 1–2's added/changed tests exactly. DB suites must RUN (AdminUI
`0 skipped`, Configuration `0 skipped`).
3. Write `## Outcomes` on this plan: sweep record, per-task table, all four live-gate
evidence excerpts, falsification notes, and this round's register (Modbus + S7-write
asymmetry, TM/CT real-CPU, cross-process reap race carried; whatever Tasks 4–7 leave
open).
4. Annotate the r2 register in `2026-08-17-perf-followups-r2.md` append-only with
"Closed by <sha> (r3)" / "Gated live (r3)" sub-bullets.
5. Update the `.tasks.json` ledger; commit docs with explicit pathspec.
---
## Outcomes
*Written at close-out, 2026-08-18, on branch `perf/followups-r3`. All 10 tasks complete
(8 planned + Tasks 9/10 joined mid-round by amendment `088a1a1e`). This round is a
**follow-up round**: every code item it closes was opened by the round-2 register in
`2026-08-17-perf-followups-r2.md`, and that register is annotated in place with the closing
SHAs. Tasks 9 and 10 are **cross-repo** — rows 38 and 39 of the ScadaBridge deferred-work
register, relayed on Joe's behalf and closed here.*
### Sweep record
**The docker-dev rig was torn down BEFORE the sweep** (`docker compose -f
docker-dev/docker-compose.yml down`, 0 `otopcua-dev-*` containers remaining). This is not
housekeeping — a running rig un-skips env-gated tests and would have made the skip count
incomparable to the r2 baseline. It did: `Host.IntegrationTests` reports **229 / 0 / 2** with
the rig up and **226 / 0 / 5** with it down, the same 231 total.
`dotnet build ZB.MOM.WW.OtOpcUa.slnx --no-incremental` → **0 errors, 904 warnings** —
**identical to r2's 904**, not merely close. The non-incremental flag matters: an incremental
build reported 896 because up-to-date projects re-emit nothing. The two pre-existing families
are unchanged in kind and in count (`OTOPCUA0001` CapabilityInvoker analyzer on test call sites
1012, `xUnit1051` cancellation-token advice 696, plus the small CS tail). **No delta to
attribute** — this round's new test call sites happened to land in files already carrying the
same families, so nothing moved.
Full unit sweep — every `*.Tests` project, run per-project with `--no-build` after the single
solution build, against the tree at `837d8a17`. `*.IntegrationTests` are build-only by
convention (as in r2); `Host.IntegrationTests` is recorded **separately below** because r2's
baseline did not include it.
**43 / 43 test projects green.**
| | Round 2 | **This round** | Δ |
|---|---|---|---|
| Passed | 10 370 | **10 377** | **+7** |
| Failed | 0 | **0** | — |
| Skipped | 19 | **19** | — |
| **Total** | 10 389 | **10 396** | +7 |
The +7 reconciles **exactly** against the two suites this round added tests to, with nothing
unaccounted for — confirmed at class granularity, not just project granularity:
| Project | Round 2 | This round | Δ | Source |
|---|---|---|---|---|
| `OpcUaServer.Tests` | 481 | **482** | +1 | `SessionAclDecisionCacheTests` 17 → **18** (T1) |
| `Driver.S7.Tests` | 401 | **407** | +6 | `S7SpanReadParityTests` 13 → **19** (T2) |
⚠️ **The S7 +6 is the sum of three separate commits, not one addition** — `4c161181` (+3, the
worst-state-wins pins), `b35e423c` (+1, the observe-nothing guard the spec review found), and
`1765e300` (+2, the code-review round's severity-escalation and OCE-flush pins). T3 (docs) and
T4–T7 (live gates) added no tests by design.
**All 19 skips are the pre-existing env-gated ones, project for project** — `Core.Tests` (1),
`Driver.Galaxy.Tests` (8), `Driver.Historian.Gateway.Tests` (6, the `LiveIntegration` category
needing the `wonder-sql-vd03` VPN), `OpcUaServer.Tests` (1), `Runtime.Tests` (3). **This round
added no skips**, and `Runtime.Tests` is unchanged at 637 / 3 as expected.
The DB-backed suites ran **against a reachable** `10.100.0.35,14330` — executed, not skipped:
`AdminUI.Tests` **1540 passed / 0 skipped**, `Configuration.Tests` **190 passed / 0 skipped**.
#### `Host.IntegrationTests` (T9 + T10) — **226 passed / 0 failed / 5 skipped** (231 total)
Not part of the r2 baseline, so there is no measured predecessor. Derived from the diff against
the merge-base `49d05bc2`, the expected delta is **+9**, all plain `[Fact]` (no theories, so
attribute count equals test count): `LocalDbSetupTests` **7 → 15** (+8) and `LocalDbWiringTests`
**6 → 7** (+1); `RoslynVirtualTagEvaluatorTests` stays **20 → 20** because T9 reworked its
racing test *in place*. ⚠️ **The task brief's "LocalDbSetupTests 13 → 15" was an intermediate
reading** — 13 was the count after `3e62f161` and before the `df533916` review round; against
the merge-base it is 7 → 15. The 5 skips are the rig/fixture-gated
`DriverTestConnectE2eTests` (2, Modbus fixture) and `DriverProbeHandshakeE2eTests` (3) — three
of which run when the rig is up, which is exactly the teardown effect noted above.
#### ⚠️ One flake, isolated and cleared — `Client.CLI.Tests`
The first sweep pass reported `Client.CLI.Tests` **1 failed / 103 passed**:
`LoggerLifecycleTests.ConfigureLogging_DisposesPreviousLogger_BeforeReassigning`, asserting
`trackerSink.Disposed` was `False`. **Isolation re-runs cleared it: the single test alone
1/1 green, and the whole project green twice more (104 / 104 both times).**
The mechanism is a **pre-existing intra-assembly race on the process-global
`Serilog.Log.Logger` static**, not a regression: the test assigns `Log.Logger` at
`LoggerLifecycleTests.cs:26` and then asserts, at `:41`, that the command's `ConfigureLogging`
disposed *that* instance — but the class carries no `[Collection]` and no
`DisableTestParallelization`, so any concurrently-scheduled test whose command path also calls
`ConfigureLogging` (which does `Log.CloseAndFlush()` then reassigns) can swap the global out
from under it in that window. **No commit in this round touches `src/Client` or `tests/Client`**
(`git log 49d05bc2..HEAD -- src/Client tests/Client` is empty). Recorded here rather than in
the register, which the close-out brief scoped explicitly; it is a worthwhile one-line fix
(pin the class to a serial collection) whenever someone is next in that file.
### Per-task outcomes
| # | Task | Commit(s) | Outcome + deviation |
|---|---|---|---|
| 1 | ACL `InvalidateIfStale` — monotonic-max CAS loop | `441b34a3`, `f4b91dbb`, `e29fab19` | Done; closes the r2 register's deferred-publication item. ⚠️ **The plan's own 200-round `Barrier` harness was measured GREEN-ON-DEFECT** (~1-in-19k hit rate — `Barrier`'s post-phase release hands one racer a head start), so it was rebuilt as long-lived racers with a third-thread release store: 25–50 % of rounds red, falsification red at rounds 1–13. 10 000 rounds kept over the reviewer's suggested 2 000 after measuring a **1-in-3 vacuous pass at 2 000** under full-suite parallelism (misses burst-correlate). 18/18. |
| 2 | S7 read-pass health — worst-state-wins | `4c161181`, `b35e423c`, `1765e300` | Done; closes the r2 register's last-writer-wins item **for the S7 READ path only** (asymmetry recorded below). The spec review found a second defect in-round — an **empty pass that observed nothing must report nothing**, or it clears a live `Faulted`. The code review then found that the OCE arms skipped the end-of-pass write and froze `LastSuccessfulRead`; the coordinator ruled the OCE path must **flush** the recorded pass evidence via `finally`, which is what protects the watchdog contract. Five falsifications, each red on its own test. 19/19. |
| 3 | Stale `OTOPCUA_CONFIG_MODE` docs | `e9ba1741` | Done as specified; compose facts verified before editing. Historical plan docs deliberately untouched. Trivial ⇒ no review. |
| 4 | Live gate — first-POST 404 + no-body POST | `3f04a4d4` | **PASSED — and the 404 mechanism is now NAMED**, closing an r2 register item the gate was only expected to instrument. Detail below. |
| 5 | Live gate — FetchAndCache legs | *(none — gate only)* | **PASSED, all six legs.** Detail below. |
| 6 | Live gate — alarm-bearing surgical ratchet | *(none — gate only)* | **PASSED, all four routings.** Detail below. |
| 7 | Live gate — ACL-enabled enforcement | *(none — gate only)* | **PASSED**, with a topology adaptation and two non-blocking findings. Detail below. |
| 9 | Roslyn evaluator racing test — remove the timing assumption | `34829ea0`, `837d8a17` | Done. **Cross-repo: ScadaBridge deferred-work register row 38**, relayed 2026-08-18. Detail below. |
| 10 | LocalDb conditional registration + baseline + deregister self-heal | `3e62f161`, `df533916` | Done. **Cross-repo: ScadaBridge deferred-work register row 39.** No pin bump. **The scadaproj umbrella index was updated and pushed to `main` as `1145df6`.** Detail below. |
| 8 | Close-out — sweep + Outcomes + register annotations | *this commit* | Done. Rig torn down first, full build + sweep, this Outcomes section, and the append-only r2 register annotations. |
### Task 4 — the first-POST 404, mechanism CONFIRMED
**2026-08-18, local OrbStack docker-dev rig built from the branch tip. Two results, and the
second is the one that matters.**
- **The prescribed fresh-boot run did NOT reproduce the 404** — the entire Traefik access log
for the boot window was **3 lines, all 2xx**, every one carrying
`RouterName = otopcua-admin@file`. ⚠️ **And `deploy.sh` under `up -d` can never reproduce
it**: Compose blocks on the `depends_on: service_healthy` chain, so `up -d` returned ~30 s
*after* Traefik started and the first poll landed long after the window closed.
- **So the window was exercised directly** — rapid-poll (~10 ms) across
`docker restart otopcua-dev-traefik-1`, twice. Result: `000` (port unbound) → **`404` for
~65–160 ms** → `200`. Body is exactly `404 page not found` (Go's `http.NotFound`), and the
access-log signature is the discriminator the r2 round asked for: **`RouterName = "-"`,
`ServiceName = "-"`, `0ms`** — no router matched, no backend dialled.
- **NAMED MECHANISM: the window between Traefik binding the `web` entrypoint and loading the
dynamic file-provider config from `/etc/traefik/dynamic.yml`.** The listener accepts
connections before the router table exists.
- **The competing candidate is excluded on evidence, not argument** — a health-checked service
with no healthy server yet would be a *matched* router answering **503**; there are **zero
503s** anywhere in the session's access log.
- ⚠️ **Caveat now recorded in both `deploy.sh` and the README: not all 404s are
access-logged.** Probe 1's seven 404s produced **zero** log lines; probe 2's produced 4 of 7.
The accesslog handler is itself part of the dynamic chain that has not been built yet, so
**an empty access log does NOT prove the 404 did not happen.**
- **No-body POST binding — VERIFIED**, four request shapes (script stdin, no data flag at all,
explicit empty body, valid JSON), all reaching the handler. The minimal-API `DeployRequest?`
**binds null**; it does not 400 and does not 415. A clean post-seal run returned **HTTP 202
`Accepted`**, and the DB confirms the null took the fallback: `CreatedBy = rest-api`.
### Task 5 — FetchAndCache, all six legs
**PASSED. Two independent full cycles** (deploy `1e990163` rev `0b9289fb`, then the revert
deploy `da56012f` rev `315de861`), both sealed `acks=6`.
- **Fetch + SHA-verify:** all four site nodes —
`Fetched + verified artifact for 1e99016312004ceca5f73aaba2c899b1 from http://central-1:4055 (1584 bytes).`
The template only logs *after* the SHA-256 == RevisionHash check, so its presence is the
verify proof. The byte count tracked the composition (1584 → 1468 on revert).
- **Serve (central):** four `Served artifact for … (1584 bytes, 1 chunks)` on `central-1`.
- **Applied-from-fetch + cached:** the **`applied fetched deployment`** variant on every site
node — and the two `Direct` central nodes emitted the plain `applied deployment` form on the
*same* deploy, which is the falsification control that the two templates are distinguishable.
- **Boot-from-cache:** after `restart site-a-1`,
`FetchAndCache boot — restored served state for deployment 1e9901… (rev 0b9289fb…) from the LocalDb pointer.`
— the wanted variant, not the empty-cache or failed-pointer ones, matching what the node
cached 52 s earlier.
- **Absence proof** over the node's whole 302-line lifetime: `entering Stale` **0**, any
`stale` **0**, `ConfigDb back` **0**, Direct-form apply **0**, and `[ERR]`/`[WRN]`/`[FTL]`
**0**. ⚠️ The Direct-form check must anchor on `": applied deployment "` — a naive
`grep "applied deployment"` matches the *cache* template and reports a false positive.
- **Bonus:** a post-restart browse showed both namespaces live (`ns=2` raw + `ns=3` UNS)
including the temporary gate area — proof the node materialised the address space from the
artifact it fetched and restored, not from a stale cache.
- ⚠️ **Method note worth carrying:** **same-revision deploys short-circuit the fetch path**
entirely (`DriverHostActor.HandleDispatchFromSteady` immediate-ACK). A bare re-run of this
gate on unchanged config shows **zero fetch lines** and that is not a failure — force a new
revision first. The gate did so with a temporary `UnsArea` row, then reverted; the revert
deploy came back **byte-identical** to the pre-gate revision.
### Task 6 — the alarm-bearing surgical ratchet, four deploys
**PASSED. All four applier lines emitted identically on `central-1` and `central-2`**, every
deploy sealed 6/6:
| Step | Lever | Applier line | Verdict |
|---|---|---|---|
| 1 | `AccessLevel` ReadWrite → Read | `kind=AttributeOnly, changed=1, surgicalRawTags=1, rebuild=False` | surgical ✅ |
| 2 | alarm ADD | `kind=Rebuild, changed=1, surgicalRawTags=0, rebuild=True` | rebuild ✅ (`Alarm != null` current side) |
| 3 | alarm REMOVE | `kind=Rebuild, changed=1, surgicalRawTags=0, rebuild=True` | rebuild ✅ (**previous** side also disqualifies) |
| 4 | `AccessLevel` Read → ReadWrite | `kind=AttributeOnly, changed=1, surgicalRawTags=1, rebuild=False` | surgical ✅ — **the ratchet is per-deploy, not latched** |
- **Deviation, and why it is sound:** the rig's ConfigDb holds exactly **one** `Tag` row, so
TagS and TagA are the same tag exercised sequentially. Each step is an independent deploy
producing exactly **one** raw-tag delta over orthogonal fields, so every verdict is
unambiguous; a second tag would have added an *added-node* delta for no gain.
- **Proven at the artifact seam, not just the log:** each `Deployment.ArtifactBlob` was pulled,
gunzipped and semantically diffed — **each step's artifact differs by exactly the intended
lever and nothing else.**
- **Only the cluster-MAIN nodes emit an applier line.** Site nodes acked every deploy but
logged nothing: `DeploymentArtifact.ResolveClusterScope` self-scopes the fleet-wide artifact,
the site plan is empty, and `Apply` early-returns on `plan.IsEmpty` before the summary log.
Confirmed they *did* process each artifact via their authority-generation lines.
- ⚠️ **A live-gate fact worth knowing for every future rig gate: the revision hash can never
return to its baseline after any `UPDATE`.** `ConfigComposer` snapshots the SQL Server
`rowversion` column into the artifact, and `rowversion` increments on every `UPDATE` including
one that writes back an identical value. A byte-diff confirmed `RowVersion` was the **only**
difference in the entire 4922-byte artifact. Semantic restore was verified instead (config
hash back to `7F75AB45…`, rowcount unchanged).
### Task 7 — ACL-enabled enforcement, first live run since the cache re-shape
**PASSED**, with a forced topology adaptation and two findings.
- ⚠️ **The planned gated node was not executable.** `site-a` serves **containers only** — the
rig's single tag belongs to cluster **MAIN**, so `site-a-1`'s authority generation always
reports `keys=0, grants=0, resolvedScopes=0` and there is no writable value node to authorize.
The gate moved to **`central-1`** (fused `admin,driver,cluster-MAIN`, serving
`ns=2;s=pymodbus/plc/HR200`) via a **scratchpad-only compose overlay** — the repo compose
file was never edited — with **`central-2` as the ungated A/B control**. Consequence recorded:
central-1 is a ConfigDb node so *key* revocation is immediate rather than next-deployment;
**grants still arrive only via the artifact**, so the code actually under test is exercised
as intended.
- **Authoring fell back to direct ConfigDb INSERT** (the Chrome extension was not connected).
`ApiKeySecret.Generate` was reproduced from source and the pepper read live off the container;
the construction is proven correct because the server accepted the key.
- **The ALLOW leg is genuinely load-bearing, because the ungated baseline was captured first.**
The *identical* key and call on the *ungated* node returned `0x801F0000` — the `Tag`-scoped
grant confers no role, so `ApiKeyInterimRoleMapper` leaves the session with `roles []` and the
server-wide gate denies. With the gate on, the same call returned **`Write successful`**.
That is the live demonstration that **the ACL decision REPLACES the role check** rather than
chaining with it — a deny-only gate would have passed against a build that never consults the
ACL.
- **Denials fail closed:** anonymous write and read both `0x801F0000` with
`AclGate: Read withheld 1 of 1 node(s) for principal anonymous`; out-of-scope browse refused;
the ungated control node still open on the same NodeId.
- **Revocation was split into its two distinct code paths, and only the first tests this
round's fix.** *Grant removal* → generation **1 → 2**, `grants=0, resolvedScopes=0`, a
deliberately **primed** decision cache discarded, and the denial arrives while
`ApiKeyAuth: granted` still logs — that is the per-key-shard/CAS-loop path. *Key disable* →
`0x80210000` `BadIdentityTokenRejected` and
`ApiKeyAuth: denied — no enabled, unexpired key with id …` — a different status, because the
session never activates and never reaches the gate.
- **Restore verified by hash:** the post-task revision returned to the exact pre-task
`a3a9061bbf50…`, with 0 `ApiKey` / 0 `NodeAcl` rows and the ENABLED warning gone.
### Task 9 — the racing test, and an honest disclosure
Renamed to `Evaluate_racing_ClearCompiledScripts_never_leaks_a_raw_disposed_failure` and
re-shaped around **three-bucket classification** (leaked ⇒ fail on first; exhausted and starved
each bounded at `max(evals/10, 8)`) with duration-bounded loops (10 s **or** 400 iterations).
- ⚠️ **The real load failure was not the one the ticket described.** It was the test's own 45 s
`WaitAsync` budget expiring under recompile pressure, not the retry legitimately exhausting.
Old shape: **RED 4/4** at 4-way concurrency. New shape: **GREEN 4/4, then 8/8**.
- The review found a further flake vector — `TimedScriptEvaluator`'s 5 s clock starts at
**enqueue**, so a starved evaluation can time out without any product fault. Closed and
falsified with a 12 ms-budget probe (old classification RED, new GREEN at a 0.11 % starve rate).
- Failure-reason literals were promoted to a shared `ScriptEvalFailureReasons` in Commons, used
by both evaluators and the test.
- ⚠️ **Disclosed honestly: the disposed race does not reproduce on this arm64 macOS box at
all.** The raw-escape assertion is the load-independent guarantee; the exhaustion/starvation
bounds are calibrated loose (see the register).
### Task 10 — LocalDb registration now follows replication config
Ported from ScadaBridge's WP1.3/WP3.3 pattern. Predicate = **`PeerAddress` OR `ApiKey`**
(`SyncListenPort` deliberately excluded — the passive endpoint fails closed on the key).
Configured ⇒ `RegisterReplicated(table, baselineExistingRows: true)` per table in the pinned
DDL→register order; not configured ⇒ `DeregisterReplicated` on every table at boot as an
idempotent self-heal. The `CLAUDE.md` bullets that recorded the *unconditional* shape as
deliberate were rewritten in the same commit.
- **No pin bump.** The 0.2.1 APIs were verified by reflection **and** a live probe (baseline
seeds `hlc=0`; `DeregisterReplicated` returns `bool`) rather than assumed from the changelog.
- **Two vacuous-fixture bugs were surfaced and fixed** in passing (`LocalDbPairHarness`, and an
`AlarmSfLegacyMigrator` two-config split) — fixtures that would have let the new predicate
pass without being exercised.
- **Pair-symmetry is the operational trap**, recorded in `CLAUDE.md` and the runbook: the sync
handshake compares registered-table digests fail-closed, so flipping registration is a
**both-nodes-together** change.
- The scadaproj umbrella index was updated and **pushed to `main` as `1145df6`**, per the
standing cross-repo rule.
### Review chain
9 implementers; **12 review verdicts** across the 4 reviewed code tasks (T1 spec + code +
delta re-review; T2 spec + code + delta re-review; T9 spec + code + delta re-review; T10 spec +
code + delta re-review); **4 fix rounds**; **2 CHANGES REQUESTED** (T2, T9). T3 was trivial
(doc-only ⇒ no review) and T4–T7 are live gates with no code to review. **Zero findings papered
over**; one coordinator ruling (T2's OCE flush).
Three **evidence-hygiene** lessons from this round, all worth carrying forward:
- ⚠️ **A race harness can be green-on-defect, and you must measure its hit rate to know.**
T1's plan-supplied `Barrier` harness "passed" at ~1-in-19 000 — it looked like a working test.
Only measuring the hit rate exposed that `Barrier`'s post-phase release hands one racer a head
start. **Round count is a function of the measured hit rate under full-suite parallelism**, not
a round number: 2 000 rounds was measured vacuous 1 time in 3 because misses burst-correlate.
- ⚠️ **Tear the rig down before a comparison sweep.** A running rig silently un-skips env-gated
tests; the r2 skip count is only comparable because the rig was down for both.
- ⚠️ **Name the version of a count you are quoting.** The "13 → 15" in this round's own close-out
brief was a mid-round reading; against the merge-base it is 7 → 15. Intermediate counts drift
the moment a review round lands.
### Follow-up register (opened by this round)
Only genuinely **new or still-open** items. Everything this round closed is annotated on the
round-2 register. **None of these blocks the branch.**
**ACL**
- ⚠️ **Browse transit stops below the realm root — a grant-holding client cannot browse down to
its own granted tag.** With the gate on, the key browses `ns=2;s=pymodbus` and
`ns=2;s=pymodbus/plc` fine but is refused `0x801F0000` on `ns=2;s=OtOpcUa` and on a recursive
browse from the Objects root. `PermissionTrieNode.BrowseTransitPrincipals` marks the ancestors
lying on the tag's **RawPath**; the synthetic realm root sits *above* the RawPath space and is
not in the trie at all. It **fails closed** (not a security hole) and blocked no leg, but it
would make an ACL-enabled deployment look broken to any browse-driven client — including the
Client.CLI's own default recursive browse. Discovered by the T7 live gate. **RECOMMEND filing a
Gitea issue before anyone enables `Security:Acl:Enabled` in production.** Likely fix: mark the
realm-root container browse-transit whenever any grant resolves beneath it.
- **`ns=0` standard nodes are ungated — the boot warning overstates.** With the gate on, both
the key and anonymous read `i=2256` and browse `i=2253` successfully: those are served by the
SDK's `CoreNodeManager` and never reach `DataPlaneAuthorizer`. Defensible (standard server
metadata, no process data), but "A principal with no grant can connect and see **nothing**"
is not literally true. Informational — a doc softening or a deliberate decision to gate ns=0.
**S7**
- **`_health` remains a plain field, versus Modbus's `Volatile.Read`/`Volatile.Write` idiom.**
Pre-existing, but **more of an outlier now** that the read pass consolidates to a single
end-of-pass write — the one place an alignment would be cheap and obvious. Follow-up
alignment, not a correctness claim.
- **Worst-state-wins landed for the S7 READ pass only.** Modbus (all paths) and the S7 **WRITE**
path keep last-writer-wins. **Deliberate scope** — both were named out of scope in this plan
because fixing them here doubles the blast radius of a watchdog-adjacent change. Recorded as a
known asymmetry so the next reader does not mistake it for an oversight.
**LocalDb**
- **`ZB.MOM.WW.LocalDb 0.3.1` is published to the Gitea feed** (per-table snapshot flags + a sync
fault-teardown fix). **This repo deliberately stays on `0.2.1`** — the 0.2.1 APIs cover
everything Task 10 needed, verified by probe. The per-**database** snapshot caveat is documented;
0.3.x makes it per-table. ⚠️ A bump is a **both-nodes-together** change (bookkeeping schema
v2 → v3 is one-way), so it wants a planned window, not an incidental pin edit.
**FetchAndCache**
- **`central-2`'s serve path was never exercised live.** All four site nodes resolved
`central-1:4055` first and stopped there — the documented walk-in-order, stop-at-first-success
behaviour, so central-2 served nothing. Not a fault; simply an untested half of the pair.
**Scripting / test calibration**
- **The disposed race does not reproduce on this arm64 macOS box at all.** The raw-escape
assertion is the load-independent guarantee and holds regardless; the **exhaustion and
starvation bounds are calibrated loose** on a machine that cannot produce the phenomenon they
bound. They would benefit from a Linux-CI observation to tighten.
**Test reliability**
- **`Client.CLI.Tests` `LoggerLifecycleTests.ConfigureLogging_DisposesPreviousLogger_BeforeReassigning`
is flaky under intra-assembly parallelism** — observed once in the r3 close-out sweep, green in
isolation (1/1) and on two whole-project re-runs (104/104). Mechanism: a pre-existing race on the
process-global `Serilog.Log.Logger` — the class carries no `[Collection]`, so a concurrent test's
`ConfigureLogging` (`CloseAndFlush` + reassign) can swap the global between arrange and assert.
No r3 commit touches `src/Client` or `tests/Client`. One-line fix when picked up: pin the class
to a serial collection.
**Carried from round 2, still open**
- **TM/CT decode at a non-zero device number still needs a real S7 CPU.** The test exists and the
env var (`S7_TIMER_NUMBER_ADDRESSING=1`) is ready; python-snap7 resolves TM/CT as a BIT address
and cannot serve it.
- **The cross-*process* plant-vs-reap race on the shared SQL server is accepted.** The 24 h age
floor is the mitigation; a lock table on a shared dev server costs more than it buys.
### Round-2 register items CLOSED by this round
- **ACL single-shot CAS deferred publication** → closed by **`441b34a3`** (T1).
- **S7 per-item decode health last-writer-wins** → closed by **`4c161181` + `b35e423c` +
`1765e300`** (T2), for the **read path**; the write-path and Modbus asymmetry is recorded above.
- **docker-dev first-POST 404** → **mechanism NAMED** by **`3f04a4d4`** (T4), and the **no-body
POST binding VERIFIED** by the same commit.
@@ -0,0 +1,17 @@
{
"planPath": "docs/plans/2026-08-17-perf-followups-r3.md",
"tasks": [
{"id": 1, "subject": "Task 1: ACL InvalidateIfStale — monotonic-max CAS loop", "status": "completed", "note": "441b34a3 + f4b91dbb (review round: hit diagnostics via ITestOutputHelper, idiom comments) + e29fab19 (coordinator: comment-fact fix). Spec ✅ + code APPROVED + delta re-APPROVED. Key learning: the plan's 200-round Barrier harness was measured GREEN-ON-DEFECT (~1/19k hit rate — Barrier post-phase release hands one racer a head start); rebuilt as long-lived racers + third-thread release store (25-50% rounds red, falsification red at rounds 1-13). 10,000 rounds kept over the reviewer's 2,000 after measuring a 1-in-3 vacuous pass at 2,000 under full-suite parallelism (misses burst-correlate). Suite 481→482/1 skip"},
{"id": 2, "subject": "Task 2: S7 read-pass health — worst-state-wins aggregation", "status": "completed", "note": "4c161181 + b35e423c (observe-nothing guard, spec-review-found) + 1765e300 (code-review round: WorstError re-points on severity escalation; OCE now FLUSHES recorded pass evidence via finally — coordinator ruling, protects the watchdog LastSuccessfulRead contract; HasObservations; poison precondition pin). Spec ✅ + code CHANGES REQUESTED → delta re-APPROVED. Suite 401→407. Falsifications: last-writer revert (4 red), timestamp-gate (3 red), guard removal (1 red), escalation revert (red on PUT/GET message), flush revert (timestamp frozen). Register: Modbus + S7-write-path last-writer-wins asymmetry deliberate; S7 _health Volatile alignment deferred"},
{"id": 3, "subject": "Task 3: Fix stale OTOPCUA_CONFIG_MODE docs", "status": "completed", "note": "e9ba1741; docs/Configuration.md:253 + CLAUDE.md:554 rewritten (compose facts verified first); historical plan docs deliberately untouched; trivial => no review"},
{"id": 4, "subject": "Task 4: Live gate — first-POST-404 catch + no-body POST binding", "status": "completed", "note": "3f04a4d4 (README + deploy.sh). 404 MECHANISM NAMED: window between Traefik binding the web entrypoint and loading the dynamic file-provider config — listener accepts before the router table exists; Go '404 page not found', empty RouterName/ServiceName/0ms; 503-candidate excluded (zero 503s in session). Caught via rapid-poll across docker restart traefik (2×, 65-160ms window) — deploy.sh under up -d can NEVER ride the window (depends_on service_healthy returns ~30s after traefik start); ⚠️ not all 404s are access-logged (the accesslog handler is part of the not-yet-built chain) — documented. No-body POST: binds null, 202 Accepted, CreatedBy=rest-api fallback confirmed in DB. Rig left UP; first deploy raced site-b-2 boot (failure status) — T5 evidence must use the later acks=6 deploys"},
{"id": 5, "subject": "Task 5: Live gate — FetchAndCache legs", "status": "completed", "note": "GATE PASSED, no commit. All 6 legs: fetch+SHA-verify on all 4 site nodes (1584 bytes from central-1:4055), Served×4 central-side, applied-FETCHED + cached on site-a-1 (acks=6), boot-from-cache after restart (restored rev matches what it cached 52s earlier), absence proof (0 Stale/ConfigDb-back/Direct-form/ERR/WRN over full lifetime), post-restart browse proves both namespaces materialised (ns=2 raw + ns=3 UNS). Method: same-revision deploys short-circuit the fetch path (immediate-ACK at HandleDispatchFromSteady) — gate forced a temp UnsArea row then reverted; rig config restored byte-identical (rev 315de861). Register: central-2 serve path unexercised (first-success endpoint walk always hit central-1)"},
{"id": 6, "subject": "Task 6: Live gate — alarm-bearing surgical ratchet", "status": "completed", "note": "GATE PASSED, no commit. Four deploys, all routings correct: Writable flip ⇒ kind=AttributeOnly surgicalRawTags=1 rebuild=False; alarm ADD ⇒ kind=Rebuild rebuild=True; alarm REMOVE ⇒ rebuild=True (previous-side disqualifies); restore ⇒ surgical again (ratchet per-deploy, not latched). All sealed 6/6 acks. Authoring: direct UPDATE on the rig's OWN sql container (Database=OtOpcUa — NOT 10.100.0.35; sqlcmd needs -I for QUOTED_IDENTIFIER). Findings: only cluster-MAIN nodes emit applier lines (site plans empty via ResolveClusterScope, apply early-returns); artifact hash can never return to baseline after any UPDATE — ConfigComposer snapshots SQL rowversion (verified by gunzip+diff: only the RowVersion differs). Rig config semantically restored; rig UP"},
{"id": 7, "subject": "Task 7: Live gate — ACL-enabled enforcement on site-a", "status": "completed", "note": "GATE PASSED, no commit. TOPOLOGY ADAPTATION: gated node = central-1 via scratchpad-only compose overlay (site-a serves NO value nodes — the rig's one tag is cluster MAIN; central-2 became the ungated A/B control). ALLOW leg genuinely load-bearing: ungated baseline captured first — same key+call DENIED 0x801F0000 with ACL off (Tag grant confers no role), SUCCEEDED with ACL on ⇒ ACL decision REPLACES the role check, live. Deny×3 (anonymous write, out-of-scope browse, ungated control reads fine); revocation split into grant-removal (gen 1→2, primed per-key shard discarded — exercises this round's CAS-loop path) and key-disable (pre-cache re-check). Authoring: DB fallback (Chrome extension not connected) — ApiKeySecret hashing reproduced from source, pepper verified live. Restore byte-identical (rev a3a9061b), zero residue. FINDINGS for register: (1) browse transit stops below the realm root — grant holder cannot browse DOWN to its own tag from ns=2;s=OtOpcUa (fails closed; file as issue); (2) ns=0 core nodes are ungated (CoreNodeManager bypasses DataPlaneAuthorizer) — boot warning overstates 'see nothing'"},
{"id": 8, "subject": "Task 8: Close-out — sweep + Outcomes + register annotations", "status": "completed", "blockedBy": [1, 2, 3, 4, 5, 6, 7, 9, 10], "note": "c4d6cba7 (Outcomes + sweep record + r2 register annotations, +383/−0) + the coordinator's flake-register append. Rig torn down BEFORE the sweep (rig-up skews skips: Host.IntegrationTests 229/0/2 up vs 226/0/5 down). Build 0 errors / 904 warnings — IDENTICAL to r2 (note: incremental builds under-report at 896). Sweep 43/43 green: 10,377 / 0 / 19 — +7 reconciled exactly (OpcUaServer +1 T1, S7 +6 T2); skips identical project-for-project; AdminUI 1540/0-skipped + Configuration 190/0-skipped ran vs 10.100.0.35,14330. Host.IntegrationTests (outside the 43-project baseline) +9 vs merge-base (LocalDbSetupTests 7→15, WiringTests 6→7). One flake isolated: Client.CLI LoggerLifecycleTests — pre-existing global-Serilog race, no r3 commit touches it, registered"}
{"id": 9, "subject": "Task 9: Roslyn evaluator racing test — remove timing assumption (ScadaBridge row 38)", "status": "completed", "note": "34829ea0 + 837d8a17 (review round). Option (b): renamed to Evaluate_racing_ClearCompiledScripts_never_leaks_a_raw_disposed_failure; three-bucket classification (leaked=fail-first, exhausted + starved each bounded max(evals/10,8)); duration-bounded loops (10s OR 400 iters) — the REAL load failure was the test's own 45s WaitAsync budget under recompile pressure (old shape RED 4/4 at 4-way concurrency, new GREEN 4/4 + 8/8); reviewer-found starvation-timeout flake vector closed (TimedScriptEvaluator's 5s clock starts at enqueue), falsified via 12ms-budget probe (old classification RED, new GREEN at 0.11%); literals promoted to shared ScriptEvalFailureReasons in Commons (both evaluators + test). Honest disclosure: disposed race does not reproduce on this arm64 box at all. Spec ✅ + code CHANGES REQUESTED → delta re-APPROVED. Host.IntegrationTests 229/0/2, Calculation 53/53"},
{"id": 10, "subject": "Task 10: LocalDb conditional registration + baseline + deregister self-heal (ScadaBridge row 39)", "status": "completed", "note": "3e62f161 + df533916 (review round: content-based data-survival pin, mid-loop loud-fail pin via exhaustive delegating fake, Log.Logger assumption comment). Spec ✅ + code APPROVED + delta re-APPROVED. Predicate = PeerAddress OR ApiKey (SyncListenPort deliberately out — passive endpoint fail-closed on key); 0.2.1 APIs verified by reflection+probe (baseline seeds hlc=0; DeregisterReplicated returns bool) — NO pin bump; 0.3.1 now published (ScadaBridge heads-up) — bump recorded as deliberate both-nodes-together future change (bookkeeping v2→v3 one-way). Surfaced+fixed two vacuous-fixture bugs (PairHarness/AlarmSfLegacyMigrator two-config split). scadaproj index updated + pushed (1145df6). Suites: LocalDbSetupTests 15/15, Host.IntegrationTests 226/0/5"}
],
"closeOut": "Round 3 (perf/followups-r3) complete: 7 implementation/gate tasks + 2 cross-repo tasks + close-out, all 10 green. Landed: T1 ACL monotonic-max CAS loop — publication never deferred (441b34a3, f4b91dbb, e29fab19; the plan's own 200-round Barrier harness was measured green-on-defect and rebuilt); T2 S7 worst-state-wins read-pass health with WorstError severity re-pointing and OCE evidence flush (4c161181, b35e423c, 1765e300); T3 stale OTOPCUA_CONFIG_MODE docs (e9ba1741); T4 first-POST-404 MECHANISM NAMED — Traefik entrypoint-bound-before-dynamic-config window, some 404s never access-logged; no-body POST binds null/202 (3f04a4d4); T5 FetchAndCache all six legs PASSED (same-revision deploys short-circuit the fetch path — gates must force a revision); T6 alarm ratchet all four routings PASSED (per-deploy, not latched; artifact hash can never return to baseline — rowversion is snapshotted); T7 ACL-enabled enforcement PASSED on central-1 (site-a serves no value nodes) with an ungated-baseline-first ALLOW proving the ACL replaces the role check, grant-revocation exercising the new CAS path live; T9 ScadaBridge row 38 — Roslyn racing test de-flaked, three-bucket classification, shared ScriptEvalFailureReasons consts (34829ea0, 837d8a17); T10 ScadaBridge row 39 — LocalDb conditional registration + baseline + deregister self-heal on 0.2.1, pair-symmetry documented (3e62f161, df533916; scadaproj index pushed 1145df6; both ScadaBridge register rows confirmed closed by that session). Review chain: 9 implementers (incl. resumed hot-context fix rounds across a session-limit interruption), 12 review verdicts, 5 fix rounds, 2 CHANGES REQUESTED both resolved, zero findings papered over. Sweep 10,377/0/19 across 43/43 (+7 reconciled exactly), build 0 errors/904 warnings identical to r2. Open r3 register (none blocking): ACL browse-transit-below-realm-root (RECOMMEND Gitea issue before enabling ACL in production), ns=0 ungated boot-warning overstatement, S7 _health Volatile alignment, Modbus/S7-write last-writer-wins asymmetry (deliberate), LocalDb 0.3.1 available (both-nodes-together bump), central-2 serve path unexercised, Roslyn bounds want a Linux-CI observation, Client.CLI logger flake (serial-collection one-liner), carried TM/CT real-CPU + cross-process reap race.",
"lastUpdated": "2026-08-18T13:40:00Z"
}
@@ -37,6 +37,36 @@ public sealed record VirtualTagEvalResult(bool Success, object? Value, string? R
public static VirtualTagEvalResult Failure(string reason) => new(false, null, reason);
}
/// <summary>
/// Failure reasons the script evaluators put on <see cref="VirtualTagEvalResult.Failure"/> and that
/// callers / tests classify on. The two evaluators — <c>RoslynVirtualTagEvaluator</c> (virtual tags)
/// and <c>CalculationEvaluator</c> (calc tags) — are deliberate mirrors of one another, so these
/// strings are a shared contract rather than two coincidentally-equal literals. They lived as three
/// unshared copies (the two evaluators plus a test const); a reader could not tell the contracts were
/// meant to be identical, and drift on one side would silently break a classifier keyed on the other.
/// Only the reasons something outside the evaluator matches on live here — the purely descriptive ones
/// (<c>compile error:</c>, <c>sandbox violation:</c>, <c>script threw:</c>) stay inline.
/// </summary>
public static class ScriptEvalFailureReasons
{
/// <summary>
/// The evaluator's one-shot retry was exhausted: a SECOND concurrent apply-boundary
/// <c>ClearCompiledScripts</c> disposed the compiled script inside the same evaluation. This is the
/// documented, well-formed outcome of losing that race twice — distinct from an
/// <see cref="ObjectDisposedException"/> escaping to the generic catch as <c>"script threw: …"</c>,
/// which is a bug.
/// </summary>
public const string EvaluatorDisposedDuringEvaluation = "evaluator disposed during evaluation";
/// <summary>
/// Prefix of the wall-clock-timeout failure; the evaluator completes it with the budget it applied
/// (<c>"{seconds:F1}s"</c>). Note the timeout covers the enqueue too — <c>TimedScriptEvaluator</c>
/// starts its clock at <c>WaitAsync</c>, not when the inner <c>Task.Run</c> gets a thread — so on a
/// starved pool this reason can mean "never got to run", not "ran too long".
/// </summary>
public const string TimedOutPrefix = "script timed out after ";
}
/// <summary>Returns <see cref="VirtualTagEvalResult.NoChange"/> from every call. Bound by default
/// when the production <c>VirtualTagEngine</c> adapter hasn't been registered (Mac dev, tests).</summary>
public sealed class NullVirtualTagEvaluator : IVirtualTagEvaluator
@@ -148,7 +148,8 @@ public sealed class CalculationEvaluator : IScriptCacheOwner, IDisposable
}
catch (ScriptTimeoutException)
{
return VirtualTagEvalResult.Failure($"script timed out after {_runTimeout.TotalSeconds:F1}s");
return VirtualTagEvalResult.Failure(
$"{ScriptEvalFailureReasons.TimedOutPrefix}{_runTimeout.TotalSeconds:F1}s");
}
catch (ObjectDisposedException) when (!_disposed && attempt == 0)
{
@@ -159,7 +160,7 @@ public sealed class CalculationEvaluator : IScriptCacheOwner, IDisposable
}
catch (ObjectDisposedException)
{
return VirtualTagEvalResult.Failure("evaluator disposed during evaluation");
return VirtualTagEvalResult.Failure(ScriptEvalFailureReasons.EvaluatorDisposedDuringEvaluation);
}
catch (Exception ex)
{
@@ -544,6 +544,9 @@ public sealed class S7Driver
RequireInitialized();
var now = DateTime.UtcNow;
var results = new DataValueSnapshot[fullReferences.Count];
// Health is decided ONCE, at the end of the pass, from every outcome the pass observed —
// never per item. See ReadPassOutcome.
var outcome = new ReadPassOutcome();
await _gate.WaitAsync(cancellationToken).ConfigureAwait(false);
try
@@ -612,7 +615,7 @@ public sealed class S7Driver
perTag.Add(span.Members[0].OriginalIndex);
continue;
}
await ReadSpanAsync(plc, span, results, now, cancellationToken).ConfigureAwait(false);
await ReadSpanAsync(plc, span, results, now, outcome, cancellationToken).ConfigureAwait(false);
}
perTag.AddRange(plan.LeftoverIndexes);
}
@@ -635,7 +638,7 @@ public sealed class S7Driver
if (_options.SpanReadMaxGapBytes >= 0)
{
perTag = await ReadLeftoversByMultiVarAsync(
plc, resolved, perTag, results, now, cancellationToken).ConfigureAwait(false);
plc, resolved, perTag, results, now, outcome, cancellationToken).ConfigureAwait(false);
}
foreach (var i in perTag)
@@ -644,7 +647,7 @@ public sealed class S7Driver
{
var value = await ReadOneAsync(plc, resolved[i]!, cancellationToken).ConfigureAwait(false);
results[i] = new DataValueSnapshot(value, 0u, now, now);
_health = new DriverHealth(DriverState.Healthy, now, null);
outcome.RecordSuccess();
}
catch (OperationCanceledException)
{
@@ -660,14 +663,131 @@ public sealed class S7Driver
}
catch (Exception ex)
{
results[i] = new DataValueSnapshot(null, RecordReadFailure(ex), null, now);
results[i] = new DataValueSnapshot(null, RecordReadFailure(ex, outcome), null, now);
}
}
}
finally { _gate.Release(); }
finally
{
// THE single health write of the pass — worst-state-wins over every outcome recorded
// above. In a FINALLY, so evidence the pass already gathered survives an abandoned
// batch: the three OCE arms rethrow mid-pass, and on a partially-working device a
// repeatedly-cancelled poll would otherwise freeze LastSuccessfulRead while tags were
// demonstrably still being read — tripping the comms-loss watchdog into a reconnect
// loop, the exact false positive the AnySuccess design exists to prevent.
//
// A pass that observed NOTHING reports nothing (HasObservations), which is also what
// makes flushing here safe on the two paths that reach the finally with no outcomes:
// the connect-failure early return, whose own Degraded write must NOT be overwritten,
// and an OCE that fired before any tag was stamped. Both no-op.
//
// LastSuccessfulRead advances whenever ANYTHING read, even into a Degraded/Faulted
// state — see ReadPassOutcome for why that is load-bearing.
if (outcome.HasObservations)
{
_health = new DriverHealth(
outcome.WorstFailure,
outcome.AnySuccess ? now : _health.LastSuccessfulRead,
outcome.WorstFailure == DriverState.Healthy ? null : outcome.WorstError);
}
_gate.Release();
}
return results;
}
/// <summary>
/// The outcomes ONE <see cref="ReadAsync"/> pass observed, accumulated so the pass writes
/// <see cref="_health"/> exactly once — <b>worst state wins</b>.
/// </summary>
/// <remarks>
/// <para>
/// Health used to be stamped per item, in three separate read loops, so the pass
/// reported whatever its LAST item happened to be: a mixed pass read <c>Healthy</c>, and
/// the access-denied <c>Faulted</c> config alert — usually a minority of the batch — was
/// erased by any later good tag. Ranking (Healthy &lt; Degraded &lt; Faulted) and
/// deciding once at the end makes the verdict a function of the whole pass rather than
/// of its item ordering.
/// </para>
/// <para>
/// <b><see cref="AnySuccess"/> is tracked separately from the state on purpose.</b> The
/// comms-loss watchdog trips only on a non-Healthy state AND a frozen
/// <c>LastSuccessfulRead</c>; several drivers latch Degraded off a single unreadable
/// address, so a pass that lands Degraded must still advance the timestamp when
/// anything at all was read, or an entirely reachable CPU would be reconnected every
/// 90 s forever.
/// </para>
/// <para>
/// Not thread-safe, and does not need to be: a pass runs wholly under <see cref="_gate"/>
/// and every read loop inside it is sequential.
/// </para>
/// </remarks>
private sealed class ReadPassOutcome
{
/// <summary>True once any tag in the pass read successfully.</summary>
public bool AnySuccess { get; private set; }
/// <summary>
/// The worst failure state recorded so far; <see cref="DriverState.Healthy"/> means no
/// failure has been recorded at all.
/// </summary>
public DriverState WorstFailure { get; private set; } = DriverState.Healthy;
/// <summary>
/// The first message recorded <b>at the worst severity</b> — the one that explains
/// <see cref="WorstFailure"/>.
/// </summary>
/// <remarks>
/// It must move WITH the state, not independently of it. Keeping the pass's
/// chronologically-first message instead desynced the pair whenever a Degraded fault
/// preceded a Faulted one: the driver reported the access-denied config alert while its
/// message talked about some unrelated device fault and never mentioned PUT/GET, which
/// is the one thing the operator has to act on. Within a severity the FIRST message
/// still wins — a later peer failure is as likely to be a consequence of it as an
/// independent fault.
/// </remarks>
public string? WorstError { get; private set; }
/// <summary>
/// True once the pass observed anything at all — a success or a failure. False for a
/// degenerate pass (empty batch, or every reference unresolvable), which must report
/// nothing rather than invent a verdict.
/// </summary>
public bool HasObservations => AnySuccess || WorstFailure != DriverState.Healthy;
/// <summary>Records that one tag read successfully.</summary>
public void RecordSuccess() => AnySuccess = true;
/// <summary>
/// Records one failed tag, keeping the worst state and the message that explains it.
/// </summary>
/// <param name="state">The state this failure would have stamped on its own.</param>
/// <param name="message">The failure's operator-facing message.</param>
public void RecordFailure(DriverState state, string message)
{
if (Rank(state) > Rank(WorstFailure))
{
// Escalating the severity MUST re-point the message at the new cause.
WorstFailure = state;
WorstError = message;
}
else
{
WorstError ??= message;
}
}
/// <summary>Severity order the pass ranks by: Healthy (none) &lt; Degraded &lt; Faulted.</summary>
/// <param name="state">The state to rank.</param>
/// <returns>Its severity, higher being worse.</returns>
private static int Rank(DriverState state) => state switch
{
DriverState.Faulted => 2,
DriverState.Degraded => 1,
_ => 0,
};
}
/// <summary>
/// Items one multi-var request may carry. <b>The caller owns chunking — S7.Net does NOT
/// split a multi-var read</b>, it throws when the request or the projected response exceeds
@@ -743,6 +863,7 @@ public sealed class S7Driver
/// <param name="leftovers">Indexes the span pass left for the per-tag path, ascending.</param>
/// <param name="results">The batch's result array, written in place at each tag's original index.</param>
/// <param name="now">The batch timestamp, shared by every tag in the batch.</param>
/// <param name="outcome">The pass's outcome accumulator; every decoded item records into it.</param>
/// <param name="ct">Cancellation token for the reads.</param>
/// <returns>The indexes still owed an individual read, ascending.</returns>
private async Task<List<int>> ReadLeftoversByMultiVarAsync(
@@ -751,6 +872,7 @@ public sealed class S7Driver
List<int> leftovers,
DataValueSnapshot[] results,
DateTime now,
ReadPassOutcome outcome,
CancellationToken ct)
{
var stillPerTag = new List<int>();
@@ -825,13 +947,13 @@ public sealed class S7Driver
?? throw new System.IO.InvalidDataException(
$"S7.Net returned null multi-var value for '{tag.Address}'");
results[index] = new DataValueSnapshot(ReinterpretRawValue(tag, addr, raw), 0u, now, now);
_health = new DriverHealth(DriverState.Healthy, now, null);
outcome.RecordSuccess();
}
catch (Exception ex)
{
// Decoding is pure and synchronous — no cancellation can surface here, so there
// is deliberately no OperationCanceledException arm to shadow the request one.
results[index] = new DataValueSnapshot(null, RecordReadFailure(ex), null, now);
results[index] = new DataValueSnapshot(null, RecordReadFailure(ex, outcome), null, now);
}
}
}
@@ -902,10 +1024,12 @@ public sealed class S7Driver
/// <param name="span">The planned block read.</param>
/// <param name="results">The batch's result array, written in place at each member's original index.</param>
/// <param name="now">The batch timestamp, shared by every tag in the batch.</param>
/// <param name="outcome">The pass's outcome accumulator; every member records into it.</param>
/// <param name="ct">Cancellation token for the read.</param>
/// <returns>A task that completes once every member of the span has been stamped.</returns>
private async Task ReadSpanAsync(
IS7Plc plc, S7ReadSpanPlanner.Span span, DataValueSnapshot[] results, DateTime now, CancellationToken ct)
IS7Plc plc, S7ReadSpanPlanner.Span span, DataValueSnapshot[] results, DateTime now,
ReadPassOutcome outcome, CancellationToken ct)
{
byte[] block;
try
@@ -926,7 +1050,7 @@ public sealed class S7Driver
}
catch (Exception ex)
{
var status = RecordReadFailure(ex);
var status = RecordReadFailure(ex, outcome);
foreach (var member in span.Members)
results[member.OriginalIndex] = new DataValueSnapshot(null, status, null, now);
return;
@@ -938,13 +1062,14 @@ public sealed class S7Driver
{
var value = DecodeMember(member, block);
results[member.OriginalIndex] = new DataValueSnapshot(value, 0u, now, now);
_health = new DriverHealth(DriverState.Healthy, now, null);
outcome.RecordSuccess();
}
catch (Exception ex)
{
// Decoding is pure and synchronous — no cancellation can surface here, so there is
// deliberately no OperationCanceledException arm to shadow the block-read one above.
results[member.OriginalIndex] = new DataValueSnapshot(null, RecordReadFailure(ex), null, now);
results[member.OriginalIndex] =
new DataValueSnapshot(null, RecordReadFailure(ex, outcome), null, now);
}
}
}
@@ -998,17 +1123,29 @@ public sealed class S7Driver
/// <summary>
/// The read-failure classification ladder, shared by the per-tag path and the span path so
/// a failed span stamps every member with exactly the status the same exception would have
/// produced on a single tag. Applies the health / dead-handle side effects and returns the
/// status code the caller must stamp.
/// produced on a single tag. Records the failure into the pass's outcome, applies the
/// dead-handle side effect, and returns the status code the caller must stamp.
/// </summary>
/// <remarks>
/// <see cref="OperationCanceledException"/> is deliberately NOT handled here: it is control
/// flow rather than a per-tag status (it marks the handle dead and propagates), and
/// rethrowing it from a helper would rewrite the stack. Both call sites catch it first.
/// <para>
/// <b>The health state is recorded, not applied.</b> It goes into
/// <paramref name="outcome"/> so the pass can write <see cref="_health"/> once at the
/// end, worst-state-wins — writing it here is what let a later good tag erase this
/// failure. The <c>_plcDead</c> / <see cref="MarkConnectionDeadIfFatal"/> side effects
/// stay IMMEDIATE: they govern whether the very next read reopens the handle, which
/// cannot wait for the pass to finish.
/// </para>
/// <para>
/// <see cref="OperationCanceledException"/> is deliberately NOT handled here: it is
/// control flow rather than a per-tag status (it marks the handle dead and propagates),
/// and rethrowing it from a helper would rewrite the stack. Both call sites catch it
/// first.
/// </para>
/// </remarks>
/// <param name="ex">The exception observed on a read.</param>
/// <param name="outcome">The pass's outcome accumulator this failure is recorded into.</param>
/// <returns>The OPC UA status code every affected tag must be stamped with.</returns>
private uint RecordReadFailure(Exception ex)
private uint RecordReadFailure(Exception ex, ReadPassOutcome outcome)
{
switch (ex)
{
@@ -1020,7 +1157,7 @@ public sealed class S7Driver
// fault, NOT a transient one. Blind retry is wasted effort, so map it to
// BadNotSupported and flag the driver as a config alert (Faulted) rather than
// Degraded — per driver-specs.md §5.
_health = new DriverHealth(DriverState.Faulted, _health.LastSuccessfulRead,
outcome.RecordFailure(DriverState.Faulted,
"S7 access denied — enable PUT/GET communication in TIA Portal " +
$"(Protection & Security) for this CPU. PLC reported: {pex.Message}");
return StatusBadNotSupported;
@@ -1031,14 +1168,14 @@ public sealed class S7Driver
// PlcException (socket drop / ConnectionError) additionally marks the handle dead
// so the next read reopens it.
MarkConnectionDeadIfFatal(pex);
_health = new DriverHealth(DriverState.Degraded, _health.LastSuccessfulRead, pex.Message);
outcome.RecordFailure(DriverState.Degraded, pex.Message);
return StatusBadDeviceFailure;
default:
// Socket / timeout / transport fault — mark the handle dead when it's a connection
// loss so EnsureConnectedAsync reopens on the next call.
MarkConnectionDeadIfFatal(ex);
_health = new DriverHealth(DriverState.Degraded, _health.LastSuccessfulRead, ex.Message);
outcome.RecordFailure(DriverState.Degraded, ex.Message);
return StatusBadCommunicationError;
}
}
@@ -7,8 +7,8 @@ namespace ZB.MOM.WW.OtOpcUa.Host.Configuration;
/// <summary>
/// The <c>onReady</c> callback handed to <c>AddZbLocalDb</c>: creates the deployment-cache,
/// alarm store-and-forward, and scripted-alarm condition-state tables and opts them into
/// replication.
/// alarm store-and-forward, and scripted-alarm condition-state tables and — when this node
/// actually replicates — opts them into change capture.
/// </summary>
/// <remarks>
/// <para>
@@ -21,7 +21,25 @@ namespace ZB.MOM.WW.OtOpcUa.Host.Configuration;
public static class LocalDbSetup
{
/// <summary>
/// Initialises the local database: DDL first, then replication registration.
/// The four tables that participate in replication — registered when this node is configured
/// to replicate, and deregistered (stale capture triggers dropped) when it is not.
/// </summary>
/// <remarks>
/// One list shared by both branches on purpose. A table added to only the registration
/// branch would replicate on a configured node and then never be cleaned off an
/// unconfigured one; a table added to only the deregistration branch would be cleaned on a
/// node that never registered it.
/// </remarks>
private static readonly string[] ReplicatedTables =
[
DeploymentCacheSchema.ArtifactsTable,
DeploymentCacheSchema.PointerTable,
AlarmSfSchema.EventsTable,
AlarmConditionStateSchema.StateTable,
];
/// <summary>
/// Initialises the local database: DDL first, then replication registration (or its removal).
/// </summary>
/// <remarks>
/// <para>
@@ -33,20 +51,53 @@ public static class LocalDbSetup
/// registration — it writes rows, and they must be captured like any other write.
/// </para>
/// <para>
/// <b>Registration is CONDITIONAL on <see cref="ReplicationIsConfigured"/>.</b> It used
/// to be unconditional, on every driver node, replicating or not. That was not merely
/// wasteful — an unreplicated node paid two INSERTs plus a <c>json_object</c> of the
/// whole row inside every write transaction, for an oplog nothing ever drained — it also
/// made <c>baselineExistingRows</c> unusable, because passing it on a node with no peer
/// would flag a snapshot resync for a peer that does not exist. The ordering rule above
/// is unaffected: when registration is skipped there is no capture to be too late for.
/// </para>
/// <para>
/// <b>The unconfigured branch actively cleans up</b> rather than merely abstaining.
/// <c>DeregisterReplicated</c> drops any capture triggers an earlier build left in the
/// file and prunes that table's oplog and row-version rows. Declining to register alone
/// would leave every file written by a pre-2026-08-18 build capturing forever — on
/// precisely the node that has no peer to capture for.
/// </para>
/// <para>
/// <b>A failure part-way through either loop fails host start, and that is deliberate.</b>
/// Neither branch catches, so a throw on the third of four tables leaves two flipped and
/// propagates out of the <c>AddZbLocalDb</c> singleton factory — a node that came up
/// anyway would be capturing (or not) on an arbitrary subset, which is silently partial
/// replication with nothing in the log to say so. Both library calls are idempotent, so
/// the retried boot simply completes the flip rather than compounding it.
/// </para>
/// <para>
/// The alarm buffer's tables are created unconditionally, regardless of whether this
/// node has <c>AlarmHistorian:Enabled</c> set. An empty registered table costs three
/// triggers and nothing else, whereas creating it lazily when the sink first appears
/// would mean a node that enables the historian later writes rows before its triggers
/// exist — which is precisely the silent-loss shape above.
/// node has <c>AlarmHistorian:Enabled</c> set, and regardless of replication. Creating
/// one lazily when the sink first appears would mean a node that enables the historian
/// later writes rows before its triggers exist — which is precisely the silent-loss
/// shape above.
/// </para>
/// </remarks>
/// <param name="db">The freshly constructed local database.</param>
/// <param name="configuration">
/// Application configuration, read by the legacy migrator for the pre-consolidation queue's
/// path. Required rather than optional: an overload that silently skipped the migration
/// would be one wiring mistake away from discarding a node's undelivered alarm history.
/// Application configuration, read for the replication predicate and by the legacy migrator
/// for the pre-consolidation queue's path. Required rather than optional: an overload that
/// silently skipped the migration would be one wiring mistake away from discarding a node's
/// undelivered alarm history.
/// </param>
public static void OnReady(ILocalDb db, IConfiguration configuration)
/// <param name="logger">
/// Where the deregistration self-heal reports what it cleaned. Defaults to Serilog's static
/// logger, which is what production uses: this runs inside the <c>AddZbLocalDb</c> singleton
/// factory, where resolving an <c>ILogger</c> would nest a service resolution inside a
/// singleton construction. <c>Program.cs</c> assigns <c>Serilog.Log.Logger</c> from the DI
/// root logger before anything resolves <c>ILocalDb</c>. The parameter exists so tests can
/// observe the line rather than infer it.
/// </param>
public static void OnReady(ILocalDb db, IConfiguration configuration, Serilog.ILogger? logger = null)
{
ArgumentNullException.ThrowIfNull(db);
ArgumentNullException.ThrowIfNull(configuration);
@@ -60,12 +111,139 @@ public static class LocalDbSetup
AlarmConditionStateSchema.Apply(connection);
}
db.RegisterReplicated(DeploymentCacheSchema.ArtifactsTable);
db.RegisterReplicated(DeploymentCacheSchema.PointerTable);
db.RegisterReplicated(AlarmSfSchema.EventsTable);
db.RegisterReplicated(AlarmConditionStateSchema.StateTable);
if (ReplicationIsConfigured(configuration))
RegisterForCapture(db);
else
RemoveStaleCapture(db, logger ?? Serilog.Log.Logger);
// LAST, and only here. This is the one call in OnReady that writes rows.
AlarmSfLegacyMigrator.Migrate(db, configuration);
}
/// <summary>
/// Whether this node participates in LocalDb replication, and therefore needs the capture
/// triggers at all.
/// </summary>
/// <remarks>
/// <para>
/// <b>Either key counts, and the OR is not belt-and-braces — it is the only predicate
/// that is true on BOTH halves of a replicating pair.</b> Replication is one
/// bidirectional stream that exactly one side dials, so only the initiator sets
/// <c>LocalDb:Replication:PeerAddress</c>; the passive node carries the shared
/// <c>ApiKey</c> and a <c>LocalDb:SyncListenPort</c> and nothing else. (The docker-dev
/// rig is the reference: <c>site-a-1</c> has PeerAddress + ApiKey, <c>site-a-2</c> has
/// ApiKey + SyncListenPort, and central / site-b carry no <c>Replication</c> section at
/// all.) Keying on PeerAddress alone would strip capture from every passive node — its
/// local writes would stop reaching the initiator and the pair would converge in one
/// direction only, silently.
/// </para>
/// <para>
/// <b><c>LocalDb:SyncListenPort</c> deliberately does NOT join the OR.</b> The passive
/// endpoint is fail-closed on the key: with a port but no <c>ApiKey</c>,
/// <c>LocalDbSyncAuthInterceptor</c> refuses every inbound stream, so such a node
/// replicates nothing and has nothing to capture for. Adding the port to the predicate
/// would install capture triggers on a node whose sync endpoint rejects all callers.
/// <c>LocalDbReplicationHealthCheck</c> deliberately asks a <i>different</i> question —
/// "was this node MEANT to replicate?", which is <c>PeerAddress</c> OR a bound listen
/// port — so a port-without-key node correctly reports Degraded there while correctly
/// capturing nothing here. The two predicates diverge only on that misconfiguration,
/// and each is right about its own question.
/// </para>
/// <para>
/// The keys are read straight from configuration rather than through
/// <c>IOptions&lt;ReplicationOptions&gt;</c> because this runs inside the
/// <c>AddZbLocalDb</c> factory, where resolving another option would nest a service
/// resolution inside a singleton construction. The section path is
/// <see cref="LocalDbRegistration.ReplicationSectionPath"/> — the same constant
/// <c>AddZbLocalDbReplication</c> binds — so the predicate and the engine cannot
/// disagree about which node replicates.
/// </para>
/// <para>
/// <b>Both directions of a change to this predicate are handled at boot, and both
/// require the PAIR to be changed together.</b> The sync handshake compares
/// registered-table digests fail-closed, so a node that drops a table its peer still
/// replicates stops syncing with a schema mismatch. Enable (or disable) replication on
/// both nodes and restart both — never one.
/// </para>
/// </remarks>
/// <param name="configuration">The application configuration.</param>
/// <returns><c>true</c> when this node is configured to replicate.</returns>
public static bool ReplicationIsConfigured(IConfiguration configuration)
{
ArgumentNullException.ThrowIfNull(configuration);
var section = configuration.GetSection(LocalDbRegistration.ReplicationSectionPath);
return !string.IsNullOrWhiteSpace(section["PeerAddress"])
|| !string.IsNullOrWhiteSpace(section["ApiKey"]);
}
/// <summary>Opts every replicated table into change capture, baselining what is already there.</summary>
/// <remarks>
/// <para>
/// <c>baselineExistingRows: true</c> is what makes turning replication ON for a node that
/// has been running WITHOUT it actually converge. Capture is change-data-capture and the
/// snapshot streamer pages from <c>__localdb_row_version</c>, so rows written before the
/// first registration are in neither: a late opt-in used to replicate only writes made
/// after the restart, silently and forever. Baselining seeds the ledger at the LWW floor
/// (HLC 0, this node's id) and flags a snapshot resync, so a baselined row loses to any
/// genuine remote write of the same key and wins only where the peer has no version at
/// all. It is idempotent, and therefore free on every boot after the first — which is
/// why it is unconditional here rather than behind a one-shot flag.
/// </para>
/// <para>
/// ⚠️ <b>On the pinned LocalDb 0.2.1 the snapshot flag is per-DATABASE, not per-table.</b>
/// Baselining anything flags a resync that streams <b>every</b> registered table in full,
/// and on a pair enabling replication late both nodes do that to each other at once — the
/// largest transfer the library performs. Bounded, but expect one slow first sync, and
/// trim <c>alarm_sf_events</c> before enabling replication on a node that has been
/// buffering alarm history for a long time.
/// </para>
/// <para>
/// The per-table loop is kept rather than collapsed into a hypothetical bulk call: the
/// library's contract is per-table (PK validation, digest, and — from LocalDb 0.3.0 — the
/// snapshot flag itself), so a bulk API would only be able to give back the coarse
/// behaviour.
/// </para>
/// </remarks>
private static void RegisterForCapture(ILocalDb db)
{
foreach (var table in ReplicatedTables)
db.RegisterReplicated(table, baselineExistingRows: true);
}
/// <summary>Drops capture this node must not pay for, and says so once if it found any.</summary>
/// <remarks>
/// <c>DeregisterReplicated</c> is idempotent and deliberately usable on a table this process
/// never registered, so a never-replicated file simply reports nothing to clean and stays
/// silent. Symmetry is not a concern on this branch: this node has no peer, so there is no
/// handshake digest for a one-sided deregistration to fail — and re-enabling later is safe
/// despite the ledger prune, because <see cref="RegisterForCapture"/> baselines.
/// </remarks>
private static void RemoveStaleCapture(ILocalDb db, Serilog.ILogger logger)
{
var cleaned = 0;
foreach (var table in ReplicatedTables)
{
if (db.DeregisterReplicated(table))
cleaned++;
}
// Only when something was actually removed. Every default-OFF node in the fleet takes this
// branch on every boot; logging unconditionally would be a daily non-event, which is how the
// one boot that DID silently stop capturing gets overlooked.
if (cleaned > 0)
{
logger.Information(
"LocalDb: removed stale change-capture from {TableCount} table(s) — this node has no "
+ "replication configured ({PeerAddressKey}/{ApiKeyKey} are both absent — unset or blank), "
+ "so the capture "
+ "triggers an earlier build installed have been dropped and their oplog/row-version "
+ "rows pruned.",
cleaned,
$"{LocalDbRegistration.ReplicationSectionPath}:PeerAddress",
$"{LocalDbRegistration.ReplicationSectionPath}:ApiKey");
}
}
}
@@ -136,7 +136,8 @@ public sealed class RoslynVirtualTagEvaluator : IVirtualTagEvaluator, IScriptCac
}
catch (ScriptTimeoutException)
{
return VirtualTagEvalResult.Failure($"script timed out after {_runTimeout.TotalSeconds:F1}s");
return VirtualTagEvalResult.Failure(
$"{ScriptEvalFailureReasons.TimedOutPrefix}{_runTimeout.TotalSeconds:F1}s");
}
catch (ObjectDisposedException) when (!_disposed && attempt == 0)
{
@@ -148,7 +149,7 @@ public sealed class RoslynVirtualTagEvaluator : IVirtualTagEvaluator, IScriptCac
}
catch (ObjectDisposedException)
{
return VirtualTagEvalResult.Failure("evaluator disposed during evaluation");
return VirtualTagEvalResult.Failure(ScriptEvalFailureReasons.EvaluatorDisposedDuringEvaluation);
}
catch (Exception ex)
{
@@ -429,6 +429,8 @@ public sealed class SessionAclDecisionCache
/// <summary>
/// Advances the cache-wide stamp when this call presents a newer generation, and purges on the way.
/// The stamp ends up holding the highest generation any caller has presented — never a lower one,
/// and never one call late.
/// </summary>
/// <remarks>
/// <para>
@@ -443,21 +445,54 @@ public sealed class SessionAclDecisionCache
/// carries its own generation; what is at stake here is only whether the cache is any use.
/// </para>
/// <para>
/// ⚠️ <b>That guard lives INSIDE the loop, against a freshly re-read stamp</b> — hoisting it to a
/// single check before the loop reintroduces exactly the backward roll it exists to prevent: a
/// straggler that lost its exchange would spin back round and re-attempt against the newer stamp
/// it just lost to, and eventually succeed in rolling it back. Re-reading means the straggler
/// sees the newer value on its second pass and leaves.
/// </para>
/// <para>
/// <b>Why a loop rather than one exchange.</b> A single shot defers publication by a call: two
/// callers read the same baseline, the older one's exchange lands first, and the newer one's
/// fails and falls out having published nothing. Its own lookup then misses and the
/// <see cref="Set"/> that follows is dropped by the <c>Generation != generation</c> guard, which
/// costs a store in the post-deploy window where the cache is coldest. Retrying against the moved
/// stamp closes that: the higher generation is published on the call that presents it.
/// </para>
/// <para>
/// <b>The elected clear survives the loop.</b> Only the thread whose exchange actually moved the
/// stamp clears, so a burst of concurrent requests arriving just after a deploy still repopulates
/// once rather than each clearing the others' fresh entries. A retry can now clear too, but only
/// by winning a move to a strictly higher generation — so clears stay bounded by the number of
/// distinct generations presented, not by request volume.
/// </para>
/// <para>
/// <b>It terminates.</b> Each iteration either returns through the guard or exchanges against a
/// <c>seen</c> strictly larger than the last iteration's (a failed exchange means someone raised
/// the stamp), and <c>_generation</c> only ever rises — so the guard is reached within a bounded
/// number of passes.
/// </para>
/// <para>
/// The straggler's own lookup is unaffected by returning early: its shard-generation check misses
/// against the newer shards regardless, so it recomputes, which is the correct outcome for a
/// request holding a superseded snapshot. <c>_generation</c> starts at <c>-1</c>, below any real
/// generation, so the first one still passes.
/// generation, so the first one — generation <c>0</c> included — still passes.
/// </para>
/// </remarks>
/// <param name="generation">The generation the calling request is being decided under.</param>
private void InvalidateIfStale(long generation)
{
var seen = Interlocked.Read(ref _generation);
if (generation <= seen) return;
while (true)
{
var seen = Interlocked.Read(ref _generation);
if (generation <= seen) return;
// Only the thread that actually moves the stamp clears, so a burst of concurrent requests arriving
// just after a deploy repopulates once rather than each clearing the others' fresh entries.
if (Interlocked.CompareExchange(ref _generation, generation, seen) == seen) ClearAll();
if (Interlocked.CompareExchange(ref _generation, generation, seen) == seen)
{
ClearAll();
return;
}
}
}
/// <summary>
@@ -387,10 +387,14 @@ public sealed class S7SpanReadParityTests
/// failed REQUEST, and firing it here would re-read tags that already have good values.
/// </summary>
/// <remarks>
/// Health ends <c>Healthy</c> rather than <c>Degraded</c> because the decode loop stamps
/// health per item in chunk order, so the good item after the bad one re-stamps it. That is
/// the same last-writer-wins behaviour the per-tag loop has always had; it is pinned here so
/// a change to it is a deliberate one.
/// Health ends <c>Degraded</c>, NOT <c>Healthy</c>. This pin used to assert the opposite:
/// the decode loop stamped health per item in chunk order, so the good item after the bad
/// one re-stamped it and a pass with failures reported <c>Healthy</c> — last-writer-wins.
/// That was deliberately replaced (perf follow-ups round 3) by <b>worst-state-wins</b>: the
/// whole read pass accumulates its outcomes and writes health ONCE at the end, so a mixed
/// pass can no longer report Healthy. Only the driver-level health claim changed — the
/// per-tag statuses below are exactly as they were, because a per-ITEM decode fault still
/// spoils only its own tag.
/// </remarks>
[Fact]
public async Task One_undecodable_multi_var_item_stamps_only_its_own_tag_Bad()
@@ -420,7 +424,267 @@ public sealed class S7SpanReadParityTests
factory.MultiVarCalls.ShouldBe(1);
factory.StringReadCalls.ShouldBe(0);
factory.ReadBytesCalls.ShouldBe(0);
driver.GetHealth().State.ShouldBe(DriverState.Healthy);
driver.GetHealth().State.ShouldBe(DriverState.Degraded);
}
// ── Worst-state-wins read-pass health ────────────────────────────────────────────────
/// <summary>
/// A pass with BOTH failures and successes reports <c>Degraded</c> — the failure is not
/// erased by the later success — AND still advances <c>LastSuccessfulRead</c>, because
/// something genuinely was read.
/// </summary>
/// <remarks>
/// Advancing the timestamp on a Degraded pass is load-bearing, not cosmetic: the
/// comms-loss watchdog (CLAUDE.md §"Comms-loss detection") trips on non-Healthy state
/// <b>AND</b> a frozen <c>LastSuccessfulRead</c>. Several drivers latch Degraded off one
/// unreadable address, so freezing the timestamp on any non-Healthy pass would reconnect a
/// perfectly reachable PLC every 90 s forever.
/// </remarks>
[Fact]
public async Task A_mixed_read_pass_reports_Degraded_and_still_advances_LastSuccessfulRead()
{
var ct = TestContext.Current.CancellationToken;
var factory = new ImageS7PlcFactory(Images()) { NullItemIndex = 1 };
using var driver = new S7Driver(Options(ScatteredWords(3), maxGap: 2), "s7-mixed-pass", factory);
await driver.InitializeAsync("{}", ct);
// The connect stamped a LastSuccessfulRead; the pass must move it PAST that value, so a
// frozen timestamp is distinguishable from a merely non-null one.
var before = driver.GetHealth().LastSuccessfulRead;
before.ShouldNotBeNull();
var results = await driver.ReadAsync(ScatteredRefs(3), ct);
results[0].StatusCode.ShouldBe(0u);
results[1].StatusCode.ShouldBe(StatusBadCommunicationError);
results[2].StatusCode.ShouldBe(0u);
var health = driver.GetHealth();
health.State.ShouldBe(DriverState.Degraded, "a pass that had a failure must not report Healthy");
health.LastSuccessfulRead.ShouldNotBeNull();
health.LastSuccessfulRead!.Value.ShouldBeGreaterThan(
before!.Value, "two of the three tags read fine — the watchdog's evidence must advance");
}
/// <summary>
/// The SPAN path obeys the same rule: one member that fails to decode leaves the pass
/// <c>Degraded</c> even though a later member of the same block decoded fine.
/// </summary>
/// <remarks>
/// The block read itself succeeds — this is the per-member decode guard, the span-path
/// sibling of the multi-var per-item guard above. The poisoned member is an S7 STRING laid
/// over the image's filler pattern, whose two-byte header declares a current length larger
/// than its capacity; <c>S7String.FromByteArray</c> rejects that. It is deliberately the
/// FIRST member (lower offset) so the good member decodes after it — the exact ordering
/// last-writer-wins used to erase.
/// </remarks>
[Fact]
public async Task One_undecodable_span_member_leaves_the_pass_Degraded()
{
var ct = TestContext.Current.CancellationToken;
// The STRING occupies DB1 bytes 100..111 (StringLength + 2), so the word at 112 is
// adjacent and lands in the SAME span.
var tags = S7RawTags.Entries(
new S7TagDefinition("BadStr", "DB1.DBB100", S7DataType.String, Writable: false, StringLength: 10),
new S7TagDefinition("GoodWord", "DB1.DBW112", S7DataType.UInt16, Writable: false));
var factory = new ImageS7PlcFactory(Images());
// The poison is the FILLER, not a fake knob: Images() writes (i * 37 + 11) & 0xFF, which
// steps +37 per byte and so runs ASCENDING except in the ~15% of positions where it wraps
// past 256. Byte 100 is not one of those, so the STRING header at 100/101 reads
// maxLen 127 / curLen 164 — a current length larger than the capacity, which
// S7String.FromByteArray rejects. Asserted rather than assumed, so a change to the filler
// pattern fails HERE, loudly, instead of silently turning this into a passing no-op test.
var db1Image = factory.Images[(S7NetDataType.DataBlock, 1)];
db1Image[101].ShouldBeGreaterThan(
db1Image[100], "the S7 STRING at DB1.DBB100 must declare curLen > maxLen to be undecodable");
using var driver = new S7Driver(Options(tags, maxGap: 16), "s7-span-decode-fault", factory);
await driver.InitializeAsync("{}", ct);
var before = driver.GetHealth().LastSuccessfulRead;
var results = await driver.ReadAsync(["BadStr", "GoodWord"], ct);
// ONE block read served both members — this really is the span path, not two per-tag reads.
factory.ReadBytesCalls.ShouldBe(1);
factory.StringReadCalls.ShouldBe(0);
// Only the poisoned member is Bad; its block-mate keeps its value.
results[0].StatusCode.ShouldNotBe(0u);
results[0].Value.ShouldBeNull();
results[1].StatusCode.ShouldBe(0u);
results[1].Value.ShouldNotBeNull();
var health = driver.GetHealth();
health.State.ShouldBe(DriverState.Degraded, "a span member that failed to decode must not be erased");
health.LastSuccessfulRead!.Value.ShouldBeGreaterThan(before!.Value);
}
/// <summary>
/// Faulted outranks BOTH Degraded and Healthy: an access-denied read (the permanent PUT/GET
/// configuration fault) on one tag survives a later device-fault tag AND a later tag that
/// read successfully, all in the same pass.
/// </summary>
/// <remarks>
/// The ordering is Healthy &lt; Degraded &lt; Faulted, so the config alert — the one state
/// an operator must act on — is precisely the one last-writer-wins was most likely to
/// erase, since the denied tag is usually a minority of the batch. Both later outcomes are
/// present deliberately: the success falsifies "any success clears the failure", the
/// Degraded falsifies "the last failure wins". <c>LastSuccessfulRead</c> still advances,
/// because one tag really was read.
/// </remarks>
[Fact]
public async Task An_access_denied_tag_keeps_the_pass_Faulted_even_after_a_later_tag_succeeds()
{
var ct = TestContext.Current.CancellationToken;
var factory = new ImageS7PlcFactory(Images());
// A: "not allowed" is what IsAccessDenied matches — PUT/GET disabled on an S7-1200/1500,
// which is the Faulted config alert. B: an ordinary device-layer fault, merely Degraded,
// observed AFTER it. C: no fault at all.
factory.PerTagFaults["DB1.DBW0"] = new PlcException(ErrorCode.ReadData, "Accessing object not allowed");
factory.PerTagFaults["DB1.DBW2"] = new PlcException(ErrorCode.ReadData, "S7 CPU reported a device fault");
// maxGap -1 turns grouping off entirely, so every tag takes the per-tag read path and the
// faults can be aimed at individual addresses.
using var driver = new S7Driver(Options(NarrowTags(), maxGap: -1), "s7-access-denied", factory);
await driver.InitializeAsync("{}", ct);
var before = driver.GetHealth().LastSuccessfulRead;
var results = await driver.ReadAsync(["A", "B", "C"], ct);
results[0].StatusCode.ShouldNotBe(0u);
results[1].StatusCode.ShouldBe(StatusBadDeviceFailure);
results[2].StatusCode.ShouldBe(0u);
var health = driver.GetHealth();
health.State.ShouldBe(
DriverState.Faulted, "a config alert must outrank a later device fault AND a later success");
health.LastError.ShouldNotBeNull();
// The FIRST failure is the causal one — the later device fault does not overwrite it.
health.LastError!.ShouldContain("PUT/GET");
health.LastSuccessfulRead!.Value.ShouldBeGreaterThan(
before!.Value, "one tag read fine, so the watchdog's evidence must still advance");
}
/// <summary>
/// The pass's message must explain the state it reports. When a merely-Degraded fault is
/// observed BEFORE the access-denied one, escalating to <c>Faulted</c> has to re-point
/// <c>LastError</c> at the access-denied cause — reporting the config alert under the
/// earlier device-fault message tells the operator to chase the wrong thing.
/// </summary>
/// <remarks>
/// This is the reversed ordering of
/// <see cref="An_access_denied_tag_keeps_the_pass_Faulted_even_after_a_later_tag_succeeds"/>,
/// and the pair is the point: keeping the pass's chronologically-first message satisfies
/// that test and fails this one, so only a message that moves WITH the severity passes both.
/// </remarks>
[Fact]
public async Task Escalating_to_Faulted_re_points_the_error_message_at_the_access_denied_cause()
{
var ct = TestContext.Current.CancellationToken;
var factory = new ImageS7PlcFactory(Images());
// A: an ordinary device-layer fault (Degraded) FIRST. B: the access-denied config alert
// (Faulted) after it. C: no fault at all.
factory.PerTagFaults["DB1.DBW0"] = new PlcException(ErrorCode.ReadData, "S7 CPU reported a device fault");
factory.PerTagFaults["DB1.DBW2"] = new PlcException(ErrorCode.ReadData, "Accessing object not allowed");
using var driver = new S7Driver(Options(NarrowTags(), maxGap: -1), "s7-escalation-message", factory);
await driver.InitializeAsync("{}", ct);
var before = driver.GetHealth().LastSuccessfulRead;
var results = await driver.ReadAsync(["A", "B", "C"], ct);
results[0].StatusCode.ShouldBe(StatusBadDeviceFailure);
results[1].StatusCode.ShouldNotBe(0u);
results[2].StatusCode.ShouldBe(0u);
var health = driver.GetHealth();
health.State.ShouldBe(DriverState.Faulted, "the access-denied fault must still outrank the earlier one");
health.LastError.ShouldNotBeNull();
health.LastError!.ShouldContain(
"PUT/GET",
customMessage: "the message must explain the FAULTED state, not the earlier Degraded one");
health.LastSuccessfulRead!.Value.ShouldBeGreaterThan(before!.Value);
}
/// <summary>
/// Cancellation mid-pass abandons the batch but must NOT discard the evidence the pass had
/// already gathered: a tag that read successfully before the cancellation still advances
/// <c>LastSuccessfulRead</c>.
/// </summary>
/// <remarks>
/// Deciding health once at the end of the pass makes this a real risk, which per-item
/// writes did not have. On a partially-working device a repeatedly-cancelled poll would
/// freeze <c>LastSuccessfulRead</c> while tags were demonstrably still being read, and the
/// comms-loss watchdog — which trips on non-Healthy state AND a frozen timestamp — would
/// reconnect a CPU that is answering. Flushing from a <c>finally</c> is what prevents it.
/// </remarks>
[Fact]
public async Task A_cancelled_pass_still_flushes_the_evidence_it_had_already_gathered()
{
var ct = TestContext.Current.CancellationToken;
// Narrow first (a per-address read, which the hang knob does NOT intercept), then a wide
// Int64 (a BLOCK read, which it does) — so the pass banks one success and is then cancelled
// mid-flight on the very next tag.
var tags = S7RawTags.Entries(
new S7TagDefinition("Narrow", "DB1.DBW0", S7DataType.UInt16, Writable: false),
new S7TagDefinition("Wide", "DB1.DBB8", S7DataType.Int64, Writable: false));
var factory = new ImageS7PlcFactory(Images()) { HangReadBytes = true };
// maxGap -1 keeps both tags on the per-tag path, in reference order.
using var driver = new S7Driver(Options(tags, maxGap: -1), "s7-cancel-flush", factory);
await driver.InitializeAsync("{}", ct);
var before = driver.GetHealth().LastSuccessfulRead;
using var cts = new CancellationTokenSource();
var reading = driver.ReadAsync(["Narrow", "Wide"], cts.Token);
await factory.ReadBytesEntered.Task.WaitAsync(TimeSpan.FromSeconds(10), ct);
await cts.CancelAsync();
await Should.ThrowAsync<OperationCanceledException>(async () => await reading);
// The first tag really was served before the cancellation — one per-address read happened.
factory.StringReadCalls.ShouldBe(1);
var health = driver.GetHealth();
health.LastSuccessfulRead!.Value.ShouldBeGreaterThan(
before!.Value, "the banked success must survive the abandoned batch");
}
/// <summary>
/// A pass that observes NOTHING — every reference unresolvable, so not one tag was read and
/// not one failed — reports nothing: it must leave the driver's prior <c>Faulted</c> config
/// alert (and its <c>LastSuccessfulRead</c>) exactly as it found them.
/// </summary>
/// <remarks>
/// Deciding health once per pass means the pass has to answer "what did I observe?", and a
/// degenerate pass observed nothing at all — writing <c>Healthy</c> for it would invent
/// evidence and silently clear a PUT/GET config alert an operator still has to act on. The
/// per-item health writes this replaced had that property for free (no item, no write); the
/// end-of-pass guard is what preserves it.
/// </remarks>
[Fact]
public async Task A_pass_that_observes_nothing_leaves_a_prior_Faulted_untouched()
{
var ct = TestContext.Current.CancellationToken;
var factory = new ImageS7PlcFactory(Images());
factory.PerTagFaults["DB1.DBW0"] = new PlcException(ErrorCode.ReadData, "Accessing object not allowed");
using var driver = new S7Driver(Options(NarrowTags(), maxGap: -1), "s7-observes-nothing", factory);
await driver.InitializeAsync("{}", ct);
// Drive the driver into the access-denied config alert first.
_ = await driver.ReadAsync(["A"], ct);
var faulted = driver.GetHealth();
faulted.State.ShouldBe(DriverState.Faulted);
// Now a pass whose every reference is unresolvable: they are stamped BadNodeIdUnknown
// before the planner ever sees them, so no span, no multi-var item and no per-tag read
// happens — the pass observes neither a success nor a failure.
var results = await driver.ReadAsync(["NoSuchTag", "AlsoMissing"], ct);
results.ShouldAllBe(s => s.StatusCode == StatusBadNodeIdUnknown);
var after = driver.GetHealth();
after.State.ShouldBe(DriverState.Faulted, "an observe-nothing pass must not clear the config alert");
after.LastError.ShouldBe(faulted.LastError);
after.LastSuccessfulRead.ShouldBe(faulted.LastSuccessfulRead, "nothing was read, so nothing advances");
}
/// <summary>
@@ -611,6 +875,14 @@ public sealed class S7SpanReadParityTests
/// <summary>When set, only the MULTI-VAR read throws this — the per-tag fallback still serves the image.</summary>
public Exception? MultiVarFault { get; init; }
/// <summary>
/// Per-address read faults, keyed by the address string (e.g. <c>DB1.DBW0</c>): only
/// those addresses throw, every other one still serves the image. Lets a test put
/// faults of DIFFERENT severities and successes in ONE pass, which
/// <see cref="ReadFault"/> (all-or-nothing) cannot express.
/// </summary>
public Dictionary<string, Exception> PerTagFaults { get; } = new(StringComparer.OrdinalIgnoreCase);
/// <summary>
/// When true, <c>ReadBytesAsync</c> hangs until its token is cancelled, so cancellation is
/// the only way out of a block read (STAB-15a). Settable so a test can turn it back off
@@ -745,6 +1017,7 @@ public sealed class S7SpanReadParityTests
public Task<object?> ReadAsync(string address, CancellationToken ct)
{
Interlocked.Increment(ref owner.StringReadCalls);
if (owner.PerTagFaults.TryGetValue(address, out var aimed)) throw aimed;
if (owner.ReadFault is { } fault) throw fault;
var addr = S7AddressParser.Parse(address);
var image = owner.Images[(ToS7NetArea(addr.Area), addr.DbNumber)];
@@ -194,8 +194,17 @@ public sealed class AlarmSfLegacyMigratorTests : IDisposable
private ILocalDb BuildDb()
{
// The sync ApiKey is what makes OnReady register the tables for capture at all — since
// 2026-08-18 registration follows the replication config rather than being unconditional
// (see LocalDbSetup.ReplicationIsConfigured). Without it these databases would have no
// capture triggers and Migrated_rows_enter_the_oplog would pin nothing. A passive node
// carries exactly this and no PeerAddress, so it is also the realistic shape.
var configuration = new ConfigurationBuilder()
.AddInMemoryCollection(new Dictionary<string, string?> { ["LocalDb:Path"] = _dbPath })
.AddInMemoryCollection(new Dictionary<string, string?>
{
["LocalDb:Path"] = _dbPath,
["LocalDb:Replication:ApiKey"] = "test-sync-key",
})
.Build();
_provider = new ServiceCollection()
@@ -91,8 +91,8 @@ public sealed class LocalDbPairHarness : IAsyncDisposable
_apiKeyA = apiKeyA ?? DefaultApiKey;
_apiKeyB = apiKeyB ?? DefaultApiKey;
_dbProviderA = BuildDatabaseProvider(_pathA);
_dbProviderB = BuildDatabaseProvider(_pathB);
_dbProviderA = BuildDatabaseProvider(_pathA, _apiKeyA);
_dbProviderB = BuildDatabaseProvider(_pathB, _apiKeyB);
}
/// <summary>Node A — the initiator, which dials the peer.</summary>
@@ -148,7 +148,7 @@ public sealed class LocalDbPairHarness : IAsyncDisposable
DeleteDatabaseFiles(_pathB);
_pathB = Path.Combine(Path.GetTempPath(), $"otopcua-pairB-{Guid.NewGuid():N}.db");
_dbProviderB = BuildDatabaseProvider(_pathB);
_dbProviderB = BuildDatabaseProvider(_pathB, _apiKeyB);
_ = B;
}
@@ -258,10 +258,20 @@ public sealed class LocalDbPairHarness : IAsyncDisposable
/// A provider owning one deployment-cache database, initialised through the host's own
/// <see cref="LocalDbSetup.OnReady"/> — same schema, same registration order.
/// </summary>
private static ServiceProvider BuildDatabaseProvider(string path)
private static ServiceProvider BuildDatabaseProvider(string path, string apiKey)
{
// The ApiKey is not decoration here. Since 2026-08-18 OnReady registers the tables for
// change capture only when this node is CONFIGURED to replicate — PeerAddress or ApiKey
// (LocalDbSetup.ReplicationIsConfigured) — so a database built from `LocalDb:Path` alone
// would come up with no capture triggers and every convergence scenario below would time
// out with nothing to send. Production reads one configuration; this harness happens to
// build the database and the replication engine from two, and they must agree.
var config = new ConfigurationBuilder()
.AddInMemoryCollection(new Dictionary<string, string?> { ["LocalDb:Path"] = path })
.AddInMemoryCollection(new Dictionary<string, string?>
{
["LocalDb:Path"] = path,
["LocalDb:Replication:ApiKey"] = apiKey,
})
.Build();
return new ServiceCollection()
@@ -1,9 +1,12 @@
using Microsoft.Data.Sqlite;
using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.DependencyInjection;
using Serilog.Core;
using Serilog.Events;
using Shouldly;
using Xunit;
using ZB.MOM.WW.LocalDb;
using ZB.MOM.WW.LocalDb.Registration;
using ZB.MOM.WW.OtOpcUa.Host.Configuration;
namespace ZB.MOM.WW.OtOpcUa.Host.IntegrationTests;
@@ -20,49 +23,163 @@ namespace ZB.MOM.WW.OtOpcUa.Host.IntegrationTests;
/// every schema-shape test while shipping a replication path that quietly moves nothing.
/// </para>
/// <para>
/// <b>BEHAVIOUR CHANGE (2026-08-18): registration is CONDITIONAL on this node actually
/// being configured to replicate.</b> Until now <c>OnReady</c> registered all four tables
/// unconditionally, so every test here could build a database from <c>LocalDb:Path</c>
/// alone and still find them registered. They now pass a replication section, because that
/// is what makes registration happen at all — see
/// <see cref="OnReady_WhenReplicationIsNotConfigured_RegistersNothingAndInstallsNoTriggers"/>
/// for the other branch. The registered-table-set pin is therefore now a pin on
/// <b>configured</b> nodes; the unconfigured node's pin is the deregistration self-heal.
/// </para>
/// <para>
/// Built against a real temp-file <see cref="ILocalDb"/> rather than a hand-written schema:
/// the library has no in-memory mode, and asserting against a schema the test itself wrote
/// would only prove the test agrees with itself.
/// would only prove the test agrees with itself. That is doubly true here — the baseline and
/// deregistration behaviours live entirely inside the library, so only a real file can show
/// them.
/// </para>
/// </remarks>
public sealed class LocalDbSetupTests : IDisposable
{
/// <summary>
/// The initiating half of a replicating pair: it dials, so it carries <c>PeerAddress</c>.
/// </summary>
private static readonly KeyValuePair<string, string?>[] InitiatorReplication =
[
new("LocalDb:Replication:PeerAddress", "http://peer:9001"),
new("LocalDb:Replication:ApiKey", "test-sync-key"),
];
/// <summary>
/// The passive half of the same pair. It never dials, so it has <b>no</b> <c>PeerAddress</c>
/// — only the shared key (plus a listen port, which is Program.cs's concern). Keying the
/// predicate on <c>PeerAddress</c> alone would strip capture from this node and leave the
/// pair converging in one direction only.
/// </summary>
private static readonly KeyValuePair<string, string?>[] PassiveReplication =
[
new("LocalDb:Replication:ApiKey", "test-sync-key"),
];
private readonly string _dbPath =
Path.Combine(Path.GetTempPath(), $"otopcua-localdb-setup-{Guid.NewGuid():N}.db");
private ServiceProvider? _provider;
private readonly List<ServiceProvider> _providers = [];
private ILocalDb BuildDb()
/// <summary>
/// Boots <see cref="LocalDbSetup.OnReady"/> over the test's database file.
/// </summary>
/// <remarks>
/// <para>
/// Successive calls reopen the <b>same</b> file, which is how the self-heal and
/// late-opt-in cases are expressed: boot once under one replication configuration, write
/// rows, then boot again under another. That is exactly the sequence an operator
/// performs by editing config and restarting the node.
/// </para>
/// <para>
/// A null <paramref name="logger"/> lets <c>OnReady</c> fall back to Serilog's static
/// <c>Log.Logger</c>, which in this assembly is never assigned and is therefore the
/// library's silent default. That is a load-bearing assumption for the two cases that
/// DO pass a logger: were anything here to install a static logger, they would still
/// pass (they assert on their own sink) but the silent cases would start writing to it.
/// Pass a logger whenever the assertion is about logging.
/// </para>
/// </remarks>
private ILocalDb Boot(
KeyValuePair<string, string?>[]? replication = null,
Serilog.ILogger? logger = null)
{
// A previous boot's provider still holds the file open; the library has no second-handle
// mode. Closing it (and the pool) is what makes a reopen behave like a process restart.
DisposeProviders();
var settings = new List<KeyValuePair<string, string?>>
{
new("LocalDb:Path", _dbPath),
};
settings.AddRange(replication ?? []);
var configuration = new ConfigurationBuilder()
.AddInMemoryCollection(new Dictionary<string, string?> { ["LocalDb:Path"] = _dbPath })
.AddInMemoryCollection(settings)
.Build();
_provider = new ServiceCollection()
.AddZbLocalDb(configuration, db => LocalDbSetup.OnReady(db, configuration))
var provider = new ServiceCollection()
.AddZbLocalDb(configuration, db => LocalDbSetup.OnReady(db, configuration, logger))
.BuildServiceProvider();
return _provider.GetRequiredService<ILocalDb>();
_providers.Add(provider);
return provider.GetRequiredService<ILocalDb>();
}
private static async Task<int> ScalarAsync(ILocalDb db, string sql) =>
(await db.QueryAsync(sql, r => r.GetInt32(0), parameters: null, TestContext.Current.CancellationToken))[0];
private static Task InsertPointerAsync(ILocalDb db, string clusterId) =>
db.ExecuteAsync(
"""
INSERT INTO deployment_pointer
(cluster_id, deployment_id, revision_hash, artifact_sha256, applied_at_utc)
VALUES (@ClusterId, @DeploymentId, @RevisionHash, @Sha, @AppliedAtUtc)
""",
new
{
ClusterId = clusterId,
DeploymentId = "0123456789abcdef0123456789abcdef",
RevisionHash = new string('a', 64),
Sha = new string('b', 64),
AppliedAtUtc = "2026-07-20T00:00:00.0000000Z",
},
TestContext.Current.CancellationToken);
[Fact]
public void OnReady_RegistersExactlyTheFourReplicatedTables()
public void OnReady_WhenReplicationIsConfigured_RegistersExactlyTheFourReplicatedTables()
{
// Both directions are load-bearing. "No fewer" catches a dropped RegisterReplicated call
// (that table then never replicates). "No more" catches an accidental registration —
// every replicated table costs three triggers and oplog volume on every write.
var db = BuildDb();
var db = Boot(InitiatorReplication);
db.ReplicatedTables.Keys.OrderBy(k => k, StringComparer.Ordinal)
.ShouldBe(["alarm_condition_state", "alarm_sf_events", "deployment_artifacts", "deployment_pointer"]);
}
[Fact]
public void OnReady_WhenOnlyTheSyncApiKeyIsSet_StillRegistersTheFourTables()
{
// The passive half of a pair carries the key and nothing else. If the predicate were
// "PeerAddress is set", this node would install no capture triggers and its OWN writes
// would never reach the initiator — a pair that replicates in one direction only, with
// nothing logged anywhere. This test is the falsifier for that narrower predicate.
var db = Boot(PassiveReplication);
db.ReplicatedTables.Keys.OrderBy(k => k, StringComparer.Ordinal)
.ShouldBe(["alarm_condition_state", "alarm_sf_events", "deployment_artifacts", "deployment_pointer"]);
}
[Fact]
public async Task OnReady_WhenReplicationIsNotConfigured_RegistersNothingAndInstallsNoTriggers()
{
// The default-OFF node. It has no peer, so capture buys it nothing and costs it two INSERTs
// plus a json_object of the whole row inside every write transaction — for an oplog that is
// never drained. Asserting the trigger count as well as ReplicatedTables matters: the
// dictionary is in-process bookkeeping, the triggers are what actually run.
var db = Boot();
db.ReplicatedTables.ShouldBeEmpty();
// None of the three application schemas defines a trigger of its own, so every trigger in
// this file would be a capture trigger.
(await ScalarAsync(db, "SELECT COUNT(*) FROM sqlite_master WHERE type = 'trigger'")).ShouldBe(0);
}
[Fact]
public void DeploymentArtifacts_PkIsDeploymentIdPlusChunkIndex()
{
// The composite PK is what makes an artifact chunkable. A single-column PK here would
// make every chunk of a deployment collide onto one row under LWW.
var db = BuildDb();
var db = Boot(InitiatorReplication);
db.ReplicatedTables["deployment_artifacts"].PkColumns
.ShouldBe(["deployment_id", "chunk_index"]);
@@ -73,7 +190,7 @@ public sealed class LocalDbSetupTests : IDisposable
{
// One current-deployment pointer per cluster: the pair's two nodes converge on the same
// row rather than each keeping its own.
var db = BuildDb();
var db = Boot(InitiatorReplication);
db.ReplicatedTables["deployment_pointer"].PkColumns.ShouldBe(["cluster_id"]);
}
@@ -84,7 +201,7 @@ public sealed class LocalDbSetupTests : IDisposable
// A single TEXT PK the application mints. The legacy queue this table replaces keyed on
// `RowId INTEGER PRIMARY KEY AUTOINCREMENT`, which LWW cannot replicate: two nodes would
// independently allocate rowid 7 for different alarms and silently overwrite each other.
var db = BuildDb();
var db = Boot(InitiatorReplication);
db.ReplicatedTables["alarm_sf_events"].PkColumns.ShouldBe(["id"]);
}
@@ -94,7 +211,7 @@ public sealed class LocalDbSetupTests : IDisposable
{
// One condition-state row per alarm identity. The pair's two nodes converge on the same row
// under LWW rather than each keeping its own, and Save is an unconditional upsert onto it.
var db = BuildDb();
var db = Boot(InitiatorReplication);
db.ReplicatedTables["alarm_condition_state"].PkColumns.ShouldBe(["scripted_alarm_id"]);
}
@@ -106,7 +223,7 @@ public sealed class LocalDbSetupTests : IDisposable
// Worth its own case because the alarm table is registered by a different call site, and a
// registration added ahead of its DDL would fail loudly while one added after the migrator
// would fail silently.
var db = BuildDb();
var db = Boot(InitiatorReplication);
await db.ExecuteAsync(
"""
@@ -123,13 +240,8 @@ public sealed class LocalDbSetupTests : IDisposable
},
TestContext.Current.CancellationToken);
var oplogRows = await db.QueryAsync(
"SELECT COUNT(*) FROM __localdb_oplog WHERE table_name = 'alarm_sf_events'",
r => r.GetInt32(0),
parameters: null,
TestContext.Current.CancellationToken);
oplogRows[0].ShouldBe(1);
(await ScalarAsync(db, "SELECT COUNT(*) FROM __localdb_oplog WHERE table_name = 'alarm_sf_events'"))
.ShouldBe(1);
}
[Fact]
@@ -138,40 +250,215 @@ public sealed class LocalDbSetupTests : IDisposable
// THE ordering assertion. If DDL and RegisterReplicated were swapped — or a write were
// added to OnReady ahead of registration — the triggers would not exist at write time and
// this count would stay 0 while every other test in this file still passed.
var db = BuildDb();
var db = Boot(InitiatorReplication);
await db.ExecuteAsync(
"""
INSERT INTO deployment_pointer
(cluster_id, deployment_id, revision_hash, artifact_sha256, applied_at_utc)
VALUES (@ClusterId, @DeploymentId, @RevisionHash, @Sha, @AppliedAtUtc)
""",
new
{
ClusterId = "SITE-A",
DeploymentId = "0123456789abcdef0123456789abcdef",
RevisionHash = new string('a', 64),
Sha = new string('b', 64),
AppliedAtUtc = "2026-07-20T00:00:00.0000000Z",
},
TestContext.Current.CancellationToken);
await InsertPointerAsync(db, "SITE-A");
var oplogRows = await db.QueryAsync(
"SELECT COUNT(*) FROM __localdb_oplog",
r => r.GetInt32(0),
(await ScalarAsync(db, "SELECT COUNT(*) FROM __localdb_oplog")).ShouldBeGreaterThanOrEqualTo(1);
}
[Fact]
public async Task EnablingReplicationLater_BaselinesTheRowsAlreadyInTheFile()
{
// The defect this whole change exists for. Capture is change-data-capture and the snapshot
// streamer pages from __localdb_row_version, so rows written while replication was off are
// in neither — a late opt-in used to converge on subsequent writes only, silently and
// forever. RegisterReplicated(table, baselineExistingRows: true) seeds the ledger at the LWW
// floor and flags a resync so they actually travel.
//
// The assertion is on the ledger entry's HLC, not merely on its existence. A row captured by
// a trigger carries a genuine (large, non-zero) stamp; a BASELINED row is seeded at the LWW
// floor of HLC 0, which is what makes it lose to any real remote write of the same key and
// win only where the peer holds no version at all. Asserting existence alone would pass
// against the old unconditional registration, where the trigger simply captured the write —
// i.e. it would prove nothing about the flag.
var unreplicated = Boot();
await InsertPointerAsync(unreplicated, "SITE-A");
var replicated = Boot(InitiatorReplication);
(await ScalarAsync(
replicated,
"""
SELECT COUNT(*) FROM __localdb_row_version
WHERE table_name = 'deployment_pointer' AND hlc = 0
"""))
.ShouldBe(1);
}
[Fact]
public async Task DisablingReplication_DropsTheCaptureTriggersAnEarlierBootInstalled()
{
// The self-heal half. Merely declining to register would leave a file registered by an
// earlier build capturing forever — on precisely the node that has no peer to capture for.
// DeregisterReplicated drops the triggers and prunes that table's oplog and row-version
// rows.
var replicated = Boot(InitiatorReplication);
await InsertPointerAsync(replicated, "SITE-A");
(await ScalarAsync(replicated, "SELECT COUNT(*) FROM sqlite_master WHERE type = 'trigger'"))
.ShouldBe(12);
var unreplicated = Boot();
unreplicated.ReplicatedTables.ShouldBeEmpty();
(await ScalarAsync(unreplicated, "SELECT COUNT(*) FROM sqlite_master WHERE type = 'trigger'"))
.ShouldBe(0);
}
[Fact]
public async Task DisablingReplication_PrunesBookkeepingButNeverTouchesTheCachedDataItself()
{
// Deregistration prunes the table's oplog and row-version rows — BOOKKEEPING. It must not
// touch the base table, because deployment_pointer/deployment_artifacts ARE the
// boot-from-cache backstop: a node whose central SQL is unreachable serves its address space
// from exactly these rows. A library regression that cleaned the base table along with the
// ledger would take that safety net out silently, on the very nodes that never replicate
// (central, site-b) and so would never notice a replication fault either.
var replicated = Boot(InitiatorReplication);
await InsertPointerAsync(replicated, "SITE-A");
(await ScalarAsync(replicated, "SELECT COUNT(*) FROM __localdb_row_version")).ShouldBeGreaterThan(0);
var unreplicated = Boot();
// The row survives, and with its content intact — a count alone would pass against a
// cleanup that blanked the columns it does not own.
var pointers = await unreplicated.QueryAsync(
"SELECT cluster_id || '|' || deployment_id || '|' || revision_hash FROM deployment_pointer",
static r => r.GetString(0),
parameters: null,
TestContext.Current.CancellationToken);
oplogRows[0].ShouldBeGreaterThanOrEqualTo(1);
pointers.ShouldBe([$"SITE-A|0123456789abcdef0123456789abcdef|{new string('a', 64)}"]);
// …while the bookkeeping it DOES own is gone.
(await ScalarAsync(unreplicated, "SELECT COUNT(*) FROM __localdb_row_version")).ShouldBe(0);
(await ScalarAsync(unreplicated, "SELECT COUNT(*) FROM __localdb_oplog")).ShouldBe(0);
}
[Fact]
public async Task DisablingReplication_LogsOnceWhenItActuallyCleanedSomething()
{
// An operator-visible record that a node just stopped capturing, and how much it dropped.
// Silent trigger removal on a node someone MEANT to replicate is the failure this line
// exists to make diagnosable.
var replicated = Boot(InitiatorReplication);
await InsertPointerAsync(replicated, "SITE-A");
var sink = new CollectingSink();
Boot(replication: null, logger: BuildLogger(sink));
sink.Events.Count(e => e.Level == LogEventLevel.Information).ShouldBe(1);
}
[Fact]
public void DisablingReplication_SaysNothingWhenThereWasNothingToClean()
{
// The steady state of every default-OFF node in the fleet: it boots unreplicated every day
// and has nothing to deregister. A log line here would be a daily false alarm, which is how
// the real one gets ignored.
var sink = new CollectingSink();
Boot(replication: null, logger: BuildLogger(sink));
sink.Events.ShouldBeEmpty();
}
[Fact]
public void AFailureMidwayThroughRegistration_FailsBootLoudly_AndTheRetriedBootConverges()
{
// OnReady flips four tables in a loop with no try/catch, so a failure on the third leaves
// two registered and two not. That is the RIGHT behaviour and this pins both halves of why:
// the throw propagates out of the AddZbLocalDb singleton factory and fails host start
// (a node half-capturing is a node whose replication is silently partial), and because both
// library APIs are idempotent the retried boot completes the flip rather than compounding it.
//
// Swallowing the throw would leave the node up, serving, and replicating two of four tables
// with nothing in the log to say so.
var real = Boot(InitiatorReplication);
var configuration = new ConfigurationBuilder()
.AddInMemoryCollection([new KeyValuePair<string, string?>("LocalDb:Path", _dbPath), .. InitiatorReplication])
.Build();
var faulty = new FailsOnNthRegistration(real, failOnCall: 3);
Should.Throw<InvalidOperationException>(() => LocalDbSetup.OnReady(faulty, configuration));
// The wrapper really did reach the third call — otherwise the assertion above would be
// pinning some unrelated throw, and the "partial flip" it claims to model never happened.
faulty.Calls.ShouldBe(3);
// The retry: same file, no wrapper. Idempotent re-registration converges on all four.
LocalDbSetup.OnReady(real, configuration);
real.ReplicatedTables.Keys.OrderBy(k => k, StringComparer.Ordinal)
.ShouldBe(["alarm_condition_state", "alarm_sf_events", "deployment_artifacts", "deployment_pointer"]);
}
/// <summary>
/// Passes everything through to a real database except the <c>failOnCall</c>-th
/// <c>RegisterReplicated</c>, which throws — the mid-loop partial-flip shape.
/// </summary>
private sealed class FailsOnNthRegistration(ILocalDb inner, int failOnCall) : ILocalDb
{
/// <summary>How many registrations were attempted, successful or not.</summary>
public int Calls { get; private set; }
public IReadOnlyDictionary<string, ReplicatedTable> ReplicatedTables => inner.ReplicatedTables;
public SqliteConnection CreateConnection() => inner.CreateConnection();
public Task<int> ExecuteAsync(string sql, object? parameters, CancellationToken cancellationToken) =>
inner.ExecuteAsync(sql, parameters, cancellationToken);
public Task<IReadOnlyList<T>> QueryAsync<T>(
string sql, Func<SqliteDataReader, T> map, object? parameters, CancellationToken cancellationToken) =>
inner.QueryAsync(sql, map, parameters, cancellationToken);
public Task<ILocalDbTransaction> BeginTransactionAsync(CancellationToken cancellationToken) =>
inner.BeginTransactionAsync(cancellationToken);
public ReplicatedTable RegisterReplicated(string tableName) =>
RegisterReplicated(tableName, baselineExistingRows: false);
public ReplicatedTable RegisterReplicated(string tableName, bool baselineExistingRows)
{
Calls++;
if (Calls == failOnCall)
throw new InvalidOperationException($"simulated registration failure on '{tableName}'");
return inner.RegisterReplicated(tableName, baselineExistingRows);
}
public bool DeregisterReplicated(string tableName) => inner.DeregisterReplicated(tableName);
}
private static Serilog.ILogger BuildLogger(ILogEventSink sink) =>
new Serilog.LoggerConfiguration().MinimumLevel.Verbose().WriteTo.Sink(sink).CreateLogger();
/// <summary>Captures whatever <see cref="LocalDbSetup.OnReady"/> logs.</summary>
private sealed class CollectingSink : ILogEventSink
{
public List<LogEvent> Events { get; } = [];
public void Emit(LogEvent logEvent) => Events.Add(logEvent);
}
private void DisposeProviders()
{
foreach (var provider in _providers)
provider.Dispose();
_providers.Clear();
// No in-memory mode, so these are real files. Pooled connections keep a handle open past
// dispose; clearing the pools first is what lets a reopen (or the delete below) succeed.
SqliteConnection.ClearAllPools();
}
public void Dispose()
{
_provider?.Dispose();
// No in-memory mode, so these are real files. Pooled connections keep a handle open past
// dispose; clearing the pools first is what makes the delete actually succeed.
SqliteConnection.ClearAllPools();
DisposeProviders();
foreach (var path in new[] { _dbPath, $"{_dbPath}-wal", $"{_dbPath}-shm" })
{
@@ -45,16 +45,27 @@ public sealed class LocalDbWiringTests : IDisposable
/// <see cref="LocalDbRegistration.AddOtOpcUaLocalDb"/>, health, and observability methods,
/// over a temp-file <c>LocalDb:Path</c>.
/// </summary>
private IServiceProvider BuildDriverGraph()
/// <param name="replicating">
/// Whether this node carries a replication configuration. Since 2026-08-18 that is what
/// decides whether <c>LocalDbSetup.OnReady</c> registers the tables for change capture at
/// all, so the two graphs are genuinely different nodes and both are pinned below. Most of
/// the fleet is the default-OFF one.
/// </param>
private IServiceProvider BuildDriverGraph(bool replicating = false)
{
var dbPath = Path.Combine(Path.GetTempPath(), $"otopcua-wiring-{Guid.NewGuid():N}.db");
_dbPaths.Add(dbPath);
var builder = WebApplication.CreateBuilder(new WebApplicationOptions { Args = [] });
builder.Configuration.AddInMemoryCollection(new Dictionary<string, string?>
var settings = new Dictionary<string, string?>
{
["LocalDb:Path"] = dbPath,
});
};
if (replicating)
settings["LocalDb:Replication:ApiKey"] = "wiring-test-sync-key";
var builder = WebApplication.CreateBuilder(new WebApplicationOptions { Args = [] });
builder.Configuration.AddInMemoryCollection(settings);
// The exact LocalDb composition Program.cs runs under hasDriver.
builder.Services.AddOtOpcUaLocalDb(builder.Configuration);
@@ -86,9 +97,9 @@ public sealed class LocalDbWiringTests : IDisposable
}
[Fact]
public void DriverGraph_LocalDbResolvesAsASingletonWithEveryReplicatedTableRegistered()
public void ReplicatingDriverGraph_LocalDbResolvesAsASingletonWithEveryReplicatedTableRegistered()
{
var sp = BuildDriverGraph();
var sp = BuildDriverGraph(replicating: true);
var first = sp.GetService<ILocalDb>();
first.ShouldNotBeNull();
@@ -100,6 +111,22 @@ public sealed class LocalDbWiringTests : IDisposable
.ShouldBe(["alarm_condition_state", "alarm_sf_events", "deployment_artifacts", "deployment_pointer"]);
}
[Fact]
public void DefaultOffDriverGraph_LocalDbStillResolvesButRegistersNoTables()
{
// BEHAVIOUR CHANGE (2026-08-18): registration follows the replication config. This graph is
// most of the fleet — central and site-b are default-OFF — and it must still get a working
// local database (the artifact cache and the alarm buffer both depend on it) while paying
// for none of the change-capture machinery it has no peer to send to.
var sp = BuildDriverGraph();
var db = sp.GetService<ILocalDb>();
db.ShouldNotBeNull();
sp.GetService<IDeploymentArtifactCache>().ShouldNotBeNull();
db.ReplicatedTables.ShouldBeEmpty();
}
[Fact]
public void DriverGraph_ArtifactCacheResolvesToTheLocalDbBackedImplementation()
{
@@ -5,6 +5,7 @@ using Serilog;
using Serilog.Events;
using Shouldly;
using Xunit;
using ZB.MOM.WW.OtOpcUa.Commons.Engines;
using ZB.MOM.WW.OtOpcUa.Commons.Messages.Logging;
using ZB.MOM.WW.OtOpcUa.Core.Scripting;
using ZB.MOM.WW.OtOpcUa.Host.Engines;
@@ -380,45 +381,112 @@ public sealed class RoslynVirtualTagEvaluatorTests
CompiledCacheCount(sut).ShouldBe(1);
}
/// <summary>02/S12 concurrent stress repro (RED on current code): while one loop runs many compiled
/// (non-passthrough) evaluations of the same expression, a second loop hammers
/// <see cref="RoslynVirtualTagEvaluator.ClearCompiledScripts"/> — the apply-boundary clear. On the
/// unfixed tree a clear landing between a child's <c>GetOrCompile</c> and the run's disposed-guard
/// surfaces an ObjectDisposedException as a <c>Failure("script threw: Cannot access a disposed
/// object…")</c>; the fix retries once and every result stays Success. The whole test is WaitAsync-
/// bounded so a regression fails fast rather than hanging.</summary>
/// <summary>How long the racing loops below keep hammering the evaluator. A DURATION rather than a
/// fixed iteration count: every clear forces a recompile, so a fixed workload's wall-clock cost tracks
/// whatever CPU the box has left, and a busy box then blows the test's own hang budget.</summary>
private static readonly TimeSpan RaceWindow = TimeSpan.FromSeconds(10);
/// <summary>Upper bound on evaluations per racing loop, so an idle box does bounded work rather than
/// spinning for the whole <see cref="RaceWindow"/>.</summary>
private const int MaxIterationsPerLoop = 400;
/// <summary>02/S12 concurrent stress: while many loops run compiled (non-passthrough) evaluations of
/// the same expression, a second loop hammers <see cref="RoslynVirtualTagEvaluator.ClearCompiledScripts"/>
/// — the apply-boundary clear. A clear landing between a child's <c>GetOrCompile</c> and the run's
/// disposed-guard raises an <see cref="ObjectDisposedException"/> inside the evaluation; on the unfixed
/// tree that escaped as <c>Failure("script threw: Cannot access a disposed object…")</c>, and the fix
/// re-fetches into the current cache generation and retries ONCE. The whole test is WaitAsync-bounded so
/// a regression fails fast rather than hanging.
///
/// <para><b>Shape history — why this is not a zero-failure assertion (renamed 2026-08-18 from
/// <c>Evaluate_racing_ClearCompiledScripts_never_fails_with_disposed</c>).</b> The test previously
/// asserted <c>failures.ShouldBeEmpty()</c>, which silently encoded a TIMING assumption: that at most
/// ONE clear can land inside a single evaluation, so the product's one-shot retry always suffices. The
/// clear loop's spin cadence was tuned to hold that assumption. It does not hold under full-solution
/// parallel test load — with the thread pool saturated the fetch→run window stretches, TWO clears land
/// inside one evaluation, and the retry legitimately exhausts. The test failed under load while passing
/// 3/3 in isolation. That is a test-design defect, not a product defect: exhausting a one-shot retry
/// under a clear cadence no production apply comes close to is a documented, bounded outcome.</para>
///
/// <para>The fix could have re-paced the clears against observed evaluation latency, but that only
/// swaps one timing assumption for a safer one — it stays load-sensitive, and needs machinery to
/// measure latency at runtime. Instead the assertion now targets the invariant the retry actually
/// guarantees, which is timing-independent: <b>no raw disposed-script failure ever ESCAPES the
/// retry</b>. A "script threw: Cannot access a disposed object…" (the generic-catch escape) fails the
/// test on the first occurrence, however loaded the box is. Everything else this race can legitimately
/// produce is bucketed and rate-bounded rather than banned, which keeps the check non-vacuous — a build
/// whose retry never absorbs anything would otherwise sail through a shape-only assertion:</para>
/// <list type="bullet">
/// <item><see cref="ScriptEvalFailureReasons.EvaluatorDisposedDuringEvaluation"/> — the documented
/// retry-exhaustion outcome (two clears inside one evaluation).</item>
/// <item><see cref="ScriptEvalFailureReasons.TimedOutPrefix"/> — <b>the second residual vector, and it
/// is a starvation symptom, not a disposed-race escape.</b> This test deliberately saturates the thread
/// pool (hundreds of <c>Task.Run</c> enqueues per second from 12 loops plus a spinning clear loop), and
/// <c>TimedScriptEvaluator</c> starts its clock at <c>WaitAsync</c> rather than when the inner
/// <c>Task.Run</c> gets a thread — so a perfectly healthy evaluation can blow the 5 s budget while still
/// queued. Classifying that as a leak would hand the test back the load-fragility this reshape removed.</item>
/// </list>
///
/// <para><b>The workload is duration-bounded, and that is the SECOND timing assumption removed.</b> The
/// loops used to run a fixed 12 × 400 = 4800 evaluations against a fixed 45 s <c>WaitAsync</c> budget.
/// Every clear forces the next evaluation to recompile (5-20 ms), so the wall-clock cost of that fixed
/// workload is set by how much CPU the box will spare — and running four instances of this test class
/// concurrently on the dev box reproduced a hard failure that has nothing to do with the race:
/// <c>System.TimeoutException</c> at the 45 s budget, 4/4 runs. That is almost certainly the shape the
/// original "fails under full-solution parallel test load" report saw. The loops now stop at
/// <see cref="RaceWindow"/> OR <see cref="MaxIterationsPerLoop"/>, whichever comes first, so a starved
/// box simply lands fewer evaluations instead of blowing a budget; the 45 s <c>WaitAsync</c> is left in
/// place purely as a hang detector, with 4× headroom over the window it now guards.</para>
///
/// <para><b>Calibration of both bounds (be sceptical of them).</b> The disposed-race did NOT
/// reproduce at all on the arm64 macOS dev box this reshape was written on — zero failures in isolation,
/// zero under concurrently-running Runtime.Tests / Host.Tests / OpcUaServer suites, and still zero with
/// the product's one-shot retry experimentally disabled, i.e. the fetch→run window never opened there
/// and this test was vacuous on that hardware whatever it asserted. So the bound could not be fitted to
/// a measured rate; it is 10% of the evaluations actually performed, hundreds of times looser than the
/// old fire-on-the-first-failure assertion. Exhaustion needs a clear inside BOTH the first attempt's
/// window and the retry's, so its rate goes as the square of the single-window hit rate — 10% of
/// evaluations exhausting implies roughly a third of them hitting a disposed evaluator on the first
/// try, which is a broken retry, not a busy machine. The starvation-timeout bucket gets the same bound
/// for the same reason: a handful of queued-too-long evaluations is the environment, but 10% of them
/// missing a 5 s budget means the evaluator stopped evaluating. If a loaded box ever does trip EITHER
/// bound, the rate itself is the finding: record it before widening the number.</para></summary>
[Fact]
public async Task Evaluate_racing_ClearCompiledScripts_never_fails_with_disposed()
public async Task Evaluate_racing_ClearCompiledScripts_never_leaks_a_raw_disposed_failure()
{
// Generous timeout so the wall-clock budget never fires and confounds the race assertion.
// Generous script budget so the wall-clock timeout rarely fires and confounds the race assertion —
// "rarely", not "never": it covers the Task.Run enqueue, so a starved pool can still blow it. That
// residual is bucketed and bounded below rather than treated as a disposed-race escape.
using var sut = new RoslynVirtualTagEvaluator(
NullLogger<RoslynVirtualTagEvaluator>.Instance, NoOpScriptRoot(), TimeSpan.FromSeconds(5));
const string expr = "return (int)ctx.GetTag(\"a\").Value + 1;";
const int loopCount = 12;
const int iterations = 400;
var failures = new System.Collections.Concurrent.ConcurrentBag<string>();
var remaining = loopCount; // number of concurrent evaluation loops still running
var evaluated = 0; // evaluations actually performed (the race window may cut loops short)
var remaining = loopCount; // number of concurrent evaluation loops still running
var stopAtMs = Environment.TickCount64 + (long)RaceWindow.TotalMilliseconds;
// Many concurrent evaluation loops put the thread pool under enough pressure that the inner
// Task.Run hop inside TimedScriptEvaluator is measurably delayed — widening the
// fetch→run-disposed-guard window so a clear reliably lands inside SOME in-flight evaluation.
// The clear loop clears on a short spin cadence (not back-to-back) so (a) most evaluations hit
// the warm cache — keeping compile cost bounded — and (b) at most one clear lands within a
// single evaluation, so the single retry the fix adds is sufficient (a back-to-back clear loop
// would both compile-swamp the RED run into a timeout and defeat the one-shot retry). Pre-fix a
// clear disposing the just-fetched evaluator surfaces as Failure("script threw: Cannot access a
// disposed object…"); post-fix the retry re-fetches into the current generation → all Success.
// fetch→run-disposed-guard window so a clear can land inside an in-flight evaluation.
// The clear loop clears on a short spin cadence rather than back-to-back purely as a COST bound:
// most evaluations then hit the warm cache instead of recompiling. Neither the cadence nor the
// iteration count is a correctness knob any more — the assertions below hold for any number of
// clears landing inside a single evaluation, and for any number of evaluations completed.
var evalLoops = Enumerable.Range(0, loopCount).Select(_ => Task.Run(() =>
{
for (var i = 0; i < iterations; i++)
var done = 0;
for (var i = 0; i < MaxIterationsPerLoop && Environment.TickCount64 < stopAtMs; i++)
{
var r = sut.Evaluate("vt-race", expr, new Dictionary<string, object?> { ["a"] = i });
done++;
if (!r.Success)
{
failures.Add(r.Reason ?? "<null reason>");
}
}
Interlocked.Add(ref evaluated, done);
Interlocked.Decrement(ref remaining);
}, TestContext.Current.CancellationToken)).ToArray();
@@ -431,11 +499,44 @@ public sealed class RoslynVirtualTagEvaluatorTests
}
}, TestContext.Current.CancellationToken);
// Hang detector only: the loops self-terminate at RaceWindow, so firing this means something
// wedged, not that the box was slow.
await Task.WhenAll(evalLoops.Append(clearLoop))
.WaitAsync(TimeSpan.FromSeconds(45), TestContext.Current.CancellationToken);
failures.ShouldBeEmpty(
$"every evaluation must succeed despite racing clears; observed: {string.Join(" | ", failures)}");
var totalEvaluations = Volatile.Read(ref evaluated);
// Loose by design, with an absolute floor so a starved run (few evaluations landed) cannot trip on
// a single occurrence. See the doc-comment: broken-behaviour detectors, not timing gates.
var rateBound = Math.Max(totalEvaluations / 10, 8);
var exhausted = failures.Count(r => r == ScriptEvalFailureReasons.EvaluatorDisposedDuringEvaluation);
var starved = failures.Count(r => r.StartsWith(ScriptEvalFailureReasons.TimedOutPrefix, StringComparison.Ordinal));
// (1) The invariant, and the only assertion that fires on a single occurrence: a raw
// ObjectDisposedException escaping the retry (pre-fix: "script threw: Cannot access a
// disposed object…") lands here, as does any other unexpected failure mode. The two
// legitimate outcomes above are excluded — they are rate-bounded instead, below.
var leaked = failures
.Where(r => r != ScriptEvalFailureReasons.EvaluatorDisposedDuringEvaluation)
.Where(r => !r.StartsWith(ScriptEvalFailureReasons.TimedOutPrefix, StringComparison.Ordinal))
.ToArray();
leaked.ShouldBeEmpty(
"a racing ClearCompiledScripts must never surface a failure other than " +
$"\"{ScriptEvalFailureReasons.EvaluatorDisposedDuringEvaluation}\" or " +
$"\"{ScriptEvalFailureReasons.TimedOutPrefix}…\"; observed: {string.Join(" | ", leaked)}");
// (2) Non-vacuity: the retry must actually be absorbing the race, not merely relabelling it.
exhausted.ShouldBeLessThan(
rateBound,
"the one-shot retry must absorb the overwhelming majority of raced clears; " +
$"{exhausted}/{totalEvaluations} evaluations exhausted it");
// (3) The starvation bucket is tolerated but not unbounded — at 10% the evaluator has stopped
// evaluating rather than the box being busy.
starved.ShouldBeLessThan(
rateBound,
"queue-starvation timeouts are expected under this stress but must stay marginal; " +
$"{starved}/{totalEvaluations} evaluations missed the 5s budget");
}
/// <summary>Reads the count of the private compiled-script cache via reflection. The cache is a
@@ -1,3 +1,4 @@
using System.Diagnostics;
using Shouldly;
using Xunit;
using ZB.MOM.WW.OtOpcUa.Commons.OpcUa;
@@ -14,7 +15,7 @@ namespace ZB.MOM.WW.OtOpcUa.OpcUaServer.Tests;
/// different from the one asked. Each test below pins one dimension the key must discriminate on,
/// because a key that collides across any of them hands one session another's authority.
/// </remarks>
public sealed class SessionAclDecisionCacheTests
public sealed class SessionAclDecisionCacheTests(ITestOutputHelper output)
{
private const string Session = "key-1";
private const string Node = "Plant/Modbus/dev1/Speed";
@@ -520,6 +521,151 @@ public sealed class SessionAclDecisionCacheTests
cache.LiveShardCount.ShouldBe(cache.Count);
}
/// <summary>
/// Two lookups arriving together at different generations must leave the <b>higher</b> one stamped,
/// whichever of them wins the compare-exchange.
/// </summary>
/// <remarks>
/// <para>
/// The single-shot-CAS defect: both callers read the same baseline stamp, and if the <i>older</i>
/// generation's exchange lands first, the newer one's exchange fails against the moved stamp and
/// falls out with no retry. Its generation is never published, so its own <c>TryGet</c> misses and
/// the <c>Set</c> that follows is dropped at the <c>Generation != generation</c> guard — a lost
/// store in exactly the post-deploy window where the cache is coldest. Verdict safety is not at
/// stake (the per-shard generation check decides that); cache usefulness is.
/// </para>
/// <para>
/// ⚠️ <b>Red is probabilistic per round</b> — it needs both racers to read the baseline stamp
/// before either exchanges, a window a few instructions wide. Everything about the harness
/// exists to buy those odds, and the measurements are why it looks the way it does: fresh
/// threads per round land red about once in twenty thousand, a two-party <see cref="Barrier"/>
/// no better (its post-phase action releases from <i>inside</i> one racer, handing it a head
/// start), while the long-lived racers plus a third-thread starter used below turn roughly a
/// sixth to a half of all rounds red.
/// </para>
/// <para>
/// ⚠️ <b>Do not cut the round count on that arithmetic.</b> A per-round rate near 25% suggests a
/// couple of hundred rounds would be overwhelming — but the misses are not independent, they
/// arrive in run-length bursts: the racers get descheduled <i>together</i> for a stretch, and the
/// stretch can be the whole run. Measured, against the mutation, with the rest of this assembly
/// running in parallel as it does in CI: <b>2,000 rounds passed vacuously in 1 run of 3</b>
/// (stale=0 — the defect present and undetected), while 10,000 was red in 5 of 5, first hit
/// within rounds 1-13, stale 1,595-4,591. The same 2,000 rounds run <i>alone</i> never missed
/// (70-986 stale), so the load from the sibling classes is the variable that matters, and a
/// standalone measurement will overstate the margin. The cost of the margin is ~20ms.
/// </para>
/// <para>
/// Every round gets a <b>fresh cache</b>: both racers must start from the <c>-1</c> seed, or the
/// previous round's stamp would let the <c>&lt;=</c> guard return before either reaches the
/// exchange and the race would never be run at all.
/// </para>
/// <para>
/// It is also the only pin on the retry loop's <b>straggler guard being re-read per attempt</b>.
/// Hoisting that guard to a single check before the loop leaves
/// <see cref="A_straggler_from_an_older_generation_neither_clears_nor_rolls_the_stamp_back"/>
/// green — that straggler is sequential, so the one pre-loop check still catches it — while a
/// straggler that <i>lost an exchange</i> spins back, re-reads the newer stamp as its expected
/// value, and rolls it backward. That lands here, as the same stale-stamp failure.
/// </para>
/// <para>
/// Nothing here uses <c>AdvanceGenerationForTest</c>: the stamp must move through the ordinary
/// lookup path, which is the path the defect lives on.
/// </para>
/// </remarks>
[Fact]
public void Concurrent_lookups_at_mixed_generations_always_publish_the_highest()
{
const int rounds = 10_000;
const int spinsBeforeYield = 4_000;
// Array-as-ref-cell: the one cell that is re-seated every round (a fresh cache per round), shared
// by the starter and both racers. A captured local would also take `ref` (gate/finished below do
// exactly that) — the array is a readability choice marking the re-seated slot, not a necessity.
var slot = new SessionAclDecisionCache[1];
var gate = 0; // starter's release signal: the round number both racers are cleared to run
var finished = 0; // racers' completion count for the current round
var firstStaleRound = -1;
var staleRounds = 0;
// ⚠️ Deliberately NOT the file's Barrier-per-round idiom (see
// Concurrent_eviction_and_insertion_leave_the_counter_exact, which is the right shape for its job:
// many workers that only need to start together). This gate/finished spin protocol exists because
// the window here is nanoseconds wide and a Barrier releases from inside one of the racers — see the
// remarks above. Both idioms are in the file on purpose; neither is a stray.
//
// Raw threads rather than the thread pool: the pool may serialise two work items onto one thread,
// which would make the race unreachable. Held for the whole run so the release is the only skew.
var low = new Thread(() => Race(1L)) { IsBackground = true };
var high = new Thread(() => Race(2L)) { IsBackground = true };
var started = Stopwatch.GetTimestamp();
low.Start();
high.Start();
for (var round = 0; round < rounds; round++)
{
Volatile.Write(ref slot[0], new SessionAclDecisionCache());
Volatile.Write(ref finished, 0);
Volatile.Write(ref gate, round + 1); // both racers are spinning on this one store
for (var spins = 0; Volatile.Read(ref finished) != 2; spins++)
if (spins < spinsBeforeYield) Thread.SpinWait(1);
else Thread.Yield();
if (Volatile.Read(ref slot[0]).Generation != 2L)
{
if (firstStaleRound < 0) firstStaleRound = round;
staleRounds++;
}
}
low.Join();
high.Join();
var elapsed = Stopwatch.GetElapsedTime(started);
// Emitted unconditionally, because the way this test fails on a constrained runner is by passing.
// ⚠️ It cannot report a hit rate: under the fixed code no round is stale BY DEFINITION, and how many
// rounds actually entered the read-then-exchange window is unobservable from out here — the only way
// to see it would be to instrument production, which is not worth a diagnostic. So it reports what it
// can honestly measure, and the reading is: fewer than 3 processors means the three threads cannot
// run concurrently and the race is unreachable, while a per-round cost well above the 1.5-3us/round
// this machine turns in means the racers are being descheduled rather than spinning (24us/round was
// observed under load, and that is the shape of a run that proves less than it looks like it does).
// The measured red rate under the single-shot mutation is 16-46% of rounds.
output.WriteLine(
$"rounds={rounds} stale={staleRounds} processors={Environment.ProcessorCount} " +
$"elapsed={elapsed.TotalMilliseconds:F1}ms perRound={elapsed.TotalMicroseconds / rounds:F2}us");
firstStaleRound.ShouldBe(
-1,
$"round {firstStaleRound} (of {staleRounds} stale in {rounds}): the newer generation must " +
"publish even when it loses the CAS race");
void Race(long generation)
{
for (var round = 0; round < rounds; round++)
{
// Tight spin on the starter's store, not a park: both racers take the same invalidation from
// a third core and so leave the spin within a few nanoseconds of each other. Releasing from
// one of the racers instead (a Barrier's post-phase action) hands the releaser a head start
// of roughly the other's wake-up latency, which is orders of magnitude wider than the
// read-then-exchange window and drives the hit rate to near zero. The yield after
// spinsBeforeYield is only a liveness backstop for a machine with fewer cores than this
// needs threads — the release normally lands long before it.
for (var spins = 0; Volatile.Read(ref gate) != round + 1; spins++)
if (spins < spinsBeforeYield) Thread.SpinWait(1);
else Thread.Yield();
Volatile.Read(ref slot[0])
.TryGet(generation, Session, OpcUaOperation.Read, AddressSpaceRealm.Raw, Node, out _);
Interlocked.Increment(ref finished);
}
}
}
private static bool Ask(
SessionAclDecisionCache cache,
long generation,
@@ -23,10 +23,14 @@ namespace ZB.MOM.WW.OtOpcUa.Runtime.Tests.DeploymentCache;
/// semantics — live entirely in SQL, so a mocked seam would assert nothing about them.
/// </para>
/// <para>
/// This project cannot reference the Host, so the schema setup here mirrors
/// <c>LocalDbSetup.OnReady</c> rather than calling it. The load-bearing
/// <c>DDL → RegisterReplicated</c> ordering is pinned by the Host's own
/// <c>LocalDbSetupTests</c>; what matters here is only that the tables exist.
/// This project cannot reference the Host, so the setup here reproduces only the two
/// cache <b>tables</b> — not <c>LocalDbSetup.OnReady</c>'s behaviour. In particular it
/// registers them unconditionally and without baselining, whereas the production callback
/// registers only when the node is configured to replicate and deregisters when it is not.
/// That divergence is intentional and inert here: these tests need a database whose tables
/// exist and capture, and nothing below asserts anything about registration. The
/// load-bearing DDL-then-RegisterReplicated ordering and the conditional-registration rules
/// are pinned by the Host's own <c>LocalDbSetupTests</c>.
/// </para>
/// </remarks>
public sealed class LocalDbDeploymentArtifactCacheTests : IDisposable