docs(drill): env2 seeded data-path soak - site-x and central failovers with live data and S&F, no buffered loss (#116)

Unreplicated, the site-x survivor came up empty (by design: no LocalDb peer);
replicated, kill and freeze each lost only the 26-30 s takeover window, every
buffered message was delivered once, and the 4 duplicate ticks came from the
frozen victim's 6 s zombie window. Central kill: 0 gap.

Claude-Session: https://claude.ai/code/session_01GT67ACmpMR7b9LGRPLijMi
This commit is contained in:
Joseph Doherty
2026-11-12 23:56:18 -05:00
parent 6c7e150a32
commit 644f564c30
26 changed files with 497 additions and 1 deletions
@@ -38,7 +38,7 @@ The central freeze rejoin was 3 s here against 34 s on the primary rig. The diff
## 2. Limits of this run
- **env2 is not seeded.** `ScadaBridgeConfig2` has 0 sites and 0 instances, and site-x reports 0 data connections, so this run proves cluster mechanics only. The rig run's data-path and store-and-forward check (§3 of the rig doc) was not repeated here. `docker-env2/seed-sites.sh` would bind a data connection to the windev MxGateway (`10.100.0.48:5120`); it was not run, because that reaches outside env2.
- **env2 is not seeded.** `ScadaBridgeConfig2` has 0 sites and 0 instances, and site-x reports 0 data connections, so this run proves cluster mechanics only. The rig run's data-path and store-and-forward check (§3 of the rig doc) was not repeated here. `docker-env2/seed-sites.sh` would bind a data connection to the windev MxGateway (`10.100.0.48:5120`); it was not run, because that reaches outside env2. **Closed 2026-11-13: see [§5](#5-seeded-data-path-soak-2026-11-13-utc-0432-0455).**
- **Transport smoke skipped.** `docker-env2/README.md` points only to `2026-05-24-second-environment-verification.md`, which is marked RETIRED (superseded by the Transport integration tests and the 2026-08-01 live run). The primary rig was also in use by another agent (a burst of about 300 `/management` calls at 04:15–04:17). No export or import was run.
## 3. Final state: env2 stays on `leader-auto-down` (soak)
@@ -62,3 +62,57 @@ A plain `bash docker-env2/deploy.sh` rebuilds and runs `scadabridge:latest` on `
## 4. Next step
QA pair vq03/vq04, which **needs owner approval**. On QA, check the exit-75 restart under the Windows service supervisor (#116 comment of 2026-11-12: with `failureflag 1`, recovery fires only on a non-zero exit, and the Host only started exiting 75 with #132). Then DEV vd03 and its sites, then the default flip.
## 5. Seeded data-path soak (2026-11-13 UTC 04:32–04:55)
The gap in §2 is closed: env2 now carries real data, and the site-x failovers were re-run with it flowing. Raw output is in the same directory, prefixed `seeded-`.
### What was seeded
- `docker-env2/seed-sites.sh`, as committed: Site-X (id 3), the *Engineering Alerts* list, the MxGateway connection *ScadaBridge Site X* to the windev gateway `http://10.100.0.48:5120`, the LDAP mappings, and the `MxAlarmDemo-1` instance. The connection authenticates with the API key `mxgw_scadabridgeshared_…`, which is written into the script itself. The management API returns it as `***REDACTED***` with `hasSecrets: true`. The windev gateway was only used as a client. The LDAP step logged two harmless `2601` duplicate-name errors, because the names already exist under other ids.
- New `docker-env2/seed-data-path.sh` (commit `8b6d3268`):
- The env2-owned sink container `scadabridge-env2-sfsink` (`docker-env2/sfsink/sink.py`). It records every POST, and answers 503 while its mode file says `fail`.
- The OPC UA connection *OPC PLC Simulator* to the shared `scadabridge-opcua`.
- The external system *EnvSink* (method `Record`, retry every 5 s, retry budget 100000).
- The instance **`env-soak-1`**: `Spike` from `ns=3;s=SpikeData`, `RandomInt` from `ns=3;s=RandomSignedInt32`, and a 2 s Interval script `SoakTick`. Each run sends `ExternalSystem.CachedCall("EnvSink","Record")` with `tick = unixSeconds / 2`. The sink therefore gets one row per tick: a missing tick is either a run that never happened or a lost message, and a repeated tick is a duplicate.
- The instance **`env-galaxy-1`**: `GalaxyInt` from `TestMachine_003.TestChangingInt`, **read only** (no write binding, no script).
- The sink's mode switch is what makes store-and-forward buffer: a 503 is transient, so the call is parked and retried. A healthy target is delivered at once and never enters the buffer.
Values flow: `debug snapshot` through Traefik `:9100` shows `Spike`/`RandomInt` Good and updating every second. `GalaxyInt` is Good: it read 11 at 04:27 and 753 at 04:45 (the Galaxy attribute changes slowly). Central's site-x health report shows both connections `Connected`, tag quality 2/2 and 1/1 good, and both cluster nodes online.
### Finding: unreplicated, a site failover brings up an empty node
The first seeded active kill ([log](2026-11-12-leader-auto-down-env2-drill/seeded-unreplicated-site-x-active-kill.log), [metrics](2026-11-12-leader-auto-down-env2-drill/seeded-unreplicated-site-x-active-kill.metrics), [survivor](2026-11-12-leader-auto-down-env2-drill/seeded-unreplicated-survivor-site-x-a.txt)) passed the cluster gate: `DOWNING` at +28 s, survivor active, rejoin 1 s, 10/10. But **data collection did not resume**. The survivor's Deployment Manager loaded only one stale config from an earlier env2 seeding, found no data connections (`Unknown connection: ScadaBridge Site X`) and ran no scripts for the 2 minutes it was watched (`site_data_connections 0/0`, 0 script runs). The 10 messages the victim had buffered stayed in the victim's own SQLite.
This is how the system is designed, not a #116 regression: site-x's `LocalDb` was **unreplicated**, like the rig's site-b and site-c, so deployed configs, artifacts and the S&F buffer exist only on the node that received them. A data-path failover needs the pair replicated. The rig's site-a and the QA pair are replicated.
**Fix (commit `6c7e150a`):** site-x now replicates. Node-a dials `http://scadabridge-env2-site-x-b:8083`, both nodes use the same dev key, and the sizing matches the rig's site-a. Both nodes were recreated together with the soak command from §3 (image and overlay kept). The baseline snapshot then carried node-b's rows to node-a, and node-a, now active, **delivered node-b's 10 stranded messages** (ticks 04:39:03–04:39:21, up to 243 s late, each exactly once).
**A second, smaller finding:** turning replication on for a pair whose stores have diverged has a boot race. Node-a won the active role at boot and loaded its own stale store at 04:42:54. The snapshot that added the other two configs and both connections arrived at 04:42:55. Its startup reconcile at 04:42:59 then found 0 gaps, because the rows were already in SQLite, so the instances never started. A `site deploy-artifacts` plus a redeploy of the two instances fixed it. Steady-state failovers are not affected, because the survivor's singleton loads from an already-converged store. It matters only for a first-time enable, or a node that boots active on a stale store.
### Failovers with data flowing (site-x replicated)
For each site drill, the sink was set to `fail` 20 s before the hit and back to `ok` 5 s after the drill script finished, so messages were buffered on the victim before it died and on the survivor during the takeover. The tick accounting is [`analyze.py`](2026-11-12-leader-auto-down-env2-drill/analyze.py) over the sink's rows. The per-node metrics are `/metrics` on 8084, every 5 s ([`sample.sh`](2026-11-12-leader-auto-down-env2-drill/sample.sh)).
| Run | Cluster gate | Data gap | Buffered messages | Duplicates |
|---|---|---|---|---|
| site-x active **kill** (victim site-x-a) — [log](2026-11-12-leader-auto-down-env2-drill/seeded-site-x-active-kill.log), [metrics](2026-11-12-leader-auto-down-env2-drill/seeded-site-x-active-kill.metrics), [ticks](2026-11-12-leader-auto-down-env2-drill/seeded-site-x-active-kill.ticks) | PASS: `DOWNING` +29 s, survivor active 29 s, rejoin 1 s, 10/10 | **30 s** (04:45:18–04:45:46): kill to the survivor's first `SoakTick` | Victim queued ~11 before the kill, survivor queued 9. Survivor delivered **20**, depth 0 within 10 s of `ok`. Every tick outside the gap present | **0** |
| site-x active **freeze** (`pause`, victim site-x-b) — [log](2026-11-12-leader-auto-down-env2-drill/seeded-site-x-active-pause.log), [metrics](2026-11-12-leader-auto-down-env2-drill/seeded-site-x-active-pause.metrics), [ticks](2026-11-12-leader-auto-down-env2-drill/seeded-site-x-active-pause.ticks), [victim](2026-11-12-leader-auto-down-env2-drill/seeded-site-x-pause-victim-lines.txt) | PASS: takeover 27 s; victim `shut out … RESTARTS`, exit 75, rejoined 38 s after unpause, 10/10 | **26 s** (04:48:14–04:48:38) | Victim queued 8 before the freeze and 8 during its zombie window; survivor queued 26. Survivor delivered **42** (= 26 + 16 inherited), depth 0 | **4**, all from the zombie window (below) |
| central active **kill** (victim central-b) with data flowing — [log](2026-11-12-leader-auto-down-env2-drill/seeded-central-active-kill.log), [metrics](2026-11-12-leader-auto-down-env2-drill/seeded-central-active-kill.metrics), [ticks](2026-11-12-leader-auto-down-env2-drill/seeded-central-active-kill.ticks) | PASS: survivor active 27 s, Traefik 29 s, rejoin 3 s, 10/10 | **0**: 43/43 ticks, site collection unaffected | n/a (sink `ok`) | **0** |
**The freeze duplicates are the accepted dual-active trade, not S&F redelivery.** At unpause (04:48:41) the frozen victim still believed it was active for 6 s, until its shut-out at 04:48:47:
- Its Interval timer fired the missed runs as one burst: 4 runs in flight, which is the cap, plus `run shed — 4 runs already in flight (cap 4)`. All 4 carried the same timestamp (`sentAtUtc 04:48:41.727`), so tick 04:48:40 appears 4×.
- One more of its runs (04:48:45.483) overlapped the survivor's own run for tick 04:48:44 (04:48:45.366), so that tick appears 2×.
All of these runs were buffered on the victim, replicated to the survivor, and delivered once each. No message was delivered twice. The #132 shut-out restart bounds the window to about 6 s.
**Whole soak** ([ticks](2026-11-12-leader-auto-down-env2-drill/seeded-whole-soak.ticks), 04:36:30–04:55:01): 400 rows, 396 unique ticks. The only gaps are the three takeover windows: the unreplicated one (264 s, until the replication recreate and redeploy) and 30 s and 26 s for the two replicated drills. The only duplicates are the 4 zombie-window rows. No buffered message was lost.
**Gauge caveat:** the standby's `scadabridge_store_and_forward_queue_depth_items` reports stale values (it showed 10–38 while the standby's copied `sf_messages` table held 0 rows), until the node is reseeded at a restart or a sweep. This is the known approximate gauge (review 2026-10-21 02/C3). Only read it on the active node.
### Final state
([status](2026-11-12-leader-auto-down-env2-drill/seeded-final-status.txt)) All four nodes run `scadabridge:env2-116` with `leader-auto-down`, each `memberCount 2, unreachableCount 0`. The active nodes are **central-a** and **site-x-a**. Traefik `:9100` returns `/health/active` 200. Site-x is replicated, with both connections up and depth 0. `env-soak-1` and `env-galaxy-1` keep running as the soak's live load, and the sink keeps recording at about 1 row per 2 s. Nothing in the primary rig, `scadabridge:latest` or shared infra was changed. `scadabridge-opcua`, `scadabridge-mssql` and the windev gateway were only used as clients.
To keep the soak: leave the sink in `ok`. Running `docker exec scadabridge-env2-sfsink sh -c 'echo fail > /data/mode'` buffers everything until it is set back to `ok`. The sink's `received.jsonl` grows by about 43k rows a day. Use [`run-site.sh`](2026-11-12-leader-auto-down-env2-drill/run-site.sh) to repeat a seeded site drill.
@@ -0,0 +1,30 @@
"""analyze.py <received.jsonl> <from_epoch> <to_epoch> [ipA ipB]
Tick accounting for the env2 S&F soak: one SoakTick per 2 s tick (tick = unix/2).
Reports rows, unique ticks, duplicates, missing tick runs (with UTC times) and, per
sender node, how many rows arrived late (= were buffered: at - tick*2 > 4 s)."""
import json, sys, datetime, collections
path, t0, t1 = sys.argv[1], float(sys.argv[2]), float(sys.argv[3])
ips = {}
if len(sys.argv) > 5: ips = {sys.argv[4]: "site-x-a", sys.argv[5]: "site-x-b"}
rows = [json.loads(l) for l in open(path) if l.strip()]
rows = [r for r in rows if isinstance(r.get("body"), dict) and t0 <= r["body"]["tick"] * 2 <= t1]
c = collections.Counter(r["body"]["tick"] for r in rows)
ts = lambda t: datetime.datetime.utcfromtimestamp(t * 2).strftime("%H:%M:%S")
print(f"window {ts(t0/2)}..{ts(t1/2)} UTC: rows={len(rows)} unique_ticks={len(c)} duplicates={sum(v-1 for v in c.values())}")
dups = sorted(t for t, v in c.items() if v > 1)
if dups: print(" duplicate ticks:", ", ".join(f"{ts(t)}x{c[t]}" for t in dups[:20]))
lo, hi = int(t0 // 2) + 1, int(t1 // 2)
missing = [t for t in range(lo, hi) if t not in c]
runs, cur = [], []
for t in missing:
if cur and t != cur[-1] + 1: runs.append(cur); cur = []
cur.append(t)
if cur: runs.append(cur)
for r in runs: print(f" gap: {ts(r[0])}..{ts(r[-1])} ({len(r)} ticks = {len(r)*2} s)")
by = collections.defaultdict(lambda: [0, 0, 0.0])
for r in rows:
n = ips.get(r["client"], r["client"]); late = r["at"] - r["body"]["tick"] * 2
by[n][0] += 1
if late > 4: by[n][1] += 1; by[n][2] = max(by[n][2], late)
for n, (k, l, mx) in sorted(by.items()):
print(f" sender {n}: rows={k} delivered_late(>4s, i.e. buffered)={l} max_delay={mx:.0f}s")
@@ -0,0 +1,23 @@
#!/bin/bash
# run-site.sh <name> <action kill|pause>: site-x active drill with the sink failing across the hit.
set -u
SP=$(dirname "$0"); WT=~/Desktop/ScadaBridge-wt-env2-seed; D=$WT/docs/plans/2026-11-12-leader-auto-down-env2-drill
NAME=$1; ACT=$2
T0=$(date +%s)
"$SP/sample.sh" 400 5 > "$D/$NAME.metrics" 2>&1 & SPID=$!
sleep 10
echo "$(date -u +%H:%M:%S) sink -> fail" | tee "$D/$NAME.events"
docker exec scadabridge-env2-sfsink sh -c 'echo fail > /data/mode'
sleep 20
echo "$(date -u +%H:%M:%S) drill start ($ACT)" | tee -a "$D/$NAME.events"
( cd $WT && DRILL_ENV=env2 DRILL_PAIR=site-x DRILL_MODE=active DRILL_ACTION=$ACT bash docker/failover-drill.sh ) > "$D/$NAME.log" 2>&1; RC=$?
echo "$(date -u +%H:%M:%S) drill end rc=$RC" | tee -a "$D/$NAME.events"
sleep 5
echo "$(date -u +%H:%M:%S) sink -> ok" | tee -a "$D/$NAME.events"
docker exec scadabridge-env2-sfsink sh -c 'echo ok > /data/mode'
sleep 60
kill $SPID 2>/dev/null
T1=$(( $(date +%s) - 10 ))
echo "$(date -u +%H:%M:%S) done" | tee -a "$D/$NAME.events"
docker exec scadabridge-env2-sfsink cat /data/received.jsonl > "$SP/received.jsonl"
python3 "$SP/analyze.py" "$SP/received.jsonl" "$T0" "$T1" 192.168.147.18 192.168.147.16 | tee "$D/$NAME.ticks"
@@ -0,0 +1,29 @@
#!/bin/bash
# sample.sh <seconds> [interval]: per-node data-path metrics + sink count, one line per interval.
DUR=${1:-120}; IV=${2:-5}; END=$(( $(date +%s) + DUR ))
m() { timeout 3 docker exec "scadabridge-env2-site-x-$1" bash -c 'exec 3<>/dev/tcp/localhost/8084 && printf "GET /metrics HTTP/1.0\r\nHost: localhost\r\n\r\n" >&3 && cat <&3' 2>/dev/null | python3 -c '
import sys,re
v={}
for l in sys.stdin:
if l.startswith("#"): continue
p=l.split()
if len(p)<2: continue
name=p[0]; val=float(p[1]) if re.match(r"^-?[0-9.e+]+$",p[1]) else 0
k=None
if name.startswith("scadabridge_site_script_runs_total"): k="runs"
elif name.startswith("scadabridge_site_data_connections_connected"): k="dc"
elif name.startswith("scadabridge_site_data_connections_total"): k="dct"
elif name.startswith("scadabridge_store_and_forward_queue_depth_items"): k="depth"
elif name.startswith("scadabridge_store_and_forward_activity_total"):
mm=re.search(r"(action)=\"([A-Za-z]+)\"",name); k="sf_"+(mm.group(2) if mm else "x")
if k: v[k]=v.get(k,0)+val
print(" ".join(f"{k}={int(x)}" for k,x in sorted(v.items())) or "DOWN")'; }
while [ "$(date +%s)" -lt "$END" ]; do
s=$(docker exec scadabridge-env2-sfsink sh -c 'wc -l < /data/received.jsonl; cat /data/mode 2>/dev/null || echo ok; tail -1 /data/received.jsonl' 2>/dev/null | python3 -c '
import sys,json
l=sys.stdin.read().splitlines()
t=json.loads(l[2])["body"]["tick"] if len(l)>2 and l[2] else "-"
print(f"sink_rows={l[0].strip()} mode={l[1].strip()} last_tick={t}")')
echo "$(date -u +%H:%M:%S) A[$(m a)] B[$(m b)] $s"
sleep "$IV"
done
@@ -0,0 +1,33 @@
env=env2 pair=central mode=active action=kill active=scadabridge-env2-central-b victim=scadabridge-env2-central-b survivor=scadabridge-env2-central-a
hit at 2026-11-13T04:52:15Z
Active kill: waiting for scadabridge-env2-central-a to take over as the active node (victim stays down; budget ~25s + hand-over)...
survivor logged the Down at +27s
PASS: scadabridge-env2-central-a took over as active in 27s with the victim still down
(downed the dead oldest, assumed Oldest, re-hosted the singletons).
Confirming Traefik routes to the new active node...
Traefik routing recovered 29s after the hit.
Recovering scadabridge-env2-central-b (kill -> start)...
Waiting for the victim to rejoin as a ready standby (scadabridge-env2-central-b /health/ready)...
Recovered: scadabridge-env2-central-b is ready as standby (rejoined) 3s after recovery.
Checking for a lingering dual-active (10 samples, 1s apart)...
Exactly one active node in 10/10 samples.
Survivor downing/singleton evidence (last 20 matching log lines from scadabridge-env2-central-a):
[04:52:26 WRN] [Central/scadabridge-env2-central-a] [leader-auto-down] akka.tcp://scadabridge@scadabridge-env2-central-b:8081 is unreachable; it will be downed if still unreachable after 00:00:15 (this node akka.tcp://scadabridge@scadabridge-env2-central-a:8081 is leader: True)
[04:52:41 WRN] [Central/scadabridge-env2-central-a] [leader-auto-down] DOWNING akka.tcp://scadabridge@scadabridge-env2-central-b:8081: unreachable for 00:00:15 and this node (akka.tcp://scadabridge@scadabridge-env2-central-a:8081) is leader
[04:52:41 INF] [Central/scadabridge-env2-central-a] Cluster Node [akka.tcp://scadabridge@scadabridge-env2-central-a:8081] - Marking unreachable node [akka.tcp://scadabridge@scadabridge-env2-central-b:8081] as [Down]
[04:52:42 INF] [Central/scadabridge-env2-central-a] Member removed [akka.tcp://scadabridge@scadabridge-env2-central-b:8081]
[04:52:42 INF] [Central/scadabridge-env2-central-a] Member removed [akka.tcp://scadabridge@scadabridge-env2-central-b:8081]
[04:52:42 INF] [Central/scadabridge-env2-central-a] Member removed [akka.tcp://scadabridge@scadabridge-env2-central-b:8081]
[04:52:42 INF] [Central/scadabridge-env2-central-a] Member removed [akka.tcp://scadabridge@scadabridge-env2-central-b:8081]
[04:52:42 INF] [Central/scadabridge-env2-central-a] Member removed [akka.tcp://scadabridge@scadabridge-env2-central-b:8081]
[04:52:42 INF] [Central/scadabridge-env2-central-a] Member removed [akka.tcp://scadabridge@scadabridge-env2-central-b:8081]
[04:52:42 INF] [Central/scadabridge-env2-central-a] Member removed [akka.tcp://scadabridge@scadabridge-env2-central-b:8081]
[04:52:42 INF] [Central/scadabridge-env2-central-a] ClusterSingletonManager state change [Younger -> Oldest] Akka.Cluster.Tools.Singleton.YoungerData
[04:52:42 INF] [Central/scadabridge-env2-central-a] ClusterSingletonManager state change [Younger -> Oldest] Akka.Cluster.Tools.Singleton.YoungerData
[04:52:42 INF] [Central/scadabridge-env2-central-a] ClusterSingletonManager state change [Younger -> Oldest] Akka.Cluster.Tools.Singleton.YoungerData
[04:52:42 INF] [Central/scadabridge-env2-central-a] ClusterSingletonManager state change [Younger -> Oldest] Akka.Cluster.Tools.Singleton.YoungerData
[04:52:42 INF] [Central/scadabridge-env2-central-a] ClusterSingletonManager state change [Younger -> Oldest] Akka.Cluster.Tools.Singleton.YoungerData
[04:52:42 INF] [Central/scadabridge-env2-central-a] ClusterSingletonManager state change [Younger -> Oldest] Akka.Cluster.Tools.Singleton.YoungerData
[04:52:42 INF] [Central/scadabridge-env2-central-a] ClusterSingletonManager state change [Younger -> Oldest] Akka.Cluster.Tools.Singleton.YoungerData
SUMMARY env=env2 pair=central mode=active action=kill down_logged_s=27 rejoin_s=3
Drill complete. Verify on the Health dashboard / Overview that both nodes show Up and exactly one is Primary.
@@ -0,0 +1,18 @@
04:51:59 A[dc=2 dct=2 depth=0 runs=98 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=0] sink_rows=318 mode=ok last_tick=897272759
04:52:05 A[dc=2 dct=2 depth=0 runs=100 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=0] sink_rows=320 mode=ok last_tick=897272761
04:52:10 A[dc=2 dct=2 depth=0 runs=103 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=0] sink_rows=323 mode=ok last_tick=897272764
04:52:15 A[dc=2 dct=2 depth=0 runs=106 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=0] sink_rows=326 mode=ok last_tick=897272767
04:52:20 A[dc=2 dct=2 depth=0 runs=108 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=0] sink_rows=328 mode=ok last_tick=897272769
04:52:25 A[dc=2 dct=2 depth=0 runs=111 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=0] sink_rows=331 mode=ok last_tick=897272772
04:52:31 A[dc=2 dct=2 depth=0 runs=113 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=0] sink_rows=333 mode=ok last_tick=897272774
04:52:36 A[dc=2 dct=2 depth=0 runs=116 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=0] sink_rows=336 mode=ok last_tick=897272777
04:52:41 A[dc=2 dct=2 depth=0 runs=119 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=0] sink_rows=339 mode=ok last_tick=897272780
04:52:46 A[dc=2 dct=2 depth=0 runs=121 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=0] sink_rows=341 mode=ok last_tick=897272782
04:52:52 A[dc=2 dct=2 depth=0 runs=124 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=0] sink_rows=344 mode=ok last_tick=897272785
04:52:57 A[dc=2 dct=2 depth=0 runs=126 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=0] sink_rows=346 mode=ok last_tick=897272787
04:53:02 A[dc=2 dct=2 depth=0 runs=129 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=0] sink_rows=349 mode=ok last_tick=897272790
04:53:07 A[dc=2 dct=2 depth=0 runs=132 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=0] sink_rows=352 mode=ok last_tick=897272793
04:53:12 A[dc=2 dct=2 depth=0 runs=134 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=0] sink_rows=354 mode=ok last_tick=897272795
04:53:17 A[dc=2 dct=2 depth=0 runs=137 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=0] sink_rows=357 mode=ok last_tick=897272798
04:53:23 A[dc=2 dct=2 depth=0 runs=139 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=0] sink_rows=359 mode=ok last_tick=897272800
04:53:28 A[dc=2 dct=2 depth=0 runs=142 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=0] sink_rows=362 mode=ok last_tick=897272803
@@ -0,0 +1,2 @@
window 04:51:59..04:53:24 UTC: rows=43 unique_ticks=43 duplicates=0
sender site-x-a: rows=43 delivered_late(>4s, i.e. buffered)=0 max_delay=0s
@@ -0,0 +1,8 @@
Fri Nov 13 04:55:07 UTC 2026
scadabridge-env2-central-a image=scadabridge:env2-116 strategy=leader-auto-down restarts=0 active=200 "memberCount":2,"unreachableCount":0
scadabridge-env2-central-b image=scadabridge:env2-116 strategy=leader-auto-down restarts=0 active=503 "memberCount":2,"unreachableCount":0
scadabridge-env2-site-x-a image=scadabridge:env2-116 strategy=leader-auto-down restarts=0 active=200 "memberCount":2,"unreachableCount":0
scadabridge-env2-site-x-b image=scadabridge:env2-116 strategy=leader-auto-down restarts=1 active=503 "memberCount":2,"unreachableCount":0
traefik :9100 /health/active 200
sink {"mode": "ok", "received": 412}
04:55:08 A[dc=2 dct=2 depth=0 runs=192 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=0] sink_rows=412 mode=ok last_tick=897272853
@@ -0,0 +1,16 @@
site-x id=3, MxGateway connection id=3
1/7 Store-and-forward sink container scadabridge-env2-sfsink...
2/7 OPC UA data connection on site-x...
id=4
3/7 External system EnvSink...
id=2
4/7 Template EnvSoak (opc-plc tags + SoakTick cached call)...
id=9
5/7 Template EnvGalaxyProbe (read-only Galaxy attribute TestMachine_003.TestChangingInt)...
id=10
6/7 Pushing artifacts (OPC UA connection + external system) to site-x...
7/7 Instances...
env-soak-1 id=9, env-galaxy-1 id=10
Done. Check: docker exec scadabridge-env2-sfsink wget -qO- localhost:5300/stats
/Users/dohertj2/Desktop/ScadaBridge-wt-env2-seed/src/ZB.MOM.WW.ScadaBridge.CLI/bin/Debug/net10.0/scadabridge --url http://localhost:9100 debug snapshot --id 9
@@ -0,0 +1,43 @@
=== Seeding ScadaBridge Env2 Sites ===
Creating Site-X (Env2 Site X)...
{"id":3,"name":"Env2 Site X","siteIdentifier":"site-x","description":"Env2 test site - two-node cluster","nodeAAddress":"akka.tcp://scadabridge@scadabridge-env2-site-x-a:8082","nodeBAddress":"akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082","grpcNodeAAddress":"http://scadabridge-env2-site-x-a:8083","grpcNodeBAddress":"http://scadabridge-env2-site-x-b:8083"}
Creating Engineering Alerts notification list...
{"id":1,"name":"Engineering Alerts","type":0,"recipients":[{"id":1,"notificationListId":1,"name":"engineer@company.com","emailAddress":"engineer@company.com"}]}
Creating MxGateway data connection (shared gateway) on site-x...
site-x (id=3): creating 'ScadaBridge Site X'...
{"id":3,"siteId":3,"name":"ScadaBridge Site X","protocol":"MxGateway","failoverRetryCount":3,"primaryConfiguration":"{\u0022endpoint\u0022:\u0022http://10.100.0.48:5120\u0022,\u0022apiKey\u0022:\u0022***REDACTED***\u0022,\u0022clientName\u0022:\u0022\u0022,\u0022writeUserId\u0022:0,\u0022useTls\u0022:false,\u0022caFile\u0022:\u0022\u0022,\u0022serverName\u0022:\u0022\u0022,\u0022readTimeoutMs\u0022:5000}","hasSecrets":true}
Seeding LDAP group mappings (Design + Deployment)...
Msg 2601, Level 14, State 1, Server 590cd6f80a52, Line 4
Cannot insert duplicate key row in object 'dbo.LdapGroupMappings' with unique index 'IX_LdapGroupMappings_LdapGroupName'. The duplicate key value is (SCADA-Designers).
The statement has been terminated.
Msg 2601, Level 14, State 1, Server 590cd6f80a52, Line 6
Cannot insert duplicate key row in object 'dbo.LdapGroupMappings' with unique index 'IX_LdapGroupMappings_LdapGroupName'. The duplicate key value is (SCADA-Deploy-All).
The statement has been terminated.
(1 rows affected)
Creating MxAlarm demo template + native alarm source binding...
{"id":8,"name":"MxAlarmDemo","description":"Demo: mirrors native MxAccess Gateway alarms (read-only)","attributes":[],"alarms":[],"scripts":[],"compositions":[],"nativeAlarmSources":[],"isDerived":false}
template 'MxAlarmDemo' (id=8): adding native alarm source 'GalaxyAlarms'...
{"id":1,"templateId":8,"name":"GalaxyAlarms","connectionName":"ScadaBridge Site X","sourceReference":"$Area_001","isMesReportable":false,"isLocked":false,"isInherited":false,"lockedInDerived":false}
creating instance 'MxAlarmDemo-1' at site-x...
{"id":8,"templateId":8,"siteId":3,"uniqueName":"MxAlarmDemo-1","state":2,"attributeOverrides":[],"alarmOverrides":[],"connectionBindings":[],"nativeAlarmSourceOverrides":[]}
Deploying artifacts to all env2 sites (pushes the data connection so the
site establishes it — the MxGateway DataConnectionActor connects eagerly)...
{"deploymentId":"de39728df90b49f0a8d16a07c78356d5","siteResults":[{"siteId":"site-x","siteName":"Env2 Site X","success":true}],"successCount":1,"failureCount":0}
Deploying the MxAlarm demo instance to site-x...
{"id":1,"instanceId":8,"status":2,"deploymentId":"d50295d79cfc494c97e97e616c1719a1","revisionHash":"sha256:51383094b6b6794f05f34774bafd89d6d1b3acae9d708e45b28d4abab21cfb30","deployedBy":"multi-role","deployedAt":"2026-11-13T04:32:33.3297321+00:00","completedAt":"2026-11-13T04:32:33.5445571+00:00","rowVersion":"AAAAAAACmFg="}
=== Env2 site seeding complete ===
Verify with: dotnet run --project /Users/dohertj2/Desktop/ScadaBridge-wt-env2-seed/src/ZB.MOM.WW.ScadaBridge.CLI -- --url http://localhost:9100 --username multi-role --password password site list
Verify connections: dotnet run --project /Users/dohertj2/Desktop/ScadaBridge-wt-env2-seed/src/ZB.MOM.WW.ScadaBridge.CLI -- --url http://localhost:9100 --username multi-role --password password data-connection list
Verify MxGateway is live: docker logs scadabridge-env2-site-x-a 2>&1 | grep -i mxgateway
Multi-role test user now has Admin + Design + Deployment in env2.
Sign out and back in to refresh session role claims.
@@ -0,0 +1,5 @@
04:44:56 sink -> fail
04:45:16 drill start (kill)
04:46:00 drill end rc=0
04:46:05 sink -> ok
04:47:05 done
@@ -0,0 +1,23 @@
env=env2 pair=site-x mode=active action=kill active=scadabridge-env2-site-x-a victim=scadabridge-env2-site-x-a survivor=scadabridge-env2-site-x-b
hit at 2026-11-13T04:45:17Z
Active kill: waiting for scadabridge-env2-site-x-b to take over as the active node (victim stays down; budget ~25s + hand-over)...
survivor logged the Down at +29s
PASS: scadabridge-env2-site-x-b took over as active in 29s with the victim still down
(downed the dead oldest, assumed Oldest, re-hosted the singletons).
Recovering scadabridge-env2-site-x-a (kill -> start)...
Waiting for the victim to rejoin as a ready standby (scadabridge-env2-site-x-a /health/ready)...
Recovered: scadabridge-env2-site-x-a is ready as standby (rejoined) 1s after recovery.
Checking for a lingering dual-active (10 samples, 1s apart)...
Exactly one active node in 10/10 samples.
Survivor downing/singleton evidence (last 20 matching log lines from scadabridge-env2-site-x-b):
[04:45:30 WRN] [Site/scadabridge-env2-site-x-b] [leader-auto-down] akka.tcp://scadabridge@scadabridge-env2-site-x-a:8082 is unreachable; it will be downed if still unreachable after 00:00:15 (this node akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082 is leader: False)
[04:45:30 INF] [Site/scadabridge-env2-site-x-b] [leader-auto-down] akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082 gained leadership (leader is now akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082); pending unreachable=[]
[04:45:45 WRN] [Site/scadabridge-env2-site-x-b] [leader-auto-down] DOWNING akka.tcp://scadabridge@scadabridge-env2-site-x-a:8082: unreachable for 00:00:15 and this node (akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082) is leader
[04:45:45 INF] [Site/scadabridge-env2-site-x-b] Cluster Node [akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082] - Marking unreachable node [akka.tcp://scadabridge@scadabridge-env2-site-x-a:8082] as [Down]
[04:45:46 INF] [Site/scadabridge-env2-site-x-b] Member removed [akka.tcp://scadabridge@scadabridge-env2-site-x-a:8082]
[04:45:46 INF] [Site/scadabridge-env2-site-x-b] Member removed [akka.tcp://scadabridge@scadabridge-env2-site-x-a:8082]
[04:45:46 INF] [Site/scadabridge-env2-site-x-b] ClusterSingletonManager state change [Younger -> Oldest] Akka.Cluster.Tools.Singleton.YoungerData
[04:45:46 INF] [Site/scadabridge-env2-site-x-b] ClusterSingletonManager state change [Younger -> Oldest] Akka.Cluster.Tools.Singleton.YoungerData
[04:45:47 INF] [Site/scadabridge-env2-site-x-b] [leader-auto-down] akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082 lost leadership (leader is now akka.tcp://scadabridge@scadabridge-env2-site-x-a:8082); pending unreachable=[]
SUMMARY env=env2 pair=site-x mode=active action=kill down_logged_s=29 rejoin_s=1
Drill complete. Verify on the Health dashboard / Overview that both nodes show Up and exactly one is Primary.
@@ -0,0 +1,27 @@
04:44:46 A[dc=2 dct=2 depth=0 runs=30 sf_Delivered=10] B[dc=0 dct=0 depth=0] sink_rows=125 mode=ok last_tick=897272542
04:44:51 A[dc=2 dct=2 depth=0 runs=33 sf_Delivered=10] B[dc=0 dct=0 depth=0] sink_rows=128 mode=ok last_tick=897272545
04:44:57 A[dc=2 dct=2 depth=0 runs=35 sf_Delivered=10] B[dc=0 dct=0 depth=0] sink_rows=130 mode=fail last_tick=897272547
04:45:02 A[dc=2 dct=2 depth=3 runs=38 sf_Delivered=10 sf_Queued=3] B[dc=0 dct=0 depth=0] sink_rows=130 mode=fail last_tick=897272547
04:45:07 A[dc=2 dct=2 depth=6 runs=41 sf_Delivered=10 sf_Queued=6 sf_Retried=1] B[dc=0 dct=0 depth=4] sink_rows=130 mode=fail last_tick=897272547
04:45:12 A[dc=2 dct=2 depth=8 runs=43 sf_Delivered=10 sf_Queued=8 sf_Retried=1] B[dc=0 dct=0 depth=4] sink_rows=130 mode=fail last_tick=897272547
04:45:17 A[DOWN] B[dc=0 dct=0 depth=4] sink_rows=130 mode=fail last_tick=897272547
04:45:23 A[DOWN] B[dc=0 dct=0 depth=4] sink_rows=130 mode=fail last_tick=897272547
04:45:28 A[DOWN] B[dc=0 dct=0 depth=4] sink_rows=130 mode=fail last_tick=897272547
04:45:33 A[DOWN] B[dc=0 dct=0 depth=4] sink_rows=130 mode=fail last_tick=897272547
04:45:38 A[DOWN] B[dc=0 dct=0 depth=4] sink_rows=130 mode=fail last_tick=897272547
04:45:43 A[DOWN] B[dc=0 dct=0 depth=4] sink_rows=130 mode=fail last_tick=897272547
04:45:49 A[dc=0 dct=0 depth=11] B[dc=1 dct=2 depth=5 runs=1 sf_Queued=1] sink_rows=130 mode=fail last_tick=897272547
04:45:54 A[dc=0 dct=0 depth=11] B[dc=1 dct=2 depth=7 runs=3 sf_Queued=3 sf_Retried=1] sink_rows=130 mode=fail last_tick=897272547
04:45:59 A[dc=0 dct=0 depth=15] B[dc=2 dct=2 depth=10 runs=6 sf_Queued=6 sf_Retried=1] sink_rows=130 mode=fail last_tick=897272547
04:46:05 A[dc=0 dct=0 depth=15] B[dc=2 dct=2 depth=19 runs=8 sf_Queued=8 sf_Retried=2] sink_rows=130 mode=fail last_tick=897272547
04:46:10 A[dc=0 dct=0 depth=15] B[dc=2 dct=2 depth=20 runs=11 sf_Queued=9 sf_Retried=2] sink_rows=132 mode=ok last_tick=897272584
04:46:15 A[dc=0 dct=0 depth=15] B[dc=2 dct=2 depth=0 runs=14 sf_Delivered=20 sf_Queued=9 sf_Retried=2] sink_rows=155 mode=ok last_tick=897272587
04:46:21 A[dc=0 dct=0 depth=15] B[dc=2 dct=2 depth=0 runs=16 sf_Delivered=20 sf_Queued=9 sf_Retried=2] sink_rows=157 mode=ok last_tick=897272589
04:46:26 A[dc=0 dct=0 depth=15] B[dc=2 dct=2 depth=0 runs=19 sf_Delivered=20 sf_Queued=9 sf_Retried=2] sink_rows=160 mode=ok last_tick=897272592
04:46:31 A[dc=0 dct=0 depth=15] B[dc=2 dct=2 depth=0 runs=21 sf_Delivered=20 sf_Queued=9 sf_Retried=2] sink_rows=162 mode=ok last_tick=897272594
04:46:36 A[dc=0 dct=0 depth=15] B[dc=2 dct=2 depth=0 runs=24 sf_Delivered=20 sf_Queued=9 sf_Retried=2] sink_rows=165 mode=ok last_tick=897272597
04:46:41 A[dc=0 dct=0 depth=15] B[dc=2 dct=2 depth=0 runs=27 sf_Delivered=20 sf_Queued=9 sf_Retried=2] sink_rows=168 mode=ok last_tick=897272600
04:46:46 A[dc=0 dct=0 depth=15] B[dc=2 dct=2 depth=0 runs=29 sf_Delivered=20 sf_Queued=9 sf_Retried=2] sink_rows=170 mode=ok last_tick=897272602
04:46:52 A[dc=0 dct=0 depth=15] B[dc=2 dct=2 depth=0 runs=32 sf_Delivered=20 sf_Queued=9 sf_Retried=2] sink_rows=173 mode=ok last_tick=897272605
04:46:57 A[dc=0 dct=0 depth=15] B[dc=2 dct=2 depth=0 runs=34 sf_Delivered=20 sf_Queued=9 sf_Retried=2] sink_rows=175 mode=ok last_tick=897272607
04:47:02 A[dc=0 dct=0 depth=0] B[dc=2 dct=2 depth=0 runs=37 sf_Delivered=20 sf_Queued=9 sf_Retried=2] sink_rows=178 mode=ok last_tick=897272610
@@ -0,0 +1,4 @@
window 04:44:46..04:46:55 UTC: rows=50 unique_ticks=50 duplicates=0
gap: 04:45:18..04:45:46 (15 ticks = 30 s)
sender site-x-a: rows=5 delivered_late(>4s, i.e. buffered)=0 max_delay=0s
sender site-x-b: rows=45 delivered_late(>4s, i.e. buffered)=20 max_delay=79s
@@ -0,0 +1,5 @@
04:47:53 sink -> fail
04:48:13 drill start (pause)
04:49:30 drill end rc=0
04:49:35 sink -> ok
04:50:35 done
@@ -0,0 +1,22 @@
env=env2 pair=site-x mode=active action=pause active=scadabridge-env2-site-x-b victim=scadabridge-env2-site-x-b survivor=scadabridge-env2-site-x-a
hit at 2026-11-13T04:48:14Z
Active pause: waiting for scadabridge-env2-site-x-a to take over as the active node (victim stays down; budget ~25s + hand-over)...
survivor logged the Down at +27s
PASS: scadabridge-env2-site-x-a took over as active in 27s with the victim still down
(downed the dead oldest, assumed Oldest, re-hosted the singletons).
Recovering scadabridge-env2-site-x-b (pause -> unpause)...
Waiting for the victim to rejoin as a ready standby (scadabridge-env2-site-x-b /health/ready)...
Recovered: scadabridge-env2-site-x-b is ready as standby (rejoined) 38s after recovery.
Checking for a lingering dual-active (10 samples, 1s apart)...
Exactly one active node in 10/10 samples.
Survivor downing/singleton evidence (last 20 matching log lines from scadabridge-env2-site-x-a):
[04:48:26 WRN] [Site/scadabridge-env2-site-x-a] [leader-auto-down] akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082 is unreachable; it will be downed if still unreachable after 00:00:15 (this node akka.tcp://scadabridge@scadabridge-env2-site-x-a:8082 is leader: True)
[04:48:41 WRN] [Site/scadabridge-env2-site-x-a] [leader-auto-down] DOWNING akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082: unreachable for 00:00:15 and this node (akka.tcp://scadabridge@scadabridge-env2-site-x-a:8082) is leader
[04:48:41 INF] [Site/scadabridge-env2-site-x-a] Cluster Node [akka.tcp://scadabridge@scadabridge-env2-site-x-a:8082] - Marking unreachable node [akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082] as [Down]
[04:48:42 INF] [Site/scadabridge-env2-site-x-a] Member removed [akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082]
[04:48:42 INF] [Site/scadabridge-env2-site-x-a] Member removed [akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082]
[04:48:42 INF] [Site/scadabridge-env2-site-x-a] ClusterSingletonManager state change [Younger -> Oldest] Akka.Cluster.Tools.Singleton.YoungerData
[04:48:42 INF] [Site/scadabridge-env2-site-x-a] ClusterSingletonManager state change [Younger -> Oldest] Akka.Cluster.Tools.Singleton.YoungerData
[04:48:47 WRN] [Site/scadabridge-env2-site-x-a] [leader-auto-down] split from akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082: it is still running the incarnation this node (akka.tcp://scadabridge@scadabridge-env2-site-x-a:8082) removed, so this node has shut it out. Giving it 00:01:00 to restart itself before the tiebreak (a frozen node that was removed restarts on its own)
SUMMARY env=env2 pair=site-x mode=active action=pause down_logged_s=27 rejoin_s=38
Drill complete. Verify on the Health dashboard / Overview that both nodes show Up and exactly one is Primary.
@@ -0,0 +1,34 @@
04:47:43 A[dc=0 dct=0 depth=0] B[dc=2 dct=2 depth=0 runs=58 sf_Delivered=20 sf_Queued=9 sf_Retried=2] sink_rows=199 mode=ok last_tick=897272631
04:47:48 A[dc=0 dct=0 depth=0] B[dc=2 dct=2 depth=0 runs=60 sf_Delivered=20 sf_Queued=9 sf_Retried=2] sink_rows=201 mode=ok last_tick=897272633
04:47:54 A[dc=0 dct=0 depth=0] B[dc=2 dct=2 depth=0 runs=63 sf_Delivered=20 sf_Queued=9 sf_Retried=2] sink_rows=204 mode=fail last_tick=897272636
04:47:59 A[dc=0 dct=0 depth=1] B[dc=2 dct=2 depth=2 runs=65 sf_Delivered=20 sf_Queued=11 sf_Retried=2] sink_rows=204 mode=fail last_tick=897272636
04:48:04 A[dc=0 dct=0 depth=1] B[dc=2 dct=2 depth=5 runs=68 sf_Delivered=20 sf_Queued=14 sf_Retried=3] sink_rows=204 mode=fail last_tick=897272636
04:48:09 A[dc=0 dct=0 depth=1] B[dc=2 dct=2 depth=8 runs=71 sf_Delivered=20 sf_Queued=17 sf_Retried=3] sink_rows=204 mode=fail last_tick=897272636
04:48:14 A[dc=0 dct=0 depth=1] B[DOWN] sink_rows=204 mode=fail last_tick=897272636
04:48:20 A[dc=0 dct=0 depth=1] B[DOWN] sink_rows=204 mode=fail last_tick=897272636
04:48:25 A[dc=0 dct=0 depth=1] B[DOWN] sink_rows=204 mode=fail last_tick=897272636
04:48:30 A[dc=0 dct=0 depth=1] B[DOWN] sink_rows=204 mode=fail last_tick=897272636
04:48:35 A[dc=0 dct=0 depth=1] B[DOWN] sink_rows=204 mode=fail last_tick=897272636
04:48:40 A[dc=0 dct=0 depth=1] B[DOWN] sink_rows=204 mode=fail last_tick=897272636
04:48:45 A[dc=1 dct=2 depth=2 runs=1 sf_Queued=1] B[dc=1 dct=2 depth=16 runs=79 sf_Delivered=20 sf_Queued=25 sf_Retried=4] sink_rows=204 mode=fail last_tick=897272636
04:48:51 A[dc=1 dct=2 depth=4 runs=3 sf_Queued=3 sf_Retried=1] B[DOWN] sink_rows=204 mode=fail last_tick=897272636
04:48:56 A[dc=2 dct=2 depth=7 runs=6 sf_Queued=6 sf_Retried=1] B[DOWN] sink_rows=204 mode=fail last_tick=897272636
04:49:01 A[dc=2 dct=2 depth=25 runs=9 sf_Queued=9 sf_Retried=2] B[DOWN] sink_rows=204 mode=fail last_tick=897272636
04:49:06 A[dc=2 dct=2 depth=27 runs=11 sf_Queued=11 sf_Retried=2] B[DOWN] sink_rows=204 mode=fail last_tick=897272636
04:49:12 A[dc=2 dct=2 depth=30 runs=14 sf_Queued=14 sf_Retried=3] B[DOWN] sink_rows=204 mode=fail last_tick=897272636
04:49:17 A[dc=2 dct=2 depth=32 runs=16 sf_Queued=16 sf_Retried=3] B[DOWN] sink_rows=204 mode=fail last_tick=897272636
04:49:22 A[dc=2 dct=2 depth=35 runs=19 sf_Queued=19 sf_Retried=4] B[dc=0 dct=0 depth=32] sink_rows=204 mode=fail last_tick=897272636
04:49:27 A[dc=2 dct=2 depth=38 runs=22 sf_Queued=22 sf_Retried=5] B[dc=0 dct=0 depth=32] sink_rows=204 mode=fail last_tick=897272636
04:49:32 A[dc=2 dct=2 depth=40 runs=24 sf_Queued=24 sf_Retried=5] B[dc=0 dct=0 depth=38] sink_rows=204 mode=fail last_tick=897272636
04:49:37 A[dc=2 dct=2 depth=2 runs=27 sf_Delivered=40 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=38] sink_rows=245 mode=ok last_tick=897272688
04:49:42 A[dc=2 dct=2 depth=2 runs=29 sf_Delivered=40 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=38] sink_rows=247 mode=ok last_tick=897272690
04:49:48 A[dc=2 dct=2 depth=0 runs=32 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=38] sink_rows=252 mode=ok last_tick=897272693
04:49:53 A[dc=2 dct=2 depth=0 runs=34 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=38] sink_rows=254 mode=ok last_tick=897272695
04:49:58 A[dc=2 dct=2 depth=0 runs=37 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=38] sink_rows=257 mode=ok last_tick=897272698
04:50:03 A[dc=2 dct=2 depth=0 runs=40 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=38] sink_rows=260 mode=ok last_tick=897272701
04:50:08 A[dc=2 dct=2 depth=0 runs=42 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=38] sink_rows=262 mode=ok last_tick=897272703
04:50:14 A[dc=2 dct=2 depth=0 runs=45 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=38] sink_rows=265 mode=ok last_tick=897272706
04:50:19 A[dc=2 dct=2 depth=0 runs=48 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=38] sink_rows=268 mode=ok last_tick=897272709
04:50:24 A[dc=2 dct=2 depth=0 runs=50 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=38] sink_rows=270 mode=ok last_tick=897272711
04:50:30 A[dc=2 dct=2 depth=0 runs=53 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=0] sink_rows=273 mode=ok last_tick=897272714
04:50:35 A[dc=2 dct=2 depth=0 runs=56 sf_Delivered=42 sf_Queued=26 sf_Retried=5] B[dc=0 dct=0 depth=0] sink_rows=275 mode=ok last_tick=897272716
@@ -0,0 +1,5 @@
window 04:47:43..04:50:25 UTC: rows=72 unique_ticks=68 duplicates=4
duplicate ticks: 04:48:40x4, 04:48:44x2
gap: 04:48:14..04:48:38 (13 ticks = 26 s)
sender site-x-a: rows=67 delivered_late(>4s, i.e. buffered)=42 max_delay=103s
sender site-x-b: rows=5 delivered_late(>4s, i.e. buffered)=0 max_delay=0s
@@ -0,0 +1,32 @@
[04:48:13 INF] [Site/scadabridge-env2-site-x-b] Start processing HTTP request POST http://scadabridge-env2-sfsink:5300/record
[04:48:13 INF] [Site/scadabridge-env2-site-x-b] Sending HTTP request POST http://scadabridge-env2-sfsink:5300/record
[04:48:41 INF] [Site/scadabridge-env2-site-x-b] Start processing HTTP request POST http://scadabridge-env2-sfsink:5300/record
[04:48:41 INF] [Site/scadabridge-env2-site-x-b] Sending HTTP request POST http://scadabridge-env2-sfsink:5300/record
[04:48:41 WRN] [Site/scadabridge-env2-site-x-b] Script 'SoakTick' on instance 'env-soak-1': run shed — 4 runs already in flight (cap 4). (1 shed(s) since the last report)
[04:48:41 INF] [Site/scadabridge-env2-site-x-b] Start processing HTTP request POST http://scadabridge-env2-sfsink:5300/record
[04:48:41 INF] [Site/scadabridge-env2-site-x-b] Sending HTTP request POST http://scadabridge-env2-sfsink:5300/record
[04:48:41 INF] [Site/scadabridge-env2-site-x-b] Start processing HTTP request POST http://scadabridge-env2-sfsink:5300/record
[04:48:41 INF] [Site/scadabridge-env2-site-x-b] Sending HTTP request POST http://scadabridge-env2-sfsink:5300/record
[04:48:41 INF] [Site/scadabridge-env2-site-x-b] Start processing HTTP request POST http://scadabridge-env2-sfsink:5300/record
[04:48:41 INF] [Site/scadabridge-env2-site-x-b] Sending HTTP request POST http://scadabridge-env2-sfsink:5300/record
[04:48:41 INF] [Site/scadabridge-env2-site-x-b] Start processing HTTP request POST http://scadabridge-env2-sfsink:5300/record
[04:48:41 INF] [Site/scadabridge-env2-site-x-b] Sending HTTP request POST http://scadabridge-env2-sfsink:5300/record
[04:48:41 WRN] [Site/scadabridge-env2-site-x-b] [leader-auto-down] akka.tcp://scadabridge@scadabridge-env2-site-x-a:8082 is unreachable; it will be downed if still unreachable after 00:00:15 (this node akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082 is l
[04:48:41 INF] [Site/scadabridge-env2-site-x-b] [leader-auto-down] akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082 gained leadership (leader is now akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082); pending unreachable=[]
[04:48:43 INF] [Site/scadabridge-env2-site-x-b] Start processing HTTP request POST http://scadabridge-env2-sfsink:5300/record
[04:48:43 INF] [Site/scadabridge-env2-site-x-b] Sending HTTP request POST http://scadabridge-env2-sfsink:5300/record
[04:48:45 INF] [Site/scadabridge-env2-site-x-b] Start processing HTTP request POST http://scadabridge-env2-sfsink:5300/record
[04:48:45 INF] [Site/scadabridge-env2-site-x-b] Sending HTTP request POST http://scadabridge-env2-sfsink:5300/record
[04:48:47 WRN] [Site/scadabridge-env2-site-x-b] [leader-auto-down] shut out by akka.tcp://scadabridge@scadabridge-env2-site-x-a:8082: it has removed and quarantined this node (akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082) while this node still counts
[04:48:47 INF] [Site/scadabridge-env2-site-x-b] Self downed, stopping
[04:48:47 INF] [Site/scadabridge-env2-site-x-b] ClusterSingletonManager state change [Oldest -> Stopping] Akka.Cluster.Tools.Singleton.OldestData
[04:48:47 INF] [Site/scadabridge-env2-site-x-b] Self downed, stopping
[04:48:47 INF] [Site/scadabridge-env2-site-x-b] ClusterSingletonManager state change [Oldest -> Stopping] Akka.Cluster.Tools.Singleton.OldestData
[04:48:47 INF] [Site/scadabridge-env2-site-x-b] [leader-auto-down] akka.tcp://scadabridge@scadabridge-env2-site-x-a:8082 was removed from the cluster; its pending Down is cancelled
[04:48:47 INF] [Site/scadabridge-env2-site-x-b] [leader-auto-down] akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082 lost leadership (leader is now none); pending unreachable=[]
[04:48:47 FTL] [Site/scadabridge-env2-site-x-b] ActorSystem terminated outside host shutdown (SBR down / run-coordinated-shutdown-when-down / leader-auto-down shut-out restart). Stopping the host process with exit code 75 so the service supervisor restarts thi
[04:49:17 WRN] [Site/scadabridge-env2-site-x-b] ScadaBridge host stopped because its actor system terminated (self-down / shut-out restart); exiting with code 75 so the service supervisor restarts it
[04:49:18 INF] [Site/scadabridge-env2-site-x-b] [leader-auto-down] shut-out restart is ON for akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082: a node split from its pair peer restarts itself — at once if only it was removed, otherwise the higher address
[04:49:18 INF] [Site/scadabridge-env2-site-x-b] [leader-auto-down] started on akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082: leader=none (this node is leader: False), unreachable-after=00:00:15, already unreachable=[]
[04:49:17 WRN] [Site/scadabridge-env2-site-x-b] ScadaBridge host stopped because its actor system terminated (self-down / shut-out restart); exiting with code 75 so the service supervisor restarts it
[04:49:18 INF] [Site/scadabridge-env2-site-x-b] [leader-auto-down] shut-out restart is ON for akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082: a node split from its pair peer restarts itself — at once if only it was removed, otherwise the higher address
@@ -0,0 +1,5 @@
04:39:02 sink -> fail
04:39:22 drill start (kill)
04:40:04 drill end rc=0
04:40:09 sink -> ok
04:41:09 done
@@ -0,0 +1,21 @@
env=env2 pair=site-x mode=active action=kill active=scadabridge-env2-site-x-b victim=scadabridge-env2-site-x-b survivor=scadabridge-env2-site-x-a
hit at 2026-11-13T04:39:23Z
Active kill: waiting for scadabridge-env2-site-x-a to take over as the active node (victim stays down; budget ~25s + hand-over)...
survivor logged the Down at +28s
PASS: scadabridge-env2-site-x-a took over as active in 28s with the victim still down
(downed the dead oldest, assumed Oldest, re-hosted the singletons).
Recovering scadabridge-env2-site-x-b (kill -> start)...
Waiting for the victim to rejoin as a ready standby (scadabridge-env2-site-x-b /health/ready)...
Recovered: scadabridge-env2-site-x-b is ready as standby (rejoined) 1s after recovery.
Checking for a lingering dual-active (10 samples, 1s apart)...
Exactly one active node in 10/10 samples.
Survivor downing/singleton evidence (last 20 matching log lines from scadabridge-env2-site-x-a):
[04:39:35 WRN] [Site/scadabridge-env2-site-x-a] [leader-auto-down] akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082 is unreachable; it will be downed if still unreachable after 00:00:15 (this node akka.tcp://scadabridge@scadabridge-env2-site-x-a:8082 is leader: True)
[04:39:50 WRN] [Site/scadabridge-env2-site-x-a] [leader-auto-down] DOWNING akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082: unreachable for 00:00:15 and this node (akka.tcp://scadabridge@scadabridge-env2-site-x-a:8082) is leader
[04:39:50 INF] [Site/scadabridge-env2-site-x-a] Cluster Node [akka.tcp://scadabridge@scadabridge-env2-site-x-a:8082] - Marking unreachable node [akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082] as [Down]
[04:39:51 INF] [Site/scadabridge-env2-site-x-a] Member removed [akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082]
[04:39:51 INF] [Site/scadabridge-env2-site-x-a] Member removed [akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082]
[04:39:51 INF] [Site/scadabridge-env2-site-x-a] ClusterSingletonManager state change [Younger -> Oldest] Akka.Cluster.Tools.Singleton.YoungerData
[04:39:51 INF] [Site/scadabridge-env2-site-x-a] ClusterSingletonManager state change [Younger -> Oldest] Akka.Cluster.Tools.Singleton.YoungerData
SUMMARY env=env2 pair=site-x mode=active action=kill down_logged_s=28 rejoin_s=1
Drill complete. Verify on the Health dashboard / Overview that both nodes show Up and exactly one is Primary.
@@ -0,0 +1,27 @@
04:38:52 A[dc=0 dct=0 depth=0] B[dc=2 dct=2 depth=0 runs=80 sf_Delivered=13 sf_Queued=13 sf_Retried=2] sink_rows=80 mode=ok last_tick=897272365
04:38:57 A[dc=0 dct=0 depth=0] B[dc=2 dct=2 depth=0 runs=83 sf_Delivered=13 sf_Queued=13 sf_Retried=2] sink_rows=83 mode=ok last_tick=897272368
04:39:03 A[dc=0 dct=0 depth=0] B[dc=2 dct=2 depth=0 runs=85 sf_Delivered=13 sf_Queued=13 sf_Retried=2] sink_rows=85 mode=fail last_tick=897272370
04:39:08 A[dc=0 dct=0 depth=0] B[dc=2 dct=2 depth=3 runs=88 sf_Delivered=13 sf_Queued=16 sf_Retried=2] sink_rows=85 mode=fail last_tick=897272370
04:39:13 A[dc=0 dct=0 depth=0] B[dc=2 dct=2 depth=6 runs=91 sf_Delivered=13 sf_Queued=19 sf_Retried=2] sink_rows=85 mode=fail last_tick=897272370
04:39:18 A[dc=0 dct=0 depth=0] B[dc=2 dct=2 depth=8 runs=93 sf_Delivered=13 sf_Queued=21 sf_Retried=3] sink_rows=85 mode=fail last_tick=897272370
04:39:23 A[dc=0 dct=0 depth=0] B[DOWN] sink_rows=85 mode=fail last_tick=897272370
04:39:28 A[dc=0 dct=0 depth=0] B[DOWN] sink_rows=85 mode=fail last_tick=897272370
04:39:34 A[dc=0 dct=0 depth=0] B[DOWN] sink_rows=85 mode=fail last_tick=897272370
04:39:39 A[dc=0 dct=0 depth=0] B[DOWN] sink_rows=85 mode=fail last_tick=897272370
04:39:44 A[dc=0 dct=0 depth=0] B[DOWN] sink_rows=85 mode=fail last_tick=897272370
04:39:49 A[dc=0 dct=0 depth=0] B[DOWN] sink_rows=85 mode=fail last_tick=897272370
04:39:54 A[dc=0 dct=0 depth=0] B[dc=0 dct=0 depth=10] sink_rows=85 mode=fail last_tick=897272370
04:39:59 A[dc=0 dct=0 depth=0] B[dc=0 dct=0 depth=10] sink_rows=85 mode=fail last_tick=897272370
04:40:04 A[dc=0 dct=0 depth=0] B[dc=0 dct=0 depth=10] sink_rows=85 mode=fail last_tick=897272370
04:40:10 A[dc=0 dct=0 depth=0] B[dc=0 dct=0 depth=10] sink_rows=85 mode=ok last_tick=897272370
04:40:15 A[dc=0 dct=0 depth=0] B[dc=0 dct=0 depth=10] sink_rows=85 mode=ok last_tick=897272370
04:40:20 A[dc=0 dct=0 depth=0] B[dc=0 dct=0 depth=10] sink_rows=85 mode=ok last_tick=897272370
04:40:25 A[dc=0 dct=0 depth=0] B[dc=0 dct=0 depth=10] sink_rows=85 mode=ok last_tick=897272370
04:40:30 A[dc=0 dct=0 depth=0] B[dc=0 dct=0 depth=10] sink_rows=85 mode=ok last_tick=897272370
04:40:36 A[dc=0 dct=0 depth=0] B[dc=0 dct=0 depth=10] sink_rows=85 mode=ok last_tick=897272370
04:40:41 A[dc=0 dct=0 depth=0] B[dc=0 dct=0 depth=10] sink_rows=85 mode=ok last_tick=897272370
04:40:46 A[dc=0 dct=0 depth=0] B[dc=0 dct=0 depth=10] sink_rows=85 mode=ok last_tick=897272370
04:40:51 A[dc=0 dct=0 depth=0] B[dc=0 dct=0 depth=10] sink_rows=85 mode=ok last_tick=897272370
04:40:56 A[dc=0 dct=0 depth=0] B[dc=0 dct=0 depth=10] sink_rows=85 mode=ok last_tick=897272370
04:41:02 A[dc=0 dct=0 depth=0] B[dc=0 dct=0 depth=10] sink_rows=85 mode=ok last_tick=897272370
04:41:07 A[dc=0 dct=0 depth=0] B[dc=0 dct=0 depth=10] sink_rows=85 mode=ok last_tick=897272370
@@ -0,0 +1,3 @@
window 04:38:52..04:40:59 UTC: rows=5 unique_ticks=5 duplicates=0
gap: 04:39:02..04:40:56 (58 ticks = 116 s)
sender site-x-b: rows=5 delivered_late(>4s, i.e. buffered)=0 max_delay=0s
@@ -0,0 +1,12 @@
# Survivor site-x-a after the 04:39:22 kill of site-x-b, BEFORE site-x's LocalDb was replicated.
# Key lines, transcribed from `docker logs scadabridge-env2-site-x-a` (the container was recreated
# at 04:42:52 to turn replication on, which discarded its docker log).
[04:39:50 WRN] [leader-auto-down] DOWNING akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082: unreachable for 00:00:15 and this node (...site-x-a:8082) is leader
[04:39:51 INF] Younger observed OldestChanged: [akka.tcp://scadabridge@scadabridge-env2-site-x-b:8082 -> myself]
[04:39:51 INF] Singleton manager started singleton actor [akka://scadabridge/user/deployment-manager-singleton/deployment-manager]
[04:39:51 INF] DeploymentManagerActor starting — loading deployed configs from SQLite...
[04:39:51 INF] Loaded 1 deployed configs (1 enabled) from SQLite <- a stale MxAlarmDemo-1 row from an earlier env2 seeding; env-soak-1 / env-galaxy-1 were never on this node
[04:39:51 INF] All 1 Instance Actors created
[04:39:51 WRN] No connection actor for ScadaBridge Site X during alarm subscribe
[04:39:51 WRN] Native alarm subscription failed for GalaxyAlarms on MxAlarmDemo-1: Unknown connection: ScadaBridge Site X; retrying in 5000ms
... repeated every 5-40 s until 04:41:06; no script runs, site_data_connections 0/0 (see seeded-unreplicated-site-x-active-kill.metrics)
@@ -0,0 +1,7 @@
window 04:36:30..04:55:01 UTC: rows=400 unique_ticks=396 duplicates=4
duplicate ticks: 04:48:40x4, 04:48:44x2
gap: 04:39:22..04:43:44 (132 ticks = 264 s)
gap: 04:45:18..04:45:46 (15 ticks = 30 s)
gap: 04:48:14..04:48:38 (13 ticks = 26 s)
sender site-x-a: rows=250 delivered_late(>4s, i.e. buffered)=52 max_delay=243s
sender site-x-b: rows=150 delivered_late(>4s, i.e. buffered)=33 max_delay=79s