runtime-adapter: reach_guest gives up on connections that Windows still opens, so allowed_host_loopback_publishes_the_listeners fails (flaky NVX microVM tests / Windows / WHP) #1033

Summary

The dev push run for cc7b8b3 (#925) failed in NVX microVM tests / Windows / WHP / Guests and sandboxes because the runtime adapter scenario vm_layered allowed_host_loopback_publishes_the_listeners never exchanged a line with a listener of the guest that OpenVMM publishes on host loopback. The guest's listener, an nc -l that serves one client, printed listener 0 without the host's answer: it served one client, which sent nothing and closed.

#925 did not cause this: it changes neither vm_layered.rs, nor the guest's announcer, nor the openvmm gitlink, and vm_layered.rs is byte-identical on the current dev head. The test races Windows: reach_guest connects with a 1 s timeout, while Windows retries a refused loopback connection every 0.5 s for about 2 s, so a retry that lands on the deadline can open a connection that reach_guest has given up on and closed. OpenVMM relays that connection to the guest, whose listener takes it for its one client, and the host's later attempts find no listener. A replica of reach_guest reproduces this in about 1% of trials on a Windows workstation, without a hypervisor. This is a flaky test, not a product defect.

Incident

• Workflow: CI run 40950585891, attempt 1, push to dev.
• Head: cc7b8b35fda7e57e334d369abee79061d35817de, the merge of nvx-rs: serve shorter images, and restore clones in RAM without a scratch file #925. Push runs on dev queue rather than cancel each other, so this run was not superseded.
• Failed job: NVX microVM tests / Windows / WHP / Guests and sandboxes, step Run runtime adapter scenarios on Windows, which runs python scripts\nvx.py test-runtime-adapter --backend whp (run-nvx-microvm-tests.yml#L1317-L1323). Of the suite's 155 scenarios, this was the only failure, and the job's earlier steps passed.
• Runner: self-hosted azure-windows-4 (self-hosted, windows, whp, virtual-machine, general), an Azure VMSS instance, runner 2.337.0.
• Downstream: Required status check failed, and Performance regression gate, Persist performance baseline, Publish development release, Package nvx crate, and Publish nvx crate were skipped.

Decisive output:

test allowed_host_loopback_publishes_the_listeners ... FAILED
…
---- allowed_host_loopback_publishes_the_listeners stdout ----

thread 'allowed_host_loopback_publishes_the_listeners' (3176) panicked at tests\vm_layered.rs:3002:5:
assertion `left == right` failed: 127.0.0.1:58617: {"epoch": "4", "exec.1.cause": "none", "exec.1.launch": "started", "exec.1.settled": "reusable", "exec.1.status": "exit 0", "exec.1.stderr": "", "exec.1.stdout": "listener 0\\n", "exec.1.truncated": "none", "instance": "ca442cfd29b0d766ae4d8311451e525c", "pid": "1864", "reattached": "live"}
  left: false
 right: true
…
test result: FAILED. 42 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 56.79s
…
the runtime adapter's suite of 155 scenarios failed:
  vm_layered allowed_host_loopback_publishes_the_listeners: FAILED
  vm_layered passed 42 tests, not 43

The 43 vm_layered scenarios ran in parallel, from 23:43:56.98Z; this one failed at 23:44:36.34Z. The output does not say whether the scenario's positive control or its own VM failed: both check a published listener the same way.

History

I checked the logs of every failed runtime adapter step in the CI runs created since 2026-10-26, a day before #883 added the scenario, that failed, were cancelled, or were rerun: about 125 of 367 runs. This is the only failure with this signature. Two other checks of a listener over host loopback failed differently, and this race does not explain them, since Linux fails a loopback connection to a closed port at once:

The other failed runtime adapter steps in that window failed vm_clone scenarios, one of which #1020 tracks, or stopped before they reported a scenario.

Root cause

Permalinks point to cc7b8b3 and to OpenVMM's c32c57d, its openvmm gitlink. vm_layered.rs is byte-identical on the current dev head, 8dffced.

1. The guest's listener serves one client. check_guest_listener (vm_layered.rs#L2968-L3009) runs LISTENER_SCRIPT (#L232-L236), printf '%s\n' "$3" | timeout "$2" nc -l -p "$1"; echo "listener $?", in the guest, while a thread of the host runs reach_guest (#L3011-L3042) until the execution ends. nc stops listening once it accepts a client, and the script prints listener 0 once that client closes its side. Without the host's answer before it, listener 0 means that a connection reached the listener and closed without sending anything.
2. OpenVMM publishes the listener once the guest announces it. The guest's announcer reads its socket tables every 100 ms (mod.rs#L100) and sends its listeners to OpenVMM's gateway, which binds the guest's port on host loopback once an announcement names it (ingress.rs#L190-L276). Until then, nothing listens at the port of host loopback that reach_guest connects to.
3. Windows retries a refused loopback connection. Windows answers the reset of a connection to a loopback port that nothing listens on by sending the SYN again, 0.5 s, 1.0 s, 1.5 s, and 2.0 s after the connection began, and fails the connection about 2.04 s after it began; a listener that appears in the meantime takes the next retry. reach_guest gives each attempt TcpStream::connect_timeout(&address, Duration::from_secs(1)) (#L3017), so its attempts time out rather than fail, and the retry at 1.0 s lands on the timeout.
4. A retry at the deadline opens a connection that the host has given up on. When OpenVMM publishes the port between 0.5 s and 1.0 s into an attempt, the 1.0 s retry can complete the handshake with OpenVMM's listening socket just as connect_timeout returns TimedOut and drops its socket, which closes the new connection. OpenVMM accepts that connection all the same and opens one to the guest's port for it (tcp.rs#L795-L905, #L1535-L1544). The guest's nc accepts it, greets it, reads the end of the stream that the host already sent, and ends: listener 0. The host's later attempts find no listener, since nc no longer listens, and reach_guest returns false once the execution ends, which fails assert_eq!(exchanged, reached, …) (#L3002).
5. Linux does not retry. It fails a loopback connection to a closed port at once, so an attempt never times out there, and the race is Windows' alone.

Since #978, vm_clone.rs has its own reach_guest (vm_clone.rs#L4232-L4264), with the same timeout, for the checks of assert_listener (#L1548-L1595), whose LISTENER (#L444-L449) serves one client too.

Reproduction

I used a 20-thread Windows 11 Enterprise workstation (10.0.26300), without a hypervisor.

• Windows' retries. A blocking connection to a closed loopback port failed after 2.035–2.045 s (3 runs). A listener bound d s after a connection began took it at 0.50–0.52 s for d up to 0.50 s, at 1.01–1.03 s for d from 0.55 s to 1.00 s, at 1.51–1.53 s for d from 1.05 s to 1.50 s, and at 2.01–2.05 s for d from 1.55 s to 2.00 s; from 2.05 s, the connection had failed.
• The race. A replica of reach_guest, with its timeouts and its 100 ms pause, runs against a listener that appears 0–3 s after the client starts, greets its first client, and stops listening once it accepted it, as nc does. It runs 64 trials at a time, each on a port of its own.

In each failure, the listener's one client sent nothing, and reach_guest returned false. Each such listener appeared 0.5–1.0 s into one of the client's attempts, which last about 1.1 s: at 0.54–0.95 s, 1.77–2.07 s, or 2.78–2.97 s. One more failed trial, whose listener received the answer, came from two parallel trials that drew the same port, and is left out.

[package]
name = "reach-guest-race"
version = "0.1.0"
edition = "2024"

//! Runs `reach_guest` of tests/runtime-adapter/tests/vm_layered.rs, with counters,
//! against a listener that appears after a random delay and serves one client, as
//! the guest's `nc -l` does once OpenVMM publishes it, and reports the trials in
//! which that client sent nothing while `reach_guest` never exchanged its line.
use std::io::{Read, Write};
use std::net::{Ipv4Addr, Shutdown, SocketAddr, TcpListener, TcpStream};
use std::sync::atomic::{AtomicBool, AtomicU64, Ordering};
use std::thread;
use std::time::{Duration, Instant};

const GREETING: &str = "RUNTIME-ADAPTER-GUEST";
const ANSWER: &str = "RUNTIME-ADAPTER-HOST";

static ATTEMPTS: AtomicU64 = AtomicU64::new(0);
static TIMEOUTS: AtomicU64 = AtomicU64::new(0);
static BLOCKING: AtomicBool = AtomicBool::new(false);

// `reach_guest` of vm_layered.rs at cc7b8b3, with counters; `blocking` connects
// without a timeout instead.
fn reach_guest(address: SocketAddr, stop: &AtomicBool) -> bool {
    while !stop.load(Ordering::SeqCst) {
        ATTEMPTS.fetch_add(1, Ordering::Relaxed);
        let attempt = if BLOCKING.load(Ordering::Relaxed) {
            TcpStream::connect(address)
        } else {
            TcpStream::connect_timeout(&address, Duration::from_secs(1))
        };
        match attempt {
            Ok(mut stream) => {
                stream.set_read_timeout(Some(Duration::from_secs(5))).unwrap();
                let mut greeting = Vec::new();
                let mut byte = [0];
                while !greeting.ends_with(b"\n") && matches!(stream.read(&mut byte), Ok(1)) {
                    greeting.push(byte[0]);
                }
                if greeting == format!("{GREETING}\n").as_bytes() {
                    stream.write_all(format!("{ANSWER}\n").as_bytes()).unwrap();
                    stream.shutdown(Shutdown::Write).unwrap();
                    let mut rest = Vec::new();
                    stream.read_to_end(&mut rest).unwrap();
                    assert!(rest.is_empty());
                    return true;
                }
                assert!(greeting.is_empty(), "greeted with {greeting:?}");
            }
            Err(error) if error.kind() == std::io::ErrorKind::TimedOut => {
                TIMEOUTS.fetch_add(1, Ordering::Relaxed);
            }
            Err(_) => {}
        }
        thread::sleep(Duration::from_millis(100));
    }
    false
}

fn free_port() -> u16 {
    TcpListener::bind((Ipv4Addr::LOCALHOST, 0)).unwrap().local_addr().unwrap().port()
}

/// One trial: returns (exchanged, what the listener's one client sent, listener delay).
fn trial(seed: u64) -> (bool, Option<String>, Duration) {
    let delay = Duration::from_millis(seed % 3000);
    let address = SocketAddr::from((Ipv4Addr::LOCALHOST, free_port()));
    let stop = AtomicBool::new(false);
    thread::scope(|scope| {
        let client = scope.spawn(|| reach_guest(address, &stop));
        thread::sleep(delay);
        let Ok(listener) = TcpListener::bind(address) else {
            stop.store(true, Ordering::SeqCst);
            let _ = client.join();
            return (true, Some("SKIPPED".to_owned()), delay);
        };
        listener.set_nonblocking(true).unwrap();
        let deadline = Instant::now() + Duration::from_secs(30);
        let mut got = None;
        while Instant::now() < deadline {
            match listener.accept() {
                Ok((mut connection, _)) => {
                    // nc closes its listening socket once it accepts its one client.
                    drop(listener);
                    connection.set_nonblocking(false).unwrap();
                    connection.set_read_timeout(Some(Duration::from_secs(10))).unwrap();
                    let _ = connection.write_all(format!("{GREETING}\n").as_bytes());
                    let mut text = Vec::new();
                    let _ = connection.read_to_end(&mut text);
                    got = Some(String::from_utf8_lossy(&text).into_owned());
                    break;
                }
                Err(_) => thread::sleep(Duration::from_millis(5)),
            }
        }
        // Give the client time to retry against the closed port, as vm.exec does
        // until the listener's execution ends.
        thread::sleep(Duration::from_millis(1500));
        stop.store(true, Ordering::SeqCst);
        (client.join().unwrap(), got, delay)
    })
}

fn main() {
    let trials: u64 = std::env::args().nth(1).and_then(|n| n.parse().ok()).unwrap_or(200);
    let parallel: u64 = std::env::args().nth(2).and_then(|n| n.parse().ok()).unwrap_or(32);
    BLOCKING.store(std::env::args().nth(3).as_deref() == Some("blocking"), Ordering::Relaxed);
    let start = Instant::now();
    let mut failures = Vec::new();
    let mut ok = 0;
    let mut skipped = 0;
    let mut round = 0u64;
    while round * parallel < trials {
        let results: Vec<_> = thread::scope(|scope| {
            (0..parallel)
                .map(|i| {
                    let seed = (round * parallel + i).wrapping_mul(2654435761) ^ start.elapsed().as_nanos() as u64;
                    scope.spawn(move || trial(seed))
                })
                .collect::<Vec<_>>()
                .into_iter()
                .map(|handle| handle.join().unwrap())
                .collect()
        });
        for (exchanged, got, delay) in results {
            if got.as_deref() == Some("SKIPPED") {
                skipped += 1;
            } else if exchanged {
                ok += 1;
            } else {
                failures.push((got, delay));
            }
        }
        round += 1;
    }
    println!(
        "trials={} skipped={} exchanged={} failed={} connect_attempts={} connect_timeouts={} elapsed={:?}",
        ok + failures.len(),
        skipped,
        ok,
        failures.len(),
        ATTEMPTS.load(Ordering::Relaxed),
        TIMEOUTS.load(Ordering::Relaxed),
        start.elapsed()
    );
    for (got, delay) in failures {
        println!("  FAILED: listener appeared after {delay:?}; its one client sent {got:?}");
    }
}

The scenario itself was not rerun: it needs WHP, an OpenVMM build, and the runtime adapter's Linux guest agent, and a race this rare needs many runs.

Impact

• cc7b8b3 has a red required check, and neither a development release nor a performance baseline. The next dev push run, 40950623209 for c5d9298 (nvx-rs: serve clones of each processor count from one template #926), contains cc7b8b3, passed, and persisted its baseline in 8dffced, so dev lost no coverage beyond cc7b8b3.
• On a pull request, the race turns Required status check red until someone reruns the job.
• Each Windows run takes the risk six times in vm_layered, in the positive control of each of the five controlled scenarios and in allowed_host_loopback_publishes_the_listeners itself, and again in vm_clone's listener checks of clones whose policy publishes on host loopback. A forward's checks do not: OpenVMM binds a forward's port when the VM starts (lib.rs#L427-L460), before the guest listens, so their connections open at once.

Suggested fix

• Let each attempt of reach_guest run until it opens or fails, with TcpStream::connect(address), in vm_layered.rs and vm_clone.rs. On loopback, a connection opens at once where something listens, and fails at once on Linux and after about 2 s on Windows where nothing does, so an attempt stays bounded and never leaves a connection behind.
• Do not retry the scenario: that would mask the race.
• managed_lifecycle's console copy needs no change: its attempts give up after 100 ms (managed_lifecycle.rs#L54-L57), before Windows' first retry at 0.5 s, so they cannot leave a connection behind.

Related work

• tests: enforce the runtime adapter's networks in VMs #883 added allowed_host_loopback_publishes_the_listeners and reach_guest.
• nvx-rs: per-clone network policies on deny-all templates #978 copied reach_guest into vm_clone.rs.
• runtime-adapter: a_clone_refuses_a_scratch_image_whose_upper_an_earlier_clone_used fails intermittently #1020 tracks a different runtime adapter flake, in vm_clone.