From c9bc358dc912dba046e6d42c9f72d4509fbda816 Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Fri, 13 Nov 2026 07:46:56 -0500 Subject: [PATCH] feat(cli): print array values; docs: #615 G9 PASS with otopcua-cli, G8 waived G9 ran on an isolated 2-node pair (otopcua-g9, 003c7f89, Mode unset as deployed) with otopcua-cli as the owner-approved client: A1-A3, A5, A7, A8 (graceful, ~11 s gap), B2 (docker kill, failover <1 s, ~2 s gap, 0 Bad, survivor 250 at +44 s) and B3 (no failback) pass; A4/A5b unmet under Unset, met under Warm (#717). G8 (CTT) waived by the owner for GA; G5 is the only open exit criterion. The run found the CLI printing every array as System.String[] (ServerArray unreadable); ValueFormatter now renders [a, b] / hex for read, subscribe and historyread, with tests. Runbook A4/A5b text updated for the #717 modes. Evidence: docs/plans/evidence/2026-11-13-615-g9/RESULTS.md. --- .../evidence/2026-11-13-615-g9/RESULTS.md | 54 +++++++ .../client/A1-A7-baseline.txt | 50 +++++++ .../client/A3-c1-servicelevel.txt | 10 ++ .../2026-11-13-615-g9/client/A8-data.txt | 116 ++++++++++++++ .../2026-11-13-615-g9/client/A8-sl.txt | 26 ++++ .../2026-11-13-615-g9/client/B2-data.txt | 141 ++++++++++++++++++ .../2026-11-13-615-g9/client/B2-sl.txt | 18 +++ .../client/B2-survivor-sl.txt | 4 + .../2026-11-13-615-g9/client/B3-final.txt | 3 + .../client/B3-survivor-sl.txt | 10 ++ .../2026-11-13-615-g9/client/actions.log | 8 + .../client/rejoin-after-graceful.txt | 3 + .../evidence/2026-11-13-615-g9/rig/Dockerfile | 5 + .../rig/central-1-excerpt.log | 115 ++++++++++++++ .../rig/central-2-excerpt.log | 81 ++++++++++ .../2026-11-13-615-g9/rig/compose.g9.yml | 102 +++++++++++++ .../evidence/2026-11-13-615-g9/rig/seed.sql | 27 ++++ .../phase-6-3-redundancy-interop-plan.md | 22 +-- docs/plans/v2-ga-lab-gates-plan.md | 11 +- docs/v2/v2-release-readiness.md | 7 +- .../Commands/HistoryReadCommand.cs | 4 +- .../Commands/ReadCommand.cs | 2 +- .../Commands/SubscribeCommand.cs | 2 +- .../Helpers/ValueFormatter.cs | 25 ++++ .../ValueFormatterTests.cs | 35 +++++ 25 files changed, 861 insertions(+), 20 deletions(-) create mode 100644 docs/plans/evidence/2026-11-13-615-g9/RESULTS.md create mode 100644 docs/plans/evidence/2026-11-13-615-g9/client/A1-A7-baseline.txt create mode 100644 docs/plans/evidence/2026-11-13-615-g9/client/A3-c1-servicelevel.txt create mode 100644 docs/plans/evidence/2026-11-13-615-g9/client/A8-data.txt create mode 100644 docs/plans/evidence/2026-11-13-615-g9/client/A8-sl.txt create mode 100644 docs/plans/evidence/2026-11-13-615-g9/client/B2-data.txt create mode 100644 docs/plans/evidence/2026-11-13-615-g9/client/B2-sl.txt create mode 100644 docs/plans/evidence/2026-11-13-615-g9/client/B2-survivor-sl.txt create mode 100644 docs/plans/evidence/2026-11-13-615-g9/client/B3-final.txt create mode 100644 docs/plans/evidence/2026-11-13-615-g9/client/B3-survivor-sl.txt create mode 100644 docs/plans/evidence/2026-11-13-615-g9/client/actions.log create mode 100644 docs/plans/evidence/2026-11-13-615-g9/client/rejoin-after-graceful.txt create mode 100644 docs/plans/evidence/2026-11-13-615-g9/rig/Dockerfile create mode 100644 docs/plans/evidence/2026-11-13-615-g9/rig/central-1-excerpt.log create mode 100644 docs/plans/evidence/2026-11-13-615-g9/rig/central-2-excerpt.log create mode 100644 docs/plans/evidence/2026-11-13-615-g9/rig/compose.g9.yml create mode 100644 docs/plans/evidence/2026-11-13-615-g9/rig/seed.sql create mode 100644 src/Client/ZB.MOM.WW.OtOpcUa.Client.CLI/Helpers/ValueFormatter.cs create mode 100644 tests/Client/ZB.MOM.WW.OtOpcUa.Client.CLI.Tests/ValueFormatterTests.cs diff --git a/docs/plans/evidence/2026-11-13-615-g9/RESULTS.md b/docs/plans/evidence/2026-11-13-615-g9/RESULTS.md new file mode 100644 index 000000000..7800f221f --- /dev/null +++ b/docs/plans/evidence/2026-11-13-615-g9/RESULTS.md @@ -0,0 +1,54 @@ +# #615 G9: non-transparent redundancy cutover with a client (2026-11-13) + +**Result: PASS.** Every runbook row in scope passes (A1–A3, A5, A7, A8, B2, B3). A4 and A5b are recorded as unmet +under the deployed `Unset` mode; they are met under `Warm` (#717 T13 L1). The client is `otopcua-cli`. The owner +approved it as the G9 client on 2026-11-13, in place of UaExpert or Ignition. The same day the owner waived G8 (CTT) +for GA. + +## Setup + +| Item | Value | +|---|---| +| Build | `master` `003c7f89`, published on the host into `rig/Dockerfile` (image `otopcua-host:g9-003c7f89`, removed afterwards). | +| Rig | compose project `otopcua-g9` (`rig/compose.g9.yml`, derived from the #717 T13b rig): own network, SQL and volumes. Ports: OPC UA `25840` (central-1) / `25841` (central-2), HTTP `29310`/`29311`, SQL `25339`. The shared docker-dev rig and the `10.100.0.35` fixtures were not touched. | +| Topology | `central-1` + `central-2`, roles `admin,driver,cluster-MAIN`, self-first seeds, each node's partner in `OpcUa:PeerApplicationUris`. | +| Mode | `OpcUa__Redundancy__Mode` **absent** = `Unset`, the default every deployment runs today. `Warm` cannot be enabled before #907 (ScadaBridge#138). | +| Config | Schema via `dotnet ef database update`, then `rig/seed.sql`: T13's seed without the API key and ACL rows (`Security:Acl:Enabled=false`, so the CLI reads anonymously), with the equipment created under its canonical id. Calculation driver `t13-calc/Device1/calc-seconds` (UTC seconds-of-day, 1 s timer), UNS reference `t13/warm/t13-equipment/calc-seconds`. Deployment `348cc165`, sealed with both nodes `Applied`. | +| Client | `otopcua-cli` built from the same tree plus the CLI array-formatting fix below. `subscribe … -F ` is the failover client. Times in `client/*.txt` are UTC in the value lines (`[11/13/2026 hh:mm:ss]`) and local EST (UTC−5) in the CLI's own log lines (`[07:mm:ss INF]`). `client/actions.log` is the operator timeline in UTC. | + +**A CLI defect found and fixed during the run.** `read` printed every array value as its CLR type name +(`System.String[]`), so the CLI could not show `ServerArray` (A5) at all. The new `Helpers/ValueFormatter` prints +`[a, b]` (hex for byte strings) and is used by `read`, `subscribe` and `historyread`; `ValueFormatterTests` covers it. +The CLI tests pass (183). + +## Results + +| Row | Check | Result | Evidence | +|---|---|---|---| +| A1 | ServiceLevel on the Primary (central-1, oldest) | **PASS**: 250 | `client/A1-A7-baseline.txt` | +| A2 | ServiceLevel on the follower | **PASS**: 240 | same | +| A3 | Stopping the follower does not demote the Primary | **PASS**: a 75 s subscription on central-1's `i=2267` received only the initial 250 while central-2 was down (12:35:08 → 12:36:28). | `client/A3-c1-servicelevel.txt` | +| A4 | RedundancySupport `i=3709` | **UNMET under `Unset`**: observed `0` (None), the SDK default. `Unset` deliberately leaves the metadata untouched; `Warm` serves `Warm` (#717 T13 L1). | `client/A1-A7-baseline.txt` | +| A5 | ServerArray `i=2254` peer discovery | **PASS**: central-1 `[urn:OtOpcUa:central-1, urn:OtOpcUa:central-2]`, central-2 `[urn:OtOpcUa:central-2, urn:OtOpcUa:central-1]`. | same | +| A5b | ServerUriArray `i=11314` | **UNMET under `Unset`**: Good `[]` (the SDK's orphan node, documented in `docs/Redundancy.md`). Not counted as a pass via A5. `Warm` serves `[self, peers]` (#717 T13 L1). | same | +| A6 | Endpoint-failure step-down | SKIP (not in the G9 minimum; covered by lmxopcua#761) | — | +| A7 | Client CLI reads ServiceLevel | **PASS** (A1/A2 were read with it) | same | +| A8 | CLI failover reconnect on a graceful Primary stop | **PASS**: `docker stop` of central-1 at 12:36:52.47 (stop returned 12:36:58.54). Both `-F` sessions logged "Session lost … Failover succeeded to :25841" (SL client 12:37:00, data client 12:37:03). ServiceLevel on central-2 already read 250 (source time 12:36:52). Data resumed Good; the gap was 12:36:52 → 12:37:03 (~11 s, the client noticing the loss by keep-alive) with no Bad value. | `client/A8-sl.txt`, `client/A8-data.txt` | +| — | Rejoin after the graceful stop | **PASS**: central-1 restarted at 12:38:55 and settled at 240 by 12:39:06; central-2 stayed 250 (no failback). | `client/rejoin-after-graceful.txt` | +| B2 | Client cuts over on a Primary **crash** | **PASS**: `docker kill` of central-2 (then Primary) at 12:39:42.16. Both `-F` clients failed over to central-1 at 12:39:42 (connection refused, immediate). Data: last Good 12:39:41, next Good 12:39:43, 127 Good notifications and 0 Bad/Uncertain in the window. Survivor ServiceLevel: 240 → 200 at 12:40:07 (+25 s, stale snapshot while the dead node is downed) → 250 at 12:40:26 (+44 s), the same timings as #717 T13b. Data stayed Good throughout. | `client/B2-data.txt`, `client/B2-sl.txt`, `client/B2-survivor-sl.txt` | +| B3 | Returning node settles as follower | **PASS**: central-2 restarted at 12:42:23 and read 240 by 12:42:31. A subscription on central-1's ServiceLevel saw only 250 throughout. Final: central-1 250 + data Good, central-2 240 + data Good. | `client/B3-survivor-sl.txt`, `client/B3-final.txt` | +| B1, B4, B5 | UaExpert / Kepware / OI Gateway | SKIP: the owner accepted the CLI as the G9 client. | — | +| C1–C3 | Galaxy failover | SKIP: no Galaxy on the rig (G6 covered Galaxy end to end). | — | + +**Server logs** (`rig/central-*-excerpt.log`, from 12:31): no `FTL`. Every `ERR`/`WRN` matches a planned action: +- "The domain 'opc.tcp://localhost:2584x/OtOpcUa' is not listed in the server certificate": one per CLI session, because the CLI connects through a `localhost` port mapping with security `None` and the certificate names the container host. +- Akka `Disassociated`: the planned peer stops and kill. +- Two `BadTimeout` service faults at 12:36:58.28: pending Publish requests failed while central-1 shut itself down (A8). +- `ForceChannelFault … BadConnectionClosed` at 12:41:49: CLI subscriptions closing at their `--duration` end. + +The `ERR` entries before 12:31 come from the first boot, before the schema existed (rig setup). The first deploy was +dropped with "No mesh gRPC targets" because central-1 had booted before the seed was retried. Both nodes were +restarted and redeployed; that is rig ordering, not a product issue. + +**Teardown:** `docker compose -p otopcua-g9 down -v` and `docker rmi otopcua-host:g9-003c7f89`. The containers, +volumes and networks outside the project are identical to the pre-run snapshot. diff --git a/docs/plans/evidence/2026-11-13-615-g9/client/A1-A7-baseline.txt b/docs/plans/evidence/2026-11-13-615-g9/client/A1-A7-baseline.txt new file mode 100644 index 000000000..12e686119 --- /dev/null +++ b/docs/plans/evidence/2026-11-13-615-g9/client/A1-A7-baseline.txt @@ -0,0 +1,50 @@ +### opc.tcp://localhost:25840 12:34:31 +Node: i=2267 +Value: 250 +Status: Good [0x00000000] +Node: i=3709 +Value: 0 +Status: Good [0x00000000] +Node: i=2254 +Value: [urn:OtOpcUa:central-1, urn:OtOpcUa:central-2] +Status: Good [0x00000000] +Node: i=11314 +Value: [] +Status: Good [0x00000000] +Invalid --node value: Invalid node ID format: 'nsu=https://zb.com/otopcua/raw;s=t13-calc/Device1/calc-seconds' +Invalid --node value: Invalid node ID format: 'nsu=https://zb.com/otopcua/uns;s=t13/warm/t13-equipment/calc-seconds' +### opc.tcp://localhost:25841 12:34:33 +Node: i=2267 +Value: 240 +Status: Good [0x00000000] +Node: i=3709 +Value: 0 +Status: Good [0x00000000] +Node: i=2254 +Value: [urn:OtOpcUa:central-2, urn:OtOpcUa:central-1] +Status: Good [0x00000000] +Node: i=11314 +Value: [] +Status: Good [0x00000000] +Invalid --node value: Invalid node ID format: 'nsu=https://zb.com/otopcua/raw;s=t13-calc/Device1/calc-seconds' +Invalid --node value: Invalid node ID format: 'nsu=https://zb.com/otopcua/uns;s=t13/warm/t13-equipment/calc-seconds' +### opc.tcp://localhost:25840 data 12:34:49 +Node: ns=2;s=t13-calc/Device1/calc-seconds +Value: 45289 +Status: Good [0x00000000] +Node: ns=3;s=t13/warm/t13-equipment/calc-seconds +Value: 45290 +Status: Good [0x00000000] +Node: ns=3;s=t13/warm/t13-equipment/vt-second +Value: +Status: BadNodeIdUnknown [0x80340000] (BadNodeIdUnknown) +### opc.tcp://localhost:25841 data 12:34:51 +Node: ns=2;s=t13-calc/Device1/calc-seconds +Value: 45291 +Status: Good [0x00000000] +Node: ns=3;s=t13/warm/t13-equipment/calc-seconds +Value: 45292 +Status: Good [0x00000000] +Node: ns=3;s=t13/warm/t13-equipment/vt-second +Value: +Status: BadNodeIdUnknown [0x80340000] (BadNodeIdUnknown) diff --git a/docs/plans/evidence/2026-11-13-615-g9/client/A3-c1-servicelevel.txt b/docs/plans/evidence/2026-11-13-615-g9/client/A3-c1-servicelevel.txt new file mode 100644 index 000000000..ad785122f --- /dev/null +++ b/docs/plans/evidence/2026-11-13-615-g9/client/A3-c1-servicelevel.txt @@ -0,0 +1,10 @@ +Subscribed to 1/1 nodes (interval: 500ms). Press Ctrl+C to stop and print summary. +[11/13/2026 12:32:22] i=2267 = 250 (Good [0x00000000]) + +==================== SUMMARY ==================== +Total subscribed: 1 + Ever went BAD during window: 0 + NEVER went bad (suspect): 1 + Last status GOOD: 1 + Last status NOT-GOOD: 0 + No update received at all: 0 diff --git a/docs/plans/evidence/2026-11-13-615-g9/client/A8-data.txt b/docs/plans/evidence/2026-11-13-615-g9/client/A8-data.txt new file mode 100644 index 000000000..ec6e5de4e --- /dev/null +++ b/docs/plans/evidence/2026-11-13-615-g9/client/A8-data.txt @@ -0,0 +1,116 @@ +[07:36:44 DBG] ApplicationConfiguration created for opc.tcp://localhost:25840 +[07:36:44 DBG] Rewrote endpoint from opc.tcp://0.0.0.0:4840/OtOpcUa to opc.tcp://localhost:25840/OtOpcUa +[07:36:44 INF] Session created: OtOpcUaClient -> opc.tcp://localhost:25840/OtOpcUa +[07:36:44 INF] Connected to opc.tcp://localhost:25840/OtOpcUa +[07:36:44 DBG] Added data change monitored item for ns=2;s=t13-calc/Device1/calc-seconds, handle=3 +[07:36:44 DBG] Subscribed to data changes on ns=2;s=t13-calc/Device1/calc-seconds +Subscribed to 1/1 nodes (interval: 1000ms). Press Ctrl+C to stop and print summary. +[11/13/2026 12:36:45] ns=2;s=t13-calc/Device1/calc-seconds = 45405 (Good [0x00000000]) +[11/13/2026 12:36:46] ns=2;s=t13-calc/Device1/calc-seconds = 45406 (Good [0x00000000]) +[11/13/2026 12:36:47] ns=2;s=t13-calc/Device1/calc-seconds = 45407 (Good [0x00000000]) +[11/13/2026 12:36:48] ns=2;s=t13-calc/Device1/calc-seconds = 45408 (Good [0x00000000]) +[11/13/2026 12:36:49] ns=2;s=t13-calc/Device1/calc-seconds = 45409 (Good [0x00000000]) +[11/13/2026 12:36:50] ns=2;s=t13-calc/Device1/calc-seconds = 45410 (Good [0x00000000]) +[11/13/2026 12:36:51] ns=2;s=t13-calc/Device1/calc-seconds = 45411 (Good [0x00000000]) +[11/13/2026 12:36:52] ns=2;s=t13-calc/Device1/calc-seconds = 45412 (Good [0x00000000]) +[07:37:03 WRN] Session lost on opc.tcp://localhost:25840/OtOpcUa. Attempting failover... +[07:37:03 INF] Failover attempt to opc.tcp://localhost:25841 +[07:37:03 DBG] ApplicationConfiguration created for opc.tcp://localhost:25841 +[07:37:03 DBG] Rewrote endpoint from opc.tcp://0.0.0.0:4840/OtOpcUa to opc.tcp://localhost:25841/OtOpcUa +[07:37:03 INF] Session created: OtOpcUaClient -> opc.tcp://localhost:25841/OtOpcUa +[07:37:03 INF] Failover succeeded to opc.tcp://localhost:25841 +[07:37:03 DBG] Added data change monitored item for ns=2;s=t13-calc/Device1/calc-seconds, handle=6 +[11/13/2026 12:37:03] ns=2;s=t13-calc/Device1/calc-seconds = 45423 (Good [0x00000000]) +[11/13/2026 12:37:04] ns=2;s=t13-calc/Device1/calc-seconds = 45424 (Good [0x00000000]) +[11/13/2026 12:37:05] ns=2;s=t13-calc/Device1/calc-seconds = 45425 (Good [0x00000000]) +[11/13/2026 12:37:06] ns=2;s=t13-calc/Device1/calc-seconds = 45426 (Good [0x00000000]) +[11/13/2026 12:37:07] ns=2;s=t13-calc/Device1/calc-seconds = 45427 (Good [0x00000000]) +[11/13/2026 12:37:08] ns=2;s=t13-calc/Device1/calc-seconds = 45428 (Good [0x00000000]) +[11/13/2026 12:37:09] ns=2;s=t13-calc/Device1/calc-seconds = 45429 (Good [0x00000000]) +[11/13/2026 12:37:10] ns=2;s=t13-calc/Device1/calc-seconds = 45430 (Good [0x00000000]) +[11/13/2026 12:37:11] ns=2;s=t13-calc/Device1/calc-seconds = 45431 (Good [0x00000000]) +[11/13/2026 12:37:12] ns=2;s=t13-calc/Device1/calc-seconds = 45432 (Good [0x00000000]) +[11/13/2026 12:37:13] ns=2;s=t13-calc/Device1/calc-seconds = 45433 (Good [0x00000000]) +[11/13/2026 12:37:15] ns=2;s=t13-calc/Device1/calc-seconds = 45435 (Good [0x00000000]) +[11/13/2026 12:37:16] ns=2;s=t13-calc/Device1/calc-seconds = 45436 (Good [0x00000000]) +[11/13/2026 12:37:17] ns=2;s=t13-calc/Device1/calc-seconds = 45437 (Good [0x00000000]) +[11/13/2026 12:37:18] ns=2;s=t13-calc/Device1/calc-seconds = 45438 (Good [0x00000000]) +[11/13/2026 12:37:19] ns=2;s=t13-calc/Device1/calc-seconds = 45439 (Good [0x00000000]) +[11/13/2026 12:37:20] ns=2;s=t13-calc/Device1/calc-seconds = 45440 (Good [0x00000000]) +[11/13/2026 12:37:21] ns=2;s=t13-calc/Device1/calc-seconds = 45441 (Good [0x00000000]) +[11/13/2026 12:37:22] ns=2;s=t13-calc/Device1/calc-seconds = 45442 (Good [0x00000000]) +[11/13/2026 12:37:23] ns=2;s=t13-calc/Device1/calc-seconds = 45443 (Good [0x00000000]) +[11/13/2026 12:37:25] ns=2;s=t13-calc/Device1/calc-seconds = 45445 (Good [0x00000000]) +[11/13/2026 12:37:26] ns=2;s=t13-calc/Device1/calc-seconds = 45446 (Good [0x00000000]) +[11/13/2026 12:37:27] ns=2;s=t13-calc/Device1/calc-seconds = 45447 (Good [0x00000000]) +[11/13/2026 12:37:28] ns=2;s=t13-calc/Device1/calc-seconds = 45448 (Good [0x00000000]) +[11/13/2026 12:37:29] ns=2;s=t13-calc/Device1/calc-seconds = 45449 (Good [0x00000000]) +[11/13/2026 12:37:30] ns=2;s=t13-calc/Device1/calc-seconds = 45450 (Good [0x00000000]) +[11/13/2026 12:37:31] ns=2;s=t13-calc/Device1/calc-seconds = 45451 (Good [0x00000000]) +[11/13/2026 12:37:32] ns=2;s=t13-calc/Device1/calc-seconds = 45452 (Good [0x00000000]) +[11/13/2026 12:37:33] ns=2;s=t13-calc/Device1/calc-seconds = 45453 (Good [0x00000000]) +[11/13/2026 12:37:34] ns=2;s=t13-calc/Device1/calc-seconds = 45454 (Good [0x00000000]) +[11/13/2026 12:37:35] ns=2;s=t13-calc/Device1/calc-seconds = 45455 (Good [0x00000000]) +[11/13/2026 12:37:36] ns=2;s=t13-calc/Device1/calc-seconds = 45456 (Good [0x00000000]) +[11/13/2026 12:37:38] ns=2;s=t13-calc/Device1/calc-seconds = 45458 (Good [0x00000000]) +[11/13/2026 12:37:39] ns=2;s=t13-calc/Device1/calc-seconds = 45459 (Good [0x00000000]) +[11/13/2026 12:37:40] ns=2;s=t13-calc/Device1/calc-seconds = 45460 (Good [0x00000000]) +[11/13/2026 12:37:41] ns=2;s=t13-calc/Device1/calc-seconds = 45461 (Good [0x00000000]) +[11/13/2026 12:37:42] ns=2;s=t13-calc/Device1/calc-seconds = 45462 (Good [0x00000000]) +[11/13/2026 12:37:43] ns=2;s=t13-calc/Device1/calc-seconds = 45463 (Good [0x00000000]) +[11/13/2026 12:37:44] ns=2;s=t13-calc/Device1/calc-seconds = 45464 (Good [0x00000000]) +[11/13/2026 12:37:45] ns=2;s=t13-calc/Device1/calc-seconds = 45465 (Good [0x00000000]) +[11/13/2026 12:37:46] ns=2;s=t13-calc/Device1/calc-seconds = 45466 (Good [0x00000000]) +[11/13/2026 12:37:48] ns=2;s=t13-calc/Device1/calc-seconds = 45468 (Good [0x00000000]) +[11/13/2026 12:37:49] ns=2;s=t13-calc/Device1/calc-seconds = 45469 (Good [0x00000000]) +[11/13/2026 12:37:50] ns=2;s=t13-calc/Device1/calc-seconds = 45470 (Good [0x00000000]) +[11/13/2026 12:37:51] ns=2;s=t13-calc/Device1/calc-seconds = 45471 (Good [0x00000000]) +[11/13/2026 12:37:52] ns=2;s=t13-calc/Device1/calc-seconds = 45472 (Good [0x00000000]) +[11/13/2026 12:37:53] ns=2;s=t13-calc/Device1/calc-seconds = 45473 (Good [0x00000000]) +[11/13/2026 12:37:54] ns=2;s=t13-calc/Device1/calc-seconds = 45474 (Good [0x00000000]) +[11/13/2026 12:37:55] ns=2;s=t13-calc/Device1/calc-seconds = 45475 (Good [0x00000000]) +[11/13/2026 12:37:56] ns=2;s=t13-calc/Device1/calc-seconds = 45476 (Good [0x00000000]) +[11/13/2026 12:37:57] ns=2;s=t13-calc/Device1/calc-seconds = 45477 (Good [0x00000000]) +[11/13/2026 12:37:59] ns=2;s=t13-calc/Device1/calc-seconds = 45479 (Good [0x00000000]) +[11/13/2026 12:38:00] ns=2;s=t13-calc/Device1/calc-seconds = 45480 (Good [0x00000000]) +[11/13/2026 12:38:01] ns=2;s=t13-calc/Device1/calc-seconds = 45481 (Good [0x00000000]) +[11/13/2026 12:38:02] ns=2;s=t13-calc/Device1/calc-seconds = 45482 (Good [0x00000000]) +[11/13/2026 12:38:03] ns=2;s=t13-calc/Device1/calc-seconds = 45483 (Good [0x00000000]) +[11/13/2026 12:38:04] ns=2;s=t13-calc/Device1/calc-seconds = 45484 (Good [0x00000000]) +[11/13/2026 12:38:05] ns=2;s=t13-calc/Device1/calc-seconds = 45485 (Good [0x00000000]) +[11/13/2026 12:38:06] ns=2;s=t13-calc/Device1/calc-seconds = 45486 (Good [0x00000000]) +[11/13/2026 12:38:07] ns=2;s=t13-calc/Device1/calc-seconds = 45487 (Good [0x00000000]) +[11/13/2026 12:38:09] ns=2;s=t13-calc/Device1/calc-seconds = 45489 (Good [0x00000000]) +[11/13/2026 12:38:10] ns=2;s=t13-calc/Device1/calc-seconds = 45490 (Good [0x00000000]) +[11/13/2026 12:38:11] ns=2;s=t13-calc/Device1/calc-seconds = 45491 (Good [0x00000000]) +[11/13/2026 12:38:12] ns=2;s=t13-calc/Device1/calc-seconds = 45492 (Good [0x00000000]) +[11/13/2026 12:38:13] ns=2;s=t13-calc/Device1/calc-seconds = 45493 (Good [0x00000000]) +[11/13/2026 12:38:14] ns=2;s=t13-calc/Device1/calc-seconds = 45494 (Good [0x00000000]) +[11/13/2026 12:38:15] ns=2;s=t13-calc/Device1/calc-seconds = 45495 (Good [0x00000000]) +[11/13/2026 12:38:16] ns=2;s=t13-calc/Device1/calc-seconds = 45496 (Good [0x00000000]) +[11/13/2026 12:38:17] ns=2;s=t13-calc/Device1/calc-seconds = 45497 (Good [0x00000000]) +[11/13/2026 12:38:18] ns=2;s=t13-calc/Device1/calc-seconds = 45498 (Good [0x00000000]) +[11/13/2026 12:38:19] ns=2;s=t13-calc/Device1/calc-seconds = 45499 (Good [0x00000000]) +[11/13/2026 12:38:20] ns=2;s=t13-calc/Device1/calc-seconds = 45500 (Good [0x00000000]) +[11/13/2026 12:38:21] ns=2;s=t13-calc/Device1/calc-seconds = 45501 (Good [0x00000000]) +[11/13/2026 12:38:22] ns=2;s=t13-calc/Device1/calc-seconds = 45502 (Good [0x00000000]) +[11/13/2026 12:38:23] ns=2;s=t13-calc/Device1/calc-seconds = 45503 (Good [0x00000000]) +[11/13/2026 12:38:24] ns=2;s=t13-calc/Device1/calc-seconds = 45504 (Good [0x00000000]) +[11/13/2026 12:38:25] ns=2;s=t13-calc/Device1/calc-seconds = 45505 (Good [0x00000000]) +[11/13/2026 12:38:27] ns=2;s=t13-calc/Device1/calc-seconds = 45507 (Good [0x00000000]) +[11/13/2026 12:38:28] ns=2;s=t13-calc/Device1/calc-seconds = 45508 (Good [0x00000000]) +[11/13/2026 12:38:29] ns=2;s=t13-calc/Device1/calc-seconds = 45509 (Good [0x00000000]) +[11/13/2026 12:38:30] ns=2;s=t13-calc/Device1/calc-seconds = 45510 (Good [0x00000000]) +[11/13/2026 12:38:31] ns=2;s=t13-calc/Device1/calc-seconds = 45511 (Good [0x00000000]) +[11/13/2026 12:38:32] ns=2;s=t13-calc/Device1/calc-seconds = 45512 (Good [0x00000000]) +[11/13/2026 12:38:33] ns=2;s=t13-calc/Device1/calc-seconds = 45513 (Good [0x00000000]) + +==================== SUMMARY ==================== +Total subscribed: 1 + Ever went BAD during window: 0 + NEVER went bad (suspect): 1 + Last status GOOD: 1 + Last status NOT-GOOD: 0 + No update received at all: 0 +[07:38:35 DBG] Removed monitored item handle=6 +[07:38:35 DBG] Unsubscribed from data changes on ns=2;s=t13-calc/Device1/calc-seconds diff --git a/docs/plans/evidence/2026-11-13-615-g9/client/A8-sl.txt b/docs/plans/evidence/2026-11-13-615-g9/client/A8-sl.txt new file mode 100644 index 000000000..a653aff96 --- /dev/null +++ b/docs/plans/evidence/2026-11-13-615-g9/client/A8-sl.txt @@ -0,0 +1,26 @@ +[07:36:44 DBG] ApplicationConfiguration created for opc.tcp://localhost:25840 +[07:36:44 DBG] Rewrote endpoint from opc.tcp://0.0.0.0:4840/OtOpcUa to opc.tcp://localhost:25840/OtOpcUa +[07:36:44 INF] Session created: OtOpcUaClient -> opc.tcp://localhost:25840/OtOpcUa +[07:36:44 INF] Connected to opc.tcp://localhost:25840/OtOpcUa +[07:36:45 DBG] Added data change monitored item for i=2267, handle=3 +[07:36:45 DBG] Subscribed to data changes on i=2267 +Subscribed to 1/1 nodes (interval: 500ms). Press Ctrl+C to stop and print summary. +[11/13/2026 12:32:22] i=2267 = 250 (Good [0x00000000]) +[07:37:00 WRN] Session lost on opc.tcp://localhost:25840/OtOpcUa. Attempting failover... +[07:37:00 INF] Failover attempt to opc.tcp://localhost:25841 +[07:37:00 DBG] ApplicationConfiguration created for opc.tcp://localhost:25841 +[07:37:00 DBG] Rewrote endpoint from opc.tcp://0.0.0.0:4840/OtOpcUa to opc.tcp://localhost:25841/OtOpcUa +[07:37:00 INF] Session created: OtOpcUaClient -> opc.tcp://localhost:25841/OtOpcUa +[07:37:00 INF] Failover succeeded to opc.tcp://localhost:25841 +[07:37:00 DBG] Added data change monitored item for i=2267, handle=6 +[11/13/2026 12:36:52] i=2267 = 250 (Good [0x00000000]) + +==================== SUMMARY ==================== +Total subscribed: 1 + Ever went BAD during window: 0 + NEVER went bad (suspect): 1 + Last status GOOD: 1 + Last status NOT-GOOD: 0 + No update received at all: 0 +[07:38:35 DBG] Removed monitored item handle=6 +[07:38:35 DBG] Unsubscribed from data changes on i=2267 diff --git a/docs/plans/evidence/2026-11-13-615-g9/client/B2-data.txt b/docs/plans/evidence/2026-11-13-615-g9/client/B2-data.txt new file mode 100644 index 000000000..ad0422ef8 --- /dev/null +++ b/docs/plans/evidence/2026-11-13-615-g9/client/B2-data.txt @@ -0,0 +1,141 @@ +[07:39:34 DBG] ApplicationConfiguration created for opc.tcp://localhost:25841 +[07:39:34 DBG] Rewrote endpoint from opc.tcp://0.0.0.0:4840/OtOpcUa to opc.tcp://localhost:25841/OtOpcUa +[07:39:34 INF] Session created: OtOpcUaClient -> opc.tcp://localhost:25841/OtOpcUa +[07:39:34 INF] Connected to opc.tcp://localhost:25841/OtOpcUa +[07:39:34 DBG] Added data change monitored item for ns=2;s=t13-calc/Device1/calc-seconds, handle=3 +[07:39:34 DBG] Subscribed to data changes on ns=2;s=t13-calc/Device1/calc-seconds +Subscribed to 1/1 nodes (interval: 1000ms). Press Ctrl+C to stop and print summary. +[11/13/2026 12:39:35] ns=2;s=t13-calc/Device1/calc-seconds = 45575 (Good [0x00000000]) +[11/13/2026 12:39:36] ns=2;s=t13-calc/Device1/calc-seconds = 45576 (Good [0x00000000]) +[11/13/2026 12:39:37] ns=2;s=t13-calc/Device1/calc-seconds = 45577 (Good [0x00000000]) +[11/13/2026 12:39:38] ns=2;s=t13-calc/Device1/calc-seconds = 45578 (Good [0x00000000]) +[11/13/2026 12:39:40] ns=2;s=t13-calc/Device1/calc-seconds = 45580 (Good [0x00000000]) +[11/13/2026 12:39:41] ns=2;s=t13-calc/Device1/calc-seconds = 45581 (Good [0x00000000]) +[07:39:42 WRN] Session lost on opc.tcp://localhost:25841/OtOpcUa. Attempting failover... +[07:39:42 INF] Failover attempt to opc.tcp://localhost:25840 +[07:39:42 DBG] ApplicationConfiguration created for opc.tcp://localhost:25840 +[07:39:42 DBG] Rewrote endpoint from opc.tcp://0.0.0.0:4840/OtOpcUa to opc.tcp://localhost:25840/OtOpcUa +[07:39:42 INF] Session created: OtOpcUaClient -> opc.tcp://localhost:25840/OtOpcUa +[07:39:42 INF] Failover succeeded to opc.tcp://localhost:25840 +[07:39:42 DBG] Added data change monitored item for ns=2;s=t13-calc/Device1/calc-seconds, handle=6 +[11/13/2026 12:39:43] ns=2;s=t13-calc/Device1/calc-seconds = 45583 (Good [0x00000000]) +[11/13/2026 12:39:44] ns=2;s=t13-calc/Device1/calc-seconds = 45584 (Good [0x00000000]) +[11/13/2026 12:39:45] ns=2;s=t13-calc/Device1/calc-seconds = 45585 (Good [0x00000000]) +[11/13/2026 12:39:46] ns=2;s=t13-calc/Device1/calc-seconds = 45586 (Good [0x00000000]) +[11/13/2026 12:39:47] ns=2;s=t13-calc/Device1/calc-seconds = 45587 (Good [0x00000000]) +[11/13/2026 12:39:48] ns=2;s=t13-calc/Device1/calc-seconds = 45588 (Good [0x00000000]) +[11/13/2026 12:39:50] ns=2;s=t13-calc/Device1/calc-seconds = 45590 (Good [0x00000000]) +[11/13/2026 12:39:51] ns=2;s=t13-calc/Device1/calc-seconds = 45591 (Good [0x00000000]) +[11/13/2026 12:39:52] ns=2;s=t13-calc/Device1/calc-seconds = 45592 (Good [0x00000000]) +[11/13/2026 12:39:53] ns=2;s=t13-calc/Device1/calc-seconds = 45593 (Good [0x00000000]) +[11/13/2026 12:39:54] ns=2;s=t13-calc/Device1/calc-seconds = 45594 (Good [0x00000000]) +[11/13/2026 12:39:55] ns=2;s=t13-calc/Device1/calc-seconds = 45595 (Good [0x00000000]) +[11/13/2026 12:39:56] ns=2;s=t13-calc/Device1/calc-seconds = 45596 (Good [0x00000000]) +[11/13/2026 12:39:57] ns=2;s=t13-calc/Device1/calc-seconds = 45597 (Good [0x00000000]) +[11/13/2026 12:39:58] ns=2;s=t13-calc/Device1/calc-seconds = 45598 (Good [0x00000000]) +[11/13/2026 12:39:59] ns=2;s=t13-calc/Device1/calc-seconds = 45599 (Good [0x00000000]) +[11/13/2026 12:40:00] ns=2;s=t13-calc/Device1/calc-seconds = 45600 (Good [0x00000000]) +[11/13/2026 12:40:01] ns=2;s=t13-calc/Device1/calc-seconds = 45601 (Good [0x00000000]) +[11/13/2026 12:40:02] ns=2;s=t13-calc/Device1/calc-seconds = 45602 (Good [0x00000000]) +[11/13/2026 12:40:03] ns=2;s=t13-calc/Device1/calc-seconds = 45603 (Good [0x00000000]) +[11/13/2026 12:40:04] ns=2;s=t13-calc/Device1/calc-seconds = 45604 (Good [0x00000000]) +[11/13/2026 12:40:05] ns=2;s=t13-calc/Device1/calc-seconds = 45605 (Good [0x00000000]) +[11/13/2026 12:40:06] ns=2;s=t13-calc/Device1/calc-seconds = 45606 (Good [0x00000000]) +[11/13/2026 12:40:07] ns=2;s=t13-calc/Device1/calc-seconds = 45607 (Good [0x00000000]) +[11/13/2026 12:40:08] ns=2;s=t13-calc/Device1/calc-seconds = 45608 (Good [0x00000000]) +[11/13/2026 12:40:09] ns=2;s=t13-calc/Device1/calc-seconds = 45609 (Good [0x00000000]) +[11/13/2026 12:40:10] ns=2;s=t13-calc/Device1/calc-seconds = 45610 (Good [0x00000000]) +[11/13/2026 12:40:12] ns=2;s=t13-calc/Device1/calc-seconds = 45612 (Good [0x00000000]) +[11/13/2026 12:40:13] ns=2;s=t13-calc/Device1/calc-seconds = 45613 (Good [0x00000000]) +[11/13/2026 12:40:14] ns=2;s=t13-calc/Device1/calc-seconds = 45614 (Good [0x00000000]) +[11/13/2026 12:40:15] ns=2;s=t13-calc/Device1/calc-seconds = 45615 (Good [0x00000000]) +[11/13/2026 12:40:16] ns=2;s=t13-calc/Device1/calc-seconds = 45616 (Good [0x00000000]) +[11/13/2026 12:40:17] ns=2;s=t13-calc/Device1/calc-seconds = 45617 (Good [0x00000000]) +[11/13/2026 12:40:18] ns=2;s=t13-calc/Device1/calc-seconds = 45618 (Good [0x00000000]) +[11/13/2026 12:40:19] ns=2;s=t13-calc/Device1/calc-seconds = 45619 (Good [0x00000000]) +[11/13/2026 12:40:20] ns=2;s=t13-calc/Device1/calc-seconds = 45620 (Good [0x00000000]) +[11/13/2026 12:40:21] ns=2;s=t13-calc/Device1/calc-seconds = 45621 (Good [0x00000000]) +[11/13/2026 12:40:22] ns=2;s=t13-calc/Device1/calc-seconds = 45622 (Good [0x00000000]) +[11/13/2026 12:40:23] ns=2;s=t13-calc/Device1/calc-seconds = 45623 (Good [0x00000000]) +[11/13/2026 12:40:24] ns=2;s=t13-calc/Device1/calc-seconds = 45624 (Good [0x00000000]) +[11/13/2026 12:40:25] ns=2;s=t13-calc/Device1/calc-seconds = 45625 (Good [0x00000000]) +[11/13/2026 12:40:26] ns=2;s=t13-calc/Device1/calc-seconds = 45626 (Good [0x00000000]) +[11/13/2026 12:40:27] ns=2;s=t13-calc/Device1/calc-seconds = 45627 (Good [0x00000000]) +[11/13/2026 12:40:28] ns=2;s=t13-calc/Device1/calc-seconds = 45628 (Good [0x00000000]) +[11/13/2026 12:40:29] ns=2;s=t13-calc/Device1/calc-seconds = 45629 (Good [0x00000000]) +[11/13/2026 12:40:30] ns=2;s=t13-calc/Device1/calc-seconds = 45630 (Good [0x00000000]) +[11/13/2026 12:40:31] ns=2;s=t13-calc/Device1/calc-seconds = 45631 (Good [0x00000000]) +[11/13/2026 12:40:33] ns=2;s=t13-calc/Device1/calc-seconds = 45633 (Good [0x00000000]) +[11/13/2026 12:40:34] ns=2;s=t13-calc/Device1/calc-seconds = 45634 (Good [0x00000000]) +[11/13/2026 12:40:35] ns=2;s=t13-calc/Device1/calc-seconds = 45635 (Good [0x00000000]) +[11/13/2026 12:40:36] ns=2;s=t13-calc/Device1/calc-seconds = 45636 (Good [0x00000000]) +[11/13/2026 12:40:37] ns=2;s=t13-calc/Device1/calc-seconds = 45637 (Good [0x00000000]) +[11/13/2026 12:40:38] ns=2;s=t13-calc/Device1/calc-seconds = 45638 (Good [0x00000000]) +[11/13/2026 12:40:39] ns=2;s=t13-calc/Device1/calc-seconds = 45639 (Good [0x00000000]) +[11/13/2026 12:40:40] ns=2;s=t13-calc/Device1/calc-seconds = 45640 (Good [0x00000000]) +[11/13/2026 12:40:41] ns=2;s=t13-calc/Device1/calc-seconds = 45641 (Good [0x00000000]) +[11/13/2026 12:40:42] ns=2;s=t13-calc/Device1/calc-seconds = 45642 (Good [0x00000000]) +[11/13/2026 12:40:43] ns=2;s=t13-calc/Device1/calc-seconds = 45643 (Good [0x00000000]) +[11/13/2026 12:40:44] ns=2;s=t13-calc/Device1/calc-seconds = 45644 (Good [0x00000000]) +[11/13/2026 12:40:45] ns=2;s=t13-calc/Device1/calc-seconds = 45645 (Good [0x00000000]) +[11/13/2026 12:40:46] ns=2;s=t13-calc/Device1/calc-seconds = 45646 (Good [0x00000000]) +[11/13/2026 12:40:47] ns=2;s=t13-calc/Device1/calc-seconds = 45647 (Good [0x00000000]) +[11/13/2026 12:40:48] ns=2;s=t13-calc/Device1/calc-seconds = 45648 (Good [0x00000000]) +[11/13/2026 12:40:49] ns=2;s=t13-calc/Device1/calc-seconds = 45649 (Good [0x00000000]) +[11/13/2026 12:40:50] ns=2;s=t13-calc/Device1/calc-seconds = 45650 (Good [0x00000000]) +[11/13/2026 12:40:51] ns=2;s=t13-calc/Device1/calc-seconds = 45651 (Good [0x00000000]) +[11/13/2026 12:40:52] ns=2;s=t13-calc/Device1/calc-seconds = 45652 (Good [0x00000000]) +[11/13/2026 12:40:53] ns=2;s=t13-calc/Device1/calc-seconds = 45653 (Good [0x00000000]) +[11/13/2026 12:40:54] ns=2;s=t13-calc/Device1/calc-seconds = 45654 (Good [0x00000000]) +[11/13/2026 12:40:55] ns=2;s=t13-calc/Device1/calc-seconds = 45655 (Good [0x00000000]) +[11/13/2026 12:40:56] ns=2;s=t13-calc/Device1/calc-seconds = 45656 (Good [0x00000000]) +[11/13/2026 12:40:57] ns=2;s=t13-calc/Device1/calc-seconds = 45657 (Good [0x00000000]) +[11/13/2026 12:40:58] ns=2;s=t13-calc/Device1/calc-seconds = 45658 (Good [0x00000000]) +[11/13/2026 12:40:59] ns=2;s=t13-calc/Device1/calc-seconds = 45659 (Good [0x00000000]) +[11/13/2026 12:41:00] ns=2;s=t13-calc/Device1/calc-seconds = 45660 (Good [0x00000000]) +[11/13/2026 12:41:01] ns=2;s=t13-calc/Device1/calc-seconds = 45661 (Good [0x00000000]) +[11/13/2026 12:41:02] ns=2;s=t13-calc/Device1/calc-seconds = 45662 (Good [0x00000000]) +[11/13/2026 12:41:03] ns=2;s=t13-calc/Device1/calc-seconds = 45663 (Good [0x00000000]) +[11/13/2026 12:41:04] ns=2;s=t13-calc/Device1/calc-seconds = 45664 (Good [0x00000000]) +[11/13/2026 12:41:05] ns=2;s=t13-calc/Device1/calc-seconds = 45665 (Good [0x00000000]) +[11/13/2026 12:41:06] ns=2;s=t13-calc/Device1/calc-seconds = 45666 (Good [0x00000000]) +[11/13/2026 12:41:08] ns=2;s=t13-calc/Device1/calc-seconds = 45668 (Good [0x00000000]) +[11/13/2026 12:41:09] ns=2;s=t13-calc/Device1/calc-seconds = 45669 (Good [0x00000000]) +[11/13/2026 12:41:10] ns=2;s=t13-calc/Device1/calc-seconds = 45670 (Good [0x00000000]) +[11/13/2026 12:41:11] ns=2;s=t13-calc/Device1/calc-seconds = 45671 (Good [0x00000000]) +[11/13/2026 12:41:12] ns=2;s=t13-calc/Device1/calc-seconds = 45672 (Good [0x00000000]) +[11/13/2026 12:41:13] ns=2;s=t13-calc/Device1/calc-seconds = 45673 (Good [0x00000000]) +[11/13/2026 12:41:14] ns=2;s=t13-calc/Device1/calc-seconds = 45674 (Good [0x00000000]) +[11/13/2026 12:41:15] ns=2;s=t13-calc/Device1/calc-seconds = 45675 (Good [0x00000000]) +[11/13/2026 12:41:16] ns=2;s=t13-calc/Device1/calc-seconds = 45676 (Good [0x00000000]) +[11/13/2026 12:41:18] ns=2;s=t13-calc/Device1/calc-seconds = 45678 (Good [0x00000000]) +[11/13/2026 12:41:19] ns=2;s=t13-calc/Device1/calc-seconds = 45679 (Good [0x00000000]) +[11/13/2026 12:41:20] ns=2;s=t13-calc/Device1/calc-seconds = 45680 (Good [0x00000000]) +[11/13/2026 12:41:21] ns=2;s=t13-calc/Device1/calc-seconds = 45681 (Good [0x00000000]) +[11/13/2026 12:41:22] ns=2;s=t13-calc/Device1/calc-seconds = 45682 (Good [0x00000000]) +[11/13/2026 12:41:23] ns=2;s=t13-calc/Device1/calc-seconds = 45683 (Good [0x00000000]) +[11/13/2026 12:41:24] ns=2;s=t13-calc/Device1/calc-seconds = 45684 (Good [0x00000000]) +[11/13/2026 12:41:25] ns=2;s=t13-calc/Device1/calc-seconds = 45685 (Good [0x00000000]) +[11/13/2026 12:41:26] ns=2;s=t13-calc/Device1/calc-seconds = 45686 (Good [0x00000000]) +[11/13/2026 12:41:27] ns=2;s=t13-calc/Device1/calc-seconds = 45687 (Good [0x00000000]) +[11/13/2026 12:41:29] ns=2;s=t13-calc/Device1/calc-seconds = 45689 (Good [0x00000000]) +[11/13/2026 12:41:30] ns=2;s=t13-calc/Device1/calc-seconds = 45690 (Good [0x00000000]) +[11/13/2026 12:41:31] ns=2;s=t13-calc/Device1/calc-seconds = 45691 (Good [0x00000000]) +[11/13/2026 12:41:32] ns=2;s=t13-calc/Device1/calc-seconds = 45692 (Good [0x00000000]) +[11/13/2026 12:41:33] ns=2;s=t13-calc/Device1/calc-seconds = 45693 (Good [0x00000000]) +[11/13/2026 12:41:34] ns=2;s=t13-calc/Device1/calc-seconds = 45694 (Good [0x00000000]) +[11/13/2026 12:41:35] ns=2;s=t13-calc/Device1/calc-seconds = 45695 (Good [0x00000000]) +[11/13/2026 12:41:36] ns=2;s=t13-calc/Device1/calc-seconds = 45696 (Good [0x00000000]) +[11/13/2026 12:41:37] ns=2;s=t13-calc/Device1/calc-seconds = 45697 (Good [0x00000000]) +[11/13/2026 12:41:38] ns=2;s=t13-calc/Device1/calc-seconds = 45698 (Good [0x00000000]) +[11/13/2026 12:41:39] ns=2;s=t13-calc/Device1/calc-seconds = 45699 (Good [0x00000000]) +[11/13/2026 12:41:40] ns=2;s=t13-calc/Device1/calc-seconds = 45700 (Good [0x00000000]) +[11/13/2026 12:41:41] ns=2;s=t13-calc/Device1/calc-seconds = 45701 (Good [0x00000000]) +[11/13/2026 12:41:42] ns=2;s=t13-calc/Device1/calc-seconds = 45702 (Good [0x00000000]) +[11/13/2026 12:41:43] ns=2;s=t13-calc/Device1/calc-seconds = 45703 (Good [0x00000000]) +[11/13/2026 12:41:44] ns=2;s=t13-calc/Device1/calc-seconds = 45704 (Good [0x00000000]) +[11/13/2026 12:41:45] ns=2;s=t13-calc/Device1/calc-seconds = 45705 (Good [0x00000000]) +[11/13/2026 12:41:46] ns=2;s=t13-calc/Device1/calc-seconds = 45706 (Good [0x00000000]) +[11/13/2026 12:41:47] ns=2;s=t13-calc/Device1/calc-seconds = 45707 (Good [0x00000000]) +[11/13/2026 12:41:48] ns=2;s=t13-calc/Device1/calc-seconds = 45708 (Good [0x00000000]) +[11/13/2026 12:41:49] ns=2;s=t13-calc/Device1/calc-seconds = 45709 (Good [0x00000000]) diff --git a/docs/plans/evidence/2026-11-13-615-g9/client/B2-sl.txt b/docs/plans/evidence/2026-11-13-615-g9/client/B2-sl.txt new file mode 100644 index 000000000..aff1ce998 --- /dev/null +++ b/docs/plans/evidence/2026-11-13-615-g9/client/B2-sl.txt @@ -0,0 +1,18 @@ +[07:39:34 DBG] ApplicationConfiguration created for opc.tcp://localhost:25841 +[07:39:34 DBG] Rewrote endpoint from opc.tcp://0.0.0.0:4840/OtOpcUa to opc.tcp://localhost:25841/OtOpcUa +[07:39:34 INF] Session created: OtOpcUaClient -> opc.tcp://localhost:25841/OtOpcUa +[07:39:34 INF] Connected to opc.tcp://localhost:25841/OtOpcUa +[07:39:34 DBG] Added data change monitored item for i=2267, handle=3 +[07:39:34 DBG] Subscribed to data changes on i=2267 +Subscribed to 1/1 nodes (interval: 500ms). Press Ctrl+C to stop and print summary. +[11/13/2026 12:36:52] i=2267 = 250 (Good [0x00000000]) +[07:39:42 WRN] Session lost on opc.tcp://localhost:25841/OtOpcUa. Attempting failover... +[07:39:42 INF] Failover attempt to opc.tcp://localhost:25840 +[07:39:42 DBG] ApplicationConfiguration created for opc.tcp://localhost:25840 +[07:39:42 DBG] Rewrote endpoint from opc.tcp://0.0.0.0:4840/OtOpcUa to opc.tcp://localhost:25840/OtOpcUa +[07:39:42 INF] Session created: OtOpcUaClient -> opc.tcp://localhost:25840/OtOpcUa +[07:39:42 INF] Failover succeeded to opc.tcp://localhost:25840 +[07:39:42 DBG] Added data change monitored item for i=2267, handle=6 +[11/13/2026 12:39:03] i=2267 = 240 (Good [0x00000000]) +[11/13/2026 12:40:07] i=2267 = 200 (Good [0x00000000]) +[11/13/2026 12:40:26] i=2267 = 250 (Good [0x00000000]) diff --git a/docs/plans/evidence/2026-11-13-615-g9/client/B2-survivor-sl.txt b/docs/plans/evidence/2026-11-13-615-g9/client/B2-survivor-sl.txt new file mode 100644 index 000000000..97f7680bc --- /dev/null +++ b/docs/plans/evidence/2026-11-13-615-g9/client/B2-survivor-sl.txt @@ -0,0 +1,4 @@ +Subscribed to 1/1 nodes (interval: 500ms). Press Ctrl+C to stop and print summary. +[11/13/2026 12:39:03] i=2267 = 240 (Good [0x00000000]) +[11/13/2026 12:40:07] i=2267 = 200 (Good [0x00000000]) +[11/13/2026 12:40:26] i=2267 = 250 (Good [0x00000000]) diff --git a/docs/plans/evidence/2026-11-13-615-g9/client/B3-final.txt b/docs/plans/evidence/2026-11-13-615-g9/client/B3-final.txt new file mode 100644 index 000000000..e2c1d4d14 --- /dev/null +++ b/docs/plans/evidence/2026-11-13-615-g9/client/B3-final.txt @@ -0,0 +1,3 @@ +final 12:43:21 +opc.tcp://localhost:25840 SL=250 data=Good +opc.tcp://localhost:25841 SL=240 data=Good diff --git a/docs/plans/evidence/2026-11-13-615-g9/client/B3-survivor-sl.txt b/docs/plans/evidence/2026-11-13-615-g9/client/B3-survivor-sl.txt new file mode 100644 index 000000000..9d5c597cf --- /dev/null +++ b/docs/plans/evidence/2026-11-13-615-g9/client/B3-survivor-sl.txt @@ -0,0 +1,10 @@ +Subscribed to 1/1 nodes (interval: 500ms). Press Ctrl+C to stop and print summary. +[11/13/2026 12:40:26] i=2267 = 250 (Good [0x00000000]) + +==================== SUMMARY ==================== +Total subscribed: 1 + Ever went BAD during window: 0 + NEVER went bad (suspect): 1 + Last status GOOD: 1 + Last status NOT-GOOD: 0 + No update received at all: 0 diff --git a/docs/plans/evidence/2026-11-13-615-g9/client/actions.log b/docs/plans/evidence/2026-11-13-615-g9/client/actions.log new file mode 100644 index 000000000..a6a41e38a --- /dev/null +++ b/docs/plans/evidence/2026-11-13-615-g9/client/actions.log @@ -0,0 +1,8 @@ +12:35:07.904 docker stop central-2 (A3 follower stop) +12:35:08.601 stopped +12:36:28.832 docker start central-2 +12:36:52.473 docker stop central-1 (A8 graceful Primary stop) +12:36:58.542 stopped +12:38:55.376 docker start central-1 (rejoin after graceful) +12:39:42.162 docker kill central-2 (B2 crash of Primary) +12:42:23.719 docker start central-2 (B3 rejoin after crash) diff --git a/docs/plans/evidence/2026-11-13-615-g9/client/rejoin-after-graceful.txt b/docs/plans/evidence/2026-11-13-615-g9/client/rejoin-after-graceful.txt new file mode 100644 index 000000000..bada97bbf --- /dev/null +++ b/docs/plans/evidence/2026-11-13-615-g9/client/rejoin-after-graceful.txt @@ -0,0 +1,3 @@ +rejoin check 12:39:26 +opc.tcp://localhost:25840 240 +opc.tcp://localhost:25841 250 diff --git a/docs/plans/evidence/2026-11-13-615-g9/rig/Dockerfile b/docs/plans/evidence/2026-11-13-615-g9/rig/Dockerfile new file mode 100644 index 000000000..c8c2804bb --- /dev/null +++ b/docs/plans/evidence/2026-11-13-615-g9/rig/Dockerfile @@ -0,0 +1,5 @@ +FROM mcr.microsoft.com/dotnet/aspnet:10.0 +WORKDIR /app +COPY publish/ ./ +EXPOSE 9000 4053 4840 +ENTRYPOINT ["dotnet", "OtOpcUa.Host.dll"] diff --git a/docs/plans/evidence/2026-11-13-615-g9/rig/central-1-excerpt.log b/docs/plans/evidence/2026-11-13-615-g9/rig/central-1-excerpt.log new file mode 100644 index 000000000..04b2e904a --- /dev/null +++ b/docs/plans/evidence/2026-11-13-615-g9/rig/central-1-excerpt.log @@ -0,0 +1,115 @@ +[12:31:04.464 WRN] The `auto-down-unreachable-after` feature has been deprecated as of Akka.NET v1.5.2 and will be removed in a future version of Akka.NET. The `keep-majority` split brain resolver will be used instead. See https://getakka.net/articles/cluster/split-brain-resolver.html for more detai +[12:31:04.464 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Starting up... +[12:31:04.470 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Started up successfully +[12:31:04.676 INF] OPC UA redundancy: Mode=Unset, effective ApplicationUri=urn:OtOpcUa:central-1, peers=[urn:OtOpcUa:central-2], PromoteWhilePrimaryUnreachable=True +[12:31:05.652 INF] OtOpcUaServerHostedService: SDK started, address-space + ServiceLevel sinks bound +[12:31:09.505 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Node [akka.tcp://otopcua@central-1:4053] is JOINING itself (with roles [driver,cluster-MAIN,admin], version [1.0.0]) and forming a new cluster +[12:31:09.506 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - is the new leader among reachable nodes (more leaders may exist) +[12:31:09.513 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Leader is moving node [akka.tcp://otopcua@central-1:4053] to [Up] +[12:31:13.624 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Received InitJoin message from [[akka.tcp://otopcua@central-2:4053/system/cluster/core/daemon/firstSeedNodeProcess-1#1125290835]] to [akka.tcp://otopcua@central-1:4053] +[12:31:13.624 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Sending InitJoinAck message from node [akka.tcp://otopcua@central-1:4053] to [[akka.tcp://otopcua@central-2:4053/system/cluster/core/daemon/firstSeedNodeProcess-1#1125290835]] +[12:31:13.635 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Node [akka.tcp://otopcua@central-2:4053] is JOINING, roles [driver,cluster-MAIN,admin], version [1.0.0] +[12:31:14.476 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Leader is moving node [akka.tcp://otopcua@central-2:4053] to [Up] +[12:32:13.485 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Leader is moving node [akka.tcp://otopcua@central-2:4053] to [Exiting] +[12:32:13.486 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Exiting confirmed [akka.tcp://otopcua@central-2:4053] +[12:32:13.504 ERR] Disassociated +[12:32:13.869 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Marked address [akka.tcp://otopcua@central-1:4053] as [Leaving] +[12:32:14.124 INF] Message [RedundancyStateChanged] wrapped in [$DeadLetterWithNoSubscribers] from [akka://otopcua/system/distributedPubSubMediator#571261437] to [akka://otopcua/deadLetters] was not delivered. [3] dead letters encountered. If this is not an expected behavior then [akka://otopcua/dea +[12:32:14.476 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Leader is moving node [akka.tcp://otopcua@central-1:4053] to [Exiting] +[12:32:14.476 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Leader is removing confirmed Exiting node [akka.tcp://otopcua@central-2:4053] +[12:32:14.744 INF] Message [RedundancyStateChanged] wrapped in [$DeadLetterWithNoSubscribers] from [akka://otopcua/system/distributedPubSubMediator#571261437] to [akka://otopcua/deadLetters] was not delivered. [6] dead letters encountered. If this is not an expected behavior then [akka://otopcua/dea +[12:32:14.877 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Exiting completed. +[12:32:14.877 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Shutting down... +[12:32:14.877 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Successfully shut down +[12:32:16.218 WRN] The `auto-down-unreachable-after` feature has been deprecated as of Akka.NET v1.5.2 and will be removed in a future version of Akka.NET. The `keep-majority` split brain resolver will be used instead. See https://getakka.net/articles/cluster/split-brain-resolver.html for more detai +[12:32:16.218 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Starting up... +[12:32:16.224 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Started up successfully +[12:32:16.391 INF] OPC UA redundancy: Mode=Unset, effective ApplicationUri=urn:OtOpcUa:central-1, peers=[urn:OtOpcUa:central-2], PromoteWhilePrimaryUnreachable=True +[12:32:17.360 INF] OtOpcUaServerHostedService: SDK started, address-space + ServiceLevel sinks bound +[12:32:17.961 INF] AddressSpaceApplier: applied plan (kind=PureAdd, added=10, removed=0, changed=0, surgicalRawTags=0, unsRefDeltas=0, renamedFolders=0, rebuild=False) +[12:32:17.975 INF] OpcUaPublish: applied rebuild (correlation=fe1fc2aac0bb40cb98ad02b0e641751a, added=10, removed=0, changed=0, rebuild=False) +[12:32:18.900 ERR] Health check akka with status Unhealthy completed after 0.7218ms with message 'Akka cluster member status: Removed' +[12:32:18.924 ERR] HTTP GET /health/ready responded 503 in 31.0610 ms +[12:32:21.258 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Node [akka.tcp://otopcua@central-1:4053] is JOINING itself (with roles [admin,cluster-MAIN,driver], version [1.0.0]) and forming a new cluster +[12:32:21.259 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - is the new leader among reachable nodes (more leaders may exist) +[12:32:21.261 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Leader is moving node [akka.tcp://otopcua@central-1:4053] to [Up] +[12:32:23.645 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Received InitJoin message from [[akka.tcp://otopcua@central-2:4053/system/cluster/core/daemon/firstSeedNodeProcess-1#1342319911]] to [akka.tcp://otopcua@central-1:4053] +[12:32:23.645 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Sending InitJoinAck message from node [akka.tcp://otopcua@central-1:4053] to [[akka.tcp://otopcua@central-2:4053/system/cluster/core/daemon/firstSeedNodeProcess-1#1342319911]] +[12:32:23.660 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Node [akka.tcp://otopcua@central-2:4053] is JOINING, roles [admin,cluster-MAIN,driver], version [1.0.0] +[12:32:24.235 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Leader is moving node [akka.tcp://otopcua@central-2:4053] to [Up] +[12:33:18.406 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:33:18.912 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:33:19.370 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:33:19.797 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:33:20.260 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:34:31.924 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:34:32.514 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:34:32.946 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:34:33.429 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:34:40.024 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:34:40.452 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:34:50.515 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:34:51.020 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:34:51.529 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:35:03.311 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:35:08.233 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Leader is moving node [akka.tcp://otopcua@central-2:4053] to [Exiting] +[12:35:08.238 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Exiting confirmed [akka.tcp://otopcua@central-2:4053] +[12:35:08.259 ERR] Disassociated +[12:35:09.240 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Leader is removing confirmed Exiting node [akka.tcp://otopcua@central-2:4053] +[12:35:09.240 INF] Member removed [akka.tcp://otopcua@central-2:4053] +[12:35:09.240 INF] Member removed [akka.tcp://otopcua@central-2:4053] +[12:35:09.240 INF] Member removed [akka.tcp://otopcua@central-2:4053] +[12:35:09.240 INF] Member removed [akka.tcp://otopcua@central-2:4053] +[12:35:09.240 INF] Member removed [akka.tcp://otopcua@central-2:4053] +[12:35:09.240 INF] Member removed [akka.tcp://otopcua@central-2:4053] +[12:36:29.516 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Received InitJoin message from [[akka.tcp://otopcua@central-2:4053/system/cluster/core/daemon/firstSeedNodeProcess-1#287714167]] to [akka.tcp://otopcua@central-1:4053] +[12:36:29.516 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Sending InitJoinAck message from node [akka.tcp://otopcua@central-1:4053] to [[akka.tcp://otopcua@central-2:4053/system/cluster/core/daemon/firstSeedNodeProcess-1#287714167]] +[12:36:29.526 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Node [akka.tcp://otopcua@central-2:4053] is JOINING, roles [admin,cluster-MAIN,driver], version [1.0.0] +[12:36:30.234 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Leader is moving node [akka.tcp://otopcua@central-2:4053] to [Up] +[12:36:36.975 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:36:44.919 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:36:44.959 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:36:52.564 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Marked address [akka.tcp://otopcua@central-1:4053] as [Leaving] +[12:36:53.233 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Leader is moving node [akka.tcp://otopcua@central-1:4053] to [Exiting] +[12:36:53.245 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Exiting completed. +[12:36:53.245 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Shutting down... +[12:36:53.245 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Successfully shut down +[12:36:58.281 WRN] SERVER - Service Fault Occurred. Reason=BadTimeout +[12:36:58.282 WRN] SERVER - Service Fault Occurred. Reason=BadTimeout +[12:38:56.104 WRN] The `auto-down-unreachable-after` feature has been deprecated as of Akka.NET v1.5.2 and will be removed in a future version of Akka.NET. The `keep-majority` split brain resolver will be used instead. See https://getakka.net/articles/cluster/split-brain-resolver.html for more detai +[12:38:56.104 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Starting up... +[12:38:56.111 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Started up successfully +[12:38:56.213 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Welcome from [akka.tcp://otopcua@central-2:4053] +[12:38:56.491 INF] OPC UA redundancy: Mode=Unset, effective ApplicationUri=urn:OtOpcUa:central-1, peers=[urn:OtOpcUa:central-2], PromoteWhilePrimaryUnreachable=True +[12:38:57.486 INF] OtOpcUaServerHostedService: SDK started, address-space + ServiceLevel sinks bound +[12:38:58.088 INF] AddressSpaceApplier: applied plan (kind=PureAdd, added=10, removed=0, changed=0, surgicalRawTags=0, unsRefDeltas=0, renamedFolders=0, rebuild=False) +[12:38:58.112 INF] OpcUaPublish: applied rebuild (correlation=5c7d6890b3e345d8b9172dece9dbada9, added=10, removed=0, changed=0, rebuild=False) +[12:38:58.125 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - is the new leader among reachable nodes (more leaders may exist) +[12:38:59.571 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:39:03.053 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:39:06.516 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:39:26.963 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:39:34.645 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:39:42.292 ERR] Disassociated +[12:39:42.436 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:39:42.468 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:39:55.131 WRN] Cluster Node [akka.tcp://otopcua@central-1:4053] - Marking node(s) as UNREACHABLE [Member(address = akka.tcp://otopcua@central-2:4053, Uid=1927360350 status = Up, role=[driver,admin,cluster-MAIN], upNumber=2, version=1.0.0)]. Node roles [driver,admin,cluster-MAIN] +[12:40:10.147 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Leader is auto-downing unreachable node [akka.tcp://otopcua@central-2:4053] +[12:40:10.147 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Marking unreachable node [akka.tcp://otopcua@central-2:4053] as [Down] +[12:40:11.127 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Leader is removing unreachable node [akka.tcp://otopcua@central-2:4053] +[12:40:26.138 INF] Member removed [akka.tcp://otopcua@central-2:4053], previous oldest [["UniqueAddress: (akka.tcp://otopcua@central-2:4053, 1927360350)"]] +[12:40:26.139 INF] Member removed [akka.tcp://otopcua@central-2:4053], previous oldest [["UniqueAddress: (akka.tcp://otopcua@central-2:4053, 1927360350)"]] +[12:40:26.139 INF] Member removed [akka.tcp://otopcua@central-2:4053], previous oldest [["UniqueAddress: (akka.tcp://otopcua@central-2:4053, 1927360350)"]] +[12:40:26.141 INF] Member removed [akka.tcp://otopcua@central-2:4053], previous oldest [["UniqueAddress: (akka.tcp://otopcua@central-2:4053, 1927360350)"]] +[12:40:26.141 INF] Member removed [akka.tcp://otopcua@central-2:4053], previous oldest [["UniqueAddress: (akka.tcp://otopcua@central-2:4053, 1927360350)"]] +[12:40:26.141 INF] Member removed [akka.tcp://otopcua@central-2:4053], previous oldest [["UniqueAddress: (akka.tcp://otopcua@central-2:4053, 1927360350)"]] +[12:41:49.781 ERR] TCPSERVERCHANNEL ForceChannelFault Transport=192.168.164.1:39756, ChannelId=16, TokenId=1, Reason=[80AE0000] (BadConnectionClosed) 'Remote side closed the connection.' +[12:41:49.781 ERR] TCPSERVERCHANNEL ForceChannelFault Transport=192.168.164.1:59076, ChannelId=13, TokenId=1, Reason=[80AE0000] (BadConnectionClosed) 'Remote side closed the connection.' +[12:41:49.781 ERR] TCPSERVERCHANNEL ForceChannelFault Transport=192.168.164.1:39784, ChannelId=18, TokenId=1, Reason=[80AE0000] (BadConnectionClosed) 'Remote side closed the connection.' +[12:42:21.107 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:42:24.533 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Received InitJoin message from [[akka.tcp://otopcua@central-2:4053/system/cluster/core/daemon/firstSeedNodeProcess-1#2009293825]] to [akka.tcp://otopcua@central-1:4053] +[12:42:24.533 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Sending InitJoinAck message from node [akka.tcp://otopcua@central-1:4053] to [[akka.tcp://otopcua@central-2:4053/system/cluster/core/daemon/firstSeedNodeProcess-1#2009293825]] +[12:42:24.543 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Node [akka.tcp://otopcua@central-2:4053] is JOINING, roles [driver,admin,cluster-MAIN], version [1.0.0] +[12:42:25.127 INF] Cluster Node [akka.tcp://otopcua@central-1:4053] - Leader is moving node [akka.tcp://otopcua@central-2:4053] to [Up] +[12:43:21.953 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. +[12:43:22.385 ERR] The domain 'opc.tcp://localhost:25840/OtOpcUa' is not listed in the server certificate. diff --git a/docs/plans/evidence/2026-11-13-615-g9/rig/central-2-excerpt.log b/docs/plans/evidence/2026-11-13-615-g9/rig/central-2-excerpt.log new file mode 100644 index 000000000..f1ecfd73a --- /dev/null +++ b/docs/plans/evidence/2026-11-13-615-g9/rig/central-2-excerpt.log @@ -0,0 +1,81 @@ +[12:31:13.542 WRN] The `auto-down-unreachable-after` feature has been deprecated as of Akka.NET v1.5.2 and will be removed in a future version of Akka.NET. The `keep-majority` split brain resolver will be used instead. See https://getakka.net/articles/cluster/split-brain-resolver.html for more detai +[12:31:13.543 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Starting up... +[12:31:13.548 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Started up successfully +[12:31:13.655 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Welcome from [akka.tcp://otopcua@central-1:4053] +[12:31:13.723 INF] OPC UA redundancy: Mode=Unset, effective ApplicationUri=urn:OtOpcUa:central-2, peers=[urn:OtOpcUa:central-1], PromoteWhilePrimaryUnreachable=True +[12:31:14.856 INF] OtOpcUaServerHostedService: SDK started, address-space + ServiceLevel sinks bound +[12:32:13.165 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Marked address [akka.tcp://otopcua@central-2:4053] as [Leaving] +[12:32:13.485 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Exiting completed. +[12:32:13.486 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Shutting down... +[12:32:13.486 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Successfully shut down +[12:32:13.489 INF] Self removed, stopping ClusterSingletonManager +[12:32:13.489 INF] Self removed, stopping ClusterSingletonManager +[12:32:13.489 INF] Self removed, stopping ClusterSingletonManager +[12:32:13.489 INF] Self removed, stopping ClusterSingletonManager +[12:32:13.489 INF] Self removed, stopping ClusterSingletonManager +[12:32:13.489 INF] Self removed, stopping ClusterSingletonManager +[12:32:23.561 WRN] The `auto-down-unreachable-after` feature has been deprecated as of Akka.NET v1.5.2 and will be removed in a future version of Akka.NET. The `keep-majority` split brain resolver will be used instead. See https://getakka.net/articles/cluster/split-brain-resolver.html for more detai +[12:32:23.561 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Starting up... +[12:32:23.566 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Started up successfully +[12:32:23.683 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Welcome from [akka.tcp://otopcua@central-1:4053] +[12:32:23.773 INF] OPC UA redundancy: Mode=Unset, effective ApplicationUri=urn:OtOpcUa:central-2, peers=[urn:OtOpcUa:central-1], PromoteWhilePrimaryUnreachable=True +[12:32:24.778 INF] OtOpcUaServerHostedService: SDK started, address-space + ServiceLevel sinks bound +[12:32:25.431 INF] AddressSpaceApplier: applied plan (kind=PureAdd, added=10, removed=0, changed=0, surgicalRawTags=0, unsRefDeltas=0, renamedFolders=0, rebuild=False) +[12:32:25.461 INF] OpcUaPublish: applied rebuild (correlation=fc41aaba2aa4498fbdc7cfb11f282765, added=10, removed=0, changed=0, rebuild=False) +[12:33:20.782 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:33:21.267 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:33:21.708 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:33:22.148 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:33:22.613 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:34:33.977 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:34:34.416 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:34:34.874 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:34:35.314 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:34:51.995 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:34:52.450 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:34:52.907 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:35:08.042 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Marked address [akka.tcp://otopcua@central-2:4053] as [Leaving] +[12:35:08.239 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Exiting completed. +[12:35:08.239 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Shutting down... +[12:35:08.239 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Successfully shut down +[12:36:29.456 WRN] The `auto-down-unreachable-after` feature has been deprecated as of Akka.NET v1.5.2 and will be removed in a future version of Akka.NET. The `keep-majority` split brain resolver will be used instead. See https://getakka.net/articles/cluster/split-brain-resolver.html for more detai +[12:36:29.456 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Starting up... +[12:36:29.460 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Started up successfully +[12:36:29.544 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Welcome from [akka.tcp://otopcua@central-1:4053] +[12:36:29.659 INF] OPC UA redundancy: Mode=Unset, effective ApplicationUri=urn:OtOpcUa:central-2, peers=[urn:OtOpcUa:central-1], PromoteWhilePrimaryUnreachable=True +[12:36:30.660 INF] OtOpcUaServerHostedService: SDK started, address-space + ServiceLevel sinks bound +[12:36:31.290 INF] AddressSpaceApplier: applied plan (kind=PureAdd, added=10, removed=0, changed=0, surgicalRawTags=0, unsRefDeltas=0, renamedFolders=0, rebuild=False) +[12:36:31.323 INF] OpcUaPublish: applied rebuild (correlation=359acd924c274cfda4bc898bce85612b, added=10, removed=0, changed=0, rebuild=False) +[12:36:33.017 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:36:36.545 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:36:53.250 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Exiting confirmed [akka.tcp://otopcua@central-1:4053] +[12:36:53.481 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - is the new leader among reachable nodes (more leaders may exist) +[12:36:53.484 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Leader is removing confirmed Exiting node [akka.tcp://otopcua@central-1:4053] +[12:36:53.485 INF] Member removed [akka.tcp://otopcua@central-1:4053] +[12:36:53.486 INF] Member removed [akka.tcp://otopcua@central-1:4053] +[12:36:53.486 INF] Member removed [akka.tcp://otopcua@central-1:4053] +[12:36:53.486 INF] Member removed [akka.tcp://otopcua@central-1:4053] +[12:36:53.486 INF] Member removed [akka.tcp://otopcua@central-1:4053] +[12:36:53.486 INF] Member removed [akka.tcp://otopcua@central-1:4053] +[12:37:00.700 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:37:03.175 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:38:56.181 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Received InitJoin message from [[akka.tcp://otopcua@central-1:4053/system/cluster/core/daemon/firstSeedNodeProcess-1#2101167875]] to [akka.tcp://otopcua@central-2:4053] +[12:38:56.181 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Sending InitJoinAck message from node [akka.tcp://otopcua@central-2:4053] to [[akka.tcp://otopcua@central-1:4053/system/cluster/core/daemon/firstSeedNodeProcess-1#2101167875]] +[12:38:56.194 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Node [akka.tcp://otopcua@central-1:4053] is JOINING, roles [driver,admin,cluster-MAIN], version [1.0.0] +[12:38:56.479 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Leader is moving node [akka.tcp://otopcua@central-1:4053] to [Up] +[12:38:57.477 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - is no longer leader +[12:39:27.425 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:39:34.688 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:39:34.706 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:42:24.471 WRN] The `auto-down-unreachable-after` feature has been deprecated as of Akka.NET v1.5.2 and will be removed in a future version of Akka.NET. The `keep-majority` split brain resolver will be used instead. See https://getakka.net/articles/cluster/split-brain-resolver.html for more detai +[12:42:24.472 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Starting up... +[12:42:24.477 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Started up successfully +[12:42:24.555 INF] Cluster Node [akka.tcp://otopcua@central-2:4053] - Welcome from [akka.tcp://otopcua@central-1:4053] +[12:42:24.697 INF] OPC UA redundancy: Mode=Unset, effective ApplicationUri=urn:OtOpcUa:central-2, peers=[urn:OtOpcUa:central-1], PromoteWhilePrimaryUnreachable=True +[12:42:25.706 INF] OtOpcUaServerHostedService: SDK started, address-space + ServiceLevel sinks bound +[12:42:26.297 INF] AddressSpaceApplier: applied plan (kind=PureAdd, added=10, removed=0, changed=0, surgicalRawTags=0, unsRefDeltas=0, renamedFolders=0, rebuild=False) +[12:42:26.326 INF] OpcUaPublish: applied rebuild (correlation=b839f94c2abf452cbea681f752aa4397, added=10, removed=0, changed=0, rebuild=False) +[12:42:27.900 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:42:31.437 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:43:22.823 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. +[12:43:23.255 ERR] The domain 'opc.tcp://localhost:25841/OtOpcUa' is not listed in the server certificate. diff --git a/docs/plans/evidence/2026-11-13-615-g9/rig/compose.g9.yml b/docs/plans/evidence/2026-11-13-615-g9/rig/compose.g9.yml new file mode 100644 index 000000000..2536bb319 --- /dev/null +++ b/docs/plans/evidence/2026-11-13-615-g9/rig/compose.g9.yml @@ -0,0 +1,102 @@ +# Isolated #615 G9 pair (Mode unset = production default). Project otopcua-g9; own network, SQL, volumes, image tag. +name: otopcua-g9 +x-host-env: &host-env + OTOPCUA_ROLES: "admin,driver,cluster-MAIN" + ASPNETCORE_URLS: "http://+:9000" + ConnectionStrings__ConfigDb: "Server=sql,1433;Database=OtOpcUa;User Id=sa;Password=OtOpcUa!Dev123;TrustServerCertificate=True;" + Secrets__SqlitePath: "/data/otopcua-secrets.db" + Secrets__Replication__Enabled: "true" + Secrets__Replication__AnnounceInterval: "00:00:05" + ZB_SECRETS_MASTER_KEY: "ZYGhIX0luS/XsevpCB2W18jYHMcqO6AjM9oXy+T6Zp4=" + Security__ApiKeys__Pepper: "t13-apikey-pepper-not-for-production" + # LDAP block is validated at boot; it is AdminUI-login only and login is disabled, so point it at loopback + # (nothing here contacts the shared GLAuth). + Security__Ldap__Enabled: "true" + Security__Ldap__DevStubMode: "false" + Security__Ldap__Server: "127.0.0.1" + Security__Ldap__Port: "3893" + Security__Ldap__Transport: "None" + Security__Ldap__AllowInsecure: "true" + Security__Ldap__SearchBase: "dc=zb,dc=local" + Security__Ldap__ServiceAccountDn: "cn=serviceaccount,dc=zb,dc=local" + Security__Ldap__ServiceAccountPassword: "unused" + Cluster__Hostname: "0.0.0.0" + Cluster__Port: "4053" + ConfigServe__GrpcListenPort: "4055" + ConfigServe__ApiKey: "configserve-t13-key" + ConfigSource__Mode: "Direct" + Telemetry__GrpcListenPort: "4056" + Telemetry__Mode: "Grpc" + Telemetry__ApiKey: "telemetry-t13-key" + TelemetryDial__Mode: "Grpc" + TelemetryDial__ApiKey: "telemetry-t13-key" + Cluster__Roles__0: "admin" + Cluster__Roles__1: "driver" + Cluster__Roles__2: "cluster-MAIN" + MeshTransport__Mode: "Grpc" + MeshTransport__GrpcPsk: "t13-mesh-psk-MAIN" + MeshTransport__CentralGrpcEndpoints__0: "http://central-1:4055" + MeshTransport__CentralGrpcEndpoints__1: "http://central-2:4055" + MeshTransport__ClusterPsks__MAIN: "t13-mesh-psk-MAIN" + Security__Jwt__SigningKey: "t13-signing-key-with-at-least-32-bytes-of-utf8-content-12345678" + Security__Jwt__Issuer: "otopcua-t13" + Security__Jwt__Audience: "otopcua-t13" + Security__DeployApiKey: "t13-deploy-key" + Security__Auth__DisableLogin: "true" + Security__Acl__Enabled: "false" + ServerHistorian__Enabled: "false" + ContinuousHistorization__Enabled: "false" + Serilog__MinimumLevel__Override__Microsoft.EntityFrameworkCore: "Warning" + Serilog__MinimumLevel__Override__Microsoft.AspNetCore: "Warning" + LocalDb__Path: "/app/data/otopcua-localdb.db" + Serilog__WriteTo__0__Args__outputTemplate: "[{Timestamp:HH:mm:ss.fff} {Level:u3}] {Message:lj}{NewLine}{Exception}" + +services: + sql: + image: mcr.microsoft.com/mssql/server:2022-latest + environment: + ACCEPT_EULA: "Y" + SA_PASSWORD: "OtOpcUa!Dev123" + MSSQL_PID: Developer + ports: ["25339:1433"] + volumes: [g9-mssql-data:/var/opt/mssql] + healthcheck: + test: ["CMD-SHELL", "/opt/mssql-tools18/bin/sqlcmd -S localhost -U sa -P 'OtOpcUa!Dev123' -No -Q 'SELECT 1' || exit 1"] + interval: 10s + timeout: 5s + retries: 20 + + central-1: + image: otopcua-host:${G9_IMAGE:-g9-003c7f89} + mem_limit: 2g + restart: unless-stopped + depends_on: { sql: { condition: service_healthy } } + environment: + <<: *host-env + Cluster__PublicHostname: "central-1" + OpcUa__ApplicationUri: "urn:OtOpcUa:central-1" + OpcUa__PeerApplicationUris__0: "urn:OtOpcUa:central-2" + Cluster__SeedNodes__0: "akka.tcp://otopcua@central-1:4053" + Cluster__SeedNodes__1: "akka.tcp://otopcua@central-2:4053" + ports: ["25840:4840", "29310:9000"] + volumes: [g9-c1:/app/data, g9-c1:/data] + + central-2: + image: otopcua-host:${G9_IMAGE:-g9-003c7f89} + mem_limit: 2g + restart: unless-stopped + depends_on: { sql: { condition: service_healthy }, central-1: { condition: service_started } } + environment: + <<: *host-env + Cluster__PublicHostname: "central-2" + OpcUa__ApplicationUri: "urn:OtOpcUa:central-2" + OpcUa__PeerApplicationUris__0: "urn:OtOpcUa:central-1" + Cluster__SeedNodes__0: "akka.tcp://otopcua@central-2:4053" + Cluster__SeedNodes__1: "akka.tcp://otopcua@central-1:4053" + ports: ["25841:4840", "29311:9000"] + volumes: [g9-c2:/app/data, g9-c2:/data] + +volumes: + g9-mssql-data: + g9-c1: + g9-c2: diff --git a/docs/plans/evidence/2026-11-13-615-g9/rig/seed.sql b/docs/plans/evidence/2026-11-13-615-g9/rig/seed.sql new file mode 100644 index 000000000..eee22c878 --- /dev/null +++ b/docs/plans/evidence/2026-11-13-615-g9/rig/seed.sql @@ -0,0 +1,27 @@ + +SET NOCOUNT ON; SET XACT_ABORT ON; BEGIN TRAN; +INSERT dbo.ServerCluster (ClusterId,Name,Enterprise,Site,NodeCount,RedundancyMode,Enabled,Notes,CreatedBy) + VALUES ('MAIN','Main cluster','zb','t13',2,'Warm',1,'717 T13 isolated pair','g9-seed'); +INSERT dbo.ClusterNode (NodeId,ClusterId,Host,OpcUaPort,DashboardPort,AkkaPort,GrpcPort,ApplicationUri,ServiceLevelBase,Enabled,CreatedBy) + VALUES ('central-1:4053','MAIN','central-1',4840,8081,4053,4056,'urn:OtOpcUa:central-1',200,1,'g9-seed'), + ('central-2:4053','MAIN','central-2',4840,8081,4053,4056,'urn:OtOpcUa:central-2',150,1,'g9-seed'); +INSERT dbo.Script (ScriptId,Name,SourceCode,SourceHash,Language) VALUES + ('SC-t13-calc','T13-Calc',N'return (int)(ctx.Now.TimeOfDay.TotalSeconds);','1476d80c7a7a30dfe7c60c1b01c5703e09df49289f855507bb1047ae4ee03e06','CSharp'), + ('SC-t13-wr','T13-Writable',N'return 0;','6be2e46a3d0765fd4d08def164c35b75afcc481db6fd11cc5118c4e2c20b634d','CSharp'), + ('SC-t13-vt','T13-VT',N'return ctx.Now.Second;','0dede8751d015ae75a5b8b0c48a3d059bea7d3af38dd31833a0ebd09be72153f','CSharp'), + ('SC-t13-alarm','T13-AlarmPredicate',N'var v = ctx.GetTag("t13-calc/Device1/calc-seconds"); if (v.Value is null) return false; return (System.Convert.ToInt32(v.Value) / 60) % 2 == 0;','e1a76a504472219eda6bf2e41a60c3522c5c87fee3ef12f599a60cc7211b389b','CSharp'); +INSERT dbo.DriverInstance (DriverInstanceId,ClusterId,Name,DriverType,Enabled,DriverConfig) + VALUES ('DI-t13-calc','MAIN','t13-calc','Calculation',1,'{}'); +INSERT dbo.Device (DeviceId,DriverInstanceId,Name,Enabled,DeviceConfig) VALUES ('DEV-t13-1','DI-t13-calc','Device1',1,'{}'); +INSERT dbo.Tag (TagId,DeviceId,Name,DataType,AccessLevel,WriteIdempotent,TagConfig) VALUES + ('TAG-t13-sec','DEV-t13-1','calc-seconds','Int32','Read',0,'{"scriptId":"SC-t13-calc","changeTriggered":true,"timerIntervalMs":1000}'), + ('TAG-t13-wr','DEV-t13-1','calc-writable','Int32','ReadWrite',0,'{"scriptId":"SC-t13-wr","changeTriggered":true,"timerIntervalMs":5000}'); +INSERT dbo.UnsArea (UnsAreaId,ClusterId,Name) VALUES ('area-t13','MAIN','t13'); +INSERT dbo.UnsLine (UnsLineId,UnsAreaId,Name) VALUES ('line-t13','area-t13','warm'); +INSERT dbo.Equipment (EquipmentId,EquipmentUuid,UnsLineId,Name,MachineCode,Enabled) VALUES ('EQ-3326c7a4728e','3326c7a4-728e-4000-8000-000000000717','line-t13','t13-equipment','T13',1); +INSERT dbo.UnsTagReference (UnsTagReferenceId,EquipmentId,TagId,SortOrder) VALUES ('REF-t13-sec','EQ-3326c7a4728e','TAG-t13-sec',0),('REF-t13-wr','EQ-3326c7a4728e','TAG-t13-wr',1); +INSERT dbo.VirtualTag (VirtualTagId,EquipmentId,Name,DataType,ScriptId,ChangeTriggered,TimerIntervalMs,Historize,Enabled) + VALUES ('VT-t13-second','EQ-3326c7a4728e','vt-second','Int32','SC-t13-vt',1,1000,0,1); +INSERT dbo.ScriptedAlarm (ScriptedAlarmId,EquipmentId,Name,AlarmType,Severity,MessageTemplate,PredicateScriptId,HistorizeToAveva,Retain,Enabled) + VALUES ('AL-t13-minute','EQ-3326c7a4728e','t13-even-minute','OffNormalAlarm',600,'T13 even minute','SC-t13-alarm',0,1,1); +COMMIT; diff --git a/docs/plans/phase-6-3-redundancy-interop-plan.md b/docs/plans/phase-6-3-redundancy-interop-plan.md index f8792504a..3a6b270a1 100644 --- a/docs/plans/phase-6-3-redundancy-interop-plan.md +++ b/docs/plans/phase-6-3-redundancy-interop-plan.md @@ -98,9 +98,9 @@ dotnet test ZB.MOM.WW.OtOpcUa.slnx --filter "FullyQualifiedName~Redundancy|Fully | A1 | ServiceLevel on Primary | Read `Server/ServerStatus/ServiceLevel` (`i=2267`) on the Primary. | 250 | Yes (Client CLI) | | A2 | ServiceLevel on follower | Read the same node on the other node. | 240 | Yes | | A3 | Peer stop does not demote the Primary | Stop the follower. Watch `ServiceLevel` on the Primary for >= 40 s. | Stays 250 (the benefit-of-the-doubt rule). A change here is a defect or an unrelated health input. | Yes | -| A4 | RedundancySupport | Read `i=3709` on either node (`otopcua-cli redundancy`). | **Known unmet:** no code sets it, so it reports the SDK default, not the cluster's `Warm`/`Hot`. Record the observed value; do not mark PASS. | Yes | +| A4 | RedundancySupport | Read `i=3709` on either node (`otopcua-cli redundancy`). | Depends on `OpcUa:Redundancy:Mode` (#717). `Warm`: `Warm`; `None`: `None`. **`Unset` (the default) leaves the SDK default `0`**: record it as unmet, not PASS. | Yes | | A5 | `ServerArray` peer discovery | Read `i=2254` on either node. | String[] contains both `ApplicationUri` values (self and peer). This is the discovery surface in use today. | Yes | -| A5b | `ServerUriArray` conformance | Read `i=11314` on either node. | **Known unmet standard-metadata gate.** The node is absent, so the read fails or is empty; the client CLI tolerates this. `ServerArray` (A5) is **not** a substitute and must not turn A5b into a PASS. | Yes | +| A5b | `ServerUriArray` conformance | Read `i=11314` on either node. | `Warm`: `[self, peers]`, read-only. `None`: `BadNodeIdUnknown`. **`Unset`: the SDK's orphan node reads Good `[]`**: record it as unmet. `ServerArray` (A5) is **not** a substitute and must not turn A5b into a PASS. | Yes | | A6 | Endpoint-failure step-down | Occupy port 4840 on the Primary host before it starts (fused admin+driver node), or follow lmxopcua#761. | Failed node publishes 0; the peer becomes Primary and publishes 250 (see `docs/Redundancy.md` "Endpoint start failure: Primary step-down"). | No | | A7 | Client CLI reads ServiceLevel | `dotnet run --project src/Client/ZB.MOM.WW.OtOpcUa.Client.CLI -- read -u opc.tcp://:4840 -n "i=2267"` | Prints the expected byte. | Yes | | A8 | otopcua-cli failover reconnect | `... -- connect -u opc.tcp://:4840 -F opc.tcp://:4840`, then stop Node A. | CLI reconnects to Node B within the session keep-alive timeout. | Yes | @@ -130,9 +130,9 @@ A negative result on C1–C3 does not necessarily indicate an OtOpcUa defect; co ## Step-by-step cutover-validation runbook Minimum procedure for the v2 GA exit criterion "Non-transparent redundancy cutover validated with at least -one production client (Ignition 8.3 recommended — see decision #85)". **Standard metadata gaps remain -(A4, A5b); those rows stay unmet and the production-client cutover gate stays open until a real client -pass is recorded.** +one production client (Ignition 8.3 recommended — see decision #85)". **A4/A5b are met only under +`Mode=Warm` (#717); under the default `Unset` record them as unmet. G9 passed on 2026-11-13 with `otopcua-cli` +(owner-approved).** ### Step 1 — Provision the cluster @@ -211,13 +211,13 @@ explicitly recorded as unmet, is required before G9 can be called satisfied. ## Known limitations -### A4 / A5b — standard redundancy metadata not exposed +### A4 / A5b — standard redundancy metadata depends on the mode -OtOpcUa does not set `RedundancySupport` and does not expose `Server.ServerRedundancy.ServerUriArray` -(`i=11314`): the SDK's default `ServerRedundancy` object is the base type with no such child. Peer discovery -works through `Server.ServerArray` (`i=2254`) only. Clients that require the standard -`NonTransparentRedundancyType` metadata will not recognise the pair. The metadata gap is tracked separately -from this runbook. +Since #717, `OpcUa:Redundancy:Mode=Warm` serves `NonTransparentRedundancyType`, `RedundancySupport=Warm` and a +read-only `ServerUriArray` (`i=11314`), and `None` serves `RedundancySupport=None`. The default `Unset` leaves the SDK +defaults (`RedundancySupport` `0`, orphan `ServerUriArray` `[]`), so under `Unset` peer discovery works through +`Server.ServerArray` (`i=2254`) only. No tier may enable `Warm` before #907 (ScadaBridge#138). The 2026-11-13 G9 pass +(`docs/plans/evidence/2026-11-13-615-g9/RESULTS.md`) ran under `Unset`; #717 T13 L1 proved the `Warm` metadata. ### Failover timing is bounded by downing, not by probes diff --git a/docs/plans/v2-ga-lab-gates-plan.md b/docs/plans/v2-ga-lab-gates-plan.md index f119282fd..1ae7f2a00 100644 --- a/docs/plans/v2-ga-lab-gates-plan.md +++ b/docs/plans/v2-ga-lab-gates-plan.md @@ -247,6 +247,9 @@ Record: CNC series, firmware version, test date, OtOpcUa git SHA. ## G8 — OPC UA Conformance Test Tool (CTT) pass +> **WAIVED 2026-11-13 by the owner (#615):** no CTT run is required for v2 GA. The procedure below is kept for a +> later conformance effort. + **Requires**: OPC Foundation OPC UA Compliance Test Tool (CTT) or the open-source UA Compliance Test Tool installed on the client machine; live OtOpcUa server endpoint. @@ -279,6 +282,10 @@ Record: CTT version, profile set, OtOpcUa git SHA, report artifact. ## G9 — Non-transparent redundancy cutover with production client +> **PASS 2026-11-13 (#615)** with `otopcua-cli` as the client (owner-approved in place of UaExpert/Ignition), on an +> isolated 2-node pair in the deployed `Unset` mode: A1–A3, A5, A7, A8, B2 and B3 pass; A4/A5b are unmet under `Unset` +> and met under `Warm` (#717). Evidence: `docs/plans/evidence/2026-11-13-615-g9/RESULTS.md`. + See `docs/plans/phase-6-3-redundancy-interop-plan.md` for the full runbook. **Minimum acceptable result**: one complete pass of the A-block (UaExpert @@ -303,5 +310,5 @@ Record: client name + version, OtOpcUa git SHA, test date. | G5 | Run deployment checklist doc | All items checked; Fleet Admin signs off | Fleet Admin | | G6 | Browse/read/subscribe against live Galaxy | Good quality, non-empty tree | Dev (dev box) | | G7 | FOCAS CNC smoke — see live-hardware runbook | Session open, Good quality reads | Dev + lab hardware | -| G8 | CTT profile run against live endpoint | Zero mandatory failures | Dev + CTT tool | -| G9 | Redundancy cutover runbook | A-block + B2 pass with >= 1 client | Dev + two instances | +| G8 | CTT profile run against live endpoint | **Waived 2026-11-13 (owner)** | — | +| G9 | Redundancy cutover runbook | A-block + B2 pass with >= 1 client — **PASS 2026-11-13** (`otopcua-cli`) | Dev + two instances | diff --git a/docs/v2/v2-release-readiness.md b/docs/v2/v2-release-readiness.md index 5c2ac2fbf..da534d90c 100644 --- a/docs/v2/v2-release-readiness.md +++ b/docs/v2/v2-release-readiness.md @@ -10,7 +10,7 @@ > near the end of the file are still live — see `deferment.md` §5. > **Last updated**: 2026-04-24 (Phase 5 driver complement closed — AB CIP, AB Legacy, TwinCAT, FOCAS all shipped; FOCAS Tier-C retired for a pure-managed in-process client) -> **Status**: **RELEASE-READY (code-path)** for v2 GA. All three original code-path release blockers remain closed. Phase 5 is now complete. Remaining work is manual (live-hardware validations, client interop matrix, deployment checklist signoff, OPC UA CTT pass) + hardening follow-ups; see exit-criteria checklist below. +> **Status**: **RELEASE-READY (code-path)** for v2 GA. All three original code-path release blockers remain closed. Phase 5 is now complete. Remaining work is the deployment checklist sign-off (G5, Fleet Admin) + hardening follow-ups; G6 and G9 passed (2026-11-12/13) and G8 (CTT) was waived by the owner (2026-11-13); see exit-criteria checklist below. This doc is the single view of where v2 stands against its release criteria. Update it whenever a deferred follow-up closes or a new release blocker is discovered. @@ -138,11 +138,12 @@ v2 GA requires all of the following: - [ ] Production deployment checklist (separate doc) signed off by Fleet Admin. - [x] At least one end-to-end integration run against the live Galaxy on the dev box succeeds. **G6 PASS 2026-11-12** (#615): windev test Galaxy `DEV` through mxaccessgw `447070a5`; browse (raw + UNS), read, subscribe, write and readback, and native alarm → Part 9 → ack (confirmed in Galaxy) → clear. Evidence: `docs/drivers/evidence/galaxy-g6-e2e-2026-11-12.md`. Found #895 (fixed, `e113faf5`) and #896 (open). DeployWatcher not exercised (no headless Galaxy redeploy). - [ ] FOCAS live-CNC wire-level smoke (#54) runs clean against a real FANUC control. -- [ ] OPC UA conformance test (CTT or UA Compliance Test Tool) passes against the live endpoint. -- [ ] Non-transparent redundancy cutover validated with at least one production client (Ignition 8.3 recommended — see decision #85). +- [x] ~~OPC UA conformance test (CTT or UA Compliance Test Tool) passes against the live endpoint.~~ **G8 WAIVED by the owner 2026-11-13** (#615): no CTT run is required for v2 GA. +- [x] Non-transparent redundancy cutover validated with at least one production client (Ignition 8.3 recommended — see decision #85). **G9 PASS 2026-11-13** (#615), with `otopcua-cli` as the client (owner-approved), on an isolated 2-node pair in the deployed `Unset` mode (`003c7f89`): A1–A3, A5, A7, A8, B2 (crash) and B3 pass; A4/A5b are recorded as unmet under `Unset` and met under `Warm` (#717). Evidence: `docs/plans/evidence/2026-11-13-615-g9/RESULTS.md`. ## Change log +- **2026-11-13** — **G9 (#615) PASS and G8 waived.** The owner approved `otopcua-cli` as the G9 client and waived the CTT (G8) for GA. G9 ran on an isolated 2-node pair (`otopcua-g9`, `master` `003c7f89`, redundancy mode `Unset` as deployed). ServiceLevel 250/240, a follower stop left the Primary at 250, and ServerArray lists both URIs. On a graceful Primary stop the CLI's `-F` sessions failed over in about 11 s. On a `docker kill` of the Primary they failed over within 1 s, with a ~2 s data gap and no Bad values; the survivor reached 250 at +44 s. The returning node settled at 240 with no failback. A4 (`RedundancySupport`) and A5b (`ServerUriArray`) are unmet under `Unset` and met under `Warm` (#717, closed; enabling Warm is #907). The run found a CLI defect: array values printed as `System.String[]`, fixed by `ValueFormatter`. Evidence: `docs/plans/evidence/2026-11-13-615-g9/RESULTS.md`. G5 (Fleet Admin sign-off) is the only open exit criterion. - **2026-11-12** — **G6 (#615) PASS: end to end against a live Galaxy.** A local fused admin+driver Host (OtOpcUa `00a5be26`) ran the `GalaxyMxGateway` driver against the windev test Galaxy `DEV` (System Platform 2020, 129 deployed objects) through mxaccessgw `447070a5`. Every plan §G6 criterion was met through both the raw (`ns=2;s=`) and UNS (`ns=3;s=Area/Line/Equipment/Signal`) NodeIds: non-empty browse mirroring area → object, `Good` reads, subscribe notifications inside 1 s, no `BadTimeout`. The only `BadNoCommunication` was a planned driver respawn on redeploy. Extra steps also passed: write and readback (also verified through an independent gateway session; anonymous negative control `BadUserAccessDenied`), and a Galaxy alarm raised by an OPC UA write surfacing as a Part 9 condition. That condition was acked over OPC UA and the ack was confirmed in Galaxy (`.Acked=True`, `.AckMsg` = the comment), then cleared. Severity 750 for AVEVA priority 500 (#887 band; data point for #894). The live run found **#895**: a native alarm authored the AdminUI-picker way (`attributeRef tag.Attr`) never went active, because the feed reports `Galaxy!Area.tag.Attr`. Fixed in `e113faf5` and re-verified live. It also found **#896** (open): the UNS mirror of an alarm-bearing tag is a dead `BadWaitingForInitialData` variable. DeployWatcher on a Galaxy redeploy was not run: no IDE/GRAccess on windev, and the Galaxy was shared with another agent. Evidence: `docs/drivers/evidence/galaxy-g6-e2e-2026-11-12.md`. - **2026-05-26** — Gap-closeout pass. `OpcUaApplicationHost.PopulateServerArray` populates `Server.ServerArray` (NodeId `i=2254`) with self + `OpcUaApplicationHostOptions.PeerApplicationUris`, giving non-transparent peer URI visibility through the standard discovery surface. New `tests/Server/ZB.MOM.WW.OtOpcUa.OpcUaServer.IntegrationTests/` IT project (`DualEndpointTests`) validates with two real `OpcUaApplicationHost` instances on loopback + a live OPCFoundation client `Session` read. CI `v2-ci.yml` `integration:` job converted to a matrix across `Host.IntegrationTests` + `OpcUaServer.IntegrationTests`. Per-role appsettings overlays shipped (`appsettings.admin.json` / `appsettings.driver.json` / `appsettings.admin-driver.json`) — `Program.cs:33-35` loads by alphabetical-joined role suffix. `FailoverScenarioTests` → `FailoverDuringDeployTests` rename. Stale empty `src/Server/{Server,Admin}` + `tests/Server/{Server.Tests,Admin.Tests,Admin.E2ETests}` directories deleted (no source, absent from `.slnx`). - **2026-04-24** — Phase 5 driver complement closed (task #120 CLOSED). AB CIP, AB Legacy, TwinCAT, FOCAS all shipped. FOCAS migration: retired the Tier-C split (`Driver.FOCAS.Host` + `Driver.FOCAS.Shared` + `FwlibNative` + shim DLL deleted) in favour of a pure-managed in-process `FocasWireClient` inlined into `Driver.FOCAS`; driver is now read-only against the CNC by design. Integration test matrix grew to cover Browse / Subscribe / IAlarmSource / Probe end-to-end. diff --git a/src/Client/ZB.MOM.WW.OtOpcUa.Client.CLI/Commands/HistoryReadCommand.cs b/src/Client/ZB.MOM.WW.OtOpcUa.Client.CLI/Commands/HistoryReadCommand.cs index 77921b4f8..7d087c8eb 100644 --- a/src/Client/ZB.MOM.WW.OtOpcUa.Client.CLI/Commands/HistoryReadCommand.cs +++ b/src/Client/ZB.MOM.WW.OtOpcUa.Client.CLI/Commands/HistoryReadCommand.cs @@ -211,7 +211,7 @@ public class HistoryReadCommand : CommandBase : StatusCode.IsBad(dv.StatusCode) ? "Bad" : "Uncertain"; await console.Output.WriteLineAsync( - $"{dv.SourceTimestamp.ToString("O"),-35} {ValueConverter.ToClrObject(dv.WrappedValue)?.ToString() ?? "(none)",-15} {status,-10} " + + $"{dv.SourceTimestamp.ToString("O"),-35} {(ValueConverter.ToClrObject(dv.WrappedValue) is { } hv ? ValueFormatter.Format(hv) : "(none)"),-15} {status,-10} " + $"{e.UpdateType,-8} {e.UserName ?? "",-20} {e.ModificationTime:O}"); } @@ -245,7 +245,7 @@ public class HistoryReadCommand : CommandBase : StatusCode.IsBad(dv.StatusCode) ? "Bad" : "Uncertain"; await console.Output.WriteLineAsync( - $"{dv.SourceTimestamp.ToString("O"),-35} {ValueConverter.ToClrObject(dv.WrappedValue),-15} {status}"); + $"{dv.SourceTimestamp.ToString("O"),-35} {ValueFormatter.Format(ValueConverter.ToClrObject(dv.WrappedValue)),-15} {status}"); } await console.Output.WriteLineAsync(); diff --git a/src/Client/ZB.MOM.WW.OtOpcUa.Client.CLI/Commands/ReadCommand.cs b/src/Client/ZB.MOM.WW.OtOpcUa.Client.CLI/Commands/ReadCommand.cs index 5677b9082..db1ab1fd6 100644 --- a/src/Client/ZB.MOM.WW.OtOpcUa.Client.CLI/Commands/ReadCommand.cs +++ b/src/Client/ZB.MOM.WW.OtOpcUa.Client.CLI/Commands/ReadCommand.cs @@ -65,7 +65,7 @@ public class ReadCommand : CommandBase } await console.Output.WriteLineAsync($"Node: {NodeId}"); - await console.Output.WriteLineAsync($"Value: {ValueConverter.ToClrObject(value.WrappedValue)}"); + await console.Output.WriteLineAsync($"Value: {ValueFormatter.Format(ValueConverter.ToClrObject(value.WrappedValue))}"); await console.Output.WriteLineAsync($"Status: {value.StatusCode}"); await console.Output.WriteLineAsync($"Source Time: {value.SourceTimestamp:O}"); await console.Output.WriteLineAsync($"Server Time: {value.ServerTimestamp:O}"); diff --git a/src/Client/ZB.MOM.WW.OtOpcUa.Client.CLI/Commands/SubscribeCommand.cs b/src/Client/ZB.MOM.WW.OtOpcUa.Client.CLI/Commands/SubscribeCommand.cs index 13d37903f..a205ce313 100644 --- a/src/Client/ZB.MOM.WW.OtOpcUa.Client.CLI/Commands/SubscribeCommand.cs +++ b/src/Client/ZB.MOM.WW.OtOpcUa.Client.CLI/Commands/SubscribeCommand.cs @@ -131,7 +131,7 @@ public class SubscribeCommand : CommandBase if (!Quiet) { var line = - $"[{e.Value.SourceTimestamp:O}] {displayNameByNodeId.GetValueOrDefault(key, key)} = {ValueConverter.ToClrObject(e.Value.WrappedValue)} ({e.Value.StatusCode})"; + $"[{e.Value.SourceTimestamp:O}] {displayNameByNodeId.GetValueOrDefault(key, key)} = {ValueFormatter.Format(ValueConverter.ToClrObject(e.Value.WrappedValue))} ({e.Value.StatusCode})"; outputChannel.Writer.TryWrite(line); } } diff --git a/src/Client/ZB.MOM.WW.OtOpcUa.Client.CLI/Helpers/ValueFormatter.cs b/src/Client/ZB.MOM.WW.OtOpcUa.Client.CLI/Helpers/ValueFormatter.cs new file mode 100644 index 000000000..5cf2e6eae --- /dev/null +++ b/src/Client/ZB.MOM.WW.OtOpcUa.Client.CLI/Helpers/ValueFormatter.cs @@ -0,0 +1,25 @@ +using System.Collections; +using System.Globalization; + +namespace ZB.MOM.WW.OtOpcUa.Client.CLI.Helpers; + +/// +/// Renders a converted OPC UA value for console output. Interpolating a CLR array prints its type name +/// (System.String[]), which hid the content of every array-valued node (e.g. ServerArray +/// i=2254, found during the #615 G9 run); this prints the elements instead. +/// +public static class ValueFormatter +{ + /// Formats a value for display. + /// The value, as returned by ValueConverter.ToClrObject. + /// [a, b, …] for a collection (recursively), hex for a byte string, otherwise the invariant text. + public static string Format(object? value) => value switch + { + null => string.Empty, + string s => s, + byte[] bytes => "0x" + Convert.ToHexString(bytes), + IEnumerable items => "[" + string.Join(", ", items.Cast().Select(Format)) + "]", + IFormattable f => f.ToString(null, CultureInfo.InvariantCulture), + _ => value.ToString() ?? string.Empty, + }; +} diff --git a/tests/Client/ZB.MOM.WW.OtOpcUa.Client.CLI.Tests/ValueFormatterTests.cs b/tests/Client/ZB.MOM.WW.OtOpcUa.Client.CLI.Tests/ValueFormatterTests.cs new file mode 100644 index 000000000..cc27529d7 --- /dev/null +++ b/tests/Client/ZB.MOM.WW.OtOpcUa.Client.CLI.Tests/ValueFormatterTests.cs @@ -0,0 +1,35 @@ +using Shouldly; +using Xunit; +using ZB.MOM.WW.OtOpcUa.Client.CLI.Helpers; + +namespace ZB.MOM.WW.OtOpcUa.Client.CLI.Tests; + +/// Array-valued nodes print their elements, not the CLR type name (#615 G9: ServerArray read as System.String[]). +public class ValueFormatterTests +{ + /// A string array (e.g. ServerArray i=2254) prints its elements in order. + [Fact] + public void String_array_prints_elements() => + ValueFormatter.Format(new[] { "urn:OtOpcUa:central-1", "urn:OtOpcUa:central-2" }) + .ShouldBe("[urn:OtOpcUa:central-1, urn:OtOpcUa:central-2]"); + + /// An empty array prints as [], distinguishable from a null value. + [Fact] + public void Empty_array_prints_brackets() => ValueFormatter.Format(Array.Empty()).ShouldBe("[]"); + + /// Numeric arrays use the invariant culture. + [Fact] + public void Numeric_array_is_invariant() => ValueFormatter.Format(new[] { 1.5, 2.25 }).ShouldBe("[1.5, 2.25]"); + + /// A byte string prints as hex rather than a list of bytes. + [Fact] + public void Byte_string_prints_hex() => ValueFormatter.Format(new byte[] { 0x0A, 0xFF }).ShouldBe("0x0AFF"); + + /// A string is not treated as a collection of characters. + [Fact] + public void String_is_not_enumerated() => ValueFormatter.Format("abc").ShouldBe("abc"); + + /// Scalars and null keep their plain rendering. + [Fact] + public void Scalars_and_null() { ValueFormatter.Format(250).ShouldBe("250"); ValueFormatter.Format(null).ShouldBe(""); } +}