scripts: increase scenario timeouts

m3nu · m3nu · commit 1fbbe81230ff · 2026-03-24T12:46:52.000Z
diff --git a/scripts/lib/common.sh b/scripts/lib/common.sh
@@ -0,0 +1,15 @@
+#!/usr/bin/env bash
+
+die() {
+  printf 'ERROR: %s\n' "$*" >&2
+  exit 1
+}
+
+log() {
+  printf '[%s] %s\n' "$(date -u +%Y-%m-%dT%H:%M:%SZ)" "$*" >&2
+}
+
+need() {
+  local cmd="$1"
+  command -v "$cmd" >/dev/null 2>&1 || die "missing required command: $cmd"
+}
diff --git a/scripts/testbench/tests/test_runner.py b/scripts/testbench/tests/test_runner.py
@@ -1,3 +1,4 @@
+import json
 import subprocess
 import tempfile
 import unittest
@@ -117,6 +118,64 @@ def test_run_scenario_validates_corpus_before_setup(self) -> None:
         write_config.assert_not_called()
         ensure_backend_ready.assert_not_called()
 
+    def test_run_scenario_records_failed_compact_phase_without_crashing(self) -> None:
+        scenario = {
+            "name": "compact-timeout",
+            "corpus": {"size_gib": 0.1},
+            "phases": [{"action": "init"}, {"action": "compact"}],
+        }
+
+        phase_results = [
+            {"action": "init", "label": "", "passed": True, "detail": "ok", "duration_sec": 0.01},
+            {
+                "action": "compact",
+                "label": "",
+                "passed": False,
+                "detail": "Command timed out after 3600 seconds",
+                "duration_sec": 3600.0,
+            },
+        ]
+
+        with tempfile.TemporaryDirectory() as output_dir:
+            with mock.patch(
+                "vykar_testbench.scenarios.corpus.validate_corpus_mix"
+            ), mock.patch(
+                "vykar_testbench.scenarios.corpus.generate_corpus",
+                return_value={"file_count": 1, "total_bytes": 1024},
+            ), mock.patch(
+                "vykar_testbench.scenarios.cfg.write_vykar_config",
+                return_value="/mnt/repos/scenario-repo",
+            ), mock.patch(
+                "vykar_testbench.scenarios.cfg.ensure_backend_ready"
+            ), mock.patch(
+                "vykar_testbench.scenarios.vykar_cmd.vykar_delete_repo"
+            ), mock.patch(
+                "vykar_testbench.scenarios._run_phase",
+                side_effect=phase_results,
+            ), mock.patch(
+                "vykar_testbench.scenarios.write_aggregate_report"
+            ), mock.patch(
+                "vykar_testbench.scenarios.print_summary"
+            ):
+                passed = scenarios.run_scenario(
+                    scenario,
+                    backend="local",
+                    runs=1,
+                    output_dir=output_dir,
+                    vykar_bin="vykar",
+                    seed=123,
+                )
+                summary_path = Path(output_dir) / "compact-timeout" / next(
+                    p.name for p in (Path(output_dir) / "compact-timeout").iterdir() if p.is_dir()
+                ) / "run-001" / "summary.json"
+                with open(summary_path) as f:
+                    summary = json.load(f)
+
+        self.assertFalse(passed)
+        self.assertEqual(summary["phases"][1]["action"], "compact")
+        self.assertFalse(summary["phases"][1]["passed"])
+        self.assertIn("timed out", summary["phases"][1]["detail"])
+
     def test_churn_phase_reports_cap_stats(self) -> None:
         ctx = {
             "vykar_bin": "vykar",
diff --git a/scripts/testbench/tests/test_stress.py b/scripts/testbench/tests/test_stress.py
@@ -0,0 +1,60 @@
+import subprocess
+import tempfile
+import unittest
+from pathlib import Path
+from unittest import mock
+
+from vykar_testbench import stress
+from vykar_testbench import vykar
+
+
+class StressRunnerTests(unittest.TestCase):
+    def test_run_vykar_logged_uses_long_timeout_for_compact(self) -> None:
+        completed = subprocess.CompletedProcess(
+            args=["vykar", "compact"],
+            returncode=0,
+            stdout="",
+            stderr="",
+        )
+
+        with tempfile.TemporaryDirectory() as tmpdir:
+            log_file = str(Path(tmpdir) / "compact.log")
+            with mock.patch("vykar_testbench.stress.subprocess.run", return_value=completed) as run:
+                rc, returned_log = stress._run_vykar_logged(
+                    "vykar",
+                    "/tmp/config.yaml",
+                    ["compact", "-R", "scenario-simple", "--threshold", "0"],
+                    env={},
+                    log_file=log_file,
+                )
+
+        self.assertEqual(rc, 0)
+        self.assertEqual(returned_log, log_file)
+        self.assertEqual(run.call_args.kwargs["timeout"], vykar.LONG_TIMEOUT_SECONDS)
+
+    def test_run_vykar_logged_returns_124_and_logs_timeout(self) -> None:
+        timeout = subprocess.TimeoutExpired(
+            cmd=["vykar", "--config", "/tmp/config.yaml", "compact", "-R", "scenario-simple"],
+            timeout=vykar.LONG_TIMEOUT_SECONDS,
+        )
+
+        with tempfile.TemporaryDirectory() as tmpdir:
+            log_file = str(Path(tmpdir) / "compact.log")
+            with mock.patch("vykar_testbench.stress.subprocess.run", side_effect=timeout):
+                rc, returned_log = stress._run_vykar_logged(
+                    "vykar",
+                    "/tmp/config.yaml",
+                    ["compact", "-R", "scenario-simple", "--threshold", "0"],
+                    env={},
+                    log_file=log_file,
+                )
+
+            log_text = Path(log_file).read_text()
+
+        self.assertEqual(rc, 124)
+        self.assertEqual(returned_log, log_file)
+        self.assertIn("timed out after 3600 seconds", log_text)
+
+
+if __name__ == "__main__":
+    unittest.main()
diff --git a/scripts/testbench/tests/test_vykar.py b/scripts/testbench/tests/test_vykar.py
@@ -6,6 +6,37 @@
 
 
 class VykarWrapperTests(unittest.TestCase):
+    def test_timeout_policy_marks_compact_prune_and_delete_as_long_running(self) -> None:
+        self.assertEqual(
+            vykar.timeout_for_args(["compact", "-R", "scenario-simple"]),
+            vykar.LONG_TIMEOUT_SECONDS,
+        )
+        self.assertEqual(
+            vykar.timeout_for_args(["prune", "-R", "scenario-simple"]),
+            vykar.LONG_TIMEOUT_SECONDS,
+        )
+        self.assertEqual(
+            vykar.timeout_for_args(["delete", "-R", "scenario-simple", "--yes-delete-this-repo"]),
+            vykar.LONG_TIMEOUT_SECONDS,
+        )
+
+    def test_compact_uses_long_running_timeout_policy(self) -> None:
+        compact_result = subprocess.CompletedProcess(
+            args=["vykar", "compact"],
+            returncode=0,
+            stdout="Compaction complete\n",
+            stderr="",
+        )
+
+        with mock.patch("vykar_testbench.vykar.subprocess.run", return_value=compact_result) as run:
+            result = vykar.vykar_compact("vykar", "/tmp/config.yaml", "scenario-simple")
+
+        self.assertEqual(result.returncode, 0)
+        self.assertEqual(
+            run.call_args.kwargs["timeout"],
+            vykar.LONG_TIMEOUT_SECONDS,
+        )
+
     def test_delete_repo_tolerates_missing_repository(self) -> None:
         missing_repo = subprocess.CompletedProcess(
             args=["vykar", "delete"],
@@ -42,6 +73,27 @@ def test_backup_ignores_runner_phase_label_for_configured_sources(self) -> None:
             ["vykar", "--config", "/tmp/config.yaml", "backup", "-R", "scenario-simple"],
         )
 
+    def test_run_vykar_converts_timeouts_to_rc_124(self) -> None:
+        timeout = subprocess.TimeoutExpired(
+            cmd=["vykar", "--config", "/tmp/config.yaml", "compact", "-R", "scenario-simple"],
+            timeout=vykar.LONG_TIMEOUT_SECONDS,
+        )
+        timeout.stdout = "partial stdout"
+        timeout.stderr = "partial stderr"
+
+        with mock.patch("vykar_testbench.vykar.subprocess.run", side_effect=timeout):
+            result = vykar.run_vykar(
+                "vykar",
+                "/tmp/config.yaml",
+                ["compact", "-R", "scenario-simple"],
+                label="compact",
+            )
+
+        self.assertEqual(result.returncode, 124)
+        self.assertEqual(result.stdout, "partial stdout")
+        self.assertIn("partial stderr", result.stderr)
+        self.assertIn("timed out after 3600 seconds", result.stderr)
+
 
 if __name__ == "__main__":
     unittest.main()
diff --git a/scripts/testbench/vykar_testbench/stress.py b/scripts/testbench/vykar_testbench/stress.py
@@ -33,25 +33,34 @@ def _run_vykar_logged(
     env: dict[str, str],
     log_file: str,
     time_v: bool = False,
-    timeout: int = 120,
+    timeout: int | None = None,
 ) -> tuple[int, str]:
     """Run vykar, capturing output to log_file. Returns (rc, log_file)."""
     cmd = [vykar_bin, "--config", config_path] + args
+    resolved_timeout = timeout if timeout is not None else vykar_cmd.timeout_for_args(args)
     if time_v:
         time_file = log_file.replace(".log", ".timev")
         full_cmd = ["/usr/bin/time", "-v", "-o", time_file] + cmd
     else:
         full_cmd = cmd
 
     with open(log_file, "w") as f:
-        result = subprocess.run(
-            full_cmd,
-            env=env,
-            stdout=f,
-            stderr=subprocess.STDOUT,
-            timeout=timeout,
-            check=False,
-        )
+        try:
+            result = subprocess.run(
+                full_cmd,
+                env=env,
+                stdout=f,
+                stderr=subprocess.STDOUT,
+                timeout=resolved_timeout,
+                check=False,
+            )
+        except subprocess.TimeoutExpired:
+            print(
+                f"Command timed out after {resolved_timeout} seconds: {' '.join(cmd)}",
+                file=f,
+                flush=True,
+            )
+            return 124, log_file
 
     return result.returncode, log_file
 
diff --git a/scripts/testbench/vykar_testbench/vykar.py b/scripts/testbench/vykar_testbench/vykar.py
@@ -15,6 +15,19 @@
 
 
 _SNAPSHOT_RE = re.compile(r"Snapshot created: (\S+)")
+SHORT_TIMEOUT_SECONDS = 120
+LONG_TIMEOUT_SECONDS = 3600
+
+
+def timeout_for_args(args: list[str]) -> int:
+    """Return the default timeout for a vykar subcommand."""
+    if not args:
+        return SHORT_TIMEOUT_SECONDS
+
+    command = args[0]
+    if command in {"backup", "restore", "check", "compact", "prune", "delete"}:
+        return LONG_TIMEOUT_SECONDS
+    return SHORT_TIMEOUT_SECONDS
 
 
 def _env_with_passphrase() -> dict[str, str]:
@@ -32,7 +45,7 @@ def run_vykar(
     config_path: str,
     args: list[str],
     *,
-    timeout: int = 120,
+    timeout: int | None = None,
     label: str = "",
     allow_missing_repo: bool = False,
     passphrase: str | None = None,
@@ -43,14 +56,33 @@ def run_vykar(
     env = _env_with_passphrase()
     if passphrase is not None:
         env["VYKAR_PASSPHRASE"] = passphrase
+    resolved_timeout = timeout if timeout is not None else timeout_for_args(args)
+
+    try:
+        result = subprocess.run(
+            cmd,
+            capture_output=capture,
+            text=True,
+            env=env,
+            timeout=resolved_timeout,
+        )
+    except subprocess.TimeoutExpired as exc:
+        stdout = exc.stdout if isinstance(exc.stdout, str) else ""
+        stderr = exc.stderr if isinstance(exc.stderr, str) else ""
+        timeout_msg = (
+            f"Command timed out after {resolved_timeout} seconds: {' '.join(cmd)}"
+        )
+        if stderr:
+            stderr = f"{stderr}\n{timeout_msg}"
+        else:
+            stderr = timeout_msg
+        result = subprocess.CompletedProcess(
+            args=cmd,
+            returncode=124,
+            stdout=stdout,
+            stderr=stderr,
+        )
 
-    result = subprocess.run(
-        cmd,
-        capture_output=capture,
-        text=True,
-        env=env,
-        timeout=timeout,
-    )
     missing_repo = allow_missing_repo and _is_missing_repo_error(result.stderr)
     if result.returncode != 0 and not missing_repo:
         print(
@@ -81,7 +113,7 @@ def vykar_backup(
 ) -> tuple[subprocess.CompletedProcess, str | None]:
     """Run backup, return (result, snapshot_id or None)."""
     args = ["backup", "-R", repo_label]
-    result = run_vykar(vykar_bin, config_path, args, timeout=3600, label="backup")
+    result = run_vykar(vykar_bin, config_path, args, label="backup")
     snapshot_id = None
     if result.returncode == 0:
         snapshot_id = extract_snapshot_id(result.stdout)
@@ -103,7 +135,6 @@ def vykar_restore(
         vykar_bin,
         config_path,
         ["restore", "-R", repo_label, snapshot_id, target_dir],
-        timeout=3600,
         label="restore",
     )
 
@@ -118,7 +149,7 @@ def vykar_check(
     args = ["check", "-R", repo_label]
     if verify_data:
         args.append("--verify-data")
-    return run_vykar(vykar_bin, config_path, args, timeout=3600, label="check")
+    return run_vykar(vykar_bin, config_path, args, label="check")
 
 
 def vykar_prune(vykar_bin: str, config_path: str, repo_label: str) -> subprocess.CompletedProcess:
