OpenVMM: consomme's test_tcp_last_ack_restarts_timeout_after_close_wait races a 1 ms close deadline, so a runner stall hangs it until nextest kills it (flaky OpenVMM unit tests / Windows) #1240

Summary

OpenVMM's consomme unit test tcp::tests::test_tcp_last_ack_restarts_timeout_after_close_wait hung until nextest killed it at 10 s in 3 of the 527 Windows unit-test jobs that OpenVMM CI completed from 2026-10-01 to 2026-11-03:

• once on x64 Windows, on upstream main;
• twice on AArch64 Windows, on NVX's microVM release branches.

It never failed in the 1,054 Linux unit-test jobs of the same runs.

The test plants a close deadline 1 ms in the future, shuts down the host's side of the connection, and waits for consomme to send the guest a FIN. If no poll sees the host's EOF within that millisecond, consomme reclaims the connection at the expired deadline and sends an RST instead. The test's wait has no limit and matches only a FIN, so it never ends. A 5 ms pause after the plant makes the test hang every time.

microsoft/openvmm#3600 added the test. Upstream main still has it, and NVX's pin has it unchanged. The defect is in the test, not in consomme.

Incident

• Workflow: OpenVMM CI run 41635817825, attempt 1, the push of feature/microvm/release/v4.0 at fe34d8645, the first OpenVMM revision that openvmm: pin microVM v4.0, reorganized onto upstream main #1238 pinned. The branch has since moved to eda13d80a, whose run 41644250255 passed every unit-test job.
• Failed job: clippy [aarch64-windows], unit tests [aarch64-windows], in its nextest run of OpenVMM's unit tests. Of 5,380 tests, 5,379 passed, and this one timed out.
• Runner: OpenVMM's AArch64 Windows runner, image win-arm64-v2 72.0.0, Windows 11 build 29704, runner 2.338.2.
• NVX's OpenVMM CI of the pinned revision job does not require the AArch64 Windows job, so this did not block openvmm: pin microVM v4.0, reorganized onto upstream main #1238. It does require unit tests [x64-windows], where the test timed out on upstream main on 2026-10-01.

Decisive output:

2026-11-03T12:52:57.7456687Z     Starting 5380 tests across 427 binaries (13 tests skipped)
2026-11-03T12:52:59.9219835Z         SLOW [>  1.000s] (─────────) consomme tcp::tests::test_tcp_last_ack_restarts_timeout_after_close_wait
…
2026-11-03T12:53:07.9416536Z         SLOW [>  9.000s] (─────────) consomme tcp::tests::test_tcp_last_ack_restarts_timeout_after_close_wait
2026-11-03T12:53:08.9420820Z  TERMINATING [> 10.000s] (─────────) consomme tcp::tests::test_tcp_last_ack_restarts_timeout_after_close_wait
2026-11-03T12:53:08.9461446Z      TIMEOUT [  10.027s] (4020/5380) consomme tcp::tests::test_tcp_last_ack_restarts_timeout_after_close_wait
2026-11-03T12:53:13.1983595Z      Summary [  15.454s] 5380 tests run: 5379 passed (17 slow), 1 timed out, 13 skipped

History

I read the logs of every failed unit-test job, every attempt, in the OpenVMM CI runs (openvmm-ci.yaml) created from 2026-10-01 through 2026-11-03 that failed, were cancelled, or were rerun: 188 of 268 runs.

• Of the 268 runs, 192 were pushes to main, 44 pushes to other branches, 4 dispatches, and 28 pull-request runs.
• Four of the 188 couldn't be read (HTTP 502).
• The test timed out 3 times, each time as its job's only failure, and never failed otherwise.
• In the same 268 runs, 527 Windows unit-test jobs completed (264 on x64 and 263 on AArch64), and 1,054 Linux ones.

Root cause

Permalinks point to upstream main at ca6b2b177. NVX's pin, eda13d80a, has the same test, and the same timer and close code in tcp.rs.

1. The test plants a 1 ms deadline. test_tcp_last_ack_restarts_timeout_after_close_wait (tests.rs#L3070-L3096) checks that LAST-ACK gets a fresh close deadline even when one is already set. After the guest's FIN moves the connection to CLOSE-WAIT, the test:
   • replaces the connection's lifetime timer with LifetimeTimer::Close(Instant::now() + Duration::from_millis(1)) (L3082);
   • shuts down the host's write half (L967-L969);
   • waits with poll_until_guest_packet (L872-L890) for a FIN to the guest;
   • asserts that the connection is in LAST-ACK, with its deadline more than 1 s away.
2. consomme checks timers before it reads the socket. In each poll, consomme first checks each connection's earliest timer.
   • When a lifetime deadline has passed, process_expired_timers returns at once (tcp.rs#L2346-L2359), and the poll reclaims the connection: it sends the guest an RST and drops the connection (L866-L911).
   • Only a poll that finds the deadline still ahead reads the host's EOF. It then calls close, which moves CLOSE-WAIT to LAST-ACK with a fresh deadline and queues the FIN (L2285-L2288).
3. So the FIN needs a poll within 1 ms. If no poll sees the host's EOF before the planted deadline, the guest gets an RST instead. poll_until_guest_packet waits for a matching packet without a limit, so the test hangs until nextest's ci profile terminates it at 10 s (.config/nextest.toml#L85-L87). A stall of over 1 ms anywhere between the plant and that poll loses the race, for example when the test thread loses its processor on a busy runner. Why all three timeouts were on Windows is not established.
4. A sibling test plants the same deadline. test_tcp_time_wait_cleanup (L2852-L2974) plants a 1 ms deadline in TIME-WAIT (L2894). It polls consomme only after a retransmitted FIN has restarted that deadline, though, and it didn't fail in these runs.

Reproduction

I used a 20-thread x64 Windows 11 Enterprise workstation and the debug build of consomme's unit tests (cargo test -p consomme --lib --no-run). Each run of the test was a process of its own, with --exact tcp::tests::test_tcp_last_ack_restarts_timeout_after_close_wait --test-threads 1.

• At NVX's fork base, c6d3da0ff, whose consomme is upstream main's: 150 sequential runs passed, and 1 of 400 runs in four parallel loops hung past 10 s.
• With NVX's pin's consomme, built at fe34d8645, whose consomme eda13d80a keeps: one of the first 40 sequential runs hung. The next 30 and 150 sequential runs passed, as did 400 runs in four parallel loops.
• With std::thread::sleep(Duration::from_millis(5)); added right after the plant, 5 of 5 runs hung, until the 15 s limit killed them.

Impact

• A timeout fails the Windows unit-test job of an OpenVMM CI run until someone reruns it, as upstream main needed on 2026-10-01.
• NVX's OpenVMM CI of the pinned revision job requires unit tests [x64-windows] for the pinned revision. A timeout there fails that job, and with it Required status check, for every NVX pull request that pins the revision. That lasts until the OpenVMM job is rerun, and the NVX job after it.

Suggested fix

The test is upstream's, so fix it in microsoft/openvmm; NVX takes the fix at the fork's next rebase.

• Plant a deadline that no stall can reach first, but that a fresh LAST-ACK deadline still beats, and compare against it. For example, plant Instant::now() + Duration::from_secs(10), below consomme's default close timeout of 60 s (lib.rs#L257). Then assert that the deadline afterwards is later than the planted one. The test still fails if LAST-ACK keeps the old deadline.
• Bound poll_until_guest_packet, or make it fail when the connection is reclaimed or an RST reaches the guest. A missed FIN then reports itself instead of hanging until nextest kills the test.
• Keep consomme's order. Reclaiming a connection whose deadline has passed, before reading its socket, is correct.

Related work

• consomme: remove tcp connections in closing state after timeout openvmm#3600 added the test on 2026-08-24. No microsoft/openvmm issue or pull request mentions it.
• openvmm: pin microVM v4.0, reorganized onto upstream main #1238's first OpenVMM CI run hit this.