dohertj2/lmxopcua
1
0
Fork 0
Code Issues 26 Pull Requests 1 Actions 2 Packages Projects Releases Wiki Activity

[deferred: further tuning] Out-of-process script runner misses §8.2 Windows host-CPU, Windows idle-latency and compiled-worker RSS budgets #789

New Issue
Open
opened 2026-11-10 02:53:14 -05:00 by dohertj2 · 1 comment
dohertj2 commented 2026-11-10 02:53:14 -05:00
Owner
Copy Link
Copy Source

Measured 2026-11-10 with the new opt-in perf harness, ScriptRunnerPerfTests (Category=Perf, OTOPCUA_SCRIPT_PERF=1, lmxopcua#780). Full tables are in design doc §12.1.

The accepted gate passes: at K=2 the runner does at least 5,000 evals/s/node with every result correct. macOS closed loop: 336k/s. windev closed loop: 51k/s. The other §8.2 budgets miss:

Budget macOS (14 CPU arm64) windev (36 CPU x64 VM)
Host CPU ≤ 25 % of a core at 10k/s (K=2) ~240 % (InProcess under the same harness: 74 %) 153 % (InProcess: 6 %)
Added latency p50 ≤ 150 µs, idle 41 µs ✓ 795 µs ✗
Worker idle RSS ≤ 80 MB + scripts ~190 MB 158 MB
Kill latency after T+G ≤ 100 ms ~32 ms ✓ ~210 ms ✗
Kill both shards → every script's next result ≤ 2 s (1,000 cached) 0.48 s ✓ 2.03 s (borderline)

What the CPU is spent on. A sequential probe on macOS used 156 µs of host CPU per evaluation, and 63 µs with DOTNET_ThreadPool_UnfairSemaphoreSpinLimit=0. Thread-pool spin-waiting between hops is therefore the larger part. At idle the host is about 1 %.

Candidates:

  • fewer thread hops per evaluation (pipe reader → completion → caller);
  • dropping the per-eval WaitAsync(timeout) timer and the hard-deadline timer allocation (one timer wheel instead);
  • the §4.5 batch submit;
  • caching the source SHA-256 per key instead of hashing on every RunAsync.

RSS. Roslyn stays resident because compiles run in the worker (§14 #7). Either accept a revised budget, or measure a worker that served only warm-cache PE loads.

Windows latency and kill timing. Re-measure on a non-VM box before treating these as real misses.

Not blocking P2 (Shadow). These are the inputs to the P3 flip decision.

Measured 2026-11-10 with the new opt-in perf harness, `ScriptRunnerPerfTests` (`Category=Perf`, `OTOPCUA_SCRIPT_PERF=1`, lmxopcua#780). Full tables are in design doc §12.1. The **accepted gate passes**: at K=2 the runner does at least 5,000 evals/s/node with every result correct. macOS closed loop: 336k/s. windev closed loop: 51k/s. The other §8.2 budgets miss: | Budget | macOS (14 CPU arm64) | windev (36 CPU x64 VM) | |---|---|---| | Host CPU ≤ 25 % of a core at 10k/s (K=2) | ~240 % (InProcess under the same harness: 74 %) | 153 % (InProcess: 6 %) | | Added latency p50 ≤ 150 µs, idle | 41 µs ✓ | 795 µs ✗ | | Worker idle RSS ≤ 80 MB + scripts | ~190 MB | 158 MB | | Kill latency after T+G ≤ 100 ms | ~32 ms ✓ | ~210 ms ✗ | | Kill both shards → every script's next result ≤ 2 s (1,000 cached) | 0.48 s ✓ | 2.03 s (borderline) | **What the CPU is spent on.** A sequential probe on macOS used 156 µs of host CPU per evaluation, and 63 µs with `DOTNET_ThreadPool_UnfairSemaphoreSpinLimit=0`. Thread-pool spin-waiting between hops is therefore the larger part. At idle the host is about 1 %. Candidates: - fewer thread hops per evaluation (pipe reader → completion → caller); - dropping the per-eval `WaitAsync(timeout)` timer and the hard-deadline timer allocation (one timer wheel instead); - the §4.5 batch submit; - caching the source SHA-256 per key instead of hashing on every `RunAsync`. **RSS.** Roslyn stays resident because compiles run in the worker (§14 #7). Either accept a revised budget, or measure a worker that served only warm-cache PE loads. **Windows latency and kill timing.** Re-measure on a non-VM box before treating these as real misses. Not blocking P2 (Shadow). These are the inputs to the P3 flip decision.
dohertj2 added the type:followuppriority:p2 labels 2026-11-10 02:53:14 -05:00
dohertj2 commented 2026-11-10 04:34:03 -05:00
Author
Owner
Copy Link
Copy Source

Partial fix landed on master @ 8582ce91. The owner deferred further tuning, so this issue stays open for the budgets below that are still missed. The full record and tables are in design doc §12.2.

What was costing host CPU. A probe run with DOTNET_ThreadPool_UnfairSemaphoreSpinLimit=0 showed the IPC work itself was only about 10 µs per evaluation. The rest was thread-pool spin-waiting, caused by several pool work items per evaluation. On Unix there was a second cost: the socket under a .NET pipe turns non-blocking after its first async call, so every read went through the socket engine.

Changes:

  • Frame writer (ScriptWorkerFrameWriter). The thread that produces a frame now writes it itself, merging any evaluations or results queued meanwhile, with one write per pass. The old loop also called PipeStream.FlushAsync; PipeStream does not override it, so that queued one pool work item per pass.
  • Frame reader (ScriptWorkerFrameReader). One buffered read now takes every frame that has arrived.
  • Deadlines. Each evaluation has one timer that covers both T and T+G.
  • Slot release. The single-flight slot is released and the deadline cancelled on the reader thread, before the caller resumes.
  • Result dispatcher. Callers resume on a per-connection thread that blocks without spinning. They do not resume on the reader, so a slow consumer cannot starve heartbeats.
  • Blocking pipe I/O on Unix, at both ends. This was the largest single gain.
  • Windows kill. A kill now terminates the worker's Job Object directly.

Tried for worker memory, and not kept, because none of them changed RSS: a ReadyToRun worker, GCgen0size, GCConserveMemory, TieredPGO=0, and an aggressive GC after a compile burst.

Before → after, §8 harness, K=2. "vs InProcess" is the new harness column: out-of-process host CPU minus in-process host CPU in the same phase, i.e. the IPC share.

Budget macOS windev (Windows VM)
Host CPU at 10k/s, raw 228–240 % → 79 % (InProcess 69 %) 153 % → 123 % (InProcess 7 %)
Host CPU vs InProcess (≤ 25 %) +157 → +10 ✓ +147 → +115 ✗
Idle p50 (≤ 150 µs) 41 → 23 µs ✓ 795 → 507 µs ✗
p99 at 10k/s (≤ 2 ms) 0.7–0.8 → 1.0 ms ✓ 1.9 → 1.7 ms ✓
Closed loop, accepted gate ≥ 5k/s 342k → 442k/s ✓ 51k → 62k/s ✓
Worker RSS after a compile (≤ 80 MB) 188 → 187 MB ✗ 158 → 161 MB ✗
Worker RSS, warm PE cache, no compile (new row) 58 MB ✓ 36 MB ✓
Kill latency after T+G (≤ 100 ms) 31–35 → 33–43 ms ✓ 10–21 ms ✓
Warm restart, 1,000 cached scripts (≤ 2 s) 0.21 s ✓ 1.8–1.9 s ✓
Kill both shards → every next result (≤ 2 s) 0.5 s ✓ 2.0–2.09 s (borderline)

Notes on the numbers:

  • Steady-load probe. Host CPU at 10k/s went from 116–158 % to 49–52 % (InProcess 60–65 %). Sequential throughput went from about 25k to 46k evals/s, and host CPU per evaluation from about 85 µs to 13 µs. This is the macOS ~240 % → 52–118 % range across the harness and the probe.
  • Load on the Mac. Other agents were running, with load averages of 5–25 during the macOS runs.
  • Windows kill latency. The old windev "kill latency" of about 210 ms was mostly harness error: the stopwatch started before the cold compile of each distinct runaway key, which takes 100–200 ms on the VM. The harness now times from the soft-timeout answer.
  • Before figures. The windev before figures are the earlier runs quoted in design §12.1; I did not re-run the old code on windev. The macOS before figures were re-measured on 1ead8f45.

Still missed (open, further tuning deferred):

  1. Windows host CPU for IPC: +115 points at 10k/s. Windows still uses overlapped async I/O, so each frame goes through the completion port and the thread pool. Next step: either two one-way pipes with synchronous handles and dedicated threads, or a measurement on a box that is not a VM.
  2. Windows idle p50: 507 µs. On that VM, InProcess alone is 92 µs.
  3. Worker RSS after a compile: 159–187 MB. Compiling in the worker (§14 #7) keeps Roslyn's code and metadata resident. Proposed revised budget, in §8.2: ≤ 80 MB + scripts for a worker that has only loaded from the PE cache, and ≤ 200 MB + scripts once Roslyn has run in it. An alternative, not built: after a compile burst, recycle the worker from the PE cache (blue/green).
  4. Windows kill-both-shards: about 2.0 s, right at the budget line.

Evidence:

  • Release build of ZB.MOM.WW.OtOpcUa.slnx with --no-incremental: 0 warnings, 0 errors.
  • AKKA_TEST_TIMEFACTOR=3, after the rebase onto 963b0d66: ScriptWorker 151 passed / 3 skipped, Core.Scripting 221 / 1, Host 269, Runtime 993 / 3, OpcUaServer.IntegrationTests 132/132.
  • ScriptWorker.Tests also passed on windev: 150 of 151 on the first run, then the one failure, a windev-only calibration problem in a new #790 test, was fixed and that test re-ran green.
  • Mutation checks, each red and then reverted:
    • resuming callers on the reader: the worker was killed for silence;
    • releasing the slot after handing off the resume: 49 of 50 runs refused;
    • not re-arming the timer for the grace: the runaway was never killed by the host.
  • New tests:
    • reader reassembly at every split, from 1 byte to 1 MB, both sync and async;
    • malformed frames and a fuzz test for the reader;
    • writer batching and frame order;
    • writer fault handling;
    • A_caller_that_blocks_after_its_result_does_not_starve_the_reader;
    • a deterministic slow-release phase in A_caller_that_awaited_its_run_is_never_refused_by_it.
**Partial fix landed on `master` @ `8582ce91`.** The owner deferred further tuning, so this issue **stays open** for the budgets below that are still missed. The full record and tables are in design doc §12.2. **What was costing host CPU.** A probe run with `DOTNET_ThreadPool_UnfairSemaphoreSpinLimit=0` showed the IPC work itself was only about 10 µs per evaluation. The rest was thread-pool spin-waiting, caused by several pool work items per evaluation. On Unix there was a second cost: the socket under a .NET pipe turns non-blocking after its first async call, so every read went through the socket engine. **Changes:** - **Frame writer (`ScriptWorkerFrameWriter`).** The thread that produces a frame now writes it itself, merging any evaluations or results queued meanwhile, with one write per pass. The old loop also called `PipeStream.FlushAsync`; PipeStream does not override it, so that queued one pool work item per pass. - **Frame reader (`ScriptWorkerFrameReader`).** One buffered read now takes every frame that has arrived. - **Deadlines.** Each evaluation has one timer that covers both T and T+G. - **Slot release.** The single-flight slot is released and the deadline cancelled on the reader thread, before the caller resumes. - **Result dispatcher.** Callers resume on a per-connection thread that blocks without spinning. They do not resume on the reader, so a slow consumer cannot starve heartbeats. - **Blocking pipe I/O on Unix**, at both ends. This was the largest single gain. - **Windows kill.** A kill now terminates the worker's Job Object directly. Tried for worker memory, and not kept, because none of them changed RSS: a ReadyToRun worker, `GCgen0size`, `GCConserveMemory`, `TieredPGO=0`, and an aggressive GC after a compile burst. **Before → after, §8 harness, K=2.** "vs InProcess" is the new harness column: out-of-process host CPU minus in-process host CPU in the same phase, i.e. the IPC share. | Budget | macOS | windev (Windows VM) | |---|---|---| | Host CPU at 10k/s, raw | 228–240 % → **79 %** (InProcess 69 %) | 153 % → **123 %** (InProcess 7 %) | | Host CPU vs InProcess (≤ 25 %) | +157 → **+10 ✓** | +147 → **+115 ✗** | | Idle p50 (≤ 150 µs) | 41 → 23 µs ✓ | 795 → **507 µs ✗** | | p99 at 10k/s (≤ 2 ms) | 0.7–0.8 → 1.0 ms ✓ | 1.9 → 1.7 ms ✓ | | Closed loop, accepted gate ≥ 5k/s | 342k → 442k/s ✓ | 51k → 62k/s ✓ | | Worker RSS after a compile (≤ 80 MB) | 188 → 187 MB ✗ | 158 → 161 MB ✗ | | Worker RSS, warm PE cache, no compile (new row) | 58 MB ✓ | 36 MB ✓ | | Kill latency after T+G (≤ 100 ms) | 31–35 → 33–43 ms ✓ | **10–21 ms ✓** | | Warm restart, 1,000 cached scripts (≤ 2 s) | 0.21 s ✓ | 1.8–1.9 s ✓ | | Kill both shards → every next result (≤ 2 s) | 0.5 s ✓ | 2.0–2.09 s (borderline) | Notes on the numbers: - **Steady-load probe.** Host CPU at 10k/s went from 116–158 % to 49–52 % (InProcess 60–65 %). Sequential throughput went from about 25k to 46k evals/s, and host CPU per evaluation from about 85 µs to 13 µs. This is the macOS ~240 % → 52–118 % range across the harness and the probe. - **Load on the Mac.** Other agents were running, with load averages of 5–25 during the macOS runs. - **Windows kill latency.** The old windev "kill latency" of about 210 ms was mostly harness error: the stopwatch started before the cold compile of each distinct runaway key, which takes 100–200 ms on the VM. The harness now times from the soft-timeout answer. - **Before figures.** The windev before figures are the earlier runs quoted in design §12.1; I did not re-run the old code on windev. The macOS before figures were re-measured on `1ead8f45`. **Still missed (open, further tuning deferred):** 1. **Windows host CPU for IPC: +115 points at 10k/s.** Windows still uses overlapped async I/O, so each frame goes through the completion port and the thread pool. Next step: either two one-way pipes with synchronous handles and dedicated threads, or a measurement on a box that is not a VM. 2. **Windows idle p50: 507 µs.** On that VM, InProcess alone is 92 µs. 3. **Worker RSS after a compile: 159–187 MB.** Compiling in the worker (§14 #7) keeps Roslyn's code and metadata resident. Proposed revised budget, in §8.2: ≤ 80 MB + scripts for a worker that has only loaded from the PE cache, and ≤ 200 MB + scripts once Roslyn has run in it. An alternative, not built: after a compile burst, recycle the worker from the PE cache (blue/green). 4. **Windows kill-both-shards: about 2.0 s**, right at the budget line. **Evidence:** - Release build of `ZB.MOM.WW.OtOpcUa.slnx` with `--no-incremental`: 0 warnings, 0 errors. - `AKKA_TEST_TIMEFACTOR=3`, after the rebase onto `963b0d66`: ScriptWorker 151 passed / 3 skipped, Core.Scripting 221 / 1, Host 269, Runtime 993 / 3, OpcUaServer.IntegrationTests 132/132. - ScriptWorker.Tests also passed on windev: 150 of 151 on the first run, then the one failure, a windev-only calibration problem in a new #790 test, was fixed and that test re-ran green. - Mutation checks, each red and then reverted: - resuming callers on the reader: the worker was killed for silence; - releasing the slot after handing off the resume: 49 of 50 runs refused; - not re-arming the timer for the grace: the runaway was never killed by the host. - New tests: - reader reassembly at every split, from 1 byte to 1 MB, both sync and async; - malformed frames and a fuzz test for the reader; - writer batching and frame order; - writer fault handling; - `A_caller_that_blocks_after_its_result_does_not_starve_the_reader`; - a deterministic slow-release phase in `A_caller_that_awaited_its_run_is_never_refused_by_it`.
dohertj2 added the type:debt label 2026-11-10 04:34:05 -05:00
dohertj2 changed title from Out-of-process script runner misses §8.2 host-CPU, idle-latency (Windows), kill-latency (Windows) and RSS budgets to [deferred: further tuning] Out-of-process script runner misses §8.2 Windows host-CPU, Windows idle-latency and compiled-worker RSS budgets 2026-11-10 04:34:05 -05:00
Sign in to join this conversation.
No Branch/Tag Specified
Branches Tags
Labels
Clear labels
auto-managed
queue management
 blocked
Blocked by dependency or external hold
 cross-driver
queue management
 cross-repo
Needs coordinated change in another family repo (wire contract etc.)
 driver/abcip
queue management
 driver/ablegacy
queue management
 driver/focas
queue management
 driver/mqtt
MQTT / Sparkplug B broker-subscribe driver
 driver/opcuaclient
queue management
 driver/s7
queue management
 driver/twincat
queue management
 migrated
Migrated from a markdown backlog (2026-11 standardization)
 phase/1
queue management
 phase/2
queue management
 phase/3
queue management
 phase/4
queue management
 phase/5
queue management
 phase/6
queue management
 priority:p0
Must-have / blocking
 priority:p1
High priority
 priority:p2
Normal priority
 priority:p3
Low priority / nice to have
 queue/blocked
queue management
 queue/done
queue management
 queue/failed
queue management
 queue/in-progress
queue management
 queue/queued
queue management
 type:bug
Defect in shipped behaviour
 type:debt
Technical debt / hygiene
 type:deploy-gate
Rollout/deploy/migration step not yet done on an environment
 type:docs
Documentation work
 type:feature
Feature implementation
 type:followup
Follow-up deferred from a plan, PR or gate
 type:infra
Infrastructure and scaffolding
 type:review-finding
Unfixed finding from an architecture/code review
 type:test
Test work
No Label priority:p2 type:debt type:followup
Milestone
No items
No Milestone
Projects
Clear projects
No project
Assignees
Clear assignees
dohertj2 (dohertj2)
No Assignees
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: dohertj2/lmxopcua#789
Delete Branch "%!s()"

Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?