LocalDb first-enable on a diverged site pair: the active node reconciles stale data before the first sync, so instances never start #135

Closed
opened 2026-11-12 23:57:25 -05:00 by dohertj2 · 1 comment
Owner

Found during the ScadaBridge#116 env2 data-path soak (2026-11-12, record docs/plans/2026-11-12-leader-auto-down-env2-drill.md §5, commits 6c7e150a/644f564c).

What happened. LocalDb replication was turned on for the env2 site-x pair, whose two per-node stores had diverged. Both nodes were recreated together. The node that came up active loaded its own stale local data about 1 s before the first sync snapshot arrived. Its startup reconcile then found nothing missing, so the deployed instances were never started on it. Re-pushing the artifacts and redeploying the two instances recovered it. Normal failovers on an already-replicated pair were not affected.

Why it matters. The QA pair and any site pair that gets replication enabled later go through this exact first-enable path. The symptom is silent: the cluster is healthy, but no instances run.

To do.

  • Reproduce on the rig: diverge a site pair's stores, enable replication, cold-start both nodes.
  • Decide the fix. Options include waiting for the first sync (or a bounded timeout) before the startup reconcile, re-running the reconcile after the first snapshot is applied, or documenting a mandatory redeploy step for first enablement.
  • Add a test for the chosen behaviour.
Found during the ScadaBridge#116 env2 data-path soak (2026-11-12, record `docs/plans/2026-11-12-leader-auto-down-env2-drill.md` §5, commits `6c7e150a`/`644f564c`). **What happened.** LocalDb replication was turned on for the env2 site-x pair, whose two per-node stores had diverged. Both nodes were recreated together. The node that came up active loaded its own stale local data about 1 s before the first sync snapshot arrived. Its startup reconcile then found nothing missing, so the deployed instances were never started on it. Re-pushing the artifacts and redeploying the two instances recovered it. Normal failovers on an already-replicated pair were not affected. **Why it matters.** The QA pair and any site pair that gets replication enabled later go through this exact first-enable path. The symptom is silent: the cluster is healthy, but no instances run. **To do.** - Reproduce on the rig: diverge a site pair's stores, enable replication, cold-start both nodes. - Decide the fix. Options include waiting for the first sync (or a bounded timeout) before the startup reconcile, re-running the reconcile after the first snapshot is applied, or documenting a mandatory redeploy step for first enablement. - Add a test for the chosen behaviour.
dohertj2 added the type:bugpriority:p3 labels 2026-11-12 23:57:25 -05:00
Author
Owner

Fixed in d7fa31f0 (main).

Root cause. The symptom was a delay of one sweep interval, not "never started". The instance reconcile sweep did heal it, but only after its plain 60 s cadence.

  • On a replicated pair that cold-starts together, the node that wins the Deployment Manager singleton loads its own store (DeploymentManagerActor.HandleStartupConfigsLoaded). The peer's rows land by LocalDb sync about 1 s later.
  • The startup reconcile (SiteReconciliationActor, at +5 s) rightly reports 0 gaps, because the rows are already in the store when it asks central. So it sends no EnsureInstanceStartedCommand.
  • The only path that starts a replicated row is the DM instance sweep (HandleInstanceSweepTick, register row 78). Its timer is armed in PreStart at InstanceSweepIntervalSeconds (60 s). Before the fix, the first useful tick came one full interval after the boot load.
  • In the env2 drill, the site-x-a logs show the operator's deploy-artifacts + redeploy at 04:43:43–45. That is about 49 s after the 04:42:54 boot load, so it got in just before the first sweep tick at 04:43:54. That tick then also restarted MxAlarmDemo-1 from its stale revision ("running stale revision … deployment-manager sweep self-heal"). Without the redeploy, the sweep would have started the two instances at about +60 s.

Rig reproduction (primary rig, site-a pair, image before the fix).

  1. Stopped site-a-a, deployed a new instance zz135-probe (lands only on site-a-b), stopped site-a-b, then started both together.
  2. site-a-a won the singleton: 05:03:16 Loaded 10 deployed configs (probe missing), 05:03:21 Reconcile pass 1/3 … 0 fetched.
  3. 05:04:16 Instance zz135-probe started by deployment-manager sweep self-heal. That is a 60 s gap.

Fix. Post-boot settle window in the DM singleton (MarkStartupInstanceCreationComplete):

  • When boot-time Instance Actor creation finishes, it runs one sweep at once, which covers rows that landed while the boot batches were being created.
  • It then sweeps every ScadaBridge:SiteRuntime:InstanceSweepSettleIntervalSeconds (default 5) for InstanceSweepSettleWindowSeconds (default 120). After that it falls back to InstanceSweepIntervalSeconds.
  • Both new settings are validated >= 0, and 0 disables the settle phase. Nothing extra runs when the sweep itself is disabled.
  • Startup never waits for the peer. A node whose peer is permanently down starts from its own store immediately, exactly as before. The extra cost is a few metadata reads.
  • All existing sweep guards (deploy-pipeline deferral, once-per-revision claims, store-generation check, silent when there is nothing to repair) apply unchanged.
  • No LocalDb change. 0.3.7 exposes no "snapshot applied" signal (ISyncStatus.LastSyncUtc is also bumped on snapshot send), so the fix uses the sweep, which does not depend on how the rows arrived. If an exact trigger is wanted later, a lib-side SnapshotsReceived counter or event on ISyncStatus would be the clean hook. The settle sweep doesn't need it.

Tests. PostBootSettleSweepTests (4 tests). Every test pins the plain interval at 60 s, so a pass can only come from the settle path. There is also a validator theory.

  • Replicated row lands after boot → started within 8 s. Fails without the fix.
  • Row lands during boot creation (the config loader writes it right after its read), settle cadence off → started by the immediate post-boot sweep. Fails without the fix, and fails if only the immediate tick is removed.
  • Settle window closes → a later row is not picked up at the fast cadence. Fails if the settle timer is never cancelled.
  • Sweep disabled → the settle window does not re-enable it.
  • SiteRuntime.Tests 1062/1062 pass. The Release solution build has 0 warnings and 0 errors.

Rig, with the fix (same scenario, zz135-probe2, site-a pair recreated together on the new image):

  • 05:11:18 Loaded 11 deployed configs (probe2 missing)
  • 05:11:19 All 11 Instance Actors created
  • 05:11:19 Instance zz135-probe2 started by deployment-manager sweep self-heal: within the same second, and before the startup reconcile at 05:11:23.

Both probe instances were deleted afterwards. site-a-a and site-a-b are Healthy, memberCount 2, replication connected, backlog 0. The env2 stack and scadabridge:env2-116 were not touched.

Side observation, not part of this fix. With site-a-a stopped, the first MgmtDeployInstance to site-a returned OUTCOME_UNKNOWN: connection failed after the command may have been applied. An immediate retry succeeded against site-a-b. This happened on both attempts.

Fixed in `d7fa31f0` (main). **Root cause.** The symptom was a delay of one sweep interval, not "never started". The instance reconcile sweep did heal it, but only after its plain 60 s cadence. - On a replicated pair that cold-starts together, the node that wins the Deployment Manager singleton loads its own store (`DeploymentManagerActor.HandleStartupConfigsLoaded`). The peer's rows land by LocalDb sync about 1 s later. - The startup reconcile (`SiteReconciliationActor`, at +5 s) rightly reports 0 gaps, because the rows are already in the store when it asks central. So it sends no `EnsureInstanceStartedCommand`. - The only path that starts a replicated row is the DM instance sweep (`HandleInstanceSweepTick`, register row 78). Its timer is armed in `PreStart` at `InstanceSweepIntervalSeconds` (60 s). Before the fix, the first useful tick came one full interval after the boot load. - In the env2 drill, the site-x-a logs show the operator's `deploy-artifacts` + redeploy at 04:43:43–45. That is about 49 s after the 04:42:54 boot load, so it got in just before the first sweep tick at 04:43:54. That tick then also restarted `MxAlarmDemo-1` from its stale revision ("running stale revision … deployment-manager sweep self-heal"). Without the redeploy, the sweep would have started the two instances at about +60 s. **Rig reproduction (primary rig, site-a pair, image before the fix).** 1. Stopped site-a-a, deployed a new instance `zz135-probe` (lands only on site-a-b), stopped site-a-b, then started both together. 2. site-a-a won the singleton: `05:03:16 Loaded 10 deployed configs` (probe missing), `05:03:21 Reconcile pass 1/3 … 0 fetched`. 3. `05:04:16 Instance zz135-probe started by deployment-manager sweep self-heal`. That is a 60 s gap. **Fix.** Post-boot settle window in the DM singleton (`MarkStartupInstanceCreationComplete`): - When boot-time Instance Actor creation finishes, it runs **one sweep at once**, which covers rows that landed while the boot batches were being created. - It then sweeps every `ScadaBridge:SiteRuntime:InstanceSweepSettleIntervalSeconds` (default 5) for `InstanceSweepSettleWindowSeconds` (default 120). After that it falls back to `InstanceSweepIntervalSeconds`. - Both new settings are validated `>= 0`, and `0` disables the settle phase. Nothing extra runs when the sweep itself is disabled. - **Startup never waits for the peer.** A node whose peer is permanently down starts from its own store immediately, exactly as before. The extra cost is a few metadata reads. - All existing sweep guards (deploy-pipeline deferral, once-per-revision claims, store-generation check, silent when there is nothing to repair) apply unchanged. - No LocalDb change. 0.3.7 exposes no "snapshot applied" signal (`ISyncStatus.LastSyncUtc` is also bumped on snapshot *send*), so the fix uses the sweep, which does not depend on how the rows arrived. If an exact trigger is wanted later, a lib-side `SnapshotsReceived` counter or event on `ISyncStatus` would be the clean hook. The settle sweep doesn't need it. **Tests.** `PostBootSettleSweepTests` (4 tests). Every test pins the plain interval at 60 s, so a pass can only come from the settle path. There is also a validator theory. - Replicated row lands after boot → started within 8 s. **Fails without the fix.** - Row lands during boot creation (the config loader writes it right after its read), settle cadence off → started by the immediate post-boot sweep. **Fails without the fix**, and fails if only the immediate tick is removed. - Settle window closes → a later row is *not* picked up at the fast cadence. **Fails if the settle timer is never cancelled.** - Sweep disabled → the settle window does not re-enable it. - SiteRuntime.Tests 1062/1062 pass. The Release solution build has 0 warnings and 0 errors. **Rig, with the fix** (same scenario, `zz135-probe2`, site-a pair recreated together on the new image): - `05:11:18 Loaded 11 deployed configs` (probe2 missing) - `05:11:19 All 11 Instance Actors created` - `05:11:19 Instance zz135-probe2 started by deployment-manager sweep self-heal`: within the same second, and before the startup reconcile at 05:11:23. Both probe instances were deleted afterwards. site-a-a and site-a-b are Healthy, `memberCount 2`, replication connected, backlog 0. The env2 stack and `scadabridge:env2-116` were not touched. **Side observation, not part of this fix.** With site-a-a stopped, the *first* `MgmtDeployInstance` to site-a returned `OUTCOME_UNKNOWN: connection failed after the command may have been applied`. An immediate retry succeeded against site-a-b. This happened on both attempts.
Sign in to join this conversation.