[Pedro Henrique Penna (ppenna)]

Part of #1076: exec-lock-flake. Fixes two flaky tests of the CLI's exec lock, which #1469 (SL3.9) added. Only the tests change.

What and why

Symptom. exec_lock::exec_processes_contend_but_other_sandboxes_and_stop_proceed failed in the job nvx-rs / windows-latest of run 43345750757 (#1555) and of run 43234396201, attempt 1 (#1533), and once on a loaded Windows workstation:

thread 'exec_lock::exec_processes_contend_but_other_sandboxes_and_stop_proceed' (5232) panicked at tests\cli\exec_lock.rs:132:5:
assertion `left == right` failed: nvx-rs ["sandbox", "stop", "--state-dir", "C:\\...\\first", "--timeout", "0.1"] exited with Some(1)
stderr: error[still-running]: cannot confirm exit of VM process 6580

Its sibling exec_lock::a_retry_that_waits_for_the_lifecycle_lock_past_the_deadline_is_busy failed once on a loaded workstation too. Under load it fails with no round delayed a retry of the exec past its deadline.

Root cause of the stop's failure. With --timeout T, sandbox stop (host/cli/sandbox/lifecycle/stop.rs) works in two windows:

1. A grace of T: it attaches with a deadline of T, sends STOP with what is left of the grace, and waits for OpenVMM to exit until the grace ends.
2. stop_verified then takes a fresh Deadline::after(T). terminate_within calls vm::stop with no grace and a 25 ms bound, which terminates the verified process (TerminateProcess on Windows) and waits 25 ms, and then wait_for_exit waits until that deadline. A process that still runs then is TimedOut: the stop fails with still-running (with no "forced termination failed", so the termination itself succeeded) and keeps the runtime record.

So T bounds the grace and, separately, the confirmation of the termination: with T = 0.1, about 100 ms after TerminateProcess returns. In this test the stop always forces the VM: the fake OpenVMM serves one control session at a time (one named-pipe instance on Windows, accepts one by one on Unix), the exec's session, whose workload sleeps for a minute, holds it, and the stop's attach fails after T (managed guest shutdown failed: ... control endpoint is busy). NVXC v2's cancellation of an exec by a shutdown (SL4.4b) applies to a STOP in the exec's own session, so a longer grace can't make this stop graceful.

Windows ends a terminated process asynchronously, and a loaded host takes a while to show it. With an instrumented copy of the test (not committed), which terminates the fake OpenVMM during the exec as the stop does and times Process::wait, with the test and its load pinned to the same CPUs (the load being two loops of the rest of the CLI suite with 16 test threads each):

CPUs	Samples	p50	p90	Max	Over 100 ms
20, idle	1	2 ms			0
2	40	11 ms	72 ms	189 ms	3
1	40	94 ms	641 ms	1378 ms	19

A test problem, not a product one. The stop behaves as documented, which lets a termination that is not confirmed in time fail:

• vm::stop's rustdoc: "If exit is still unconfirmed, attempts forced termination and waits until deadline. [...] An unconfirmed exit fails with ErrorKind::StillRunning". terminate_within's: "waits until deadline for it to exit [...] One that still runs at the deadline is StopOutcome::TimedOut [...] keep the record."
• doc/run.md: "A stop that cannot determine the OpenVMM process, whose terminated OpenVMM does not exit in time, or whose wait Ctrl-C ends, keeps the sandbox's runtime record, and the next stop retries", and, for a VM of another runtime identity, "stop terminates its OpenVMM without a guest shutdown, waits up to --timeout seconds for it to exit".
• doc/usage.md, still-running: "A stop could not confirm the VM process's exit, so the caller keeps its verified process."
• Design 5.2, Table 5.2: Stop "reports an exit only once it is confirmed"; 5.6: StillRunning is "for an exit that it could not confirm".

The 0.1-second budget was the test's own: it asked the stop to confirm a termination within 100 ms.

Root cause of the retry race's failure. The sibling needs an exec whose retry waits for the lifecycle lock until after its --wait deadline. The exec holds that lock only while it tries the exec lock, briefly, every 25 ms or so, so the test polls it with try_lock until it finds a try, and takes it; it accepts a try found within the first half of --wait (4 s) after the spawn. A round that misses gives way to another, and the test fails after 5. Two things made rounds miss under load:

1. The poll loop yielded after each try (thread::yield_now(), SwitchToThread on Windows), which on a busy processor lets every other ready thread run first. On one loaded CPU, most rounds polled only tens of times in their 4 to 5 seconds, and the exec's tries passed unseen.
2. Its window, 2 s from the spawn, is shorter than a loaded host can take to start the exec and let the test find one of its tries.

Rounds that reached the precondition, with an instrumented copy of the test under the load above (not committed). Each run interleaved its two variants under the same load:

Run	CPUs	--wait	Poll	Rounds	Found a try	Reached
A	2	4 s	yields (before)	20	19	17
A	2	4 s	spins	20	20	20
B	1	4 s	yields (before)	20	12	8
B	1	4 s	spins	20	14	9
C	1	4 s	spins	15	11	3
C	1	8 s	spins (after)	15	13	11

Fix.

• The stop of exec_processes_contend_but_other_sandboxes_and_stop_proceed takes --timeout 5, with a comment that says why. Its grace stays far below the minute that the workload sleeps, so it still forces the VM, and forcibly terminated still holds, now with 5 s to confirm the termination. It takes about 5 s, the time that its attach waits for the busy endpoint, and still ends well within the test's 30-second bound, which still shows that it waited neither for the exec lock nor for the workload.
• a_retry_that_waits_for_the_lifecycle_lock_past_the_deadline_is_busy polls without yielding, and its exec's --wait is 8 s, with comments: a round finds a try within 4 s, and the precondition keeps half of --wait, now 4 s, before the exec's deadline. A reached round holds the lifecycle lock for 8.5 s instead of 4.5 s.

Every assertion of both tests stays. No product code, default, or retry changes.

Not changed here.

• doc/usage.md's --timeout row lists the stop's control requests, its wait for the VM to exit once the guest shuts it down, and its wait for the lifecycle lock, but not its wait after a forced termination, which doc/run.md describes.
• On one CPU loaded with 32 test threads, the sibling still failed once in 15 runs, as it did before (below): finding a try there needs the exec to be preempted in the middle of one.
• stop_forces_the_verified_vm_after_its_grace_period_even_after_an_acknowledgement in tests/cli.rs gives its forced stops 1 s to confirm the termination, which the one-CPU maximum above exceeds; it has not been seen failing.

Size

0 core lines in 0 counted files: the change is in nvx-rs/tests/cli/exec_lock.rs alone, with 17 lines added and 11 removed.

Changes to existing tests

python scripts\check_test_changes.py --base origin/feature/nvx-refactor lists 2 changes to existing tests, hence tests-modified:

• exec_processes_contend_but_other_sandboxes_and_stop_proceed: its stop's --timeout goes from 0.1 to 5, with a comment that explains the stop's two windows. Every assertion stays.
• a_retry_that_waits_for_the_lifecycle_lock_past_the_deadline_is_busy: WAIT goes from 4 s to 8 s, and its poll loop no longer calls thread::yield_now(), with comments. Every assertion stays.

doc/acceptance-case-matrix.md lists no test of nvx-rs/tests/cli/, so no row changes.

Validation

Stress, before and after, on a Windows workstation (20 logical CPUs): the base's and this change's test binaries, both built on ab2673e7751, ran the test one after the other, in turns, under the same load, pinned to the same CPUs with start /affinity. Load: two loops of the rest of the CLI suite (cli.exe --skip TEST --test-threads 16).

Test	CPUs	Before (base)	After
exec_processes_contend_but_other_sandboxes_and_stop_proceed	2	10 of 30 failed, each with still-running at line 132; 2 of 15 in an earlier run	0 of 30 (median 11.4 s, max 21.3 s)
a_retry_that_waits_for_the_lifecycle_lock_past_the_deadline_is_busy	2	0 of 12 (7.3 to 13.7 s)	0 of 12 (10.6 to 14.5 s)
a_retry_that_waits_for_the_lifecycle_lock_past_the_deadline_is_busy	1	1 of 15 failed (no round delayed a retry); 1 of 10 in an earlier run	1 of 15 failed (no round delayed a retry)

CPU-bound load alone (busy loops) failed neither test before the change.

Check	Result
cargo fmt --all --check	Passed
cargo clippy --locked --all-targets --all-features -- -D warnings, the only Clippy run that compiles tests/cli	Passed on Windows and on Linux (nvx-mshv-test)
cargo test --locked --all-features --test cli exec_lock::	Windows: 6 passed (9.3 s). Linux, nvx-mshv-test (Azure Linux 3, kernel 6.18, 8 vCPUs): 5 passed
cargo test --locked --all-features --test cli	Windows: 113 passed, 2 ignored (30.6 s). Linux, nvx-mshv-test: 123 passed in 62.1 s, as the base did on the same host (62.1 s)
cargo +1.89 check --locked --all-targets --all-features (MSRV)	Passed on Linux
python scripts\check_test_layout.py	Passed
python scripts\check_test_changes.py --base origin/feature/nvx-refactor	2 changes to existing tests, above
Code-review subagent	No issues

Every check but the Windows exec_lock:: run ran on this commit before its rebase onto ecd6e02d85f, which changes rustdoc, docs, and scripts only (git range-diff shows no change); the Windows exec_lock:: run is on the rebased head.

The stop's stderr on Windows with --timeout 5, which took 5.02 s: warning: managed guest shutdown failed: Error { code: TimedOut, message: "the control connection timed out: control endpoint is busy" }, warning: OpenVMM was forcibly terminated after managed stop, warning: the forced stop produced no outcome report.

Left to CI: the rest of cargo test and the other gates, which this change doesn't touch. No microVM scenario runs these tests.

[github-actions]

This pull request changes existing tests

It modifies or removes 2 existing test asset(s), listed below. Review each with care: a change to a test can hide a regression that the test caught. See doc/contribute.md#changes-to-existing-tests.

Test code

Change	What	Before	After
modified test	fn exec_processes_contend_but_other_sandboxes_and_stop_proceed in cli/exec_lock (tests)	nvx-rs/tests/cli/exec_lock.rs:78	nvx-rs/tests/cli/exec_lock.rs:78
modified test	fn a_retry_that_waits_for_the_lifecycle_lock_past_the_deadline_is_busy in cli/exec_lock (tests)	nvx-rs/tests/cli/exec_lock.rs:184	nvx-rs/tests/cli/exec_lock.rs:188

Relocated unchanged: 0; added: 0. Compared the merge base 05cb371d6be2 with 0e8dae6f46f4.

[Copilot]

🟢 Approval recommended

No active review issues were identified for the test-only exec-lock timing adjustments.

No open issues 🎉

What changed in this PR

This tests-only PR reduces timing sensitivity in the CLI exec-lock tests on loaded hosts, supporting the NVX refactoring workstream without changing product behavior.

Changes:

• Increases the contention test’s stop timeout from 0.1 to 5 seconds to allow forced-termination confirmation.
• Extends the retry-race admission wait from 4 to 8 seconds and removes yielding from its polling loop.
• Documents the timing rationale while preserving all existing assertions.

File	Description
nvx-rs/​tests/​cli/​exec_lock.rs	Adjusts timing and polling in two exec-lock tests for loaded hosts.

_{Review effort: Balanced}