diff --git a/l4d2web/services/job_worker.py b/l4d2web/services/job_worker.py index 7a6e81b..8d23393 100644 --- a/l4d2web/services/job_worker.py +++ b/l4d2web/services/job_worker.py @@ -7,6 +7,8 @@ import time from sqlalchemy import func, select from sqlalchemy.orm import Session +from typing import Callable + from l4d2web.db import session_scope from l4d2web.models import Job, JobLog, Server from l4d2web.services.host_commands import CommandCancelledError @@ -80,12 +82,17 @@ def run_worker_once() -> bool: def run_job(job_id: int) -> None: from l4d2web.services import l4d2_facade + server_name = "unknown" with session_scope() as db: job = db.scalar(select(Job).where(Job.id == job_id)) if job is None: return operation = job.operation server_id = job.server_id + if server_id is not None: + server = db.scalar(select(Server).where(Server.id == server_id)) + if server is not None: + server_name = server.name max_chars = 4096 @@ -104,21 +111,73 @@ def run_job(job_id: int) -> None: if should_cancel(): raise CommandCancelledError(returncode=1, cmd=[operation], output="", stderr="") + def _run_with_boundaries(action: str, target: str, func: Callable, *args, **kwargs): + append_job_log_line(job_id, "stdout", f"starting {action} for {target}") + func(*args, **kwargs) + append_job_log_line(job_id, "stdout", f"finished {action} successfully") + try: if operation == "install": - l4d2_facade.install_runtime(on_stdout=on_stdout, on_stderr=on_stderr, should_cancel=should_cancel) + _run_with_boundaries( + "install", + "server", + l4d2_facade.install_runtime, + on_stdout=on_stdout, + on_stderr=on_stderr, + should_cancel=should_cancel, + ) elif operation in SERVER_OPERATIONS and server_id is None: raise ValueError(f"{operation} job has no server_id") elif operation == "initialize": - l4d2_facade.initialize_server(server_id, on_stdout=on_stdout, on_stderr=on_stderr, should_cancel=should_cancel) + _run_with_boundaries( + "initialize", + server_name, + l4d2_facade.initialize_server, + server_id, + on_stdout=on_stdout, + on_stderr=on_stderr, + should_cancel=should_cancel, + ) elif operation == "start": - l4d2_facade.initialize_server(server_id, on_stdout=on_stdout, on_stderr=on_stderr, should_cancel=should_cancel) + _run_with_boundaries( + "initialize", + server_name, + l4d2_facade.initialize_server, + server_id, + on_stdout=on_stdout, + on_stderr=on_stderr, + should_cancel=should_cancel, + ) raise_if_cancelled() - l4d2_facade.start_server(server_id, on_stdout=on_stdout, on_stderr=on_stderr, should_cancel=should_cancel) + _run_with_boundaries( + "start", + server_name, + l4d2_facade.start_server, + server_id, + on_stdout=on_stdout, + on_stderr=on_stderr, + should_cancel=should_cancel, + ) elif operation == "stop": - l4d2_facade.stop_server(server_id, on_stdout=on_stdout, on_stderr=on_stderr, should_cancel=should_cancel) + _run_with_boundaries( + "stop", + server_name, + l4d2_facade.stop_server, + server_id, + on_stdout=on_stdout, + on_stderr=on_stderr, + should_cancel=should_cancel, + ) elif operation == "delete": - l4d2_facade.delete_server(server_id, on_stdout=on_stdout, on_stderr=on_stderr, should_cancel=should_cancel) + _run_with_boundaries( + "delete", + server_name, + l4d2_facade.delete_server, + server_id, + on_stdout=on_stdout, + on_stderr=on_stderr, + should_cancel=should_cancel, + ) else: raise ValueError(f"unknown job operation: {operation}") diff --git a/l4d2web/tests/test_job_worker.py b/l4d2web/tests/test_job_worker.py index e874be6..fa80dda 100644 --- a/l4d2web/tests/test_job_worker.py +++ b/l4d2web/tests/test_job_worker.py @@ -126,13 +126,13 @@ def test_successful_start_job_logs_and_refreshes_server_state(seeded_worker, mon def fake_initialize(server_id, *, on_stdout=None, on_stderr=None, should_cancel=None): del should_cancel calls.append(("initialize", server_id)) - on_stdout("initialized") + on_stdout("Step: creating instance directories...") on_stderr("init warning") def fake_start(server_id, *, on_stdout=None, on_stderr=None, should_cancel=None): del should_cancel calls.append(("start", server_id)) - on_stdout("started") + on_stdout("Step: mounting runtime overlay...") monkeypatch.setattr(l4d2_facade, "initialize_server", fake_initialize) monkeypatch.setattr(l4d2_facade, "start_server", fake_start) @@ -154,9 +154,13 @@ def test_successful_start_job_logs_and_refreshes_server_state(seeded_worker, mon assert job.finished_at is not None assert job.updated_at is not None assert lines == [ - (1, "stdout", "initialized"), - (2, "stderr", "init warning"), - (3, "stdout", "started"), + (1, "stdout", "starting initialize for alpha"), + (2, "stdout", "Step: creating instance directories..."), + (3, "stderr", "init warning"), + (4, "stdout", "finished initialize successfully"), + (5, "stdout", "starting start for alpha"), + (6, "stdout", "Step: mounting runtime overlay..."), + (7, "stdout", "finished start successfully"), ] assert server is not None assert server.actual_state == "running" @@ -192,6 +196,7 @@ def test_called_process_error_fails_job_and_sets_server_error(seeded_worker, mon assert job.exit_code == 7 assert server is not None assert server.last_error == "stop failed" + assert "starting stop for alpha" in lines assert "stop failed" in lines @@ -218,6 +223,8 @@ def test_refresh_failure_does_not_hide_operation_failure(seeded_worker, monkeypa assert job.exit_code == 7 assert server is not None assert server.last_error == "stop failed" + assert "starting stop for alpha" in lines + assert "stop failed" in lines assert "status refresh failed: status down" in lines @@ -292,6 +299,7 @@ def test_cancelled_process_finishes_job_as_cancelled(seeded_worker, monkeypatch) assert job.finished_at is not None assert server is not None assert server.last_error == "job cancelled; runtime state may be partial" + assert "starting stop for alpha" in lines assert "terminating" in lines assert "job cancelled; runtime state may be partial" in lines