diff --git a/check.sh b/check.sh index e9992b14..1857d853 100755 --- a/check.sh +++ b/check.sh @@ -13,7 +13,7 @@ timeout $TMO make check -j4 > "$TMP" 2>&1 || { [ $(date +%s) -ge $((START + TMO)) ] && echo "TIMEOUT (${TMO}s)" >&2 exit 1 } -grep -E '\[PASS|\[FAIL|\[SKIP|Test Results|Failed tests|Log directory|^====' "$TMP" +grep -E '\[INFO|\[PASS|\[FAIL|\[SKIP|Test Results|Failed tests|Log directory|^====' "$TMP" rm -f "$TMP" # Интеграционный тест tcp_proxy_full (требует sudo; без passwordless sudo — пропускаем) diff --git a/tests/Makefile.am b/tests/Makefile.am index 368b2b76..3686941d 100644 --- a/tests/Makefile.am +++ b/tests/Makefile.am @@ -1,6 +1,6 @@ # Tests Makefile.am for utun - all tests with new ll_queue library -EXTRA_DIST = fixtures/reality_openssl_hello.hex data/silero_speech.pcm data/silero_speech.txt test_net.h +EXTRA_DIST = fixtures/reality_openssl_hello.hex data/silero_speech.pcm data/silero_speech.txt test_net.h run_tests.py test_run_tests.py # Порядок по замерам Linux: быстрые проверки раньше длительных; состав зависит от прежних configure-условий. @@ -730,63 +730,14 @@ clean-local: # Test logs directory TEST_LOG_DIR = $(top_builddir)/tests/logs -# Custom check target that runs tests and saves logs to files -check-local: $(check_PROGRAMS) - @rm -f $(TEST_LOG_DIR)/*.log 2>/dev/null || true; $(MKDIR_P) $(TEST_LOG_DIR); \ - G='\033[0;32m'; R='\033[0;31m'; Y='\033[0;33m'; N='\033[0m'; \ - passed=0; \ - failed=0; \ - skipped=0; \ - total=0; \ - failed_tests=""; \ - for test in $(check_PROGRAMS); do \ - total=$$((total + 1)); \ - logfile="$(TEST_LOG_DIR)/$$test.log"; \ - if test -f "./$$test"; then \ - set -- "./$$test"; \ - if test "$$test" = test_auto_socket_dynamic && test "$$(id -u)" -ne 0 \ - && command -v sudo >/dev/null 2>&1 && sudo -n true 2>/dev/null; then \ - set -- sudo -n -- "./$$test"; \ - printf "[INFO] %s: running as root via sudo -n\n" "$$test"; \ - fi; \ - start=$$(date +%s%N); \ - if "$$@" > "$$logfile" 2>&1; then \ - end=$$(date +%s%N); \ - elapsed_ms=$$(( (end - start) / 1000000 )); \ - printf "$${G}[PASS]$${N} %s (%sms)\n" "$$test" "$$elapsed_ms"; \ - passed=$$((passed + 1)); \ - elif test $$? -eq 77; then \ - end=$$(date +%s%N); \ - elapsed_ms=$$(( (end - start) / 1000000 )); \ - printf "$${Y}[SKIP]$${N} %s (see %s)\n" "$$test" "$$logfile"; \ - skipped=$$((skipped + 1)); \ - else \ - end=$$(date +%s%N); \ - elapsed_ms=$$(( (end - start) / 1000000 )); \ - printf "$${R}[FAIL]$${N} %s (%sms) (see %s)\n" "$$test" "$$elapsed_ms" "$$logfile"; \ - failed=$$((failed + 1)); \ - if test -z "$$failed_tests"; then \ - failed_tests="$$test"; \ - else \ - failed_tests="$$failed_tests $$test"; \ - fi; \ - fi; \ - else \ - printf "$${Y}[SKIP]$${N} %s (not built)\n" "$$test"; \ - skipped=$$((skipped + 1)); \ - fi; \ - done; \ - echo ""; \ - echo "=========================================="; \ - echo "Test Results: $$passed passed, $$failed failed, $$skipped skipped ($$total total)"; \ - echo "Log directory: $(TEST_LOG_DIR)"; \ - echo "=========================================="; \ - if test $$failed -gt 0; then \ - echo ""; \ - echo "Failed tests: $$failed_tests"; \ - echo "Run 'cat $(TEST_LOG_DIR)/.log' to see details"; \ - exit 1; \ - fi +# По умолчанию jobs = доступные CPU; TEST_JOBS=1 сохраняет последовательный запуск. +check-local: check-runner $(check_PROGRAMS) + @python3 "$(srcdir)/run_tests.py" --log-dir "$(TEST_LOG_DIR)" $(check_PROGRAMS) + +.PHONY: check-runner +check-runner: + @python3 "$(srcdir)/test_run_tests.py" + @echo "[INFO] test runner regression checks passed" # Интеграционный тест tcp_proxy_full (требует sudo, TUN, iptables). Запускается из check.sh. .PHONY: check-proxy diff --git a/tests/run_tests.py b/tests/run_tests.py new file mode 100644 index 00000000..a391c09c --- /dev/null +++ b/tests/run_tests.py @@ -0,0 +1,205 @@ +#!/usr/bin/env python3 +"""Запуск make check: ограниченный пул, отдельные логи и барьеры для замеров CPU.""" + +import argparse +import os +from pathlib import Path +import shutil +import signal +import subprocess +import sys +import time + + +# Эти тесты измеряют скорость/нагрузку CPU; autosocket проверяем отдельно с sudo. +EXCLUSIVE = frozenset({ + "bench_timeout_heap", "bench_uasync_timeouts", "test_u_async_performance", + "test_intensive_memory_pool", "test_media_async", "test_bbr_integration", + "test_uasync_load", "test_auto_socket_dynamic", +}) +EXCLUSIVE |= {name + ".exe" for name in EXCLUSIVE} + + +def available_cpus(): + if hasattr(os, "sched_getaffinity"): + try: + return max(1, len(os.sched_getaffinity(0))) + except OSError as error: + print(f"[WARN] CPU affinity unavailable: {error}; using system CPU count", file=sys.stderr) + return os.cpu_count() or 1 + + +def positive_int(value): + try: + number = int(value) + except ValueError: + raise argparse.ArgumentTypeError("expected a positive integer") from None + if number < 1: + raise argparse.ArgumentTypeError("expected a positive integer") + return number + + +class InterruptedRun(Exception): + def __init__(self, signum): + self.signum = signum + + +# Advisory lock снимается ОС даже при SIGKILL; соседний запуск не перезапишет логи. +def lock_logs(path): + lock = (path / ".runner.lock").open("a+b") + try: + if os.name == "posix": + import fcntl + fcntl.flock(lock, fcntl.LOCK_EX | fcntl.LOCK_NB) + else: + import msvcrt + if not lock.tell(): + lock.write(b"\0"); lock.flush() + lock.seek(0) + msvcrt.locking(lock.fileno(), msvcrt.LK_NBLCK, 1) + except OSError: + lock.close() + raise + return lock + + +# Останавливаем всю группу теста, включая fork/exec-помощников, с общей паузой 1с. +def stop_processes(processes): + if os.name != "posix": + for process in processes: + subprocess.run(["taskkill", "/PID", str(process.pid), "/T", "/F"], + stdout=subprocess.DEVNULL, stderr=subprocess.DEVNULL, check=False) + process.wait() + return + for process in processes: + try: + os.killpg(process.pid, signal.SIGTERM) + except ProcessLookupError: + pass + deadline = time.monotonic() + 1 + for process in processes: + try: + process.wait(timeout=max(0, deadline - time.monotonic())) + except subprocess.TimeoutExpired: + pass + for process in processes: + try: + os.killpg(process.pid, signal.SIGKILL) + except ProcessLookupError: + pass + process.wait() + + +def run_tests(args, requested_signals): + counts = dict(PASS=0, FAIL=0, SKIP=0) + failed = [] + running = [] + index = 0 + use_sudo = ("test_auto_socket_dynamic" in args.tests and hasattr(os, "geteuid") and os.geteuid() != 0 + and shutil.which("sudo") and subprocess.run(["sudo", "-n", "true"], + stdout=subprocess.DEVNULL, stderr=subprocess.DEVNULL).returncode == 0) + + def report(name, status, elapsed, reason=""): + counts[status] += 1 + if status == "FAIL": + failed.append(name) + detail = f" ({reason}; see {args.log_dir / (name + '.log')})" if reason else "" + print(f"[{status}] {name} ({elapsed * 1000:.0f}ms){detail}", flush=True) + + print(f"[INFO] test runner: jobs={args.jobs} available_cpus={available_cpus()} timeout={args.timeout}s", flush=True) + try: + while index < len(args.tests) or running: + if requested_signals: + raise InterruptedRun(requested_signals[0]) + while index < len(args.tests) and len(running) < args.jobs: + if requested_signals: + break + name = args.tests[index] + if running and (name in EXCLUSIVE or running[0][0] in EXCLUSIVE): + break + index += 1 + if not Path(name).is_file(): + report(name, "SKIP", 0, "not built") + continue + command = [str(Path(name).resolve())] + if name == "test_auto_socket_dynamic" and use_sudo: + command = ["sudo", "-n", "--"] + command + print(f"[INFO] {name}: running as root via sudo -n", flush=True) + log = (args.log_dir / (name + ".log")).open("wb") + log.write(f"[INFO] runner: test={name} exclusive={name in EXCLUSIVE} command={command}\n".encode()) + log.flush() + started = time.monotonic() + try: + process = subprocess.Popen(command, stdout=log, stderr=subprocess.STDOUT, start_new_session=True) + except OSError as error: + log.write(f"[ERROR] cannot start test: {error}\n".encode()); log.close() + report(name, "FAIL", time.monotonic() - started, f"cannot start: {error}") + continue + running.append((name, process, log, started)) + log.write(f"[INFO] runner: pid={process.pid}\n".encode()); log.flush() + if name in EXCLUSIVE: + break + for entry in running[:]: + name, process, log, started = entry + elapsed = time.monotonic() - started + rc = process.poll() + reason = "" + if rc is None and elapsed >= args.timeout: + stop_processes([process]) + rc = 124 + reason = f"timeout={args.timeout}s" + log.write(f"[ERROR] runner: {reason}; process group stopped\n".encode()) + if rc is not None: + if rc and rc != 77 and not reason: + stop_processes([process]) + log.close(); running.remove(entry) + status = "PASS" if rc == 0 else "SKIP" if rc == 77 else "FAIL" + report(name, status, time.monotonic() - started, reason or (f"exit={rc}" if rc else "")) + if running: + time.sleep(0.01) + finally: + if running: + stop_processes([entry[1] for entry in running]) + for name, process, log, started in running: + log.write(b"[ERROR] runner: interrupted; process group stopped\n"); log.close() + print("\n==========================================") + print(f"Test Results: {counts['PASS']} passed, {counts['FAIL']} failed, {counts['SKIP']} skipped ({len(args.tests)} total)") + print(f"Log directory: {args.log_dir}") + print("==========================================") + if failed: + print("Failed tests: " + " ".join(failed)) + return int(bool(failed)) + + +def main(): + parser = argparse.ArgumentParser(description=__doc__) + parser.add_argument("--jobs", type=positive_int, default=os.environ.get("TEST_JOBS", str(available_cpus()))) + parser.add_argument("--timeout", type=positive_int, default=90, help="per-test timeout in seconds") + parser.add_argument("--log-dir", type=Path, default=Path("logs")) + parser.add_argument("tests", nargs="+") + args = parser.parse_args() + if len(set(args.tests)) != len(args.tests) or any(Path(name).name != name for name in args.tests): + parser.error("test names must be unique basenames") + requested_signals = [] + + # Не выбрасываем исключение внутри Popen: сначала учитываем новый процесс и его fd. + def interrupted(signum, frame): + if not requested_signals: + requested_signals.append(signum) + + signal.signal(signal.SIGINT, interrupted) + signal.signal(signal.SIGTERM, interrupted) + try: + args.log_dir.mkdir(parents=True, exist_ok=True) + with lock_logs(args.log_dir): + return run_tests(args, requested_signals) + except InterruptedRun as error: + print(f"[ERROR] runner interrupted by signal {error.signum}; test processes stopped", file=sys.stderr, flush=True) + return 128 + error.signum + except OSError as error: + print(f"[ERROR] runner: {error}; log directory={args.log_dir} (check permissions or concurrent runs)", file=sys.stderr) + return 1 + + +if __name__ == "__main__": + sys.exit(main()) diff --git a/tests/test_run_tests.py b/tests/test_run_tests.py new file mode 100644 index 00000000..ba756866 --- /dev/null +++ b/tests/test_run_tests.py @@ -0,0 +1,168 @@ +#!/usr/bin/env python3 +"""Регрессии запускателя: лимит jobs, CPU-барьеры, ошибки и освобождение дочерних процессов.""" + +import json +import os +from pathlib import Path +import signal +import subprocess +import sys +import tempfile +import time +import unittest + +from run_tests import available_cpus + + +@unittest.skipUnless(os.name == "posix", "fixtures use POSIX executables and fork") +class RunnerTests(unittest.TestCase): + def setUp(self): + self.directory = tempfile.TemporaryDirectory(prefix="utun_runner_") + self.addCleanup(self.directory.cleanup) + self.root = Path(self.directory.name) + self.runner = Path(__file__).with_name("run_tests.py").resolve() + + def fixture(self, name, body=""): + path = self.root / name + path.write_text(f"#!{sys.executable}\n" + """ +import json, os, signal, sys, time +from pathlib import Path +name = Path(__file__).name +def event(state): + fd = os.open('events', os.O_WRONLY | os.O_CREAT | os.O_APPEND, 0o600) + os.write(fd, (json.dumps([name, state]) + '\\n').encode()); os.close(fd) +event('start') +""" + body + "\nevent('end')\nprint('fixture output: ' + name)\n") + path.chmod(0o755) + + def command(self, tests, options=()): + return [sys.executable, str(self.runner), "--log-dir", "logs", *options, *tests] + + def run_runner(self, tests, options=(), environment=None): + env = dict(os.environ, TEST_JOBS="2") if environment is None else environment + return subprocess.run(self.command(tests, options), cwd=self.root, env=env, + stdout=subprocess.PIPE, stderr=subprocess.STDOUT, text=True, timeout=15) + + def test_default_cpu_count_and_override(self): + self.fixture("fast") + env = os.environ.copy(); env.pop("TEST_JOBS", None) + result = self.run_runner(["fast"], environment=env) + self.assertEqual(result.returncode, 0, result.stdout) + self.assertIn(f"jobs={available_cpus()} available_cpus=", result.stdout) + if hasattr(os, "sched_setaffinity"): + affinity = {min(os.sched_getaffinity(0))} + result = subprocess.run(self.command(["fast"]), cwd=self.root, env=env, text=True, + stdout=subprocess.PIPE, stderr=subprocess.STDOUT, timeout=10, + preexec_fn=lambda: os.sched_setaffinity(0, affinity)) + self.assertEqual(result.returncode, 0, result.stdout) + self.assertIn("jobs=1 available_cpus=1", result.stdout) + result = self.run_runner(["fast"], environment=dict(env, TEST_JOBS="1")) + self.assertEqual(result.returncode, 0, result.stdout) + self.assertIn("jobs=1 available_cpus=", result.stdout) + result = self.run_runner(["fast"], environment=dict(env, TEST_JOBS="0")) + self.assertEqual(result.returncode, 2, result.stdout) + self.assertIn("expected a positive integer", result.stdout) + + def test_parallel_limit_and_exclusive_barrier(self): + for name, pair in (("first_a", "first"), ("first_b", "first"), ("last_a", "last"), ("last_b", "last")): + self.fixture(name, f""" +Path(name + '.ready').touch() +deadline = time.monotonic() + 5 +while len(list(Path('.').glob('{pair}_*.ready'))) < 2: + if time.monotonic() > deadline: sys.exit(9) + time.sleep(0.01) +time.sleep(0.05) +""") + self.fixture("test_media_async", "time.sleep(0.05)\n") + result = self.run_runner(["first_a", "first_b", "test_media_async", "last_a", "last_b"]) + self.assertEqual(result.returncode, 0, result.stdout) + active, maximum = set(), 0 + events = [json.loads(line) for line in (self.root / "events").read_text().splitlines()] + for name, state in events: + if state == "start": + if name == "test_media_async": self.assertFalse(active) + self.assertNotIn("test_media_async", active) + active.add(name); maximum = max(maximum, len(active)) + else: + active.remove(name) + self.assertFalse(active) + self.assertEqual(maximum, 2) + self.assertEqual({name for name, _ in events[:2]}, {"first_a", "first_b"}) + self.assertEqual(events[4:6], [["test_media_async", "start"], ["test_media_async", "end"]]) + + def test_exit_codes_and_separate_logs(self): + self.fixture("ok") + self.fixture("bad", "print('failure detail', flush=True)\nsys.exit(42)\n") + self.fixture("skip", "sys.exit(77)\n") + result = self.run_runner(["ok", "bad", "skip", "missing"]) + self.assertEqual(result.returncode, 1, result.stdout) + self.assertIn("1 passed, 1 failed, 2 skipped (4 total)", result.stdout) + self.assertIn("Failed tests: bad", result.stdout) + self.assertIn("failure detail", (self.root / "logs/bad.log").read_text()) + self.assertNotIn("failure detail", (self.root / "logs/ok.log").read_text()) + + def test_serial_override(self): + self.fixture("serial_a", "time.sleep(0.05)\n") + self.fixture("serial_b", "time.sleep(0.05)\n") + result = self.run_runner(["serial_a", "serial_b"], environment=dict(os.environ, TEST_JOBS="1")) + self.assertEqual(result.returncode, 0, result.stdout) + events = [json.loads(line) for line in (self.root / "events").read_text().splitlines()] + self.assertEqual(events, [["serial_a", "start"], ["serial_a", "end"], ["serial_b", "start"], ["serial_b", "end"]]) + + def stubborn_fixture(self): + self.fixture("stubborn", """ +signal.signal(signal.SIGTERM, signal.SIG_IGN) +pid = os.fork() +Path('child.pid' if pid == 0 else 'parent.pid').write_text(str(os.getpid())) +while True: time.sleep(1) +""") + + def assert_descendant_stopped(self): + pid = int((self.root / "child.pid").read_text()) + deadline = time.monotonic() + 2 + while time.monotonic() < deadline: + try: + os.kill(pid, 0) + stat = Path(f"/proc/{pid}/stat") + if stat.exists() and stat.read_text().split(")", 1)[1].split()[0] == "Z": return + except ProcessLookupError: + return + time.sleep(0.01) + self.fail(f"descendant pid={pid} survived runner cleanup") + + def test_timeout_stops_descendant(self): + self.stubborn_fixture() + result = self.run_runner(["stubborn"], ["--timeout", "1"]) + self.assertEqual(result.returncode, 1, result.stdout) + self.assertIn("timeout=1s", result.stdout) + self.assertIn("0 passed, 1 failed, 0 skipped", result.stdout) + self.assert_descendant_stopped() + + def test_interruption_and_log_directory_lock(self): + self.stubborn_fixture() + process = subprocess.Popen(self.command(["stubborn"]), cwd=self.root, + stdout=subprocess.PIPE, stderr=subprocess.STDOUT, text=True) + try: + deadline = time.monotonic() + 5 + while not (self.root / "child.pid").exists() and time.monotonic() < deadline: + time.sleep(0.01) + self.assertTrue((self.root / "child.pid").exists()) + result = self.run_runner(["stubborn"]) + self.assertEqual(result.returncode, 1, result.stdout) + self.assertIn("concurrent runs", result.stdout) + self.assertIsNone(process.poll()) + process.send_signal(signal.SIGTERM) + output, _ = process.communicate(timeout=5) + self.assertEqual(process.returncode, 128 + signal.SIGTERM, output) + self.assertIn("test processes stopped", output) + self.assert_descendant_stopped() + self.fixture("ok") + result = self.run_runner(["ok"]) + self.assertEqual(result.returncode, 0, result.stdout) + finally: + if process.poll() is None: + process.send_signal(signal.SIGTERM); process.communicate(timeout=5) + + +if __name__ == "__main__": + unittest.main()