Script runner load timeout counts the time a load waits behind other compiles #790

New Issue

2026-11-10T02:53:14-05:00

dohertj2 commented

2026-11-10 02:53:14 -05:00

Found while fixing the compile-burst heartbeat starvation (lmxopcua#780, 2026-11-10).

In OutOfProcessScriptRunner.RunAsync, each caller waits at most LoadTimeout (60 s) for EnsureLoadedAsync(...). That clock starts when the host asks for the load. The worker now compiles on min(8, max(1, CPUs/2)) dedicated threads, so a load can sit in the worker's queue behind hundreds of others.

On windev, 1,500 cold compiles on one shard take about 18 s. A larger cold load can therefore push the last keys past 60 s while no compile is actually stuck: a big node start with an empty PE cache, or a slower box. When that happens, the runner kills the worker with KilledLoadTimeout and strikes the key whose timer fired. That key is innocent; it was only queued. Every other key in flight becomes a victim.

Fix shape.

Have the worker report when it starts compiling a key (a LoadStarted frame, or a per-outcome compile-duration field), and apply the timeout from that moment.
Or apply the timeout only to the oldest outstanding load per connection.

Pin it with a test that queues more compiles than fit in LoadTimeout and asserts no kill and no strike.

Found while fixing the compile-burst heartbeat starvation (lmxopcua#780, 2026-11-10). In `OutOfProcessScriptRunner.RunAsync`, each caller waits at most `LoadTimeout` (60 s) for `EnsureLoadedAsync(...)`. That clock starts when the **host** asks for the load. The worker now compiles on `min(8, max(1, CPUs/2))` dedicated threads, so a load can sit in the worker's queue behind hundreds of others. On windev, 1,500 cold compiles on one shard take about 18 s. A larger cold load can therefore push the last keys past 60 s while no compile is actually stuck: a big node start with an empty PE cache, or a slower box. When that happens, the runner kills the worker with `KilledLoadTimeout` and strikes the key whose timer fired. That key is innocent; it was only queued. Every other key in flight becomes a victim. **Fix shape.** - Have the worker report when it **starts** compiling a key (a `LoadStarted` frame, or a per-outcome compile-duration field), and apply the timeout from that moment. - Or apply the timeout only to the oldest outstanding load per connection. Pin it with a test that queues more compiles than fit in `LoadTimeout` and asserts no kill and no strike.

dohertj2 added the type:bug priority:p2 labels 2026-11-10 02:53:14 -05:00

dohertj2 referenced this issue from a commit

2026-11-10 03:00:53 -05:00

feat(scripting): self-contained script worker publish, docker-dev drill, §8 perf harness (lmxopcua#780 P1)

dohertj2 referenced this issue

2026-11-10 03:01:18 -05:00

Implement the out-of-process script runner (design #750) — code on master; QA shadow week (#793, #794) + P3 flip remain #780

dohertj2 referenced this issue from a commit

2026-11-10 04:33:21 -05:00

perf(scripting): cut out-of-process runner host CPU; compile timeout from compile start; quiet start-failure logs (lmxopcua#789, #790, #788)

dohertj2 referenced this issue

2026-11-10 04:34:03 -05:00

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

dohertj2 commented

2026-11-10 04:34:04 -05:00

Fixed on master @ 8582ce91.

When a compile thread picks a load up, the worker now sends a new LoadStarted { load_id } frame.
The host arms that load's compile timer at that moment. It no longer starts per caller at enqueue.
A load that is only waiting in the queue is therefore never killed or struck.
A compile that is still running LoadTimeout after it started kills the worker. Only that key takes the strike, through LoadEntry.TimedOut → KilledLoadTimeout, and the caller gets compile failure: compile did not finish within N s.
Hello.compile_threads is a test knob; the default is 0, which keeps the worker's own default.

Tests (SupervisionTests):

Compiles_queued_behind_others_longer_than_the_load_timeout_are_not_killed_or_struck
- Runs with one compile thread. The compiler is warmed up first, then the live connection's timeout is lowered to max(3 s, 4 × one measured compile).
- The burst is grown until it outlasts three timeouts. The test asserts this, so it cannot pass vacuously.
- It asserts no kill, the same pid, no quarantine and no suspects.
- Mutation check: with the timer armed when the host sends the load, it fails with compile did not finish.
A_compile_still_running_a_load_timeout_after_it_started_is_killed_and_struck (positive control)
- A 20,000-statement script and a 2 s timeout give KilledLoadTimeout naming that key, twice, and then quarantine.
- The healthy key on the same shard is not blamed.
- Mutation check: with the timer never armed, the huge compile simply finishes.

Both pass on macOS and on windev. All suites pass; see #789 for the numbers. Closing.

**Fixed on `master` @ `8582ce91`.** - When a compile thread picks a load up, the worker now sends a new `LoadStarted { load_id }` frame. - The host arms that load's compile timer at that moment. It no longer starts per caller at enqueue. - A load that is only waiting in the queue is therefore never killed or struck. - A compile that is still running `LoadTimeout` after it started kills the worker. Only that key takes the strike, through `LoadEntry.TimedOut` → `KilledLoadTimeout`, and the caller gets `compile failure: compile did not finish within N s`. - `Hello.compile_threads` is a test knob; the default is 0, which keeps the worker's own default. **Tests (`SupervisionTests`):** - `Compiles_queued_behind_others_longer_than_the_load_timeout_are_not_killed_or_struck` - Runs with one compile thread. The compiler is warmed up first, then the live connection's timeout is lowered to max(3 s, 4 × one measured compile). - The burst is grown until it outlasts three timeouts. The test asserts this, so it cannot pass vacuously. - It asserts no kill, the same pid, no quarantine and no suspects. - Mutation check: with the timer armed when the host sends the load, it fails with `compile did not finish`. - `A_compile_still_running_a_load_timeout_after_it_started_is_killed_and_struck` (positive control) - A 20,000-statement script and a 2 s timeout give `KilledLoadTimeout` naming that key, twice, and then quarantine. - The healthy key on the same shard is not blamed. - Mutation check: with the timer never armed, the huge compile simply finishes. Both pass on macOS and on windev. All suites pass; see #789 for the numbers. Closing.

dohertj2 closed this issue

2026-11-10 04:34:04 -05:00

Sign in to join this conversation.

1 Participants

Notifications

Due Date

No due date set.

Dependencies

No dependencies set.

Reference: dohertj2/lmxopcua#790