Skip to content

OpenVMM: microVM snapshot commit terminates source without draining portb output (flaky WHP vmm-test) #231

Closed

Description

Summary

ttrpc::test_ttrpc_microvm_linux_direct_lifecycle_and_snapshot failed intermittently in OpenVMM vmm-tests / Windows / WHP on a dev push. The cause is an OpenVMM product defect: when a microVM snapshot is committed, OpenVMM terminates the source process without first draining buffered portb output. Bytes the guest wrote just before requesting the snapshot never reach the source endpoint.

Failing run

  • Run: https://github.com/microsoft/nvx/actions/runs/36445795618/job/109011613889 (attempt 1)
  • Event: push to dev at e878053c970602977210d43b2f8652d3172b5f01. This is not a superseded run.
  • OpenVMM gitlink: nanvix/openvmm@c9f659c36c8cb36d5aac745f7c26808296689f3f
  • Failed step: Run OpenVMM tests on Windows. Required status check failed only as a consequence.
  • The next dev push (67ffaf2, same OpenVMM pin) passed, which is consistent with a timing-dependent failure. e878053 changed only Python release helpers.

Decisive log lines:

INFO state_unit::quiesce: save quiesce complete
INFO openvmm_entry::vm_controller::microvm: microVM snapshot committed; terminating source process
ERROR petri::tracing: test failed error=portb closed before the expected marker after bytes "[    0.000000] Linux version 6.18.38 ..."

The guest script writes OPENVMM-LINUX-MPTABLE-SNAPSHOT-READY to portb (port 0xE9) and then requests a snapshot through port 0x605. The snapshot committed, so the guest had already emitted the marker, yet the source endpoint reached EOF without it. The log has no output buffer full or portb output failed warning, so the device did not drop the bytes.

Root cause (at c9f659c)

  1. Buffered device output. MicrovmPortb::io_write (vm/devices/chipset/src/microvm.rs) appends guest bytes to tx_buffer, which poll_device / poll_tx flush to the socket asynchronously. ChangeDeviceState::stop() makes one non-blocking poll_tx attempt. By design, any remaining bytes are saved in MicrovmPortbSavedState.tx_buffer and replayed after restore.
  2. The snapshot termination path skips the output drain. In openvmm/openvmm_entry/src/vm_controller.rs, Event::SnapshotRequest → GuestSnapshotAction::Terminate { exit_code } sends VmControllerEvent::ExitRequested directly. The normal guest-exit path goes through VmController::request_exit() → guest_exit_event() → MicrovmOutputDrain::drain(), which asks portb to write and flush tx_buffer before closing. The snapshot-commit path never drains.
  3. Result. Any bytes still in tx_buffer at quiesce time move only into the snapshot. The source process exits, the socket closes, and the test's wait_for_bytes sees EOF before the marker. This is timing dependent: the snapshot request immediately follows the marker, and socket write readiness on WHP/Windows (AFD polling) can lag.

Reproduction

This is a deterministic device-level reproduction at c9f659c in chipset (patch below). The guest writes the marker, the endpoint is not yet writable, stop() runs and saves, and the device is dropped without a drain, mirroring the snapshot-terminate path.

cargo test -p chipset --lib microvm::tests::
...
test microvm::tests::repro_snapshot_terminate_loses_marker_left_in_tx_buffer ... FAILED
assertion `left == right` failed: source endpoint closed without the marker; 36 byte(s) moved into the snapshot
  left: []
test result: FAILED. 19 passed; 1 failed
Reproduction test
#[test]
fn repro_snapshot_terminate_loses_marker_left_in_tx_buffer() {
    use futures::executor::block_on;
    let state = Arc::new(Mutex::new(OutputState::default()));
    let mut portb = MicrovmPortb::new(
        Box::new(Connected::new(BufferedOutput(state.clone()))),
        TEST_GENERATION_ID,
        Vec::new(),
    );
    let marker = b"OPENVMM-LINUX-MPTABLE-SNAPSHOT-READY";
    assert!(matches!(portb.io_write(DATA_PORT, marker), IoResult::Ok));
    block_on(portb.stop());
    let saved = portb.save().unwrap();
    drop(portb);
    let state = state.lock();
    assert!(state.closed);
    assert_eq!(
        state.bytes,
        marker,
        "source endpoint closed without the marker; {} byte(s) moved into the snapshot",
        saved.tx_buffer.len()
    );
}

The full end-to-end WHP vmm-test was not rerun locally because the failure is timing dependent.

Proposed fix

  • Product fix (recommended), in nanvix/openvmm. On the snapshot-commit path, drain portb output with a bounded timeout, as request_exit() does, before quiescing and saving. The source then delivers every byte the guest wrote before its snapshot request, and restores no longer replay stale source output. Add regression coverage for the snapshot-terminate path.
  • Test-only alternative. Make the guest wait for a host acknowledgement before requesting the snapshot, or accept the marker from either the source or the restored VM. This hides the product behavior and is not preferred.
  • After the OpenVMM fix merges, promote the pin into NVX with nvx-openvmm-promote.

No upstream nanvix/openvmm commits have touched vm_controller.rs, chipset/src/microvm.rs, or the test since c9f659c.

Activity

  1. added
    confirmedIssue affects multiple people.
    and removed
    bugSomething isn't working
    on Sep 28, 2026
  2. ppenna commented on Oct 1, 2026

    @ppenna
    ContributorAuthor

    Recurrences

    The bug is still present at OpenVMM pin nanvix/openvmm@885fde30f334dc18c1042a0acfe6a1b43c9a7f2b, the current dev gitlink. It has now happened on three different pins.

    Run Event NVX head OpenVMM pin
    36445795618 (original) push to dev e878053 c9f659c
    36526970004 push to dev 220b4f4 e2c982a
    36905413804, attempt 1 pull_request for #291 60558ad 885fde3

    All three logs show the same sequence:

    INFO state_unit::quiesce:  save quiesce complete
    INFO openvmm_entry::vm_controller::microvm:  microVM snapshot committed; terminating source process
    ERROR petri::tracing: test failed error=portb closed before the expected marker after bytes "[    0.000000] Linux version 6.18.38 ..."
    

    In 36905413804 the other 28 WHP vmm-tests passed, along with every other job. #291 changes only scripts/nvx_tools/collect_ubuntu_sources.py and scripts/test_nvx_tools.py, so the failure is unrelated to the pull request.

    Frequency

    Since 2026-09-28, 66 OpenVMM vmm-tests / Windows / WHP jobs completed and 6 failed, all in ttrpc::test_ttrpc_microvm_linux_direct_lifecycle_and_snapshot:

    Still reproducible at 885fde3

    The device-level reproduction from the issue description still fails at 885fde30f:

    cargo test --locked -p chipset --lib microvm::tests::
    test microvm::tests::repro_snapshot_terminate_loses_marker_left_in_tx_buffer ... FAILED
    assertion `left == right` failed: source endpoint closed without the marker; 36 byte(s) moved into the snapshot
    test result: FAILED. 19 passed; 1 failed
    

    The code paths are unchanged:

    • In openvmm/openvmm_entry/src/vm_controller.rs, the Event::SnapshotRequest handler sends GuestSnapshotAction::Terminate straight to VmControllerEvent::ExitRequested and never calls request_exit(), so MicrovmOutputDrain never runs.
    • MicrovmPortb::stop() in vm/devices/chipset/src/microvm.rs still makes only one non-blocking poll_tx attempt.

    nanvix/openvmm#58 added the drain for guest-requested exit only. As of 2026-10-01, no open nanvix/openvmm pull request fixes the snapshot-commit path (nanvix/openvmm#103, nanvix/openvmm#105 and nanvix/openvmm#106 do not), and main is only 2 commits ahead of 885fde3, neither of them related.

    I am rerunning the failed job on 36905413804 to unblock #291.

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

Metadata

Metadata

Labels

confirmedIssue affects multiple people.

Type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions