diff --git a/docs/ScriptEditor.md b/docs/ScriptEditor.md index 5735ce1a4..e0c7b7b84 100644 --- a/docs/ScriptEditor.md +++ b/docs/ScriptEditor.md @@ -193,8 +193,10 @@ scripted-alarm predicates) runs scripts through the shared `ScriptRunGuard`: a run that returns (value or throw) resets it. A quarantined script is never dispatched again; it reads Bad `"script quarantined: …"`, logs one Error and increments `otopcua_script_quarantined`. -- **Stuck-orphan quarantine.** A never-returning script (`while(true)`) times out - once and is then only refused, so the timeout streak alone never reaches 3. +- **Stuck-orphan quarantine** (in-process runner only: `Scripting:Runner=InProcess`, the default and + the rollback; under `OutOfProcess` a never-returning script is killed at `T + G` and quarantined + after two kills, so this rule never fires there — lmxopcua#780 P4). A never-returning script + (`while(true)`) times out once and is then only refused, so the timeout streak alone never reaches 3. Instead, a refusal behind an orphan that has been running longer than `Scripting:StuckOrphanQuarantineFactor` × the timeout (default 10 × — 20 s at the 2 s default) quarantines immediately, through the same path (Error log, metric @@ -234,7 +236,7 @@ scripted-alarm predicates) runs scripts through the shared `ScriptRunGuard`: | `Scripting:RunTimeout` | `00:00:02` (2 s) | zero or negative becomes the default; above `00:01:00` becomes 60 s. The per-run budget of virtual tags and scripted-alarm predicates (lmxopcua#779 — alarms used to fall back to 250 ms). Calculation tags keep their per-driver `runTimeoutMs`. | | `Scripting:MaxAllocBytesPerRun` | `67108864` (64 MB) | `0` (or negative) disables the budget; a positive value below `1048576` (1 MB) becomes 1 MB | | `Scripting:QuarantineAfterConsecutiveTimeouts` | `3` | `1`–`1000` | - | `Scripting:StuckOrphanQuarantineFactor` | `10` | `0` (or negative) disables the rule; above `1000` becomes `1000`; `NaN` becomes the default | + | `Scripting:StuckOrphanQuarantineFactor` | `10` | `0` (or negative) disables the rule; above `1000` becomes `1000`; `NaN` becomes the default. In-process runner only (lmxopcua#780 P4) | A Calculation driver may override `maxAllocBytesPerRun` and `quarantineAfterConsecutiveTimeouts` in its own driver config. Those keys are diff --git a/docs/deploy/qa-upgrade-b8b4c18f-to-fea7de0a.md b/docs/deploy/qa-upgrade-b8b4c18f-to-fea7de0a.md index 21343ef1a..52dc420dc 100644 --- a/docs/deploy/qa-upgrade-b8b4c18f-to-fea7de0a.md +++ b/docs/deploy/qa-upgrade-b8b4c18f-to-fea7de0a.md @@ -1,6 +1,6 @@ # QA wonder-app-vq03/vq04 upgrade `b8b4c18f` → master `fea7de0a` (SDK 2.0.1), with the DEV rehearsal -> **Status: EXECUTED 2026-11-12.** DEV vd03 runs `fea7de0a` (from `5fb4b4db`). The QA pair vq03 + vq04 runs +> **Status: EXECUTED 2026-11-12.** Follow-up run the same evening: the #890 re-apply, a script-runner canary, the live #794 step 5 check and the #780 runaway drill (last section). DEV vd03 runs `fea7de0a` (from `5fb4b4db`). The QA pair vq03 + vq04 runs > `fea7de0a` (from `b8b4c18f`) with the out-of-process script runner on (Calculation + VirtualTag seams) and the > ScriptWorker isolation installed. Tracking: #801 (SDK 2 live gate), #793 (ConfigDb preflight), #794 (worker > isolation install), #780 (P3 runner flip). Template: [`vd03-upgrade-b8b4c18f-to-master.md`](vd03-upgrade-b8b4c18f-to-master.md). @@ -152,7 +152,7 @@ siblings `E:\ApiInstall\OtOpcUa\pki` (including `own\private\*.pfx`) and `data\` `BUILTIN\Users:ReadAndExecute`. Users is one of the worker token's restricting SIDs, so those folders are not covered by the deny. File-level ACLs were not inspected. Follow-up: #890. -**#890 fix, PENDING re-apply on vq03 and vq04.** Not run on QA yet. This is a deploy step for a later, user-requested window. +**#890 fix: re-applied on vq03 and vq04 later the same day** (see "Canary, live isolation check and runaway drill" below, which also adds the KEK folder to the list). The original instructions follow. The installer now takes `-DenyPaths` and records them. Once the scripts at that commit are staged on each node, run the following in an elevated Windows PowerShell 5.1 session. The services can stay up: only folder ACLs change for the worker identity, and no worker runs on QA today. @@ -207,3 +207,114 @@ Rollback stays `… -ConfigureHostService -Uninstall`. It now also removes the d `OtOpcUaConfig_pre-fea7de0a_20261112.bak` is the DB fallback. - **DEV:** `E:\ApiInstall\_stage-otopcua-fea7de0a\rollback.ps1` (→ `5fb4b4db`). - SDK 1.5 tooling caveat after a rollback: see the rollout runbook §Rollback item 4 (#880). + +## Canary, live isolation check and runaway drill (2026-11-12, 18:49–19:07 EST) + +Owner request the same day: "add the canary tag and finish QA". WinRM was used only for the on-box steps below +(installer, SQL role grant, live-token probe, log check of the drill). Everything else ran over HTTP / opc.tcp / SMB +from the Mac. No service restart; the pair stayed at **vq03 250 (Primary) / vq04 240** throughout. + +### 1. #890 re-apply (both nodes, services up) + +Scripts `scripts/install/{Install-ScriptWorkerIsolation.ps1,ScriptWorkerIsolation.psm1}` at `f75ee7d0` (SHA-256 `E0C11AEA…`, +`F9425E4C…`), staged over SMB to `E:\psrem-stage\otopcua-890-f75ee7d0\install`, hashes checked on each box. + +- **Path check (service env):** `Secrets__SqlitePath=E:\ApiInstall\OtOpcUa\data\secrets.db` and + `LocalDb__Path=E:\ApiInstall\OtOpcUa\data\otopcua-localdb.db` are inside. **`Secrets__MasterKey__FilePath=C:\ProgramData\ZB\kek\otopcua.kek` + is outside**, so `C:\ProgramData\ZB\kek` was added. That folder is already protected (SYSTEM + Administrators only), + so the deny there is defence in depth. +- `$deny = 'E:\ApiInstall\OtOpcUa','E:\ApiInstall\OtOpcUa\pki','E:\ApiInstall\OtOpcUa\data','C:\ProgramData\ZB\kek'`, then + `-WhatIf` (12 operations, nothing changed) → apply → apply. +- **First apply: 12 steps, 7 `changed`:** `DenyPathRecord`, `InstallRootDeny` (`0x1` → `0xD0157`), four `SensitiveDirDeny`, + and **`HostServiceEnv`**. The last one is a reorder only: the earlier P3 flip had appended the `Scripting__Runner*` + entries after `Scripting__Worker__Identity`/`PeCacheDir`, and the step rewrites the list with its two entries last. + Same values, env count unchanged (46 / 45). **Second apply: 12/12 `unchanged`** on both nodes. +- **Coverage:** vq03 `5 denied folder(s); 0 protected item(s)`. vq04 WARNs that `C:\ProgramData\ZB\kek\historiangw.kek` and + `mxgateway.kek` have protected DACLs. The live probe below shows the worker cannot read either. +- **State, both nodes:** `icacls` on `E:\ApiInstall\OtOpcUa`, `pki`, `data`, `app` and `C:\ProgramData\ZB\kek` shows + `NT SERVICE\OtOpcUaScriptWorker:(OI)(CI)(DENY)(W,D,WDAC,WO,RD,DC)`; `app\script-worker` keeps the explicit `(OI)(CI)(RX)` + ahead of the inherited deny. `reg query …\OtOpcUaScriptWorker\Parameters /v DenyPaths` lists the four folders. Anchor + DISABLED, firewall rule Outbound/Block on the worker exe. `/health/ready` 200 on both afterwards. + +### 2. Canary configuration (authored in the AdminUI, deployed with "Deploy current configuration") + +The QA AdminUI cannot be used from a browser over plain HTTP (its auth cookie is `Secure`), and QA had no LDAP +group → role grant. For this run only: a local forwarder `localhost:19003 → wonder-app-vq03:9000` (Chrome treats +`http://localhost` as secure), and a **temporary** `LdapGroupRoleMapping` row (`SCADA-Admins` → `Administrator`, +system-wide, on-box SQL with the service's own connection) for the box GLAuth test login. **The row was deleted at the +end** (QA again has 0 role mappings; the same login now gets AccessDenied). + +| Object | Value | +|---|---| +| Scripts | `ScriptRunnerCanary-Calc` (`SC-82e11d9323ff`): `return (int)DateTime.UtcNow.TimeOfDay.TotalSeconds;` · `ScriptRunnerCanary-VT` (`SC-c2ec9b4c4c53`): `return DateTime.UtcNow.Second;` | +| Raw | Calculation driver `script-runner-canary` (under the QA cluster) → `Device1` → tag `canary-calc-seconds`, Int32, Read, `{"scriptId":"SC-82e11d9323ff","changeTriggered":true,"timerIntervalMs":1000}` → `ns=2;s=script-runner-canary/Device1/canary-calc-seconds` | +| UNS | area `canary` (`area-canary`) → line `script-runner` (`line-canary`) → equipment `script-runner-canary` (`EQ-ec3979550d90`, MachineCode `SCRIPT_RUNNER_CANARY`) → virtual tag `canary-vt-second` (`VT-script-runner-canary`), Int32, timer 1000 ms → `ns=3;s=EQ-ec3979550d90/canary-vt-second` | +| Deployment | `bcaba714` rev `82dd0598c37f…` Sealed, both nodes in sync (the first deployment ever on QA) | + +**Result:** both values **Good and advancing once a second on both endpoints** (`opc.tcp://10.220.158.2:4840` and +`.3:4840`, anonymous, read by the OtOpcUa CLI). Both nodes run the drivers, so no failover was needed to see it. +Workers started on the first evaluation: `otopcua_script_worker_up{shard=0,1}` = 1, `runner_state` 0, two PE entries +in `C:\ProgramData\OtOpcUa\script-pe-cache\pe\` on each node (listed over SMB). + +**Kept on QA as a runner monitor** (the design and #780 say nothing about removing it): a Bad or frozen +`canary-calc-seconds` / `canary-vt-second`, or `otopcua_script_worker_up` = 0, means the out-of-process runner is sick. + +### 3. #794 step 5: the live worker under the real service session (both nodes) + +Probe: an admin PowerShell on the box duplicated the **live worker's own token** (opened under the host's LocalSystem +token, since an admin cannot open it directly) and impersonated it for file opens. The same reads were then repeated +without impersonation as the positive control (all READ-OK). + +| Check | vq03 and vq04 (identical) | +|---|---| +| Worker processes | 2 per node, `…\app\script-worker\ZB.MOM.WW.OtOpcUa.ScriptWorker.exe`, parent = `OtOpcUa.Host.exe` | +| Token | user `NT AUTHORITY\SYSTEM`, **restricted = True**, privileges **only `SeChangeNotifyPrivilege`**, restricting SIDs `NT SERVICE\OtOpcUaScriptWorker, Everyone, BUILTIN\Users, NT AUTHORITY\RESTRICTED` (host token: unrestricted, 28 privileges) | +| Window-station grant | works under the real service session: both shards run and evaluate (no `ERROR_DLL_INIT_FAILED`) | +| **#890 paths, read** | **DENIED:** `pki\own\private\*.pfx`, `pki\trusted\certs\*.der`, `data\secrets.db`, `data\otopcua-localdb.db`, `app\appsettings.json`, `app\OtOpcUa.Host.dll`, `app\logs\scripts-*.log`, `app.bak.…\appsettings.json`, `C:\ProgramData\ZB\kek\{otopcua,historiangw,mxgateway}.kek`, `script-pe-cache\pe-cache.key` | +| **#890 paths, write** | **DENIED:** create a file in `pki\trusted\certs`, `data`, `app`, `app\script-worker` | +| Positive controls | READ-OK: `app\script-worker\ZB.MOM.WW.OtOpcUa.ScriptWorker.dll`, `C:\Windows\System32\kernel32.dll` | +| Network | 0 TCP / 0 UDP endpoints owned by either worker pid; rule `OtOpcUa-ScriptWorker-BlockOutbound` Outbound/Block/Any/enabled and its program equals the running image path | +| PE cache | filled on first use (above); after the drill's worker restarts `otopcua_script_compile{cache="hit"}` = 4 on each node | + +Not done: the dropped-packet firewall log. The worker has no code path that opens a socket, so the log would be empty +whether or not the rule worked. Turning on profile-wide logging was not worth it for that. + +**Finding (outside #890's scope, filed as #891):** the worker token **can** read some Users-readable files outside +OtOpcUa's folders: `E:\psrem-stage\otopcua-fea7de0a\backup\OtOpcUaHost-pre-fea7de0a.reg` (a registry export of the +OtOpcUaHost environment, which holds secrets), and `E:\ApiInstall\ScadaBridge\app\appsettings.json` / +`E:\ApiInstall\HistorianGateway\app\appsettings.json`. `C:\ProgramData\ZB\qa-build\*` is denied (protected ACL). Those +folders belong to other apps or to deploy staging, so no deny was added there in this run. Follow-up: #891. + +### 4. #780 runaway drill (live gate: "a QA flip with the same drill") + +A second script `ScriptRunnerCanary-RunawayDrill` = `while (true) { }` bound to VT `canary-runaway-drill` (Int32, timer +1000 ms) on the canary equipment, deployed as `e746cc5f` (rev `43bd8917…`). Seams: Calculation + VirtualTag. + +| Observed | vq03 | vq04 | +|---|---|---| +| Drill VT | `BadInternalError` from the first sample (00:02:59Z) | same | +| Kills | 19:03:03.32 and 19:03:08.31 EST: `exceeded its hard deadline (4000 ms); killing ScriptWorker[0]` → `ended: "KilledDeadline" … culprit 1:VT-script-runner-canary-runaway, 1 evaluation(s) … in flight` | 19:03:03.32 and 19:03:08.27, same lines | +| Quarantine | `Script "1:VT-script-runner-canary-runaway" quarantined: "it exceeded its hard deadline and its worker was killed (2 time(s) in the last hour)…"`; `otopcua_script_quarantined_total{reason="killed"}` 1, `worker_exits_total{reason="killed_deadline",shard="0"}` 2, `run_refused` 4 | same | +| Shard 0 restart | back in about 0.5 s each time | same | +| Siblings | `canary-vt-second` 77 updates, `canary-calc-seconds` 88 updates over the drill, **all Good** | 74 / 88, all Good | +| Node | `/health/ready` 200, `runner_state` 0, `/health/active` 200 | `/health/ready` 200, `/health/active` 503 (Secondary) | +| ServiceLevel | **250** on all 21 samples | **240** on all 21 samples | + +**Cleanup:** the drill VT and its script were deleted in the AdminUI and the configuration redeployed as `5905003e`. Its +revision is **`82dd0598…`, the same as the canary-only deployment `bcaba714`**. The drill node now reads `BadNodeIdUnknown` +and both canary values are Good on both nodes. + +**ScriptedAlarm seam: left off.** No canary scripted alarm was added: alarms go last (§14 #10), and the alarm drill +already passed on docker-dev (§12.4). + +### Final QA state (19:07 EST) + +- vq03 **250** Primary, `/health/active` 200. vq04 **240** Secondary, 503. Both `/health/ready` 200 with 5/5 components. + Overview: OtOpcUa Up, 2 members / 0 unreachable. +- `Scripting__Runner=OutOfProcess`, seams Calculation + VirtualTag. Isolation with the #890 denies on both nodes. +- ConfigDb: the canary only (1 driver, 1 device, 1 tag, 1 VT, 2 scripts, 1 area/line/equipment, 0 scripted alarms, 0 role + mappings, 0 API keys). Three sealed deployments; `5905003e` is current. +- ScadaBridge, mxgw and HistorianGateway on QA were not touched. +- **Rollback of this run:** remove the canary by deleting its rows in the AdminUI and deploying (or restore + `OtOpcUaConfig_pre-fea7de0a_20261112.bak`). The isolation rollback is unchanged: `… -ConfigureHostService -Uninstall` + removes the four recorded denies. diff --git a/docs/plans/2026-11-09-out-of-process-script-runner-design.md b/docs/plans/2026-11-09-out-of-process-script-runner-design.md index 9d84bf942..b45e0d269 100644 --- a/docs/plans/2026-11-09-out-of-process-script-runner-design.md +++ b/docs/plans/2026-11-09-out-of-process-script-runner-design.md @@ -719,6 +719,11 @@ per-shard state, restarts in the last hour and the quarantine list. Quarantines hold), so tier rollout rides normal deploys. 5. **P4, decide the long-term status of `InProcess`.** The recommendation is to keep it for dev and tests and as the documented rollback, and to retire `StuckOrphanQuarantineFactor` from the docs as "in-process only". + - **Decided (owner, §14, 2026-11-09) and recorded 2026-11-12:** `InProcess` stays the compiled default (dev, tests, + docker-dev) and the documented rollback (set the flag back and restart the node). `StuckOrphanQuarantineFactor` + is documented as in-process only in `docs/ScriptEditor.md`. The QA flip with the live runaway drill passed + (record: `docs/deploy/qa-upgrade-b8b4c18f-to-fea7de0a.md`, section "Canary, live isolation check and runaway + drill"). **Rollback:** set the flag back to `InProcess` and restart the node. No data or config migration is involved. The PE cache directory can be deleted at any time. @@ -1663,7 +1668,7 @@ measures the §8 table: p50/p99 added latency, throughput at K=1/2/4, host CPU, - docker-dev rig: a deploy with VTs, Calc tags and scripted alarms; drill a runaway script through the AdminUI and watch `/uns` go Bad, the quarantine appear, and siblings stay Good; - ~~QA shadow week (P2)~~ — dropped by the owner 2026-11-12; -- a QA flip with the same drill. +- a QA flip with the same drill. **Done 2026-11-12** on vq03/vq04 (record above). ---