From 22ee0dfbf2e62b8dba0cee6cc3bcc630dbfc23f8 Mon Sep 17 00:00:00 2001 From: Stanley Phoong Date: Wed, 19 Aug 2026 00:52:16 -0700 Subject: [PATCH] fix(swebench-service): give Pyxis container creation its own deadline Under Pyxis, creating the container is its own piece of infrastructure work: `--container-image` makes enroot import a multi-GB SWE-bench image and slurmstepd launch a step for it. That was charged against `environment.timeout` -- the per-*command* budget, 300s in both templates, sized for `pytest`-scale work inside an already-running container -- because `PyxisSweBenchRunner._configure_environment` dropped the template's `pull_timeout: 3600` as a docker-only key and `PyxisEnvironment.__init__` had nothing else to use. A create budget must be separate from a per-command budget because the two scale with completely different things. A command's cost depends on the task; a create's cost depends on how much other work is contending for the node. Measured on an idle node, one create is ~35s and eight concurrent creates finish in 55s wall -- so 300s looks generous right up until it isn't. In the run that exposed this, four SWE-bench services drove 40 concurrent agents across 5,148 srun steps in 78 minutes, every step requesting all 144 CPUs, on a node also running four vLLM engines. Creation slowed by an order of magnitude, `subprocess.run(timeout=timeout_s + 30)` SIGKILLed the step, and 96 steps died at a uniform 5m47s-5m56s -- 330s plus step-accounting skew, against 3-11s for every ordinary command step. 17 of 20 units were lost and the run produced no accuracy number at all. The registry was never the bottleneck; step contention was. Carry `pull_timeout` through to a distinct `create_timeout_s` (default 3600) and use it for the create step only. Command steps keep `timeout`. Also stop discarding srun's own output. Both infrastructure-failure paths in `run_srun_step()` raised a fixed string and threw away the captured stream, so an import failure, an out-of-space enroot, and a step that never got resources were one indistinguishable message -- the 17 lost units above could not be told apart from their artifacts. The failure now carries srun's last 2000 characters, names the deadline it blew, and reports srun's exit code. Finally, make creation measurable while it happens rather than only afterwards in `sacct`: with `SWEBENCH_PYXIS_CREATE_TIMING_PATH` set, each create appends one JSONL record with its duration and outcome. Off by default, and a sink that cannot be written degrades to nothing -- a create that succeeded and could not be logged is still a create that succeeded. --- .../swebench_service/pyxis_environment.py | 89 ++++++++- .../swebench_service/runner.py | 8 +- .../swebench_service/test_runner.py | 172 +++++++++++++++++- 3 files changed, 262 insertions(+), 7 deletions(-) diff --git a/src/inference_endpoint/evaluation/swebench_service/swebench_service/pyxis_environment.py b/src/inference_endpoint/evaluation/swebench_service/swebench_service/pyxis_environment.py index 141c1ccba..6637e06b1 100644 --- a/src/inference_endpoint/evaluation/swebench_service/swebench_service/pyxis_environment.py +++ b/src/inference_endpoint/evaluation/swebench_service/swebench_service/pyxis_environment.py @@ -3,6 +3,7 @@ from __future__ import annotations +import json import logging import os import platform @@ -10,6 +11,7 @@ import subprocess import tempfile import threading +import time import uuid from pathlib import Path from typing import Any @@ -136,19 +138,80 @@ def run_srun_step( timeout=timeout_s + 30, env=safe_srun_env(), ) + except subprocess.TimeoutExpired as exc: + if failure_path is not None: + failure_path.touch() + raise RunnerError( + f"Pyxis step exceeded its {timeout_s + 30}s deadline and was killed" + + _srun_evidence(exc.output) + ) from exc except (OSError, subprocess.SubprocessError) as exc: if failure_path is not None: failure_path.touch() raise RunnerError( - "Pyxis infrastructure failure before the command completed" + "Pyxis infrastructure failure before the command completed: " + f"{type(exc).__name__}: {exc}" ) from exc if status_path.read_text().strip() != f"finished:{result.returncode}": if failure_path is not None: failure_path.touch() - raise RunnerError("Pyxis infrastructure failure before the command completed") + raise RunnerError( + "Pyxis infrastructure failure before the command completed " + f"(srun exited {result.returncode})" + _srun_evidence(result.stdout) + ) return result +#: Opt-in JSONL sink for container-create durations. Off unless set, so this +#: adds nothing to a normal run. Creation is the step whose cost was invisible +#: -- it was only ever observable as a uniform block of SIGKILLs in `sacct`, +#: after the run was already lost -- so measuring it has to be possible without +#: re-deriving it from step accounting. +_CREATE_TIMING_ENV = "SWEBENCH_PYXIS_CREATE_TIMING_PATH" + + +def _record_create_timing(image: str | Path, seconds: float, *, ok: bool) -> None: + path = os.environ.get(_CREATE_TIMING_ENV) + if not path: + return + record = { + "ts": time.time(), + "image": str(image), + "secs": round(seconds, 2), + "ok": ok, + "pid": os.getpid(), + } + try: + # One short line per create, O_APPEND from many concurrent workers. + with open(path, "a", encoding="utf-8") as handle: + handle.write(json.dumps(record) + "\n") + except OSError: + # Observability must never be able to fail a run. A create that + # succeeded and could not be logged is still a create that succeeded. + logger.debug("could not record Pyxis create timing", exc_info=True) + + +def _srun_evidence(output: str | bytes | None, limit: int = 2000) -> str: + """Attach srun's own words to a Pyxis failure. + + srun/pyxis/enroot report the actual cause -- image import failure, no space + left, a step that never got resources -- on the stream this function + captures. Dropping it turns every distinct infrastructure failure into one + indistinguishable message, which is exactly what made a 200-instance run's + 17 lost units undiagnosable from its artifacts. + """ + if not output: + return "" + if isinstance(output, bytes): + output = output.decode("utf-8", errors="replace") + text = output.strip() + if not text: + return "" + if len(text) > limit: + text = "..." + text[-limit:] + return f"\n--- srun output ---\n{text}" + + def resolve_image(image_registry: str, instance_id: str) -> str: if Path(instance_id).name != instance_id or instance_id in {".", ".."}: raise RunnerError(f"invalid SWE-bench instance ID: {instance_id}") @@ -171,6 +234,19 @@ class PyxisEnvironmentConfig(BaseModel): validation_alias=AliasChoices("timeout_s", "timeout"), serialization_alias="timeout", ) + #: Deadline for *creating* the container, which under Pyxis includes the + #: enroot import of a multi-GB SWE-bench image from a remote registry. + #: Deliberately separate from ``timeout_s``: that is a per-*command* + #: budget, sized for `pytest`-scale work inside an already-running + #: container. Charging an image import against it made every agent whose + #: image was not already in the enroot cache fail once the registry was + #: shared by enough concurrent workers to push a single import past ~5 + #: minutes. Defaults to, and accepts, mini-swe-agent's ``pull_timeout``. + create_timeout_s: int = Field( + default=3600, + validation_alias=AliasChoices("create_timeout_s", "pull_timeout"), + serialization_alias="pull_timeout", + ) interpreter: list[str] = Field(default_factory=lambda: ["bash", "-c"]) infrastructure_failure_path: Path | None = None @@ -185,6 +261,7 @@ def __init__(self, **kwargs: Any): self._tmp_dir.chmod(0o1777) self._lock = threading.Lock() self._cleaned = False + started = time.monotonic() try: # A no-op initializes and validates the named persistent container. run_srun_step( @@ -194,14 +271,18 @@ def __init__(self, **kwargs: Any): workdir=self.config.cwd, argv=["true"], status_path=self._tmp_dir / Path(_STEP_STATUS).name, - timeout_s=self.config.timeout_s, + timeout_s=self.config.create_timeout_s, failure_path=self.config.infrastructure_failure_path, ) except RunnerError as exc: + _record_create_timing( + self.config.image, time.monotonic() - started, ok=False + ) self.cleanup() raise RunnerError( - f"failed to start Pyxis container for {self.config.image}" + f"failed to start Pyxis container for {self.config.image}: {exc}" ) from exc + _record_create_timing(self.config.image, time.monotonic() - started, ok=True) def execute( self, action: dict[str, Any], cwd: str = "", *, timeout: int | None = None diff --git a/src/inference_endpoint/evaluation/swebench_service/swebench_service/runner.py b/src/inference_endpoint/evaluation/swebench_service/swebench_service/runner.py index 62f414a82..8682b40a7 100644 --- a/src/inference_endpoint/evaluation/swebench_service/swebench_service/runner.py +++ b/src/inference_endpoint/evaluation/swebench_service/swebench_service/runner.py @@ -647,7 +647,13 @@ def __init__( def _configure_environment( self, environment_cfg: dict[str, Any], run_id: str ) -> None: - for key in ("run_args", "pull_timeout", "container_timeout"): + # ``pull_timeout`` is the template's image-acquisition budget and is + # exactly what the Pyxis container-create step needs, so it is carried + # over rather than dropped. Without it the create step fell back to the + # per-command ``timeout`` (300s in both templates) and every image + # import slower than that was killed as an "infrastructure failure". + # ``run_args``/``container_timeout`` stay dropped: both are docker-only. + for key in ("run_args", "container_timeout"): environment_cfg.pop(key, None) environment_cfg["environment_class"] = ( "swebench_service.pyxis_environment.PyxisEnvironment" diff --git a/tests/unit/evaluation/swebench_service/test_runner.py b/tests/unit/evaluation/swebench_service/test_runner.py index f6c92e135..7d55b8b97 100644 --- a/tests/unit/evaluation/swebench_service/test_runner.py +++ b/tests/unit/evaluation/swebench_service/test_runner.py @@ -1,6 +1,7 @@ # SPDX-FileCopyrightText: Copyright (c) 2026 NVIDIA CORPORATION & AFFILIATES. All rights reserved. # SPDX-License-Identifier: Apache-2.0 +import json import logging import stat import subprocess @@ -713,8 +714,9 @@ def test_pyxis_patch_config_selects_pyxis_environment(tmp_path): assert environment["cwd"] == "/testbed" assert environment["run_id"] == "run-1" assert "run_args" not in environment - assert "pull_timeout" not in environment assert "container_timeout" not in environment + # Carried over, not dropped: the Pyxis create step *is* the image pull. + assert environment["pull_timeout"] == 3600 def test_pyxis_resolves_registry_image_from_instance_id(): @@ -1014,12 +1016,178 @@ def test_pyxis_environment_raises_when_srun_never_starts_command(monkeypatch, tm ), ) - with pytest.raises(RunnerError, match="before the command completed"): + with pytest.raises(RunnerError, match=r"exceeded its 60s deadline"): environment.execute({"command": "pytest -q"}) assert failure_path.exists() +def test_pyxis_container_create_uses_the_pull_budget_not_the_command_budget( + monkeypatch, tmp_path +): + """Creating the container is an image import, not a shell command. + + Under Pyxis, `--container-image` triggers an enroot import of a multi-GB + SWE-bench image from a remote registry. Charging that against the + per-command `timeout` (300s in both templates) killed the create step as + soon as enough concurrent workers shared the registry -- 96 srun steps of + one 200-instance run were SIGKILLed at a uniform ~5m50s (= 300 + 30 grace), + which the service reported as an undiagnosable "failed to start Pyxis + container" and cost 17 of 20 units. + """ + monkeypatch.setenv("SLURM_JOB_ID", "1738605") + monkeypatch.setenv("SLURMD_NODENAME", "gb-nvl-053-compute04") + timeouts: list[float] = [] + + def fake_run(command, **kwargs): + timeouts.append(kwargs["timeout"]) + _finish_srun_step(command, 0) + return subprocess.CompletedProcess(command, 0, stdout="ok\n", stderr="") + + monkeypatch.setattr(subprocess, "run", fake_run) + environment = PyxisEnvironment( + image=tmp_path / "task.sqsh", + run_id="run-1", + timeout=300, + pull_timeout=3600, + ) + environment.execute({"command": "pytest -q"}) + + create_timeout, command_timeout = timeouts[0], timeouts[1] + assert create_timeout == 3600 + 30 + assert command_timeout == 300 + 30 + assert create_timeout > command_timeout, ( + "container creation must not be bounded by the per-command timeout" + ) + environment.cleanup() + + +def test_pyxis_container_create_budget_defaults_without_a_template_value( + monkeypatch, tmp_path +): + """A template that never mentions pull_timeout still gets a pull budget.""" + monkeypatch.setenv("SLURM_JOB_ID", "1738605") + monkeypatch.setenv("SLURMD_NODENAME", "gb-nvl-053-compute04") + timeouts: list[float] = [] + + def fake_run(command, **kwargs): + timeouts.append(kwargs["timeout"]) + _finish_srun_step(command, 0) + return subprocess.CompletedProcess(command, 0, stdout="ok\n", stderr="") + + monkeypatch.setattr(subprocess, "run", fake_run) + environment = PyxisEnvironment( + image=tmp_path / "task.sqsh", run_id="run-1", timeout=300 + ) + + assert timeouts[0] == 3600 + 30 + environment.cleanup() + + +def test_pyxis_records_create_timing_when_enabled(monkeypatch, tmp_path): + """Container-create cost must be measurable without re-deriving it. + + Creation was only ever observable after the fact, as a uniform block of + SIGKILLed steps in `sacct` -- by which point the run was already lost. + """ + monkeypatch.setenv("SLURM_JOB_ID", "1738605") + monkeypatch.setenv("SLURMD_NODENAME", "gb-nvl-053-compute04") + timing = tmp_path / "creates.jsonl" + monkeypatch.setenv("SWEBENCH_PYXIS_CREATE_TIMING_PATH", str(timing)) + + def fake_run(command, **kwargs): + _finish_srun_step(command, 0) + return subprocess.CompletedProcess(command, 0, stdout="ok\n", stderr="") + + monkeypatch.setattr(subprocess, "run", fake_run) + environment = PyxisEnvironment(image=tmp_path / "task.sqsh", run_id="run-1") + environment.cleanup() + + records = [json.loads(line) for line in timing.read_text().splitlines()] + assert len(records) == 1 + assert records[0]["ok"] is True + assert records[0]["secs"] >= 0 + assert records[0]["image"].endswith("task.sqsh") + + +def test_pyxis_records_create_timing_for_a_failed_create(monkeypatch, tmp_path): + """A create that failed is the one whose duration matters most.""" + monkeypatch.setenv("SLURM_JOB_ID", "1738605") + monkeypatch.setenv("SLURMD_NODENAME", "gb-nvl-053-compute04") + timing = tmp_path / "creates.jsonl" + monkeypatch.setenv("SWEBENCH_PYXIS_CREATE_TIMING_PATH", str(timing)) + + monkeypatch.setattr( + subprocess, + "run", + lambda command, **kwargs: subprocess.CompletedProcess(command, 1, stdout=""), + ) + + with pytest.raises(RunnerError): + PyxisEnvironment(image=tmp_path / "task.sqsh", run_id="run-1") + + records = [json.loads(line) for line in timing.read_text().splitlines()] + assert [r["ok"] for r in records] == [False] + + +def test_pyxis_create_timing_is_off_by_default(monkeypatch, tmp_path): + """No env var, no writes, no behaviour change on a normal run.""" + monkeypatch.setenv("SLURM_JOB_ID", "1738605") + monkeypatch.setenv("SLURMD_NODENAME", "gb-nvl-053-compute04") + monkeypatch.delenv("SWEBENCH_PYXIS_CREATE_TIMING_PATH", raising=False) + + def fake_run(command, **kwargs): + _finish_srun_step(command, 0) + return subprocess.CompletedProcess(command, 0, stdout="ok\n", stderr="") + + monkeypatch.setattr(subprocess, "run", fake_run) + environment = PyxisEnvironment(image=tmp_path / "task.sqsh", run_id="run-1") + environment.cleanup() + + assert list(tmp_path.glob("*.jsonl")) == [] + + +def test_pyxis_create_timing_never_fails_the_run(monkeypatch, tmp_path): + """An unwritable sink degrades to nothing; it does not lose the container.""" + monkeypatch.setenv("SLURM_JOB_ID", "1738605") + monkeypatch.setenv("SLURMD_NODENAME", "gb-nvl-053-compute04") + monkeypatch.setenv( + "SWEBENCH_PYXIS_CREATE_TIMING_PATH", str(tmp_path / "nope" / "creates.jsonl") + ) + + def fake_run(command, **kwargs): + _finish_srun_step(command, 0) + return subprocess.CompletedProcess(command, 0, stdout="ok\n", stderr="") + + monkeypatch.setattr(subprocess, "run", fake_run) + environment = PyxisEnvironment(image=tmp_path / "task.sqsh", run_id="run-1") + environment.cleanup() + + +def test_pyxis_failure_carries_srun_output(monkeypatch, tmp_path): + """srun's own words must survive into the error. + + Without them every distinct infrastructure failure -- import failure, no + space left, a step that never got resources -- collapses into one + indistinguishable message and cannot be diagnosed from the artifacts. + """ + monkeypatch.setenv("SLURM_JOB_ID", "1738605") + monkeypatch.setenv("SLURMD_NODENAME", "gb-nvl-053-compute04") + + def fake_run(command, **kwargs): + # Step never wrote its status file: srun died before the command ran. + return subprocess.CompletedProcess( + command, 1, stdout="slurmstepd: error: pyxis: no space left\n", stderr="" + ) + + monkeypatch.setattr(subprocess, "run", fake_run) + + with pytest.raises(RunnerError, match="no space left") as exc_info: + PyxisEnvironment(image=tmp_path / "task.sqsh", run_id="run-1") + + assert "failed to start Pyxis container" in str(exc_info.value) + + def test_pyxis_environment_preserves_command_failure(monkeypatch, tmp_path): monkeypatch.setenv("SLURM_JOB_ID", "1738605") monkeypatch.setenv("SLURMD_NODENAME", "gb-nvl-053-compute04")