# Host Lifecycle Step Logging Implementation Plan

> **For agentic workers:** REQUIRED SUB-SKILL: Use superpowers:subagent-driven-development (recommended) or superpowers:executing-plans to implement this plan task-by-task. Steps use checkbox (`- [ ]`) syntax for tracking.

**Goal:** Provide granular, live progress feedback in the web GUI during lifecycle operations without exposing sensitive internal paths or raw subprocess mechanics.

**Architecture:** Modifies `l4d2host/instances.py` to emit safe, high-level step markers to `stdout` via an explicit helper function. These are automatically captured by `l4d2web/services/job_worker.py` and forwarded to the UI via existing SSE endpoints. The job worker will also add boundary markers for top-level operations.

**Tech Stack:** Python, subprocess, pytest

---

### Task 1: Add step logging helper to host library

**Files:**
- Modify: `l4d2host/instances.py`
- Modify: `l4d2host/tests/test_initialize.py`

- [ ] **Step 1: Write the failing test for the helper behavior**

In `l4d2host/tests/test_initialize.py`, add imports and a test verifying `_emit_step` correctly uses the callback or `sys.stdout` depending on arguments:

```python
import sys
from io import StringIO
from l4d2host.instances import _emit_step

def test_emit_step_uses_callback() -> None:
    calls: list[str] = []
    _emit_step("test step", on_stdout=calls.append, passthrough=False)
    assert calls == ["Step: test step"]

def test_emit_step_uses_passthrough_stdout(monkeypatch) -> None:
    fake_out = StringIO()
    monkeypatch.setattr(sys, "stdout", fake_out)
    _emit_step("passthrough step", on_stdout=None, passthrough=True)
    assert fake_out.getvalue() == "Step: passthrough step\n"
    
def test_emit_step_does_nothing_if_no_target() -> None:
    _emit_step("silent step", on_stdout=None, passthrough=False)
```

- [ ] **Step 2: Run test to verify it fails**

Run: `pytest l4d2host/tests/test_initialize.py -k test_emit_step -q`
Expected: FAIL due to `_emit_step` not defined.

- [ ] **Step 3: Implement minimal code**

In `l4d2host/instances.py`, add imports (if needed) and the `_emit_step` function at the top of the file:

```python
import sys

def _emit_step(msg: str, on_stdout: Callable[[str], None] | None, passthrough: bool) -> None:
    formatted = f"Step: {msg}"
    if on_stdout is not None:
        on_stdout(formatted)
    elif passthrough:
        print(formatted, flush=True)
```

- [ ] **Step 4: Run test to verify it passes**

Run: `pytest l4d2host/tests/test_initialize.py -k test_emit_step -q`
Expected: PASS

- [ ] **Step 5: Commit**

```bash
git add l4d2host/instances.py l4d2host/tests/test_initialize.py
git commit -m "feat(host): add _emit_step helper for lifecycle logging"
```

---

### Task 2: Add step logging to initialize_instance

**Files:**
- Modify: `l4d2host/instances.py`
- Modify: `l4d2host/tests/test_initialize.py`

- [ ] **Step 1: Write the failing test**

In `l4d2host/tests/test_initialize.py`, add a test to verify `initialize_instance` logs the correct steps:

```python
def test_initialize_instance_emits_steps(tmp_path: Path) -> None:
    spec = tmp_path / "spec.yaml"
    spec.write_text("port: 27015\noverlays: [standard]\n")
    
    steps: list[str] = []
    initialize_instance("alpha", spec, root=tmp_path, on_stdout=steps.append)
    
    assert steps == [
        "Step: creating instance directories...",
        "Step: writing instance.env...",
        "Step: writing server.cfg...",
        "Step: initialization complete.",
    ]
```

- [ ] **Step 2: Run test to verify it fails**

Run: `pytest l4d2host/tests/test_initialize.py -k test_initialize_instance_emits_steps -q`
Expected: FAIL because `steps` is empty.

- [ ] **Step 3: Add step logs to initialize_instance**

Modify `initialize_instance` in `l4d2host/instances.py` to include `_emit_step` calls. Use the parameters `on_stdout` and `passthrough`:

```python
    _emit_step("creating instance directories...", on_stdout, passthrough)
    instance_dir = root / "instances" / name
    runtime_dir = root / "runtime" / name
    (runtime_dir / "upper").mkdir(parents=True, exist_ok=True)
    (runtime_dir / "work").mkdir(parents=True, exist_ok=True)
    (runtime_dir / "merged").mkdir(parents=True, exist_ok=True)
    instance_dir.mkdir(parents=True, exist_ok=True)

    lowerdirs = [str(overlay_path(overlay, root=root)) for overlay in spec.overlays]
    lowerdirs.append(str(root / "installation"))

    _emit_step("writing instance.env...", on_stdout, passthrough)
    instance_env = "\n".join(
        [
            f"L4D2_PORT={spec.port}",
            f"L4D2_ARGS={' '.join(spec.arguments)}",
            f"L4D2_LOWERDIRS={':'.join(lowerdirs)}",
        ]
    ) + "\n"
    (instance_dir / "instance.env").write_text(instance_env)

    _emit_step("writing server.cfg...", on_stdout, passthrough)
    server_cfg = "\n".join(spec.config) if spec.config else ""
    (instance_dir / "server.cfg").write_text(server_cfg)
    _emit_step("initialization complete.", on_stdout, passthrough)
```

- [ ] **Step 4: Run test to verify it passes**

Run: `pytest l4d2host/tests/test_initialize.py -k test_initialize_instance_emits_steps -q`
Expected: PASS

- [ ] **Step 5: Commit**

```bash
git add l4d2host/instances.py l4d2host/tests/test_initialize.py
git commit -m "feat(host): emit steps during initialize_instance"
```

---

### Task 3: Add step logging to start_instance

**Files:**
- Modify: `l4d2host/instances.py`
- Modify: `l4d2web/tests/test_job_worker.py` (adjusting mocks that expect `on_stdout` logic)

- [ ] **Step 1: Check test suite safety net for start/stop**

We don't have dedicated host unit tests for `start`/`stop`/`delete` due to their systemd/fuse dependency, but they are mocked in web tests (`l4d2web/tests/test_job_worker.py` and `test_l4d2_facade.py`).
We must ensure our `_emit_step` calls inside `start_instance` don't break existing tests, and we'll add the logs to the implementation.

- [ ] **Step 2: Add step logs to start_instance**

In `l4d2host/instances.py`, modify `start_instance`:

```python
    env = _load_instance_env(instance_dir / "instance.env")

    _emit_step("mounting runtime overlay...", on_stdout, passthrough)
    run_command(
        [
            "fuse-overlayfs",
            "-o",
            (
                f"lowerdir={env['L4D2_LOWERDIRS']},"
                f"upperdir={runtime_dir / 'upper'},"
                f"workdir={runtime_dir / 'work'}"
            ),
            str(runtime_dir / "merged"),
        ],
        on_stdout=on_stdout,
        on_stderr=on_stderr,
        passthrough=passthrough,
        should_cancel=should_cancel,
    )

    _emit_step("copying server.cfg to runtime...", on_stdout, passthrough)
    target_cfg = runtime_dir / "merged" / "left4dead2" / "cfg" / "server.cfg"
    target_cfg.parent.mkdir(parents=True, exist_ok=True)
    shutil.copy2(instance_dir / "server.cfg", target_cfg)

    _emit_step("starting systemd service...", on_stdout, passthrough)
    start_service(
        name,
        on_stdout=on_stdout,
        on_stderr=on_stderr,
        passthrough=passthrough,
        should_cancel=should_cancel,
    )
    _emit_step("start complete.", on_stdout, passthrough)
```

- [ ] **Step 3: Add step logs to stop_instance**

In `l4d2host/instances.py`, modify `stop_instance`:

```python
    _emit_step("stopping systemd service...", on_stdout, passthrough)
    stop_service(
        name,
        on_stdout=on_stdout,
        on_stderr=on_stderr,
        passthrough=passthrough,
        should_cancel=should_cancel,
    )
    _emit_step("unmounting runtime overlay...", on_stdout, passthrough)
    run_command(
        ["fusermount3", "-u", str(root / "runtime" / name / "merged")],
        on_stdout=on_stdout,
        on_stderr=on_stderr,
        passthrough=passthrough,
        should_cancel=should_cancel,
    )
    _emit_step("stop complete.", on_stdout, passthrough)
```

- [ ] **Step 4: Add step logs to delete_instance**

In `l4d2host/instances.py`, modify `delete_instance`:

```python
    if not instance_dir.exists() and not runtime_dir.exists():
        return

    _emit_step("stopping systemd service (if running)...", on_stdout, passthrough)
    stop_service(
        name,
        on_stdout=on_stdout,
        on_stderr=on_stderr,
        passthrough=passthrough,
        should_cancel=should_cancel,
    )

    merged = runtime_dir / "merged"
    if merged.is_mount():
        _emit_step("unmounting runtime overlay (if mounted)...", on_stdout, passthrough)
        run_command(
            ["fusermount3", "-u", str(merged)],
            on_stdout=on_stdout,
            on_stderr=on_stderr,
            passthrough=passthrough,
            should_cancel=should_cancel,
        )

    _emit_step("removing instance files...", on_stdout, passthrough)
    if instance_dir.exists():
        shutil.rmtree(instance_dir)
    if runtime_dir.exists():
        shutil.rmtree(runtime_dir)
    _emit_step("delete complete.", on_stdout, passthrough)
```

- [ ] **Step 5: Run full test suite**

Run: `pytest l4d2host/tests l4d2web/tests -q`
Expected: PASS. If tests fail because of expected outputs in mock fake `run_command` handlers, update the mock assertions in the tests to allow the newly emitted step lines.

- [ ] **Step 6: Commit**

```bash
git add l4d2host/instances.py
git commit -m "feat(host): emit steps during start, stop, and delete operations"
```

---

### Task 4: Add boundary markers to job worker

**Files:**
- Modify: `l4d2web/services/job_worker.py`
- Modify: `l4d2web/tests/test_job_worker.py`

- [ ] **Step 1: Write failing tests for job worker boundaries**

In `l4d2web/tests/test_job_worker.py`, update `test_successful_start_job_logs_and_refreshes_server_state` to expect the synthetic boundary lines. Also, modify the mock to simulate actual stdout lines instead of arbitrary "initialized" text:

```python
    def fake_initialize(server_id, *, on_stdout=None, on_stderr=None, should_cancel=None):
        del should_cancel
        calls.append(("initialize", server_id))
        on_stdout("Step: creating instance directories...")

    def fake_start(server_id, *, on_stdout=None, on_stderr=None, should_cancel=None):
        del should_cancel
        calls.append(("start", server_id))
        on_stdout("Step: mounting runtime overlay...")
```

Change the `assert lines == ` section at the bottom of the test:

```python
    assert lines == [
        (1, "stdout", "starting initialize for alpha"),
        (2, "stdout", "Step: creating instance directories..."),
        (3, "stdout", "finished initialize successfully"),
        (4, "stdout", "starting start for alpha"),
        (5, "stdout", "Step: mounting runtime overlay..."),
        (6, "stdout", "finished start successfully"),
    ]
```

- [ ] **Step 2: Run test to verify it fails**

Run: `pytest l4d2web/tests/test_job_worker.py::test_successful_start_job_logs_and_refreshes_server_state -v`
Expected: FAIL because boundary markers are missing.

- [ ] **Step 3: Implement boundary logging in job worker**

In `l4d2web/services/job_worker.py`, modify the `run_job` execution block:

First, add a helper to fetch the server name if `server_id` is present:
```python
    server_name = None
    if server_id is not None:
        with session_scope() as db:
            s = db.scalar(select(Server).where(Server.id == server_id))
            server_name = s.name if s else "unknown"
```

Then, wrap the facade calls:
```python
    def _run_with_boundaries(action: str, target: str, func, *args, **kwargs):
        append_job_log_line(job_id, "stdout", f"starting {action} for {target}", max_chars=max_chars)
        func(*args, **kwargs)
        append_job_log_line(job_id, "stdout", f"finished {action} successfully", max_chars=max_chars)

    try:
        if operation == "install":
            _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":
            _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":
            _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()
            _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":
            _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":
            _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}")
```

- [ ] **Step 4: Run test to verify it passes**

Run: `pytest l4d2web/tests/test_job_worker.py::test_successful_start_job_logs_and_refreshes_server_state -v`
Expected: PASS

- [ ] **Step 5: Verify remaining job worker tests**

Run: `pytest l4d2web/tests/test_job_worker.py -q`
Some tests might fail if they explicitly check log content. Fix them to accommodate the boundary lines. For instance, `test_called_process_error_fails_job_and_sets_server_error` might need the new boundary lines in its assertions.

Example fix in `test_called_process_error_fails_job_and_sets_server_error`:
```python
    assert "starting stop for alpha" in lines
    assert "stop failed" in lines
```

Example fix in `test_cancelled_process_finishes_job_as_cancelled`:
```python
    assert "starting stop for alpha" in lines
    assert "terminating" in lines
```

- [ ] **Step 6: Commit**

```bash
git add l4d2web/services/job_worker.py l4d2web/tests/test_job_worker.py
git commit -m "feat(web): add boundary log lines to job worker execution"
```

---

### Task 5: Verify full test suite and clean up

- [ ] **Step 1: Run all tests**

Run: `pytest l4d2host/tests l4d2web/tests deploy/tests -q`
Expected: ALL PASS.

- [ ] **Step 2: Push changes**

```bash
git push
```