ci: the IMDS deadline tests need the request's worker to reach `connect` within 0.2 s, so a runner stall fails them (flaky NVX CLI / Windows)

Start with the two named tests in scripts/test_host_telemetry.py and the deadline behavior in scripts/nvx_tools/host_telemetry.py. Run the tests, then use the reproduction script's delayed-worker setup to check how they behave when scheduling is delayed. Done means the tests reliably verify the deadline behavior without failing when the worker reaches connect late.

Summary

scripts.test_host_telemetry.AzureMetadataRequestTests.test_a_connect_still_in_progress_is_shut_down_at_the_deadline failed NVX CLI / Windows 6 times from 2026-10-28 to 2026-11-03. Each time it failed with AssertionError: False is not true at self.assertTrue(blocked.is_set()), and nothing else in the job failed except, once, its sibling AzureProvenanceTests.test_metadata_request_is_aborted_at_the_deadline. Since #523 added the tests on 2026-10-15, they account for 6 of the 23 failed NVX CLI / Windows jobs, of 1,335 that completed: about 1 in 220. Neither failed on Linux.

Both tests give read_azure_compute_metadata a 0.2 s deadline and need the request's worker thread to reach connect before it. When a hosted runner does not run the worker within 0.2 s, the deadline cuts the request off first, and the worker's late connect is refused. The request still raises the expected TimeoutError, but the tests' checks that a connect was in progress fail. Delaying the worker by 0.25 s reproduces both failures exactly. The code under test behaves as designed in either order, so the defect is in the tests.

Incident

• Workflow: CI run 41637877205, attempt 1, pull_request for #1238 at ef2c4470c. Later pushes superseded that head, and the run of the current head, 340d4662c, passed.
• Failed job: NVX CLI / Windows, step Validate NVX CLI. It failed in the python -m unittest command of the validate-nvx action's Windows step (action.yml#L26-L35). Of 1,788 tests, 66 were skipped, and this test was the only failure.
• Runner: GitHub-hosted windows-latest, image windows-2025-vs2026 20261030.294.1, runner 2.338.2, Python 3.12.10, on a Standard_D4ads_v5 VM with 4 logical processors (AMD EPYC 7763).
• #1238 changes neither the tests nor the code that they test. Both are byte-identical at all six failing heads and on dev at 41bc47533.

Decisive output:

test_a_connect_still_in_progress_is_shut_down_at_the_deadline (scripts.test_host_telemetry.AzureMetadataRequestTests.test_a_connect_still_in_progress_is_shut_down_at_the_deadline) ... FAIL
…
======================================================================
FAIL: test_a_connect_still_in_progress_is_shut_down_at_the_deadline (scripts.test_host_telemetry.AzureMetadataRequestTests.test_a_connect_still_in_progress_is_shut_down_at_the_deadline)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "D:\a\nvx\nvx\scripts\test_host_telemetry.py", line 2087, in test_a_connect_still_in_progress_is_shut_down_at_the_deadline
    self.assertTrue(blocked.is_set())
AssertionError: False is not true

----------------------------------------------------------------------
Ran 1788 tests in 400.607s

FAILED (failures=1, skipped=66)

The test took about 0.28 s, from the previous test's result line at 12:49:32.914Z to its own at 12:49:33.197Z. That covers its 0.2 s deadline and part of the 0.1 s grace that follows it.

History

I read the logs of every failed NVX CLI job, every attempt, in the CI runs created from 2026-10-15 through 2026-11-03 that failed, were cancelled, or were rerun: 443 of 1,722 runs, with 40 failed NVX CLI jobs, 23 on Windows and 17 on Linux.

• These tests failed 6 of them, all on Windows, and nothing else failed in those 6 jobs.
• In the same runs, 1,335 NVX CLI / Windows jobs completed, of which 1,312 passed. Of the 1,347 NVX CLI / Linux jobs that completed, 1,330 passed.
• The two tests and the code that they test were byte-identical at all six heads.

Each test time runs from the previous test's result line to the failure's, in the job log.

In job 124310135694, the sibling failed with:

  File "D:\a\nvx\nvx\scripts\test_host_telemetry.py", line 472, in test_metadata_request_is_aborted_at_the_deadline
    self.assertTrue(aborted.wait(2), "the metadata connection was left open")
AssertionError: False is not true : the metadata connection was left open

Root cause

Permalinks point to dev at 41bc47533.

1. The request has an end-to-end deadline. read_azure_compute_metadata (host_telemetry.py#L537-L568) runs the request on a daemon worker thread and joins it until the deadline. If the worker is still running at the deadline, it does three things (L559-L565):

   • it cuts the request off;
   • it waits up to AZURE_IMDS_CUT_OFF_GRACE_SECONDS, 0.1 s (L467), for the worker;
   • it raises TimeoutError.

   The cut-off shuts down every socket that the request registered and refuses any later one (L470-L491). Connection.connect registers its socket before it connects. If the cut-off came first, it closes the socket and raises TimeoutError without connecting (L497-L516).

2. The main test needs the connect to start before the deadline. test_a_connect_still_in_progress_is_shut_down_at_the_deadline (test_host_telemetry.py#L2061-L2088) replaces socket.socket with a class whose connect sets blocked and then waits until shutdown releases it. It calls read_azure_compute_metadata(timeout=0.2) and asserts that blocked and released are set.

   • If the worker has not created its socket by the deadline, the cut-off has nothing to shut down.
   • The worker's late connect is then refused before it reaches the patched connect.
   • read_azure_compute_metadata still raises the expected TimeoutError, so the test fails only at self.assertTrue(blocked.is_set()).

3. The sibling has the same race. test_metadata_request_is_aborted_at_the_deadline (L443-L482) serves headers from a real socket server, which keeps sending until its connection breaks. The test asserts that a send failed within 2 s. If the worker's connect is refused, the server never accepts a connection, so aborted is never set. The test then fails with the misleading message "the metadata connection was left open".

4. A hosted runner can hold the worker up for longer. Locally, the worker reaches connect in under 0.05 s: with a 0.15 s delay, both tests still pass. All six failures were on the 4-processor windows-latest runners, whose stalls also caused #1030. The logs don't show where the worker was held up, because the tests don't report how far it got.

Reproduction

I used a 20-thread Windows 11 Enterprise workstation with Python 3.14.10, and dev's versions of the tests and of host_telemetry.py. No hypervisor is needed.

• Unchanged, the main test passed 100 of 100 runs, in 0.204 s each, and the sibling 100 of 100, in 0.272 s each.
• Delaying the worker decides the outcome. The script below wraps host_telemetry._fetch_compute_metadata, which the worker calls to open the request, with a time.sleep:

"""Usage: python repro_telemetry.py <nvx-root> <delay-seconds> [iterations]"""

import io
import sys
import time
import unittest
from pathlib import Path

root = Path(sys.argv[1])
delay = float(sys.argv[2])
iterations = int(sys.argv[3]) if len(sys.argv) > 3 else 1
sys.path.insert(0, str(root / "scripts"))
import test_host_telemetry  # noqa: E402
from nvx_tools import host_telemetry  # noqa: E402

original = host_telemetry._fetch_compute_metadata


def delayed(*args, **kwargs):
    # Stands in for a worker that the runner does not schedule for `delay` seconds.
    time.sleep(delay)
    return original(*args, **kwargs)


if delay > 0:
    host_telemetry._fetch_compute_metadata = delayed

for case, name in [
    (test_host_telemetry.AzureMetadataRequestTests, "test_a_connect_still_in_progress_is_shut_down_at_the_deadline"),
    (test_host_telemetry.AzureProvenanceTests, "test_metadata_request_is_aborted_at_the_deadline"),
]:
    failures = 0
    for _ in range(iterations):
        result = unittest.TextTestRunner(stream=io.StringIO(), verbosity=0).run(case(name))
        failures += bool(result.failures or result.errors)
    print(f"delay={delay}s {name}: {failures}/{iterations} failed")

Impact

• A failure turns NVX CLI / Windows and Required status check red. On a dev push, it also skips Record performance results and Publish development release, which need the job, so that commit gets neither.
• On a pull request, the check stays red until someone reruns the job, as in run 40943638955, whose attempt 2 passed.
• In a merge group that the queue does not replace, a failure removes the group's pull requests from the queue. The queue replaced the group of run 41553658419 before that happened.

Suggested fix

• Let the tests, not a 0.2 s timer, decide when the deadline passes. For example, use a clock that the tests control, and let the deadline expire only once the patched connect is pending. A worker that starts late then still exercises a connect in progress.
• Make the sibling assert first that the server accepted a connection, before it asserts that the connection was aborted, so that a refused connect fails with an accurate message.
• Neither raise the 0.2 s alone nor retry. A longer timer only narrows the race, at the cost of slower tests. A retry would hide a cut-off that really misses a pending connect.

Related work

• #523 added both tests, in 021b91651 and 69f99b3df, and merged on 2026-10-15.
• #1030 and #1017 were earlier flakes of short limits on hosted Windows runners.
• #1238's first CI run hit this.