Skip to content

host: never expire a restore step before its deadline (SL4.3 follow-up) - #1483

Merged
Pedro Henrique Penna (ppenna) merged 1 commit into
feature/nvx-refactorfrom
agents/slim-sl4-3-deadline
Nov 11, 2026
Merged

Pedro Henrique Penna (ppenna) merged 1 commit into
feature/nvx-refactorfrom
agents/slim-sl4-3-deadline

Conversation

@ppenna

Copy link
Copy Markdown
Contributor

Part of #1076. Follow-up to #1476 (SL4.3).

What and why

Symptom. The push CI of feature/nvx-refactor failed on Windows at a53a2626d6c (run 42994995631), and earlier at d40228be1ca (run 42993194889). In both, the job nvx-rs / windows-latest failed in the restore driver's test that SL4.3 (#1476) added:

test host::restore_driver::tests::ready_has_sixty_seconds_and_start_thirty_from_ready_for_each_pending_accept_and_read ... FAILED
panicked at src\host\restore_driver\tests.rs:489:9:
activate-read: 59.9994275s, Machine(RestoreError { phase: Activate, attribution: Unknown, evidence: Expired, guest_may_have_run: true, message: "restore failed during Activate: Expired", source: None })

The test starts its clock before it calls restore, which allows 60 s until the guest's Ready, so the driver reported that budget as expired before 60 s had passed (59.9993305 s in the earlier run). The failure is intermittent. Of the four finished push runs since SL4.3 merged, it failed at d40228be1ca and a53a2626d6c and passed at 35cedfdbc3a (run 42989576833) and ab7c9b5f58c. It also failed once on a developer's Windows machine.

Root cause. The driver reports Expired when a step fails with SessionError::TimedOut, which HostConnection returns when its transport's read or write times out. On Windows, PipeTransport runs each read and write as overlapped I/O through overlapped(). That function waited once with WaitForSingleObject for the time left, truncated to whole milliseconds, then cancelled the operation and reported TimedOut. WaitForSingleObject times out at a tick of the system timer, about every 15.6 ms, by the interrupt time, not by the QueryPerformanceCounter that Instant reads. When a tick fell within the truncated fraction of a millisecond, the wait ended before the caller's deadline by Instant, and the step failed Expired early. Every step that waits in a pipe transfer is exposed: the attach, activate and mapping-table reads that the test stalls, and the writes. The early expiry comes from nowhere else:

  • The driver waits for the restore-ready event and for a connection in slices of at most 50 ms, and it checks its deadline by Instant before each slice, so a slice that ends early only starts another.
  • RestoreMachine reads no clock. The driver gives it Expired only when a step fails with TimedOut.
  • On Linux, the transport's socket timeouts and polls end by CLOCK_MONOTONIC, which Instant reads. None of 300 SO_RCVTIMEO reads on nvx-kvm-test timed out early.

Fix. overlapped() takes its caller's deadline rather than a timeout, and waits through the new wait_until. When WaitForSingleObject times out before the deadline by Instant, wait_until waits again for what is left, and sleeps a remainder below a millisecond before a last check, as ProcessHandle::wait already does with wait_step. A pipe read, write or restore-ready accept therefore never times out before its deadline. PipeTransport::read turns its timeout into a deadline when it starts, and write_all and ReadyListener::receive pass the deadlines that they already computed. The fix belongs in the transport, which owns the wait, not above it: HostConnection treats a transport's TimedOut as final, and a write that the transport cancels may have sent part of a record, which ends the connection. No test's assertion, budget or timeout changes.

Before and after, on a Windows 11 workstation whose waits time out at ticks of about 15.6 ms, and on nvx-kvm-test:

Check At the base a53a2626d6c With the fix
The new a_wait_that_times_out_early_waits_again_until_its_deadline: wait_until, with a wait that always times out at once, returns only after its deadline has passed by Instant fails, with the former single truncated wait put back passes
PipeTransport::read of an idle pipe, 300 timeouts of 20 to 40 ms at random phases of the timer (a scratch test, not committed) 7 and 8 of 300 reads timed out early, by up to 0.87 ms 0 of 300, twice
The 60/30 s restore test, Windows 1 of 10 sequential runs failed (activate-read, Expired after 59.9999802 s), and 0 of 15 parallel runs 36 of 36 passed before the rebase (35 runs and the --all-features suite), and 8 of 8 after it
The 60/30 s restore test, Linux (nvx-kvm-test) not run 6 of 6 passed (5 runs and the module's tests)

Size

Measured against 66fd43145ce: 31 core lines in 1 counted file, host/platform/windows/endpoint.rs. The new test adds 16 lines to host/platform/windows/endpoint/tests.rs.

Not in this PR

The Linux transport, whose waits already end by the clock that Instant reads, and Windows waits that a restore's steps don't use.

Validation

On the head c09a914e1e1, rebased onto 66fd43145ce with no change to its content (git range-diff against 25ccafc6f30 on a53a2626d6c), on the local Windows 11 workstation, in nvx-rs/ with NVX_BUNDLE=skip:

Check Result
cargo fmt --all --check passed
cargo clippy --locked with -D warnings: --all-targets --all-features, --lib, --lib --no-default-features, --lib --bins --features cli, --lib --bins --no-default-features --features testing passed, all five
cargo test --locked --features cli --lib -- host::platform::windows::endpoint 5 passed, 1 ignored (a subprocess helper)
ready_has_sixty_seconds_and_start_thirty_from_ready_for_each_pending_accept_and_read, 4 parallel workers, 2 runs each 8 of 8 passed
python scripts\check_test_layout.py passed
python scripts\check_test_changes.py --base origin/feature/nvx-refactor 0 changes to existing tests, 1 added

Before the rebase, on the same tree on a53a2626d6c, every Windows gate that local_gates.py selects for these files passed, run with this branch's commands from check-nvx-rs, check-quality and validate-nvx:

  • cargo test --locked --all-features (1456 library tests, the integration tests and the doctests), cargo test --locked, and the --lib --no-default-features build and tests (283).
  • Artifact bundling (21 tests), cargo doc --no-deps --all-features with -D warnings, and the MSRV 1.89 cargo check --all-targets --all-features.
  • The runtime adapter's protocol-only and host-only configurations: fmt, Clippy, build, tests, doc and MSRV.
  • Markdown links, and nvx-cli: compileall, the 1834 script unit tests, the adversarial and host tests, and nvx.py's help. Its pip install step was skipped because its packages were already installed.

On Linux (nvx-kvm-test, an Azure Linux 3 VM with KVM and kernel 6.6), on the same tree, these passed: fmt, the five Clippy configurations, cargo test --locked, the --lib --no-default-features build and tests, cargo doc with -D warnings, the MSRV 1.89 check and scripts/public_api.py. cargo test --locked --all-features failed only the 28 guest:: tests that fail at the base on that host. This change compiles only on Windows, so the Linux build is the base's.

Not run locally: the WHP microVM scenarios that local_gates.py selects, because this workstation has no built nvx-rs or artifacts. Left to CI: those scenarios, the other backends' suites, and the full Linux and Windows suites at this head.

check_test_changes.py lists no change to an existing test, so this PR has no tests-modified label.

The feature branch's push CI failed on Windows at a53a262 (run
42994995631) in the activate-read case of the restore driver's test
ready_has_sixty_seconds_and_start_thirty_from_ready_for_each_pending_accept_and_read:
the restore failed Expired after 59.9994275 s by the test's clock,
which starts before the restore, so the driver reported the 60 s Ready
budget as expired before 60 s had passed. The test passes most of the
time.

The driver reports Expired when a session step fails with TimedOut,
which a transfer on the Windows control pipe returns once the wait for
its overlapped operation times out. That wait was a single
WaitForSingleObject for the time left, truncated to whole
milliseconds, and WaitForSingleObject times out at a tick of the
system timer, of about 15.6 ms, by the interrupt time rather than by
the QueryPerformanceCounter that Instant reads. When a tick fell
within the truncated fraction of a millisecond, the wait timed out
before the deadline by Instant, the operation was cancelled, and the
step failed Expired early; the timer can also end a wait slightly
before its whole milliseconds by Instant.

overlapped() now takes its caller's deadline rather than a timeout,
and waits through wait_until: when WaitForSingleObject times out
before the deadline by Instant, it waits again for what is left, and
it sleeps a remainder below a millisecond before a last check, as
ProcessHandle::wait does with wait_step. A pipe read, write or
restore-ready accept thus never times out before its deadline.
PipeTransport::read turns its timeout into a deadline, and write_all
and ReadyListener::receive pass their own. The Linux transport needs
no change: its socket timeout and polls run on the kernel's monotonic
clock, which Instant reads, and never end early.

Evidence, on a Windows 11 host whose waits time out at ticks of about
15.6 ms: PipeTransport::read on a pipe with nothing to read, with
timeouts of 20 ms to 40 ms at random phases of the timer, timed out
before its timeout in 7 and 8 of 300 reads at a53a262, by up to
0.87 ms, and in none of 2 x 300 with the fix. The restore driver's
test failed 1 of 10 runs at a53a262 (activate-read, Expired after
59.9999802 s) and none of 15 more that ran beside the fix's; with the
fix it passed 36 of 36 runs. On nvx-kvm-test (Linux, KVM) it passed 6
of 6 runs, and none of 300 SO_RCVTIMEO reads timed out early.

Tests: wait_until, with a wait that always times out at once, returns
only once its deadline has passed by Instant, and with a deadline that
has passed checks the event once. The test fails with the former
single truncated wait.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟢 Approval recommended

No active review issues are reported for the Windows named-pipe deadline changes.

No open issues 🎉

What changed in this PR

This follow-up to #1476 prevents Windows named-pipe operations used by the blocking restore driver from reporting a timeout before the caller’s deadline.

Changes:

  • Pass absolute deadlines through overlapped pipe operations and retry waits that time out early.
  • Add a regression test covering early timeouts and event checks after a deadline has passed.
File Description
nvx-rs/​src/​host/​platform/​windows/​endpoint/​tests.rs Tests deadline enforcement and nonblocking event checks at expired deadlines.
nvx-rs/​src/​host/​platform/​windows/​endpoint.rs Adds deadline-aware waiting for pipe reads, writes, and restore-ready connections.

Review effort: Balanced

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants