From 93d18094847caaf6f555410a99249ab80049c82d Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Wed, 11 Nov 2026 12:10:59 -0500 Subject: [PATCH 1/2] =?UTF-8?q?docs(script-runner):=20=C2=A78.2=20worker?= =?UTF-8?q?=20idle=20RSS=20budget=20revised=20to=20200=20MB=20+=20scripts?= =?UTF-8?q?=20(#789)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The owner revised the per-shard worker idle RSS budget from 80 MB to 200 MB + scripts on 2026-11-11: compiles run in the worker, so Roslyn's code and metadata stay resident (measured 159-187 MB) and no GC setting moves it. The perf harness now reports both RSS rows against the 200 MB constant with a PASS/MISS mark; A-3 records what the measurement showed. Claude-Session: https://claude.ai/code/session_01GT67AD99zQQqpLCVm3p7xk --- ...1-09-out-of-process-script-runner-design.md | 4 ++-- .../ScriptRunnerPerfTests.cs | 18 +++++++++++++++--- 2 files changed, 17 insertions(+), 5 deletions(-) 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 234aefca1..b48d3db87 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 @@ -536,7 +536,7 @@ size for 2× headroom (10k/s). The passthrough fast path is excluded because it | Host CPU for IPC | ≤ 25% of one core at 10k evals/s | Serialisation + pipe I/O, measured by an opt-in perf test. Since lmxopcua#789 the harness reports it as the out-of-process runner's host CPU minus the in-process runner's in the same phase ("vs InProcess"): the raw figure includes the harness's own pacing loop and pool, which InProcess pays too (§12.2) | | Bytes per eval on the wire | ≤ 64 B + 24 B per input | Positional slots, §4.4 | | Shard restart → first result, 1,000 cached scripts | ≤ 2 s | §7 lazy PE load | -| Worker idle RSS | ≤ 80 MB + scripts **[A-3]** | Per shard. **Proposed revision (lmxopcua#789, §12.2):** ≤ 80 MB + scripts for a worker that has only loaded cached PEs (measured 36–58 MB); ≤ 200 MB + scripts once Roslyn has run in it (measured 159–187 MB), because compiling in the worker (§14 #7) keeps Roslyn's code and metadata resident and no GC setting moves it | +| Worker idle RSS | ≤ 200 MB + scripts | Per shard. **Revised by the owner 2026-11-11 (lmxopcua#789)** from the original ≤ 80 MB + scripts **[A-3]**. Compiling in the worker (§14 #7) keeps Roslyn's code and metadata resident once it has run (measured 159–187 MB), and no GC setting moves it (§12.2). A worker that has only loaded cached PEs sits far below that (measured 36–58 MB). The perf harness reports both against 200 MB | | Kill latency after `T+G` | ≤ 100 ms | Host timer resolution plus `Process.Kill` | **Comparison with today:** the in-process cost per compiled run is one `Task.Run` hop plus `WaitAsync`, which @@ -1367,7 +1367,7 @@ Each has a recommendation, marked ★. |---|---|---| | A-1 | Unbounded recursion in a script throws `StackOverflowException` and kills the host today | Reproduce in a throwaway process (not the test host) | | A-2 | A collectible ALC whose code is still executing on an orphan thread cannot be unloaded | .NET docs / a `WeakReference` test with a spinning orphan | -| A-3 | A minimal .NET 10 worker idles at tens of MB RSS | Measure the P1 worker | +| A-3 | A minimal .NET 10 worker idles at tens of MB RSS | Measured (§12.1/§12.2): true only for a worker that has never compiled (36–58 MB); a worker that has run Roslyn idles at 159–187 MB, so §8.2 was revised to 200 MB | | A-4 | `P = max(2, cores/K)` evaluation threads per worker is enough | P1 perf harness | | A-5 | Passthrough scripts are a large share of evaluations on real deployments | Count `PassthroughScript.TryMatch` hits against compiled runs on QA (add a counter in P0) | | A-6 | A local pipe round trip costs tens of µs | P1 perf harness | diff --git a/tests/Server/ZB.MOM.WW.OtOpcUa.ScriptWorker.Tests/ScriptRunnerPerfTests.cs b/tests/Server/ZB.MOM.WW.OtOpcUa.ScriptWorker.Tests/ScriptRunnerPerfTests.cs index 2235faa5b..f78053f6b 100644 --- a/tests/Server/ZB.MOM.WW.OtOpcUa.ScriptWorker.Tests/ScriptRunnerPerfTests.cs +++ b/tests/Server/ZB.MOM.WW.OtOpcUa.ScriptWorker.Tests/ScriptRunnerPerfTests.cs @@ -32,6 +32,12 @@ public sealed class ScriptRunnerPerfTests { private const string OptInVariable = "OTOPCUA_SCRIPT_PERF"; private const int AcceptedGateEvalsPerSecond = 5_000; + + /// + /// §8.2 "Worker idle RSS ≤ 200 MB + scripts", per shard (revised by the owner 2026-11-11, lmxopcua#789: compiles + /// run in the worker, so Roslyn stays resident; the original 80 MB [A-3] is only met by a warm-PE-cache worker). + /// + private const int WorkerIdleRssBudgetMb = 200; private const int Keys = 2_000; private const int DistinctSources = 50; @@ -481,7 +487,7 @@ public sealed class ScriptRunnerPerfTests } /// - /// §8.2 "Shard restart → first result, 1,000 cached scripts ≤ 2 s", "Worker idle RSS ≤ 80 MB + scripts" and + /// §8.2 "Shard restart → first result, 1,000 cached scripts ≤ 2 s", "Worker idle RSS ≤ 200 MB + scripts" and /// "Kill latency after T+G ≤ 100 ms". Report-only. /// [Fact] @@ -559,14 +565,20 @@ public sealed class ScriptRunnerPerfTests } } + static string RssCell(long bytes) + { + var mb = bytes / 1048576.0; + return $"{mb:N0} MB {(mb <= WorkerIdleRssBudgetMb ? "PASS" : "MISS")}"; + } + report.AppendLine("| Measure | Result | §8.2 budget |") .AppendLine("|---|---:|---|") .AppendLine($"| {scripts} scripts, empty cache, all first results (compile + write) | {cold.TotalMilliseconds:N0} ms | — |") .AppendLine($"| {scripts} scripts, fresh runner on a warm cache, all first results | {warmFresh.TotalMilliseconds:N0} ms | ≤ 2,000 ms |") .AppendLine($"| kill both shards → every script's next correct result | {killRestart.TotalMilliseconds:N0} ms | ≤ 2,000 ms |") - .AppendLine($"| worker RSS after first eval, compiled (max of 2 shards) | {rssIdle / 1048576.0:N0} MB | ≤ 80 MB + scripts |") + .AppendLine($"| worker RSS after first eval, compiled (max of 2 shards) | {RssCell(rssIdle)} | ≤ {WorkerIdleRssBudgetMb} MB + scripts |") .AppendLine($"| worker RSS with {scripts / 2} scripts compiled per shard (max) | {rssLoaded / 1048576.0:N0} MB | — |") - .AppendLine($"| worker RSS after first eval, warm PE cache, no compile (max) | {rssWarmIdle / 1048576.0:N0} MB | ≤ 80 MB + scripts |") + .AppendLine($"| worker RSS after first eval, warm PE cache, no compile (max) | {RssCell(rssWarmIdle)} | ≤ {WorkerIdleRssBudgetMb} MB + scripts |") .AppendLine($"| worker RSS with {scripts / 2} scripts loaded from the cache per shard (max) | {rssWarmLoaded / 1048576.0:N0} MB | — |") .AppendLine($"| kill latency after T+G (5 runs, ms) | {string.Join(" / ", killLatencies.Select(l => l.ToString("N0")))} | ≤ 100 ms |"); Report(report); From 8f30c1e5212c1a52bc08b69c4dd914b502119b11 Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Wed, 11 Nov 2026 12:34:07 -0500 Subject: [PATCH 2/2] docs(script-runner): windev re-measure (#789) and Windows soft-clock test run (#842) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit §12.1 gains the 2026-11-11 windev (VMware VM) perf table: idle p50 581 us (MISS), kill latency after T+G 8-16 ms (PASS), kill both shards 2.12-2.14 s (MISS by ~6 %), worker RSS 160 MB compiled / 36 MB warm-cache (PASS under the revised 200 MB budget), host CPU +131 % vs InProcess (MISS, untuned). It also records the first Windows run of Category=ScriptWorker: 107/0/2 from C:\build, all 13 WorkerSoftClockTests cases (5 freezing a real worker with NtSuspendProcess) green with no code change. From a user-profile directory the restricted-identity isolation test fails because the restricted token cannot read the worker dll there (profile ACL), which is environment, not a defect. Claude-Session: https://claude.ai/code/session_01GT67AD99zQQqpLCVm3p7xk --- ...-09-out-of-process-script-runner-design.md | 52 +++++++++++++++++++ 1 file changed, 52 insertions(+) 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 b48d3db87..f9bd8e713 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 @@ -884,6 +884,58 @@ Both misses → lmxopcua#789 (the §4.5 batching and per-eval allocation work). The host load timeout still counts the time a load waits behind other compiles → lmxopcua#790. +**windev re-measure, 2026-11-11 (lmxopcua#789, after the §12.2–§12.3 changes; budget revision applied).** +- **windev is a VM:** VMware20,1 on an Intel Xeon E5-2697 v4 @ 2.30 GHz, 36 logical CPUs, 32 GB RAM, Windows, + .NET 10.0.8. The box was otherwise idle (about 4 % total CPU before the run). The issue's "re-measure on a non-VM + box" request is therefore still open; these are VM figures. +- Run from `C:\build\otopcua-842` (a `git archive` of the branch head) with `-c Release`, `OTOPCUA_SCRIPT_PERF=1`, + 10 s phases, filtered to `Throughput_and_latency_against_the_accepted_gate` and `Restart_rss_and_kill_latency`. + The restart test ran twice; both figures are given. +- Framework-dependent worker built beside the tests (`dotnet exec`), as in the earlier windev rows. + +| Measure (K = 2 unless stated) | windev 2026-11-11 | §8.2 budget | Verdict | +|---|---:|---|---| +| Added latency p50, idle sequential | 581 µs (K=1 490, K=4 537; InProcess 134) | ≤ 150 µs | MISS | +| p99 at paced 10k/s | 3,220 µs (K=1 5,380, K=4 1,358) | ≤ 2 ms | MISS at K=2 (was 1,676 µs in §12.2) | +| Host CPU at 10k/s, vs InProcess | +131 % (raw 141 %, InProcess 10 %) | ≤ 25 % | MISS (not tuned in this task) | +| Closed loop ×64 | 54,152 evals/s, 0 not ok | gate ≥ 5,000 | PASS | +| Kill latency after T+G (5 runs × 2) | 16 / 11 / 10 / 11 / 12 and 16 / 12 / 8 / 11 / 12 ms | ≤ 100 ms | PASS | +| Kill both shards → every script's next correct result (1,000 cached) | 2,135 ms and 2,117 ms | ≤ 2,000 ms | MISS by about 6 % | +| Warm restart, 1,000 cached, fresh runner | 1,847 ms and 1,829 ms | ≤ 2,000 ms | PASS | +| Worker RSS after first eval, compiled (max of 2 shards) | 160 MB (both runs) | ≤ 200 MB + scripts | PASS | +| Worker RSS after first eval, warm PE cache, no compile | 36 MB (both runs) | ≤ 200 MB + scripts | PASS | +| Worker RSS, 500 scripts compiled per shard | 236 / 262 MB | — (200 MB + scripts) | — | +| Worker RSS, 500 scripts loaded from the cache per shard | 93 / 96 MB | — | — | +| 1,000 scripts, empty cache, all first results | 12,380 / 12,800 ms | — | — | + +Notes: +- Under the revised budget, RSS passes. Kill latency stays fixed since §12.2: the earlier 210 ms was compile time. +- Kill-both-shards is about 120 ms over the line. It includes the 250 ms first restart backoff and the warm-cache + load of 1,000 PEs. The warm-cache restart alone takes about 1.83 s on this VM, so the kill path adds only about + 300 ms on top. +- Idle p50 and host CPU are the overlapped-I/O path that §12.2 left open; CPU tuning is deliberately not part of + this re-measure. The K=2 p99 at 10k/s reads worse than §12.2's 1,676 µs. K=4 is 1,358 µs in the same run, so this + is likely VM scheduling noise on a single run, but it was not re-run to confirm. + +**Windows `ScriptWorker.Tests` run, 2026-11-11 (lmxopcua#842).** `--filter Category=ScriptWorker`, Debug, on the +same VM. This is the first Windows run of the #827 soft-clock tests, which freeze the worker with `NtSuspendProcess` +/ `NtResumeProcess`. +- From `C:\build\otopcua-842`: **107 passed, 0 failed, 2 skipped (109)**, 13 m 37 s, 0 build warnings. + - All 13 `WorkerSoftClockTests` cases passed, including the 5 that suspend a real worker process: stalled > T, + stalled past T+G, late-starting runaway, Shadow under a stall (two freezes), and a notice that arrives after the + transport deadline. No code change was needed. + - Skipped by design: `A_published_self_contained_worker_runs_as_its_own_process` (needs + `OTOPCUA_SCRIPTWORKER_TEST_PATH`, §12.1) and the off-Windows identity refusal. +- From `C:\Users\dohertj2\otopcua-842`: 106 / **1 failed** / 2. The failure is + `WorkerIsolationTests.A_worker_under_the_identity_runs_scripts_with_a_restricted_token_and_a_plain_one_does_not`: + "The application to execute does not exist: …\script-worker\ZB.MOM.WW.OtOpcUa.ScriptWorker.dll", exit + `0x80008081`. + - **Cause: the test environment, not the code.** The restricted worker token cannot read the worker dll inside a + user profile, whose ACL is SYSTEM, Administrators and the owner only. That is the access §6 intends. + - In production the installer grants the identity read+execute on `script-worker\` (§12.5). + - Run the Windows suite from a directory the `BUILTIN\Users` group can read, such as `C:\build`. The §12.5 green + run used that. + ### 12.2 lmxopcua#789 / #790 / #788 record (2026-11-10) **What cost the host CPU (#789).** With `DOTNET_ThreadPool_UnfairSemaphoreSpinLimit=0` a scratch probe showed the