diff --git a/.github/actions/check-quality/action.yml b/.github/actions/check-quality/action.yml index f40b6a954..3201f92c3 100644 --- a/.github/actions/check-quality/action.yml +++ b/.github/actions/check-quality/action.yml @@ -51,6 +51,7 @@ runs: scripts/setup/setup-linux-mshv.sh \ scripts/setup/setup-linux-runner.sh ${SHELLCHECK} --shell=bash \ + .github/actions/run-benchmark/forward-signals.sh \ .github/specula/setup-runner.sh guest/ubuntu/nvx-bashrc \ scripts/setup/azure/linux/bootstrap-runner.sh \ scripts/setup/azure/linux/block-runner-metadata.sh \ @@ -72,6 +73,7 @@ runs: scripts/setup/setup-linux-mshv.sh \ scripts/setup/setup-linux-runner.sh ${SHFMT} -d -ln bash -i 4 -ci \ + .github/actions/run-benchmark/forward-signals.sh \ .github/specula/setup-runner.sh guest/ubuntu/nvx-bashrc \ scripts/setup/azure/linux/bootstrap-runner.sh \ scripts/setup/azure/linux/block-runner-metadata.sh \ diff --git a/.github/actions/run-benchmark/action.yml b/.github/actions/run-benchmark/action.yml index 3323165ef..f9497c1e1 100644 --- a/.github/actions/run-benchmark/action.yml +++ b/.github/actions/run-benchmark/action.yml @@ -51,6 +51,10 @@ runs: --output "data/runs/${{ inputs.platform }}/${{ inputs.platform }}-host.json" \ --summary "${GITHUB_STEP_SUMMARY}" + # The runner signals only a step's shell when the job is cancelled, so the + # Linux steps run the test harness with run_harness, which passes SIGINT + # and SIGTERM on to it as SIGTERM, or exec it, so that it can stop OpenVMM + # and remove its scratch directories (doc/ci.md#cancellation). - name: Run Linux acceptance test if: runner.os != 'Windows' shell: bash @@ -60,6 +64,7 @@ runs: NVX_BENCHMARK_MARKER_TIMEOUT: ${{ inputs.marker-timeout }} run: | set -euo pipefail + source "${GITHUB_ACTION_PATH}/forward-signals.sh" cpu_args=(--host-cpu-reserve "${NVX_BENCHMARK_HOST_CPU_RESERVE}") if [[ -n "${NVX_BENCHMARK_CPUS}" ]]; then cpu_args+=(--cpus "${NVX_BENCHMARK_CPUS}") @@ -71,7 +76,7 @@ runs: "${run_dir}"/acceptance-attempt-*.json for attempt in 1 2; do attempt_output="${run_dir}/acceptance-attempt-${attempt}.json" - python3 scripts/nvx.py benchmark \ + run_harness python3 scripts/nvx.py benchmark \ --suite e2e \ --backend "${{ inputs.backend }}" \ --platform "${{ inputs.platform }}" \ @@ -108,6 +113,7 @@ runs: NVX_BENCHMARK_MARKER_TIMEOUT: ${{ inputs.marker-timeout }} run: | set -euo pipefail + source "${GITHUB_ACTION_PATH}/forward-signals.sh" cpu_args=(--host-cpu-reserve "${NVX_BENCHMARK_HOST_CPU_RESERVE}") if [[ -n "${NVX_BENCHMARK_CPUS}" ]]; then cpu_args+=(--cpus "${NVX_BENCHMARK_CPUS}") @@ -118,7 +124,7 @@ runs: rm -rf "${run_dir}"/performance-attempt-* for attempt in 1 2; do attempt_dir="${run_dir}/performance-attempt-${attempt}" - python3 scripts/nvx.py benchmark \ + run_harness python3 scripts/nvx.py benchmark \ --suite performance \ --backend "${{ inputs.backend }}" \ --platform "${{ inputs.platform }}" \ @@ -154,6 +160,7 @@ runs: NVX_BENCHMARK_MARKER_TIMEOUT: ${{ inputs.marker-timeout }} run: | set -euo pipefail + source "${GITHUB_ACTION_PATH}/forward-signals.sh" cpu_args=(--host-cpu-reserve "${NVX_BENCHMARK_HOST_CPU_RESERVE}") if [[ -n "${NVX_BENCHMARK_CPUS}" ]]; then cpu_args+=(--cpus "${NVX_BENCHMARK_CPUS}") @@ -165,7 +172,7 @@ runs: rm -rf "${run_dir}"/shell-snapshot-restore-attempt-* for attempt in 1 2; do attempt_dir="${run_dir}/shell-snapshot-restore-attempt-${attempt}" - python3 scripts/nvx.py benchmark \ + run_harness python3 scripts/nvx.py benchmark \ --suite shell-snapshot-restore \ --backend "${{ inputs.backend }}" \ --platform "${{ inputs.platform }}" \ @@ -207,7 +214,7 @@ runs: cpu_args+=(--cpus "${NVX_BENCHMARK_CPUS}") fi run_dir="data/runs/${{ inputs.platform }}/microvm-v2/1vcpu/device-io" - python3 scripts/nvx.py benchmark \ + exec python3 scripts/nvx.py benchmark \ --suite device-io \ --backend "${{ inputs.backend }}" \ --platform "${{ inputs.platform }}" \ diff --git a/.github/actions/run-benchmark/forward-signals.sh b/.github/actions/run-benchmark/forward-signals.sh new file mode 100644 index 000000000..5462216f8 --- /dev/null +++ b/.github/actions/run-benchmark/forward-signals.sh @@ -0,0 +1,64 @@ +# shellcheck shell=bash +# Sourced by the Linux steps of run-benchmark, which run the test harness +# among other commands (see doc/ci.md#cancellation). +# +# When a job is cancelled, the runner sends SIGINT, and then SIGTERM, to the +# step's shell alone, and Bash runs a trap only once its foreground command +# ends. So sourcing this file traps both signals: one that arrives while +# run_harness runs a command reaches that command as SIGTERM, which nvx.py +# handles as SIGINT, so that it stops its OpenVMM processes and removes its +# scratch directories, and ends the step once the command exits; one that +# arrives at any other time ends the step at once. + +harness_pid= +starting= +deferred= +cancelled= + +on_cancellation() { + cancelled=$1 + if [[ -n "${starting}" ]]; then + # The command may have started, but run_harness doesn't know its PID + # yet, so it passes the signal on once it does. + deferred=1 + elif [[ -n "${harness_pid}" ]]; then + # The command may have exited already, so that the signal reaches nothing. + kill -TERM "${harness_pid}" 2>/dev/null || true + else + exit "$1" + fi +} + +trap 'on_cancellation 130' INT +trap 'on_cancellation 143' TERM + +# Runs a command in the background, where Bash would ignore SIGINT unless the +# command restored it, and returns its exit status once it exits. A +# cancellation reaches the command as SIGTERM, which it never ignores, not +# even before it has restored SIGINT, as it has not when a cancellation that +# arrived as it started reaches it. +run_harness() { + starting=1 + ( + trap - INT + exec "$@" + ) & + harness_pid=$! + starting= + if [[ -n "${deferred}" ]]; then + deferred= + kill -TERM "${harness_pid}" 2>/dev/null || true + fi + local status=0 + wait "${harness_pid}" || status=$? + # A trapped signal ends the wait before the command exits. + while kill -0 "${harness_pid}" 2>/dev/null; do + status=0 + wait "${harness_pid}" || status=$? + done + harness_pid= + if [[ -n "${cancelled}" ]]; then + exit "${cancelled}" + fi + return "${status}" +} diff --git a/.github/actions/validate-runner/action.yml b/.github/actions/validate-runner/action.yml index d90e4d2d2..bf95777a4 100644 --- a/.github/actions/validate-runner/action.yml +++ b/.github/actions/validate-runner/action.yml @@ -211,6 +211,29 @@ runs: exit 1 fi + # A harness that something killed outright, as the runner's orphan + # cleanup killed those of cancelled jobs, leaves its scenarios' scratch + # directories in the temporary directory (#946). As with OpenVMM, no step + # before this one runs the harness, so the account's harness directories + # there are left from earlier jobs. + - name: Remove scratch left by earlier jobs + if: runner.os != 'Windows' + shell: bash + run: | + set -euo pipefail + temporary=$(python3 -c 'import tempfile; print(tempfile.gettempdir())') + find "${temporary}" -mindepth 1 -maxdepth 1 -type d -user "$(id -u)" \ + \( -name 'nvx-*' -o -name 'openvmm-*' \) -print0 | + while IFS= read -r -d '' directory; do + modified=$(stat -c %y "${directory}" || true) + echo "::notice::Removing ${directory}, last modified ${modified:-at an unknown time}, which an earlier job left behind" + # A scenario can leave a directory that even its owner can't write. + chmod -R u+rwX -- "${directory}" 2>/dev/null || true + if ! rm -rf --one-file-system -- "${directory}"; then + echo "::warning::Could not remove ${directory}, which an earlier job left behind" + fi + done + # Host time. The time ABI host qualification (doc/ci.md, # "Host qualification") checks the backend, the CPU fingerprint and # generation, and the TSC rate stability on its short CI schedule, and, diff --git a/.github/workflows/run-nvx-microvm-tests.yml b/.github/workflows/run-nvx-microvm-tests.yml index 1e78acaae..964fc2315 100644 --- a/.github/workflows/run-nvx-microvm-tests.yml +++ b/.github/workflows/run-nvx-microvm-tests.yml @@ -179,11 +179,14 @@ jobs: backend: ${{ inputs.backend }} verify-openvmm: "true" + # The runner signals only a step's shell when the job is cancelled, so + # the Linux steps exec the test harness, which can then stop OpenVMM and + # remove its scratch directories (doc/ci.md#cancellation). - name: Run NVX microVM tests on Linux if: runner.os != 'Windows' && !inputs.guests-and-sandboxes shell: bash run: >- - python3 scripts/nvx.py test-microvm + exec python3 scripts/nvx.py test-microvm --backend "${{ inputs.backend }}" ${{ inputs.debug-kernel && '--debug-kernel' || '' }} ${{ inputs.shard && format('--shard {0}/{1}', inputs.shard, inputs.shard-count) || '' }} @@ -203,7 +206,7 @@ jobs: if: runner.os != 'Windows' && inputs.guests-and-sandboxes && !inputs.debug-kernel shell: bash run: >- - python3 scripts/nvx.py test-microvm + exec python3 scripts/nvx.py test-microvm --backend "${{ inputs.backend }}" --scenario managed-exec-config --scenario sandbox-lifecycle @@ -225,7 +228,7 @@ jobs: if: runner.os != 'Windows' && inputs.guests-and-sandboxes && !inputs.debug-kernel shell: bash run: >- - python3 scripts/nvx.py test-microvm + exec python3 scripts/nvx.py test-microvm --backend "${{ inputs.backend }}" --guest ubuntu --processors 1 @@ -257,7 +260,7 @@ jobs: if: runner.os != 'Windows' && inputs.guests-and-sandboxes && !inputs.debug-kernel shell: bash run: >- - python3 scripts/nvx.py test-microvm + exec python3 scripts/nvx.py test-microvm --backend "${{ inputs.backend }}" --guest azurelinux --processors 1 @@ -291,7 +294,7 @@ jobs: if: inputs.backend == 'kvm' && inputs.guests-and-sandboxes && !inputs.debug-kernel shell: bash run: >- - python3 scripts/nvx.py test-microvm + exec python3 scripts/nvx.py test-microvm --backend kvm --guest ubuntu --scenario managed-lifecycle diff --git a/doc/benchmarks.md b/doc/benchmarks.md index c0901fa7e..6b2432750 100644 --- a/doc/benchmarks.md +++ b/doc/benchmarks.md @@ -871,7 +871,11 @@ After the merge, `dev` pushes restart the series' ten-point warmup. The lifecycle benchmark uses the optimized 128 MiB shell-ready guest as one baseline across KVM, MSHV, and WHP. Host timing starts immediately before `Popen`, so cold-start and restore values -include OpenVMM process startup and VM construction. Snapshot generation uses OpenVMM's monotonic +include OpenVMM process startup and VM construction. On Linux, that startup includes the execs of +`setpriv` and of a shell that checks that the coordinator still runs, which make the coordinator's +exit kill OpenVMM (see [Cancellation](ci.md#cancellation)). On a Xeon Silver 4114 host, they added +2.1 ms to the time until OpenVMM ran with Dash as `/bin/sh`, and 3.5 ms with Bash, which the Azure +Linux runners use. Snapshot generation uses OpenVMM's monotonic process clock from the beginning of input gating, after the guest requests the snapshot, through atomic publication. It does not include delivery of `nvx-snapshot` over the polling console. Host request-to-publication and first publication observation (polled every 1 ms) remain diagnostics. diff --git a/doc/ci.md b/doc/ci.md index c07e6191d..a30bca4b2 100644 --- a/doc/ci.md +++ b/doc/ci.md @@ -270,11 +270,18 @@ Every job that uses the `validate-runner` action first ends, on Linux, any OpenVMM process that its runner's account still runs, with a warning that names it, and fails if one survives SIGKILL or the processes can't be listed. A runner runs one job at a time, so such a process is left from an -earlier job: when a job is cancelled, the runner signals only the step's shell, -so the test harness keeps running, and it can start a VM after the runner's -orphan cleanup has listed the job's processes; the cleanup then kills the -harness, and the VM runs on (#768). The action then reports the Linux -runner's kernel, CPU, clocksource, and TSC flags, and qualifies the runner +earlier job. Before a cancellation reached the test harness (see +[Cancellation](#cancellation)), the harness of a cancelled job kept running +and could start a VM after the runner's orphan cleanup had listed the job's +processes; the cleanup then killed the harness, and the VM ran on for 8 days +(#768). It still ends a VM that escapes both the harness's cleanup and its +parent-death signal. The action next removes the account's `nvx-*` and +`openvmm-*` directories in Python's temporary directory, where the test +harness runs its scenarios, with a notice that names each one, and fails if it +can't list them: a harness that something killed outright left them behind, +and on October 28, 2026, the ten Linux runners held 64 of them (#946). It then +reports the Linux runner's kernel, CPU, clocksource, and TSC flags, and +qualifies the runner for the time ABI with `nvx.py doctor --checks H1 H2 H4 --ci-schedule` (see [Host qualification](#host-qualification)): the backend, the CPU fingerprint and generation, and the TSC rate stability on its short schedule. The microVM @@ -984,6 +991,54 @@ SHA after applying the results to the current `dev` history: it drops rows already present for the same platform, ABI, processor count, commit, and metric, but otherwise appends them and pushes a baseline update. +## Cancellation + +When a run is cancelled, as a push to a pull request cancels the run of its +previous head, the runner +[cancels each running step](https://docs.github.com/en/actions/reference/workflows-and-actions/workflow-cancellation): +it sends SIGINT to the step's shell, SIGTERM if the shell still runs 7.5 s +later, and kills the shell's process tree another 2.5 s later. After the +job's last step, the runner's orphan cleanup kills every process that the job +started and that still runs. `nvx.py` handles SIGTERM as it handles SIGINT: +either one interrupts its command, which then stops the OpenVMM processes and +removes the scratch directories that it started and created, and exits with +status 130 (see [Commands](usage.md#commands)). + +The runner signals only the step's shell, though, and Bash runs a trap only +once the command in its foreground ends, so a harness that a Linux step ran in +the foreground never learned of the cancellation: it ran on until the orphan +cleanup killed it, which left the scratch directories of its scenario behind. +The Linux steps that run `test-microvm` therefore `exec` it, so that it is the +step's process. The Linux steps of `run-benchmark`, which run the harness among +other commands, `exec` it as their last command or source +`.github/actions/run-benchmark/forward-signals.sh`, whose `run_harness` runs +the harness in the background, with the SIGINT that Bash ignores there +restored, and passes SIGINT and SIGTERM on to it as SIGTERM, which, unlike +SIGINT, the harness never ignores, not even before it has restored SIGINT. A +signal that arrives as `run_harness` starts the harness, before it knows the +harness's PID, reaches the harness once it does. The step then ends once the +harness exits, even if the signal came too late to stop it, and a signal that +arrives between two harness runs ends the step at once. + +On Linux, OpenVMM also ends with `nvx.py` when something kills `nvx.py` +before its cleanup runs, as the orphan cleanup does. Where the host has +util-linux's `setpriv`, as the runners do, `nvx.py` starts OpenVMM through +`setpriv --pdeathsig KILL`, so that the kernel kills OpenVMM when `nvx.py` +exits, and through a shell that starts OpenVMM only if `nvx.py` is still its +parent, since an `nvx.py` that died before `setpriv` armed the signal sent +none. A contained process tree, such as `nvx-rs run` and the +OpenVMM that it starts, runs under a supervisor that the kernel sends SIGTERM +when `nvx.py` exits, and which then kills the whole tree. The supervisor runs +without the job's `RUNNER_TRACKING_ID`, which it gives back to the command, +because the orphan cleanup kills the processes whose environment holds it and +could kill the supervisor before it ended a tree that the cleanup didn't list, +such as an OpenVMM that started after the listing. The kernel sends +these signals when the thread that started the process exits, so only a +process that the main thread starts gets them, and `nvx.py` starts its VMs +from its main thread. The `validate-runner` action of the runner's next job +ends the OpenVMM processes and removes the scratch directories that still +escape all of this. + ## OpenVMM VMM tests OpenVMM's `vmm-tests-run` builds the tests that a filter selects and then runs diff --git a/doc/usage.md b/doc/usage.md index fcda8a12a..fe875a4ee 100644 --- a/doc/usage.md +++ b/doc/usage.md @@ -80,8 +80,8 @@ match codes, and stable fragments of messages, such as the names of options, fields, and files, never whole messages. A code keeps its meaning and is never reused, and a later release may add codes, which callers treat as failures of the command. The usage errors that `nvx.py` itself reports, as `argparse` does, -carry no code, and neither does an interruption, which prints `Interrupted` -and exits with status 130. The +carry no code, and neither does an interruption by SIGINT or, outside +Windows, SIGTERM, which prints `Interrupted` and exits with status 130. The [`nvx-rs` README](../nvx-rs/README.md#error-codes) gives the `ErrorKind` of each code for callers of the `nvx` library. @@ -448,6 +448,14 @@ is authorized for the organization when it enforces single sign-on. | `archive-release` | Create a deterministic archive from a staged distribution. | | `verify` | Verify source and submodule inputs. | +Ctrl-C, that is SIGINT, interrupts a command, and so does SIGTERM outside +Windows, which is how CI ends a cancelled step (see +[Cancellation](ci.md#cancellation)). The command then runs its cleanup, as +`test-microvm` and `benchmark` stop their OpenVMM processes and remove their +scratch directories, prints `Interrupted`, and exits with status 130. On +Linux, the OpenVMM processes that they start, and the process trees that they +contain, end with `nvx.py` even when something kills it outright. + ## Initialization and verification ### `init` @@ -1166,7 +1174,8 @@ follow one another without gaps, so they add up to the run's time: outcome. Every span has its `started_at`, its `seconds`, rounded to the millisecond, its -`outcome`, `passed`, `failed`, or `interrupted`, for example by `SIGINT`, and +`outcome`, `passed`, `failed`, or `interrupted`, for example by `SIGINT` or +`SIGTERM`, and an `error`: for a failure, the exception's type and message, cut to 1,000 characters, and otherwise `null`. A `scenario` record also has the `scenario`, the `guest`, `backend`, and `kernel`, and its `processors`: the diff --git a/scripts/nvx.py b/scripts/nvx.py index 67488ce67..c70f05e7f 100644 --- a/scripts/nvx.py +++ b/scripts/nvx.py @@ -7,9 +7,12 @@ import json import os import shlex +import signal import subprocess import sys -from collections.abc import Sequence +import threading +from collections.abc import Generator, Sequence +from contextlib import contextmanager from pathlib import Path from nvx_tools import nvx_rs @@ -938,10 +941,34 @@ def parse_args(argv: Sequence[str] | None = None) -> argparse.Namespace: return parser.parse_args(argv) +@contextmanager +def _sigterm_interrupts() -> Generator[None]: + """Let SIGTERM interrupt a command as SIGINT does, so that its cleanup runs. + + A cancelled CI step gets SIGINT and, if it still runs 7.5 s later, SIGTERM + (see doc/ci.md#cancellation). On SIGTERM, Python exits without unwinding, + which would leave the command's OpenVMM processes and scratch directories + behind. As Python does for SIGINT, an ignored SIGTERM stays ignored. + """ + if ( + os.name != "posix" + or threading.current_thread() is not threading.main_thread() + or signal.getsignal(signal.SIGTERM) != signal.SIG_DFL + ): + yield + return + signal.signal(signal.SIGTERM, signal.default_int_handler) + try: + yield + finally: + signal.signal(signal.SIGTERM, signal.SIG_DFL) + + def main(argv: Sequence[str] | None = None) -> int: args = parse_args(argv) try: - result = args.handler(args) + with _sigterm_interrupts(): + result = args.handler(args) except KeyboardInterrupt: print("Interrupted", file=sys.stderr) return 130 diff --git a/scripts/nvx_tools/adversarial_oracles.py b/scripts/nvx_tools/adversarial_oracles.py index 1925a2013..66135da47 100644 --- a/scripts/nvx_tools/adversarial_oracles.py +++ b/scripts/nvx_tools/adversarial_oracles.py @@ -3,6 +3,7 @@ from __future__ import annotations import base64 +import contextlib import ctypes import hashlib import json @@ -31,13 +32,17 @@ PROCESS_TERMINATION_WAIT_SECONDS * 2 + PROCESS_READER_JOIN_SECONDS * 2 ) _LINUX_CHILD_SUBREAPER = 36 +_LINUX_PARENT_DEATH_SIGNAL = 1 _LINUX_EXITED_TASK_STATES = frozenset({"Z", "X", "x"}) _WINDOWS_CREATE_SUSPENDED = 0x00000004 +# The runner's orphan cleanup kills the processes whose environment names the +# job in this variable. A supervisor gets it under the other name, and gives it +# back to its command (see ProcessTreeContainment.environment). +_RUNNER_TRACKING_ID = "RUNNER_TRACKING_ID" +_SUPERVISED_RUNNER_TRACKING_ID = "NVX_SUPERVISED_RUNNER_TRACKING_ID" -def _enable_linux_child_subreaper() -> None: - if not sys.platform.startswith("linux"): - return +def _linux_prctl(option: int, argument: int, name: str) -> None: libc = ctypes.CDLL(None, use_errno=True) prctl = libc.prctl prctl.argtypes = ( @@ -48,9 +53,68 @@ def _enable_linux_child_subreaper() -> None: ctypes.c_ulong, ) prctl.restype = ctypes.c_int - if prctl(_LINUX_CHILD_SUBREAPER, 1, 0, 0, 0) != 0: + if prctl(option, argument, 0, 0, 0) != 0: error = ctypes.get_errno() - raise OSError(error, "prctl(PR_SET_CHILD_SUBREAPER) failed") + raise OSError(error, f"prctl({name}) failed") + + +def _enable_linux_child_subreaper() -> None: + if not sys.platform.startswith("linux"): + return + _linux_prctl(_LINUX_CHILD_SUBREAPER, 1, "PR_SET_CHILD_SUBREAPER") + + +def _set_linux_parent_death_signal(signum: int) -> None: + """Have the kernel send this process ``signum`` when its parent exits. + + The kernel sends it only for an exit after this call, and when the thread + that started this process exits, not only the whole parent process. + """ + _linux_prctl(_LINUX_PARENT_DEATH_SIGNAL, signum, "PR_SET_PDEATHSIG") + + +# Run once setpriv has armed the parent-death signal, with the ID of the +# process that started setpriv and the command: the command runs only while +# that process is still the parent, since one that died before then sent no +# signal. +_OWNED_EXEC = '[ "$PPID" = "$1" ] || exit 1; shift; exec "$@"' + + +def killed_with_parent(command: Sequence[str]) -> list[str]: + """Return a command line that runs ``command`` until its parent exits. + + On Linux, setpriv(1) makes SIGKILL the parent-death signal of the + command, which survives the execs that follow, so that the command ends + even with a parent that is killed outright, as the runner's orphan + cleanup kills the test harness of a cancelled CI job (#946). A parent + that dies before setpriv arms the signal sends none, so a shell then + starts the command only if this process is still its parent. setpriv and + the shell keep vfork and cost two execs, where a preexec_fn that called + prctl would make each spawn fork the whole harness. The kernel sends the + signal when the thread that started the command exits, so only the main + thread, which lives as long as its process, gets the wrapper. The + command line is unchanged elsewhere, and without setpriv. + """ + if ( + not sys.platform.startswith("linux") + or threading.current_thread() is not threading.main_thread() + ): + return list(command) + setpriv = shutil.which("setpriv") + if setpriv is None: + return list(command) + return [ + setpriv, + "--pdeathsig", + "KILL", + "--", + "/bin/sh", + "-c", + _OWNED_EXEC, + "sh", + str(os.getpid()), + *command, + ] def _resource_sample(path: Path) -> dict[str, object]: @@ -534,15 +598,49 @@ def _redeliver_linux_signal(signum: int) -> None: raise ScriptError(f"failed to redeliver signal {signum} to process supervisor") -def supervise_linux_process(command: Sequence[str]) -> int: - """Run and fully reap one process tree inside a private subreaper.""" +class _SupervisorOrphaned(BaseException): + """The process that started a supervisor exited before its process tree.""" + + +def supervise_linux_process(command: Sequence[str], *, parent: int | None) -> int: + """Run and fully reap one process tree inside a private subreaper. + + ``parent`` names the process that started the supervisor. Once it exits, + even when something kills it outright, as the runner's orphan cleanup + kills the test harness of a cancelled CI job (#946), the supervisor + kills the whole tree and then ends by SIGTERM: the kernel sends it + SIGTERM, its parent-death signal, and a signal that finds it with + another parent ends the tree instead of reaching the command. Without + ``parent``, the tree outlives the process that started the supervisor. + The command gets back the runner's tracking ID that the supervisor runs + without. + """ if not command: raise ValueError("supervised command is required") _enable_linux_child_subreaper() - process = subprocess.Popen(command) + environment = dict(os.environ) + tracking = environment.pop(_SUPERVISED_RUNNER_TRACKING_ID, None) + if tracking is not None: + environment[_RUNNER_TRACKING_ID] = tracking + process: subprocess.Popen[bytes] | None = None + orphaned = False + # Signals that arrive before the command starts reach it once it does. + pending: list[int] = [] previous_handlers: dict[int, object] = {} + def check_parent() -> None: + nonlocal orphaned + if parent is not None and not orphaned and os.getppid() != parent: + orphaned = True + raise _SupervisorOrphaned + def forward_signal(signum: int, _frame: object) -> None: + if orphaned or (process is not None and process.returncode is not None): + return + check_parent() + if process is None: + pending.append(signum) + return try: process.send_signal(signum) except ProcessLookupError: @@ -554,8 +652,20 @@ def forward_signal(signum: int, _frame: object) -> None: forwarded_signals.insert(0, sighup) for signum in forwarded_signals: previous_handlers[signum] = signal.signal(signum, forward_signal) - returncode = process.wait() try: + try: + if parent is not None: + _set_linux_parent_death_signal(int(signal.SIGTERM)) + # A parent that exited before that call sends no signal. + check_parent() + process = subprocess.Popen(command, env=environment) + for signum in pending: + with contextlib.suppress(ProcessLookupError): + process.send_signal(signum) + returncode = process.wait() + except _SupervisorOrphaned: + # Nothing waits for the tree any more. + returncode = -int(signal.SIGTERM) _reap_linux_children(os.getpid()) finally: for signum, handler in previous_handlers.items(): @@ -788,7 +898,34 @@ def command(self, command: Sequence[str]) -> list[str]: if not sys.platform.startswith("linux"): return list(command) supervisor = Path(__file__).with_name("process_supervisor.py") - return [sys.executable, "-I", str(supervisor), "--", *command] + # The kernel sends the supervisor its parent-death signal when the + # thread that started it exits, which would end the tree early, so + # only the main thread, which lives as long as this process, ties the + # tree to this process (see killed_with_parent). + parent = ( + [str(os.getpid())] + if threading.current_thread() is threading.main_thread() + else [] + ) + return [sys.executable, "-I", str(supervisor), *parent, "--", *command] + + def environment(self, environment: Mapping[str, str]) -> dict[str, str]: + """Return the environment of the supervisor of a command whose + environment is ``environment``. + + The runner's orphan cleanup kills each process whose environment names + the job in RUNNER_TRACKING_ID. It would kill the supervisor too, maybe + before the supervisor ended a tree that the cleanup didn't list, such + as an OpenVMM that started after the listing (#946). So on Linux, the + supervisor runs without that ID, and gives it back to the command, + which the cleanup tracks as before. + """ + supervisor = dict(environment) + if sys.platform.startswith("linux") and _RUNNER_TRACKING_ID in supervisor: + supervisor[_SUPERVISED_RUNNER_TRACKING_ID] = supervisor.pop( + _RUNNER_TRACKING_ID + ) + return supervisor @property def creationflags(self) -> int: @@ -926,7 +1063,11 @@ def run_bounded_process( process = subprocess.Popen( process_command, cwd=cwd, - env=dict(environment), + env=( + containment.environment(environment) + if containment is not None + else dict(environment) + ), stdin=subprocess.PIPE if stdin_data is not None else subprocess.DEVNULL, stdout=subprocess.PIPE, stderr=subprocess.PIPE, diff --git a/scripts/nvx_tools/benchmark.py b/scripts/nvx_tools/benchmark.py index 563900e65..965e49d71 100644 --- a/scripts/nvx_tools/benchmark.py +++ b/scripts/nvx_tools/benchmark.py @@ -34,7 +34,7 @@ from typing import IO, Literal, Protocol, TextIO, TypedDict, cast from . import benchmark_host, common, host_telemetry -from .adversarial_oracles import ProcessTreeContainment +from .adversarial_oracles import ProcessTreeContainment, killed_with_parent from .build_constants import ( AlpineBuildConstants, BuildConstants, @@ -1538,6 +1538,11 @@ class InteractiveProcess: Linux attaches the console to a pseudo-terminal, and other platforms use pipes. stderr shares the console stream unless ``separate_stderr`` gives it a pipe of its own, which the caller must drain with ``read_stderr``. + + On Linux, a command started from the main thread ends with this process, + even when this process is killed outright: OpenVMM by its parent-death + signal (``killed_with_parent``), and with ``contain_process_tree``, the + whole tree by its supervisor. """ def __init__( @@ -1556,7 +1561,12 @@ def __init__( process_command = ( self.containment.command(command) if self.containment is not None - else list(command) + else killed_with_parent(command) + ) + process_environment = ( + self.containment.environment(environment) + if self.containment is not None + else environment ) if sys.platform.startswith("linux"): openpty = cast( @@ -1572,7 +1582,7 @@ def __init__( stdin=child_fd, stdout=child_fd, stderr=subprocess.PIPE if separate_stderr else child_fd, - env=environment, + env=process_environment, creationflags=creationflags, ) except Exception: @@ -1590,7 +1600,7 @@ def __init__( stdin=subprocess.PIPE, stdout=subprocess.PIPE, stderr=subprocess.PIPE if separate_stderr else subprocess.STDOUT, - env=environment, + env=process_environment, creationflags=creationflags, ) except Exception: diff --git a/scripts/nvx_tools/openvmm_process.py b/scripts/nvx_tools/openvmm_process.py index ff4385b2d..1b75de33b 100644 --- a/scripts/nvx_tools/openvmm_process.py +++ b/scripts/nvx_tools/openvmm_process.py @@ -79,6 +79,10 @@ def __init__( """ if output_read_delay < 0: raise ValueError("OpenVMM output read delay cannot be negative") + # The monitor exists before OpenVMM does, so that nothing that it + # raises leaves OpenVMM running outside the cleanup below (#720). + self._monitor = TimeAbiMonitor(command) + self._query_status = time_abi_status and self._monitor.cold_boot process_environment = os.environ.copy() process_environment["OPENVMM_LOG"] = "off" if environment is not None: @@ -111,8 +115,6 @@ def __init__( self._search_offset = 0 self._log_path = log_path self._finished = False - self._monitor = TimeAbiMonitor(command) - self._query_status = time_abi_status and self._monitor.cold_boot self._status_sent = False @property diff --git a/scripts/nvx_tools/process_supervisor.py b/scripts/nvx_tools/process_supervisor.py index 25bca650e..5e4e361fb 100644 --- a/scripts/nvx_tools/process_supervisor.py +++ b/scripts/nvx_tools/process_supervisor.py @@ -13,9 +13,15 @@ def main() -> int: if not sys.platform.startswith("linux"): raise RuntimeError("process supervisor is supported only on Linux") - if len(sys.argv) < 3 or sys.argv[1] != "--": - raise ValueError("usage: process_supervisor.py -- COMMAND [ARG ...]") - return supervise_linux_process(sys.argv[2:]) + arguments = sys.argv[1:] + parent = None + if arguments and arguments[0] != "--": + if not arguments[0].isdecimal(): + raise ValueError(f"invalid parent process ID: {arguments[0]!r}") + parent = int(arguments.pop(0)) + if len(arguments) < 2 or arguments[0] != "--": + raise ValueError("usage: process_supervisor.py [PARENT] -- COMMAND [ARG ...]") + return supervise_linux_process(arguments[1:], parent=parent) if __name__ == "__main__": diff --git a/scripts/nvx_tools/sandbox_lifecycle_tests.py b/scripts/nvx_tools/sandbox_lifecycle_tests.py index 4cd2b2a93..dcf2b5f3b 100644 --- a/scripts/nvx_tools/sandbox_lifecycle_tests.py +++ b/scripts/nvx_tools/sandbox_lifecycle_tests.py @@ -1071,10 +1071,14 @@ def clean_up(self) -> list[Exception]: def run_acceptance(acceptance: LifecycleAcceptance) -> None: """Runs an acceptance, then removes its fixture, which a failure keeps only - if its cleanup leaves a sandbox's state behind.""" + if its cleanup leaves a sandbox's state behind. + + An interruption, as when CI cancels the job (#946), stops the sandboxes + that the acceptance started, as a failure does, and then propagates as it + is, after a warning that names any cleanup errors.""" try: acceptance.run() - except Exception as error: + except BaseException as error: errors = acceptance.clean_up() try: acceptance.write_checks() @@ -1087,8 +1091,14 @@ def run_acceptance(acceptance: LifecycleAcceptance) -> None: errors.append(RuntimeError(f"fixture preserved for recovery: {preserved}")) else: shutil.rmtree(acceptance.root, ignore_errors=True) - if errors: + if errors and isinstance(error, Exception): raise RuntimeError(f"{error}; cleanup: {format_errors(errors)}") from error + if errors: + print( + f"warning: cleanup after the interruption: {format_errors(errors)}", + file=sys.stderr, + flush=True, + ) raise acceptance.write_checks() shutil.rmtree(acceptance.root) diff --git a/scripts/test_adversarial.py b/scripts/test_adversarial.py index 9af8734e0..1b3cb3a2c 100644 --- a/scripts/test_adversarial.py +++ b/scripts/test_adversarial.py @@ -9,6 +9,7 @@ import json import os import queue +import shutil import signal import socket import subprocess @@ -17,7 +18,7 @@ import threading import time import unittest -from collections.abc import Mapping, Sequence +from collections.abc import Callable, Mapping, Sequence from pathlib import Path from typing import cast from unittest.mock import MagicMock, call, patch @@ -61,14 +62,17 @@ sanitized_environment, ) from nvx_tools.adversarial_oracles import ( + _OWNED_EXEC, BoundedProcessResult, NetworkCanary, OracleSession, + ProcessTreeContainment, _freeze_linux_process_tree, _linux_process_exited, _reap_linux_children, _reap_linux_descendants, _WindowsJob, + killed_with_parent, run_bounded_process, terminate_process_tree, ) @@ -1263,6 +1267,394 @@ def fail_pid_journal(_pid: int, _environment: object) -> None: unrelated.kill() unrelated.wait() + def test_only_main_thread_commands_end_with_their_parent(self) -> None: + # #946: the kernel sends a parent-death signal when the thread that + # started the process exits, so only the main thread, which lives as + # long as its process, ties a process to its own. + command = ["openvmm", "--hypervisor", "kvm"] + containment = ProcessTreeContainment() + self.addCleanup(containment.abort_spawn) + + def from_thread(start: Callable[[], list[str]]) -> list[str]: + started: list[list[str]] = [] + thread = threading.Thread(target=lambda: started.append(start())) + thread.start() + thread.join() + return started[0] + + with ( + patch("nvx_tools.adversarial_oracles.sys.platform", "linux"), + patch( + "nvx_tools.adversarial_oracles.shutil.which", + return_value="/usr/bin/setpriv", + ) as which, + ): + self.assertEqual( + killed_with_parent(command), + [ + "/usr/bin/setpriv", + "--pdeathsig", + "KILL", + "--", + "/bin/sh", + "-c", + _OWNED_EXEC, + "sh", + str(os.getpid()), + *command, + ], + ) + which.assert_called_once_with("setpriv") + self.assertEqual(from_thread(lambda: killed_with_parent(command)), command) + supervised = containment.command(command) + self.assertEqual(supervised[:2], [sys.executable, "-I"]) + self.assertEqual(Path(supervised[2]).name, "process_supervisor.py") + self.assertEqual(supervised[3:], [str(os.getpid()), "--", *command]) + self.assertEqual( + from_thread(lambda: containment.command(command))[3:], + ["--", *command], + ) + with ( + patch("nvx_tools.adversarial_oracles.sys.platform", "linux"), + patch("nvx_tools.adversarial_oracles.shutil.which", return_value=None), + ): + self.assertEqual(killed_with_parent(command), command) + with patch("nvx_tools.adversarial_oracles.sys.platform", "win32"): + self.assertEqual(killed_with_parent(command), command) + self.assertEqual(containment.command(command), command) + + @unittest.skipUnless(sys.platform.startswith("linux"), "Linux parent-death signal") + def test_a_killed_owner_takes_its_interactive_processes_along(self) -> None: + # #946: the runner's orphan cleanup kills the test harness of a + # cancelled job outright, and a VM that the harness had started after + # the cleanup listed the job's processes ran on for days (#768). What + # InteractiveProcess starts ends with its owner all the same: OpenVMM + # by its parent-death signal, and a contained tree, descendants that + # leave its session included, by its supervisor. + owner_script = ( + "import os, sys\n" + "sys.path.insert(0, sys.argv[1])\n" + "from nvx_tools.benchmark import InteractiveProcess\n" + "interaction = InteractiveProcess(\n" + " sys.argv[3:],\n" + " dict(os.environ),\n" + " contain_process_tree=sys.argv[2] == 'contained',\n" + ")\n" + "print(interaction.process.pid, flush=True)\n" + "sys.stdin.read()\n" + ) + for contained in (False, True): + with ( + self.subTest(contained=contained), + tempfile.TemporaryDirectory() as temporary, + ): + if not contained and shutil.which("setpriv") is None: + self.skipTest("needs setpriv") + root = Path(temporary) + pid_paths = [root / "command.pid"] + script = ( + "import os, pathlib, subprocess, sys, time\n" + "pathlib.Path(sys.argv[1]).write_text(str(os.getpid()))\n" + ) + if contained: + pid_paths.append(root / "descendant.pid") + script += ( + "child = subprocess.Popen([sys.executable, '-c', " + "'import os, time; os.setsid(); time.sleep(60)'])\n" + "pathlib.Path(sys.argv[2]).write_text(str(child.pid))\n" + ) + script += "time.sleep(60)\n" + owner = subprocess.Popen( + [ + sys.executable, + "-c", + owner_script, + str(Path(__file__).resolve().parent), + "contained" if contained else "direct", + sys.executable, + "-c", + script, + *(str(path) for path in pid_paths), + ], + stdin=subprocess.PIPE, + stdout=subprocess.PIPE, + ) + owned: list[int] = [] + try: + assert owner.stdout is not None + line = owner.stdout.readline() + self.assertTrue(line, "the owner exited before it started") + owned.append(int(line)) + deadline = time.monotonic() + 30 + for path in pid_paths: + while True: + self.assertLess(time.monotonic(), deadline) + try: + owned.append(int(path.read_text(encoding="utf-8"))) + break + except (FileNotFoundError, ValueError): + time.sleep(0.01) + owner.kill() + owner.wait() + deadline = time.monotonic() + 10 + while not all(_process_exited(pid) for pid in owned): + self.assertLess( + time.monotonic(), + deadline, + f"processes {owned} outlived their owner", + ) + time.sleep(0.05) + finally: + for pid in owned: + if _process_running(pid): + with contextlib.suppress(ProcessLookupError): + os.kill(pid, 9) + if owner.poll() is None: + owner.kill() + owner.wait() + for stream in (owner.stdin, owner.stdout): + if stream is not None: + stream.close() + + @unittest.skipUnless(sys.platform.startswith("linux"), "Linux parent-death signal") + def test_a_command_whose_owner_exited_never_starts(self) -> None: + # #946: an owner that dies before setpriv arms the parent-death signal + # sends none, and the orphaned command is then another process's + # child, as it is here, where a shell starts it. It must not start. + if shutil.which("setpriv") is None: + self.skipTest("needs setpriv") + with tempfile.TemporaryDirectory() as temporary: + started = Path(temporary) / "started" + command = killed_with_parent( + [ + sys.executable, + "-c", + "import pathlib, sys; pathlib.Path(sys.argv[1]).touch()", + str(started), + ] + ) + orphaned = subprocess.run( + ["/bin/sh", "-c", '"$@"; exit "$?"', "sh", *command], + timeout=30, + check=False, + ) + self.assertNotEqual(orphaned.returncode, 0) + self.assertFalse(started.exists()) + # Its owner starts it. + owned = subprocess.run(command, timeout=30, check=False) + self.assertEqual(owned.returncode, 0) + self.assertTrue(started.exists()) + + def test_supervisors_run_without_the_runners_tracking_id(self) -> None: + # #946: the runner's orphan cleanup kills the processes whose + # environment names the job in RUNNER_TRACKING_ID. The supervisor runs + # without it, so that the cleanup can't kill it before it ends its + # tree, and gives it back to its command, which the cleanup tracks. + containment = ProcessTreeContainment() + self.addCleanup(containment.abort_spawn) + environment = {"RUNNER_TRACKING_ID": "github_1234", "NVX_MARKER": "kept"} + with patch("nvx_tools.adversarial_oracles.sys.platform", "linux"): + self.assertEqual( + containment.environment(environment), + { + "NVX_SUPERVISED_RUNNER_TRACKING_ID": "github_1234", + "NVX_MARKER": "kept", + }, + ) + self.assertEqual( + containment.environment({"NVX_MARKER": "kept"}), + {"NVX_MARKER": "kept"}, + ) + with patch("nvx_tools.adversarial_oracles.sys.platform", "win32"): + self.assertEqual(containment.environment(environment), environment) + self.assertEqual(environment["RUNNER_TRACKING_ID"], "github_1234") + + @unittest.skipUnless(sys.platform.startswith("linux"), "Linux process ownership") + def test_the_orphan_cleanup_leaves_a_contained_tree_to_its_supervisor( + self, + ) -> None: + # #946: the runner's orphan cleanup lists the processes whose + # environment names the job in RUNNER_TRACKING_ID and then kills them, + # the test harness first. A process that the harness's contained tree + # starts after the listing, such as OpenVMM, escapes the list, and the + # supervisor, which the cleanup doesn't list, ends it. + tracking = f"nvx-test-{os.getpid()}-{time.monotonic_ns()}" + owner_script = ( + "import os, sys\n" + "sys.path.insert(0, sys.argv[1])\n" + "from nvx_tools.benchmark import InteractiveProcess\n" + "interaction = InteractiveProcess(\n" + " sys.argv[2:], dict(os.environ), contain_process_tree=True\n" + ")\n" + "print(interaction.process.pid, flush=True)\n" + "sys.stdin.read()\n" + ) + command_script = ( + "import os, pathlib, subprocess, sys, time\n" + "pathlib.Path(sys.argv[1]).write_text(str(os.getpid()))\n" + "while not pathlib.Path(sys.argv[2]).exists():\n" + " time.sleep(0.01)\n" + "late = subprocess.Popen([sys.executable, '-c', " + "'import os, time; os.setsid(); time.sleep(60)'])\n" + "pathlib.Path(sys.argv[3]).write_text(str(late.pid))\n" + "time.sleep(60)\n" + ) + + def listed() -> list[int]: + tracked = f"RUNNER_TRACKING_ID={tracking}".encode() + found: list[int] = [] + for entry in Path("/proc").iterdir(): + if not entry.name.isdigit(): + continue + try: + environment = (entry / "environ").read_bytes().split(b"\0") + except OSError: + continue + if tracked in environment: + found.append(int(entry.name)) + return sorted(found) + + def read_pid(path: Path) -> int: + deadline = time.monotonic() + 30 + while True: + self.assertLess(time.monotonic(), deadline) + try: + return int(path.read_text(encoding="utf-8")) + except (FileNotFoundError, ValueError): + time.sleep(0.01) + + with tempfile.TemporaryDirectory() as temporary: + root = Path(temporary) + go = root / "go" + owner = subprocess.Popen( + [ + sys.executable, + "-c", + owner_script, + str(Path(__file__).resolve().parent), + sys.executable, + "-c", + command_script, + str(root / "command.pid"), + str(go), + str(root / "late.pid"), + ], + env=dict(os.environ, RUNNER_TRACKING_ID=tracking), + stdin=subprocess.PIPE, + stdout=subprocess.PIPE, + ) + owned: list[int] = [] + try: + assert owner.stdout is not None + line = owner.stdout.readline() + self.assertTrue(line, "the owner exited before it started") + supervisor = int(line) + owned.append(supervisor) + command = read_pid(root / "command.pid") + owned.append(command) + snapshot = listed() + self.assertIn(owner.pid, snapshot) + self.assertIn(command, snapshot) + self.assertNotIn(supervisor, snapshot) + go.touch() + owned.append(read_pid(root / "late.pid")) + for pid in snapshot: + with contextlib.suppress(ProcessLookupError): + os.kill(pid, 9) + owner.wait() + deadline = time.monotonic() + 10 + while not all(_process_exited(pid) for pid in owned): + self.assertLess( + time.monotonic(), + deadline, + f"processes {owned} outlived the cleanup", + ) + time.sleep(0.05) + finally: + for pid in owned: + if _process_running(pid): + with contextlib.suppress(ProcessLookupError): + os.kill(pid, 9) + if owner.poll() is None: + owner.kill() + owner.wait() + for stream in (owner.stdin, owner.stdout): + if stream is not None: + stream.close() + + @unittest.skipUnless(sys.platform.startswith("linux"), "Linux process ownership") + def test_a_supervisor_whose_parent_exited_starts_nothing(self) -> None: + # A parent that exited before the supervisor set its parent-death + # signal sends no signal, so the supervisor checks its parent first. + exited = subprocess.Popen([sys.executable, "-c", ""]) + exited.wait() + supervisor = ( + Path(__file__).resolve().parent / "nvx_tools" / "process_supervisor.py" + ) + with tempfile.TemporaryDirectory() as temporary: + started = Path(temporary) / "started" + result = subprocess.run( + [ + sys.executable, + "-I", + str(supervisor), + str(exited.pid), + "--", + sys.executable, + "-c", + "import pathlib, sys; pathlib.Path(sys.argv[1]).touch()", + str(started), + ], + timeout=30, + check=False, + ) + self.assertEqual(result.returncode, -signal.SIGTERM) + self.assertFalse(started.exists()) + + @unittest.skipUnless(sys.platform.startswith("linux"), "Linux process ownership") + def test_a_supervisor_forwards_signals_while_its_parent_lives(self) -> None: + # The command handles the forwarded SIGTERM and exits with status 7, + # which a supervisor that took its parent for dead would have killed. + with tempfile.TemporaryDirectory() as temporary: + root = Path(temporary) + pid_path = root / "command.pid" + stopped = root / "stopped" + script = ( + "import os, pathlib, signal, sys, time\n" + "def stop(signum, frame):\n" + " pathlib.Path(sys.argv[2]).touch()\n" + " sys.exit(7)\n" + "signal.signal(signal.SIGTERM, stop)\n" + "pathlib.Path(sys.argv[1]).write_text(str(os.getpid()))\n" + "time.sleep(60)\n" + ) + containment = ProcessTreeContainment() + supervisor = subprocess.Popen( + containment.command( + [sys.executable, "-c", script, str(pid_path), str(stopped)] + ) + ) + command_pid: int | None = None + try: + deadline = time.monotonic() + 30 + while command_pid is None: + self.assertLess(time.monotonic(), deadline) + try: + command_pid = int(pid_path.read_text(encoding="utf-8")) + except (FileNotFoundError, ValueError): + time.sleep(0.01) + supervisor.send_signal(signal.SIGTERM) + self.assertEqual(supervisor.wait(timeout=30), 7) + self.assertTrue(stopped.exists()) + self.assertTrue(_process_exited(command_pid)) + finally: + if command_pid is not None and _process_running(command_pid): + with contextlib.suppress(ProcessLookupError): + os.kill(command_pid, 9) + if supervisor.poll() is None: + supervisor.kill() + supervisor.wait() + def test_network_canary_counts_connections_queued_at_close(self) -> None: with tempfile.TemporaryDirectory() as temporary: canary = NetworkCanary(Path(temporary) / "network-canary.jsonl") diff --git a/scripts/test_microvm_tests.py b/scripts/test_microvm_tests.py index 61fcf7fad..a9bea001e 100644 --- a/scripts/test_microvm_tests.py +++ b/scripts/test_microvm_tests.py @@ -23,7 +23,7 @@ import time import unittest from collections.abc import Callable, Collection, Sequence -from contextlib import ExitStack, nullcontext, redirect_stdout +from contextlib import ExitStack, nullcontext, redirect_stderr, redirect_stdout from datetime import datetime from pathlib import Path from typing import Any, cast @@ -1226,6 +1226,9 @@ def _exec( files[arguments[0]] = b"" elif entrypoint == sandbox_lifecycle_tests.PROBE: self.probed = True + if "probe-interrupted" in self.faults: + # SIGINT reaches the harness while it waits for the probe. + raise KeyboardInterrupt if "probe-fails" in self.faults: returncode = 1 stderr = b"NVX-UBUNTU-SANDBOX-FAIL: the workload shares a namespace\n" @@ -1688,6 +1691,45 @@ def test_failed_cleanup_preserves_the_fixture(self): (root / "results" / "sandbox-lifecycle-openvmm.log").is_file() ) + def test_an_interrupted_acceptance_stops_its_sandboxes(self): + # A cancelled CI job interrupts the harness (#946), which stops the + # sandboxes that the acceptance started, as a failure does, and still + # reports the interruption, not a failure. + for faults, preserved in ( + (("probe-interrupted",), False), + (("probe-interrupted", "cleanup-deprovision-fails"), True), + ): + with ( + self.subTest(faults=faults), + tempfile.TemporaryDirectory() as temporary, + ): + root = Path(temporary) + fake = _FakeSandboxCli(*faults) + stderr = io.StringIO() + with ( + redirect_stderr(stderr), + self.assertRaises(KeyboardInterrupt), + ): + self._run(root, fake) + fixtures = list(root.glob("nvx-public-lifecycle-*")) + + # The cleanup stopped and deprovisioned the running sandbox. + self.assertEqual(fake.operations[-3:], ["exec", "stop", "deprovision"]) + self.assertFalse(any(fake.running.values())) + self.assertEqual(len(fixtures), int(preserved)) + self.assertTrue( + (root / "results" / "sandbox-lifecycle-checks.json").is_file() + ) + if preserved: + self.assertIn(str(fixtures[0]), stderr.getvalue()) + self.assertRegex( + stderr.getvalue(), + "^warning: cleanup after the interruption: .*" + "fixture preserved for recovery", + ) + else: + self.assertEqual(stderr.getvalue(), "") + def test_scratch_journal_check_reads_the_ext4_recovery_flag(self): with tempfile.TemporaryDirectory() as temporary: image = Path(temporary) / "scratch.ext4" @@ -5150,6 +5192,24 @@ def test_negative_output_read_delay_does_not_start_process(self): ) interaction.assert_not_called() + def test_time_abi_monitor_failure_does_not_start_process(self): + # #720: the monitor is built before OpenVMM starts, so that its + # failure cannot leave OpenVMM running outside the cleanup. + with tempfile.TemporaryDirectory() as temporary: + log_path = Path(temporary) / "output.log" + with ( + patch.object( + openvmm_process, + "TimeAbiMonitor", + side_effect=RuntimeError("synthetic monitor failure"), + ), + patch.object(openvmm_process, "InteractiveProcess") as interaction, + self.assertRaisesRegex(RuntimeError, "synthetic monitor failure"), + ): + openvmm_process.OpenvmmProcess(["openvmm"], log_path) + self.assertFalse(log_path.exists()) + interaction.assert_not_called() + def test_snapshot_restore_runs_the_time_abi_steps_through_nvx_time(self): snapshot = ( Path(__file__).parents[1] / "guest" / "common" / "nvx-snapshot" diff --git a/scripts/test_nvx_tools.py b/scripts/test_nvx_tools.py index 046be05ed..4c4902d91 100644 --- a/scripts/test_nvx_tools.py +++ b/scripts/test_nvx_tools.py @@ -141,6 +141,46 @@ def _composite_action_script(action: str, step_name: str) -> str: return "\n".join(line[8:] for line in lines[start:end]) +_FORWARD_SIGNALS_SOURCE = 'source "${GITHUB_ACTION_PATH}/forward-signals.sh"\n' + + +def _harness_in_foreground(script: str) -> str: + """Return a Linux run-benchmark step script whose run_harness runs the + harness in the foreground, so that a test can stub the harness with a + shell function, which the exec in forward-signals.sh would bypass.""" + if script.count(_FORWARD_SIGNALS_SOURCE) != 1: + raise AssertionError(f"the step doesn't source forward-signals.sh:\n{script}") + return script.replace(_FORWARD_SIGNALS_SOURCE, 'run_harness() { "$@"; }\n') + + +_FORWARD_SIGNALS = ( + BuildConstants.REPO_ROOT + / ".github" + / "actions" + / "run-benchmark" + / "forward-signals.sh" +) + +# A harness for run_harness that handles SIGTERM as SIGINT, as nvx.py does, +# and cleans up when either one interrupts it, unless it ignores both. Its +# arguments are the files that it creates as it starts and as it cleans up, +# how long it then runs, its exit status, and "handle" or "ignore". +_CANCELLABLE_HARNESS = ( + "import pathlib, signal, sys, time\n" + "signal.signal(signal.SIGTERM, signal.default_int_handler)\n" + "if sys.argv[5] == 'ignore':\n" + " signal.signal(signal.SIGINT, signal.SIG_IGN)\n" + " signal.signal(signal.SIGTERM, signal.SIG_IGN)\n" + "try:\n" + " pathlib.Path(sys.argv[1]).touch()\n" + " time.sleep(float(sys.argv[3]))\n" + "except KeyboardInterrupt:\n" + " pathlib.Path(sys.argv[2]).touch()\n" + " sys.exit(130)\n" + "sys.exit(int(sys.argv[4]))\n" +) + + def _workflow_step(workflow: str, job_name: str, step_name: str) -> str: lines = _workflow_job(workflow, job_name).splitlines() start = lines.index(f" - name: {step_name}") @@ -756,6 +796,56 @@ def section(title: str, level: int) -> str: set(option.findall(usage_of(*command))), ) + @unittest.skipUnless(os.name == "posix", "SIGTERM is a POSIX signal") + def test_sigterm_interrupts_a_command_as_sigint_does(self): + # A cancelled CI step gets SIGINT and then SIGTERM (#946). Either one + # unwinds the command, so that its cleanup stops OpenVMM and removes + # its scratch directories, and nvx.py then exits as after Ctrl-C. + previous = signal.signal(signal.SIGTERM, signal.SIG_DFL) + self.addCleanup(signal.signal, signal.SIGTERM, previous) + cleaned: list[bool] = [] + + def interrupted(_args: argparse.Namespace) -> int: + try: + # Without its handler, SIGTERM would end this test process. + self.assertIs( + signal.getsignal(signal.SIGTERM), signal.default_int_handler + ) + os.kill(os.getpid(), signal.SIGTERM) + deadline = time.monotonic() + 10 + while time.monotonic() < deadline: + time.sleep(0.01) + self.fail("SIGTERM did not interrupt the command") + finally: + cleaned.append(True) + + stderr = io.StringIO() + with ( + patch.object( + nvx, "parse_args", return_value=argparse.Namespace(handler=interrupted) + ), + contextlib.redirect_stderr(stderr), + ): + self.assertEqual(nvx.main([]), 130) + self.assertEqual(cleaned, [True]) + self.assertEqual(stderr.getvalue(), "Interrupted\n") + self.assertEqual(signal.getsignal(signal.SIGTERM), signal.SIG_DFL) + + # As Python does for SIGINT, nvx.py leaves an ignored SIGTERM ignored. + signal.signal(signal.SIGTERM, signal.SIG_IGN) + + def ignored(_args: argparse.Namespace) -> int: + self.assertEqual(signal.getsignal(signal.SIGTERM), signal.SIG_IGN) + os.kill(os.getpid(), signal.SIGTERM) + time.sleep(0.05) + return 0 + + with patch.object( + nvx, "parse_args", return_value=argparse.Namespace(handler=ignored) + ): + self.assertEqual(nvx.main([]), 0) + self.assertEqual(signal.getsignal(signal.SIGTERM), signal.SIG_IGN) + def test_check_required_ci_rejects_malformed_run_flags(self): # microsoft/nvx#496: an empty or malformed --run-* value must not be # silently accepted as false, which would let required-status checking @@ -12288,6 +12378,147 @@ def run( environment["PATH"] = f"{stubs}{os.pathsep}{environment['PATH']}" self.assertNotEqual(run(environment).returncode, 0) + def test_linux_runners_remove_scratch_left_by_earlier_jobs(self): + validate_runner = ( + BuildConstants.REPO_ROOT + / ".github" + / "actions" + / "validate-runner" + / "action.yml" + ).read_text(encoding="utf-8") + + # #946: a harness that the runner's orphan cleanup killed left its + # scenario's scratch directory behind, and the ten Linux runners held + # 64 of them. The next job removes the account's harness directories, + # once it has ended the OpenVMM processes that could still use them. + name = "Remove scratch left by earlier jobs" + self.assertLess( + validate_runner.index( + " - name: Terminate OpenVMM left by earlier jobs\n" + ), + validate_runner.index(f" - name: {name}\n"), + ) + self.assertLess( + validate_runner.index(f" - name: {name}\n"), + validate_runner.index(" - name: Report host TSC\n"), + ) + step = validate_runner.split(f" - name: {name}\n", 1)[1] + step = step.split("\n\n", 1)[0] + self.assertIn(" if: runner.os != 'Windows'\n", step) + self.assertIn(" shell: bash\n", step) + script = "\n".join( + line.removeprefix(" ") + for line in step.split(" run: |\n", 1)[1].splitlines() + ) + temporary_line = ( + "temporary=$(python3 -c 'import tempfile; print(tempfile.gettempdir())')\n" + ) + self.assertIn(temporary_line, script) + # Each scratch directory that the harness creates in the temporary + # directory has a prefix that the step removes. + for module in ( + "benchmark", + "managed_exec_tests", + "microvm_tests", + "sandbox_lifecycle_tests", + "sandbox_proxy_tests", + ): + source = ( + BuildConstants.REPO_ROOT / "scripts" / "nvx_tools" / f"{module}.py" + ).read_text(encoding="utf-8") + calls = re.findall( + r"(?:TemporaryDirectory|mkdtemp)\((.*?)\)", source, re.DOTALL + ) + self.assertTrue(calls, module) + for arguments in calls: + with self.subTest(module=module, arguments=arguments): + self.assertRegex(arguments, r'^\s*prefix=f?"(nvx|openvmm)-') + self.assertNotIn("dir=", arguments) + if sys.platform != "linux": + return + + with tempfile.TemporaryDirectory() as temporary: + root = Path(temporary) + scratch = root / "tmp" + scratch.mkdir() + # The step never sees the temporary directory of this host. + check = script.replace( + temporary_line, f"temporary={shlex.quote(str(scratch))}\n", 1 + ) + + def run( + environment: dict[str, str] | None = None, + ) -> subprocess.CompletedProcess[str]: + return subprocess.run( + ["bash", "-c", check], + capture_output=True, + text=True, + timeout=30, + check=False, + env=environment, + ) + + left = [ + scratch / "nvx-restore-downtime-duijv83o", + scratch / "openvmm-device-io-ep0lqoc8", + ] + for directory in left: + (directory / "snapshot").mkdir(parents=True) + (directory / "snapshot" / "memory.bin").write_bytes(bytes(16)) + # A directory that even its owner can't empty as it is. + locked = left[0] / "locked" + locked.mkdir() + (locked / "file").write_text("locked", encoding="utf-8") + locked.chmod(0o500) + # Neither a file nor a link to a directory is a harness directory. + outside = root / "outside" + outside.mkdir() + (outside / "data").write_text("outside", encoding="utf-8") + other = scratch / "other-directory" + other.mkdir() + file = scratch / "nvx-file" + file.write_text("file", encoding="utf-8") + link = scratch / "nvx-link" + link.symlink_to(outside, target_is_directory=True) + + result = run() + self.assertEqual(result.returncode, 0, result.stderr) + for directory in left: + self.assertFalse(directory.exists()) + self.assertIn( + f"::notice::Removing {directory}, last modified ", result.stdout + ) + self.assertIn(", which an earlier job left behind\n", result.stdout) + self.assertNotIn("::warning::", result.stdout) + self.assertTrue(other.is_dir()) + self.assertEqual(file.read_text(encoding="utf-8"), "file") + self.assertTrue(link.is_symlink()) + self.assertEqual((outside / "data").read_text(encoding="utf-8"), "outside") + # Without leftover directories, the step says nothing. + result = run() + self.assertEqual(result.returncode, 0, result.stderr) + self.assertEqual(result.stdout, "") + # A directory that the step can't remove warns but doesn't fail the + # job, and a failure to list the directories fails it. + stubs = root / "stubs" + stubs.mkdir() + stuck = scratch / "nvx-stuck" + stuck.mkdir() + (stubs / "rm").write_text("#!/bin/sh\nexit 1\n", encoding="utf-8") + (stubs / "rm").chmod(0o755) + environment = dict(os.environ) + environment["PATH"] = f"{stubs}{os.pathsep}{environment['PATH']}" + result = run(environment) + self.assertEqual(result.returncode, 0, result.stderr) + self.assertIn( + f"::warning::Could not remove {stuck}, which an earlier job left behind", + result.stdout, + ) + (stubs / "rm").unlink() + (stubs / "find").write_text("#!/bin/sh\nexit 2\n", encoding="utf-8") + (stubs / "find").chmod(0o755) + self.assertNotEqual(run(environment).returncode, 0) + def test_runners_qualify_their_host_time_before_every_job(self): validate_runner = ( BuildConstants.REPO_ROOT @@ -13587,7 +13818,9 @@ def test_linux_acceptance_preserves_attempts_and_publishes_only_valid_data(self) / "run-benchmark" / "action.yml" ).read_text(encoding="utf-8") - script = _composite_action_script(action, "Run Linux acceptance test") + script = _harness_in_foreground( + _composite_action_script(action, "Run Linux acceptance test") + ) platform = "linux-kvm-virtual-machine" for name, value in ( ("backend", "kvm"), @@ -13820,7 +14053,9 @@ def test_linux_restore_suites_preserve_attempts_and_publish_only_valid_data( } ) for step, suite, processor_counts, scenarios in RESTORE_REMEASUREMENT_STEPS: - script = _composite_action_script(action, f"Run Linux {step}") + script = _harness_in_foreground( + _composite_action_script(action, f"Run Linux {step}") + ) for name, value in ( ("backend", "mshv"), ("platform", platform), @@ -13879,6 +14114,224 @@ def test_linux_restore_suites_preserve_attempts_and_publish_only_valid_data( root, platform, suite, processor_counts, measured, published ) + def test_a_cancellation_reaches_the_linux_test_harness(self): + # #946: the runner signals only a cancelled step's shell, and Bash + # runs a trap only once its foreground command ends, so the harness + # ran on until the runner's orphan cleanup killed it, which left its + # scratch directories behind. Each Linux step execs the harness, or + # runs it with run_harness, which passes a cancellation on to it. + github = BuildConstants.REPO_ROOT / ".github" + workflow = yaml.safe_load( + (github / "workflows" / "run-nvx-microvm-tests.yml").read_text( + encoding="utf-8" + ) + ) + harness = "python3 scripts/nvx.py test-microvm" + steps = [ + step + for job in workflow["jobs"].values() + for step in job["steps"] + if step.get("shell") == "bash" and harness in step.get("run", "") + ] + self.assertTrue(steps) + for step in steps: + with self.subTest(step=step["name"]): + self.assertTrue(step["run"].startswith(f"exec {harness} ")) + + action = yaml.safe_load( + (github / "actions" / "run-benchmark" / "action.yml").read_text( + encoding="utf-8" + ) + ) + harness = "python3 scripts/nvx.py benchmark" + scripts = { + step["name"]: step["run"] + for step in action["runs"]["steps"] + if step.get("shell") == "bash" and harness in step.get("run", "") + } + self.assertEqual( + set(scripts), + { + "Run Linux acceptance test", + "Run Linux performance suite", + "Run Linux multi-vCPU shell restore", + "Run Linux device operation rates", + }, + ) + for name, script in scripts.items(): + with self.subTest(step=name): + commands = [ + line.strip() for line in script.splitlines() if harness in line + ] + if commands == [f"exec {harness} \\"]: + continue + self.assertTrue(commands) + self.assertTrue( + all(command == f"run_harness {harness} \\" for command in commands) + ) + self.assertLess( + script.index(_FORWARD_SIGNALS_SOURCE), script.index("run_harness") + ) + # The quality checks lint the file that the steps source. + quality = (github / "actions" / "check-quality" / "action.yml").read_text( + encoding="utf-8" + ) + for linter in ("${SHELLCHECK} --shell=bash", "${SHFMT} -d -ln bash"): + with self.subTest(linter=linter): + checked = quality.split(linter, 1)[1].split("\n\n", 1)[0] + checked = checked.split("${", 1)[0] + self.assertIn( + ".github/actions/run-benchmark/forward-signals.sh", checked + ) + + @unittest.skipUnless(sys.platform.startswith("linux"), "Linux signals") + def test_run_harness_passes_a_cancellation_on_to_the_harness(self): + if signal.getsignal(signal.SIGINT) == signal.SIG_IGN: + self.skipTest("Bash cannot trap a SIGINT that this process ignores") + for name, signum, delay, status, mode, expected in ( + # The runner's SIGINT, and its SIGTERM, reach the harness, which + # cleans up, and the step then fails with the status of the + # signal. + ("sigint", signal.SIGINT, 60, 0, "handle", 130), + ("sigterm", signal.SIGTERM, 60, 0, "handle", 143), + # Without a cancellation, run_harness returns the harness's + # status, which set -e turns into the step's. + ("success", None, 0, 0, "handle", 0), + ("failure", None, 0, 3, "handle", 3), + # A cancellation that doesn't stop the harness, as one that + # arrives as it exits, still ends the step once it exits. + ("late", signal.SIGINT, 1, 0, "ignore", 130), + # A cancellation between two harness runs ends the step. + ("between", signal.SIGINT, 0, 0, "handle", 130), + ): + with ( + self.subTest(name=name), + tempfile.TemporaryDirectory() as temporary, + ): + root = Path(temporary) + started, cleaned = root / "started", root / "cleaned" + waiting, finished = root / "waiting", root / "finished" + run = shlex.join( + [ + "run_harness", + sys.executable, + "-c", + _CANCELLABLE_HARNESS, + str(started), + str(cleaned), + str(delay), + str(status), + mode, + ] + ) + script = ( + "set -euo pipefail\n" + f"source {shlex.quote(str(_FORWARD_SIGNALS))}\n" + + ( + f"{run}\ntouch {shlex.quote(str(waiting))}\nsleep 2\n" + if name == "between" + else "" + ) + + f"{run}\ntouch {shlex.quote(str(finished))}\n" + ) + shell = subprocess.Popen( + ["bash", "--noprofile", "--norc", "-c", script] + ) + try: + if signum is not None: + ready = waiting if name == "between" else started + deadline = time.monotonic() + 30 + while not ready.exists(): + self.assertLess(time.monotonic(), deadline) + time.sleep(0.01) + if name == "between": + started.unlink() + shell.send_signal(signum) + self.assertEqual(shell.wait(timeout=30), expected) + finally: + if shell.poll() is None: + shell.kill() + shell.wait() + self.assertEqual(finished.exists(), expected == 0) + if name in ("sigint", "sigterm"): + self.assertTrue(cleaned.exists()) + if name == "between": + # The step ended before it started the second harness. + self.assertFalse(started.exists()) + + def test_run_harness_passes_on_a_cancellation_that_arrives_as_it_starts(self): + # A cancellation that arrived once run_harness had started the + # harness, but before it knew the harness's PID, ended the step at + # once and left the harness to run on. Passed on as SIGINT, it would + # also be lost on a harness that had yet to restore the SIGINT that + # Bash ignores in a background command. + if sys.platform != "linux": + self.skipTest("Linux signals") + if signal.getsignal(signal.SIGINT) == signal.SIG_IGN: + self.skipTest("Bash cannot trap a SIGINT that this process ignores") + for signum, expected in ((signal.SIGINT, 130), (signal.SIGTERM, 143)): + with ( + self.subTest(signal=signum.name), + tempfile.TemporaryDirectory() as temporary, + ): + root = Path(temporary) + started, cleaned = root / "started", root / "cleaned" + recorded, finished = root / "harness-pid", root / "finished" + # With functrace, a DEBUG trap runs before each command of + # run_harness too, so the shell signals itself right after it + # starts the harness, before the first command that runs once + # $! holds the harness's PID. + script = ( + "set -euo pipefail\n" + f"source {shlex.quote(str(_FORWARD_SIGNALS))}\n" + "cancel() {\n" + f' if [[ -n "${{!:-}}" && ! -e {shlex.quote(str(recorded))} ]]; then\n' + f' echo "$!" >{shlex.quote(str(recorded))}\n' + f' kill -{signum.name.removeprefix("SIG")} "$$"\n' + " fi\n" + "}\n" + "set -T\n" + "trap cancel DEBUG\n" + + shlex.join( + [ + "run_harness", + sys.executable, + "-c", + _CANCELLABLE_HARNESS, + str(started), + str(cleaned), + "60", + "0", + "handle", + ] + ) + + f"\ntouch {shlex.quote(str(finished))}\n" + ) + shell = subprocess.Popen( + ["bash", "--noprofile", "--norc", "-c", script] + ) + try: + # Unless the signal reached it, the harness runs for a + # minute. + self.assertEqual(shell.wait(timeout=30), expected) + finally: + if shell.poll() is None: + shell.kill() + shell.wait() + outlived = False + if recorded.exists(): + pid = int(recorded.read_text(encoding="utf-8")) + with contextlib.suppress(ProcessLookupError): + os.kill(pid, 0) + outlived = True + os.kill(pid, signal.SIGKILL) + self.assertTrue(recorded.exists(), "the shell never cancelled itself") + # The step ended only once the harness had exited. + self.assertFalse(outlived) + self.assertFalse(finished.exists()) + # The signal stopped the harness as it started, or it cleaned up. + self.assertTrue(cleaned.exists() or not started.exists()) + @unittest.skipUnless(os.name == "nt", "requires Windows PowerShell") def test_windows_restore_suites_preserve_attempts_and_publish_only_valid_data( self,