diff --git a/docs/superpowers/plans/2026-05-19-log-streaming-and-temp-listener.md b/docs/superpowers/plans/2026-05-19-log-streaming-and-temp-listener.md new file mode 100644 index 0000000..aca7682 --- /dev/null +++ b/docs/superpowers/plans/2026-05-19-log-streaming-and-temp-listener.md @@ -0,0 +1,244 @@ +# Enable srcds log streaming + temp UDP capture listener + +## Context + +We want to start gathering data about what actually happens on our L4D2 +servers (round boundaries, kills, team selection, lobby arrivals) so we can +later build round/match tracking and visualizations. The Source engine's +HL Log Standard UDP streaming (`logaddress_add`) is the right primary +source — it's built into srcds, no plugin required, well-documented (see +[HL Log Standard](https://developer.valvesoftware.com/wiki/HL_Log_Standard)). + +This change does **two** things: + +1. **Make every managed L4D2 server stream its logs** to a known UDP + endpoint, by auto-injecting `log on`, `mp_logdetail 3`, and + `logaddress_add ` into generated `server.cfg` — alongside + `rcon_password`, where users can't accidentally break it. +2. **Stand up a deliberately disposable UDP listener** in the web app + that writes raw log lines to flat files (one per source address), + so we can observe a few days of real traffic before committing to + any schema or reducer design. + +The listener is explicitly a Phase-1 *capture-only* tool. It does **not** +parse, reduce, store in DB, or render anything. That's the next plan, +once we have evidence of what L4D2 actually emits on our servers. + +## Scope (in / out) + +**In scope** +- Inject 3 cvars into the generated `server.cfg` at facade level. +- Config-driven listener address (env var, sensible default). +- UDP listener daemon thread, sibling of `live_state_poller`. +- Flat-file capture, one file per `(srcip, srcport)`. +- Dev-server integration (capture dir under `LEFT4ME_ROOT`). +- Production wiring (capture dir under `/var/lib/left4me/`, systemd + unit changes if any). +- Minimal smoke test for the listener. + +**Out of scope (Phase 2+)** +- Parsing log lines into structured events. +- DB schema (`RawLogLine`, `LogEvent`, `MatchSession`, `Round`, etc.). +- Mapping source addr → `Server` row reliably (we have the data + in the flat-file name; we don't *need* to resolve it yet). +- `sv_logsecret` authentication (single-host loopback, defer). +- Any UI. + +## Design + +### 1. Auto-injected cvars in `server.cfg` + +**File:** `l4d2web/l4d2web/services/l4d2_facade.py` (around line 41-48, +where `rcon_password` is appended after the user blueprint config). + +After the existing `rcon_password` append, add: + +```python +config_lines.append("log on") +config_lines.append("mp_logdetail 3") +log_addr = current_app.config["LOG_LISTENER_ADDR"] # e.g. "127.0.0.1:27800" +config_lines.append(f"logaddress_add {log_addr}") +``` + +Notes: +- Order matters: cvars must come *after* anything in the user + blueprint so users can't override them. +- `log on` is idempotent; safe to re-issue. +- `logaddress_add` is *additive* — re-running it just re-registers + the same destination. srcds tolerates this. + +### 2. Listener address configuration + +**File:** `l4d2web/l4d2web/config.py` + +Add to `DEFAULT_CONFIG` (and the env-var loader): + +```python +"LOG_LISTENER_ADDR": "127.0.0.1:27800", # what srcds logs to +"LOG_LISTENER_BIND": "127.0.0.1:27800", # what our listener binds +"LOG_LISTENER_ENABLED": True, +"LOG_CAPTURE_DIR": "/var/lib/left4me/captures", # overridden in dev +``` + +Port **27800** chosen to avoid: +- SRCDS server range 27015–27050 +- Steam client range 27000–27015 +- Steam master server range 27010–27050 + +Override env var: `LEFT4ME_LOG_LISTENER_ADDR`, `LEFT4ME_LOG_LISTENER_BIND`, +`LEFT4ME_LOG_CAPTURE_DIR`. + +**Dev override:** `scripts/dev-server.py` already sets +`LEFT4ME_ROOT=.tmp/dev-server` — extend it to also set +`LEFT4ME_LOG_CAPTURE_DIR=$LEFT4ME_ROOT/captures` so dev captures live +under `.tmp/` and don't pollute `/var/lib/left4me`. + +### 3. The listener + +**New file:** `l4d2web/l4d2web/services/log_listener.py` + +Pattern: copy the daemon-thread shape from +`live_state_poller.py:230-245`. Single global guard; one thread. + +Sketch: + +```python +def start_log_listener(app): + if not app.config["LOG_LISTENER_ENABLED"]: + return + if _started: # global guard (match poller pattern) + return + bind = app.config["LOG_LISTENER_BIND"] + capture_dir = Path(app.config["LOG_CAPTURE_DIR"]) + capture_dir.mkdir(parents=True, exist_ok=True) + t = threading.Thread( + target=_listener_loop, + args=(bind, capture_dir), + name="left4me-log-listener", + daemon=True, + ) + t.start() + +def _listener_loop(bind: str, capture_dir: Path) -> None: + host, port = bind.rsplit(":", 1) + sock = socket.socket(socket.AF_INET, socket.SOCK_DGRAM) + sock.bind((host, int(port))) + while True: + data, (srcip, srcport) = sock.recvfrom(4096) + # srcds log packets: 0xFF 0xFF 0xFF 0xFF 'R' or 'S', then body, then trailing 0x00 0x0A + # See HL Log Standard. We strip nothing on first pass — write raw. + path = capture_dir / f"{srcip}-{srcport}.log" + with path.open("ab") as f: + f.write(data) +``` + +Wiring (`l4d2web/l4d2web/app.py:157`, alongside the poller): + +```python +if not app.config.get("TESTING"): + start_live_state_poller(app) + start_log_listener(app) +``` + +### 4. UDP packet structure note + +srcds log packets aren't bare text — they have a small header: + +- 4 bytes of `0xFF` (out-of-band marker) +- 1 byte type: `'R'` (no secret) or `'S'` (with `sv_logsecret`) +- If `'S'`: 4-byte little-endian secret +- Body: ASCII log line including the `L mm/dd/yyyy ...` prefix +- Trailing `0x00 0x0A` (null + newline) + +For capture-only we just **write the raw bytes**; later parsers will +strip the header. The header is also useful diagnostic info (it tells +us whether `sv_logsecret` made it through). + +### 5. Capture file format + +One file per `(srcip, srcport)`, name `-.log`, append mode, +unbuffered byte writes. Rotation is **out of scope** — these are +short-lived (days), and operators can `rm` them manually. If a file +gets surprisingly large, that itself is data. + +### 6. Restart implications + +Cvars in `server.cfg` are read by srcds at instance startup +(`instances.py:54,87`). Existing running servers **will not pick up +the new log destination** until they are restarted via +`l4d2ctl initialize` or a process restart. Document this in the +verification section — don't try to be clever about live-applying. + +## Critical files + +**To modify:** +- `l4d2web/l4d2web/services/l4d2_facade.py` — inject 3 cvars after `rcon_password` +- `l4d2web/l4d2web/config.py` — add 4 new config keys with env overrides +- `l4d2web/l4d2web/app.py` — start listener thread next to poller +- `scripts/dev-server.py` — set `LEFT4ME_LOG_CAPTURE_DIR` under `.tmp/` + +**To create:** +- `l4d2web/l4d2web/services/log_listener.py` — UDP listener thread + +**To reference (read-only):** +- `l4d2web/l4d2web/services/live_state_poller.py:230-245` — thread pattern +- `l4d2web/l4d2web/services/l4d2_facade.py:41-48` — rcon_password injection pattern +- `l4d2host/l4d2host/instances.py:54,87` — confirms server.cfg is generated at init time +- `deploy/files/usr/local/lib/systemd/system/left4me-web.service` — may need a + read-write path entry if `ReadWritePaths=` is set restrictively (check before + modifying) + +## Verification + +End-to-end smoke test, on the dev box first: + +1. **Static checks** + ```bash + cd /Users/mwiegand/Projekte/left4me + uv run --project l4d2web ruff check l4d2web + uv run --project l4d2web pytest l4d2web/tests -k "facade or config" -x + ``` + +2. **Cvar injection unit test** + - Add a test in `l4d2web/tests/` that calls `build_server_spec_payload` + and asserts the generated config lines include `log on`, + `mp_logdetail 3`, and a `logaddress_add` line whose target matches + `LOG_LISTENER_ADDR`. + +3. **Listener smoke test** + - Run dev server: `scripts/dev-server.py` + - In another shell, fake an srcds log packet: + ```bash + printf '\xff\xff\xff\xff' \ + 'RL 05/19/2026 - 14:23:11: "Test<1><>" connected, address "127.0.0.1:27015"\x00\x0a' \ + | nc -u -w1 127.0.0.1 27800 + ``` + - Confirm `ls .tmp/dev-server/captures/` shows a `127.0.0.1-.log`. + - Confirm the file contains the bytes (use `xxd` to inspect the + header + body shape). + +4. **Live end-to-end on one production server** + - Pick **one** server (least-busy), trigger a re-init via the web + UI so `server.cfg` is regenerated with the new cvars. + - Verify via RCON: `logaddress_list` should show our address. + - Connect to the server, run around. Confirm a file appears in + `/var/lib/left4me/captures/` with the server's source IP. + - `tail -f` and verify HL-Log-Standard lines (`L ... : "..." + entered the game`, `Loading map`, `World triggered "round_start"`). + +5. **What we are explicitly NOT verifying yet** + - Parsing correctness — there's no parser. + - Reliable server-id mapping — we have srcip/srcport in the + filename, that's enough for now. + - Long-running stability past a few days — listener is temp. + +## Follow-ups (separate plans) + +Once we have ~3–7 days of capture data: +- Decide event vocabulary based on what L4D2 *actually* emits on our + servers (vs. what specs say). +- Design `RawLogLine` / `LogEvent` / `MatchSession` / `Round` schema. +- Build a reducer. +- Consider a small SourceMod bridge plugin in `l4d2host/` to surface + `tank_spawn`, `mission_lost`, finale events as `LogMessage()` lines. +- `sv_logsecret` once the listener is reachable beyond loopback. diff --git a/l4d2web/l4d2web/app.py b/l4d2web/l4d2web/app.py index faad17f..8e558a9 100644 --- a/l4d2web/l4d2web/app.py +++ b/l4d2web/l4d2web/app.py @@ -28,6 +28,7 @@ from l4d2web.services.job_worker import ( start_state_poller, ) from l4d2web.services.live_state_poller import start_live_state_poller +from l4d2web.services.log_listener import start_log_listener from l4d2web.services.timeago import format_time_html @@ -155,6 +156,7 @@ def create_app(test_config: dict[str, object] | None = None) -> Flask: start_state_poller(app) if not app.config.get("TESTING"): start_live_state_poller(app) + start_log_listener(app) @app.get("/health") def health(): diff --git a/l4d2web/l4d2web/config.py b/l4d2web/l4d2web/config.py index c046ac0..7491919 100644 --- a/l4d2web/l4d2web/config.py +++ b/l4d2web/l4d2web/config.py @@ -21,6 +21,10 @@ DEFAULT_CONFIG: dict[str, object] = { "STUCK_SESSION_SECONDS": 60, "STEAM_PROFILE_TTL_SECONDS": 86400, "STEAM_WEB_API_KEY": "", + "LOG_LISTENER_ENABLED": True, + "LOG_LISTENER_BIND": "127.0.0.1:28000", + "LOG_LISTENER_ADDR": "127.0.0.1:28000", + "LOG_CAPTURE_DIR": "/var/lib/left4me/captures", } @@ -49,4 +53,8 @@ def load_config() -> dict[str, object]: "STUCK_SESSION_SECONDS": int(os.getenv("STUCK_SESSION_SECONDS", "60")), "STEAM_PROFILE_TTL_SECONDS": int(os.getenv("STEAM_PROFILE_TTL_SECONDS", "86400")), "STEAM_WEB_API_KEY": os.getenv("STEAM_WEB_API_KEY", ""), + "LOG_LISTENER_ENABLED": _bool_from_env(os.getenv("LOG_LISTENER_ENABLED", "true")), + "LOG_LISTENER_BIND": os.getenv("LOG_LISTENER_BIND", "127.0.0.1:28000"), + "LOG_LISTENER_ADDR": os.getenv("LOG_LISTENER_ADDR", "127.0.0.1:28000"), + "LOG_CAPTURE_DIR": os.getenv("LOG_CAPTURE_DIR", "/var/lib/left4me/captures"), } diff --git a/l4d2web/l4d2web/services/l4d2_facade.py b/l4d2web/l4d2web/services/l4d2_facade.py index 9dff64f..07b5f78 100644 --- a/l4d2web/l4d2web/services/l4d2_facade.py +++ b/l4d2web/l4d2web/services/l4d2_facade.py @@ -1,7 +1,7 @@ from dataclasses import dataclass import json -from pathlib import Path +from flask import current_app from sqlalchemy import select from l4d2web.db import session_scope @@ -33,6 +33,7 @@ def build_server_spec_payload( overlay_rows: list[tuple[int, str, bool]], *, resolved_hostname: str = "", + log_listener_addr: str = "", ) -> dict: overlays: list[dict] = [] for overlay_id, path, expose in overlay_rows: @@ -54,6 +55,14 @@ def build_server_spec_payload( # nor hostname can override it (Source's cvar semantics are last-wins). if server.rcon_password: config_lines.append(f'rcon_password "{server.rcon_password}"') + # HL-Log-Standard UDP streaming. Auto-injected (not in user blueprint) so + # the listener in l4d2web/services/log_listener.py reliably receives + # game events from every managed server. logaddress_add is additive and + # safe to re-issue on restart. + if log_listener_addr: + config_lines.append("log on") + config_lines.append("mp_logdetail 3") + config_lines.append(f"logaddress_add {log_listener_addr}") return { "port": server.port, "overlays": overlays, @@ -111,8 +120,17 @@ def initialize_server(server_id: int, on_stdout=None, on_stderr=None, should_can user = db.get(User, server.user_id) resolved_hostname = f"{user.username} {server.name}" + log_listener_addr = "" + try: + if current_app.config.get("LOG_LISTENER_ENABLED"): + log_listener_addr = current_app.config.get("LOG_LISTENER_ADDR", "") + except RuntimeError: + pass # no app context (tests / cli) — skip log streaming + spec_path = write_temp_spec(build_server_spec_payload( - server, blueprint, overlay_rows, resolved_hostname=resolved_hostname, + server, blueprint, overlay_rows, + resolved_hostname=resolved_hostname, + log_listener_addr=log_listener_addr, )) try: host_commands.run_command( diff --git a/l4d2web/l4d2web/services/log_listener.py b/l4d2web/l4d2web/services/log_listener.py new file mode 100644 index 0000000..4a7c70c --- /dev/null +++ b/l4d2web/l4d2web/services/log_listener.py @@ -0,0 +1,81 @@ +"""Temporary UDP listener for srcds log streaming (HL Log Standard). + +Captures raw `logaddress_add`-streamed packets from every managed L4D2 +server into flat files under LOG_CAPTURE_DIR — one file per source +(srcip, srcport). Deliberately capture-only: no parsing, no DB, no +reducer. The goal is to observe what L4D2 actually emits on our +servers before we commit to a schema or event vocabulary. + +Packet shape (per HL Log Standard): + 4 bytes 0xFF | out-of-band marker + 1 byte 'R'/'S' | with-secret if 'S' (then 4 bytes LE secret) + body | ASCII "L mm/dd/yyyy - hh:mm:ss: ..." plus trailing 0x00 0x0A + +We write the raw bytes verbatim — the header is useful diagnostic info +(it tells future-us whether sv_logsecret was in play). +""" +from __future__ import annotations + +import logging +import socket +import threading +from pathlib import Path + + +logger = logging.getLogger(__name__) + +_listener_started_lock = threading.Lock() +_listener_started = False + + +def start_log_listener(app) -> None: + """Spawn the daemon listener thread once per process.""" + global _listener_started + if not app.config.get("LOG_LISTENER_ENABLED"): + return + with _listener_started_lock: + if _listener_started: + return + bind = str(app.config.get("LOG_LISTENER_BIND", "127.0.0.1:28000")) + capture_dir = Path(str(app.config.get("LOG_CAPTURE_DIR", "/var/lib/left4me/captures"))) + try: + capture_dir.mkdir(parents=True, exist_ok=True) + except OSError: + logger.exception("log listener: cannot create capture dir %s", capture_dir) + return + host, _, port_str = bind.rpartition(":") + try: + port = int(port_str) + except ValueError: + logger.error("log listener: invalid LOG_LISTENER_BIND %r", bind) + return + try: + sock = socket.socket(socket.AF_INET, socket.SOCK_DGRAM) + sock.bind((host, port)) + except OSError: + logger.exception("log listener: cannot bind %s:%d", host, port) + return + _listener_started = True + thread = threading.Thread( + target=_listener_loop, + args=(sock, capture_dir), + name="left4me-log-listener", + daemon=True, + ) + thread.start() + logger.info("log listener bound to %s:%d -> %s", host, port, capture_dir) + + +def _listener_loop(sock: socket.socket, capture_dir: Path) -> None: + while True: + try: + data, (srcip, srcport) = sock.recvfrom(4096) + except OSError: + logger.exception("log listener: recvfrom failed") + continue + path = capture_dir / f"{srcip}-{srcport}.log" + try: + with path.open("ab") as f: + f.write(data) + except OSError: + logger.exception("log listener: write failed for %s", path) diff --git a/l4d2web/tests/test_l4d2_facade.py b/l4d2web/tests/test_l4d2_facade.py index 08485c8..8a3caf0 100644 --- a/l4d2web/tests/test_l4d2_facade.py +++ b/l4d2web/tests/test_l4d2_facade.py @@ -411,6 +411,41 @@ def test_build_server_spec_payload_omits_hostname_when_empty() -> None: assert not line.startswith("hostname ") +# --------------------------------------------------------------------------- +# build_server_spec_payload — log streaming cvar injection +# --------------------------------------------------------------------------- + + +def test_build_server_spec_payload_injects_log_cvars() -> None: + from l4d2web.services.l4d2_facade import build_server_spec_payload + + srv, bp = _make_server_blueprint(rcon="sekret") + spec = build_server_spec_payload( + srv, bp, [], log_listener_addr="127.0.0.1:28000", + ) + cfg = spec["config"] + # All three log cvars emitted, AFTER rcon_password (so blueprint can't + # override them — Source cvars are last-wins). + assert "log on" in cfg + assert "mp_logdetail 3" in cfg + assert "logaddress_add 127.0.0.1:28000" in cfg + rcon_idx = cfg.index('rcon_password "sekret"') + log_idx = cfg.index("log on") + assert log_idx > rcon_idx, "log cvars must come after rcon_password" + assert cfg[-1] == "logaddress_add 127.0.0.1:28000" + + +def test_build_server_spec_payload_omits_log_cvars_when_addr_empty() -> None: + from l4d2web.services.l4d2_facade import build_server_spec_payload + + srv, bp = _make_server_blueprint(rcon="sekret") + spec = build_server_spec_payload(srv, bp, []) # default "" → no inject + cfg = spec["config"] + assert "log on" not in cfg + assert "mp_logdetail 3" not in cfg + assert not any(line.startswith("logaddress_add ") for line in cfg) + + def test_initialize_server_resolves_fallback_hostname( monkeypatch: pytest.MonkeyPatch, server_with_blueprint, ) -> None: diff --git a/scripts/dev-server.py b/scripts/dev-server.py index 2099f00..b00a791 100755 --- a/scripts/dev-server.py +++ b/scripts/dev-server.py @@ -126,6 +126,7 @@ def main(): "LEFT4ME_ROOT": str(DEV_ROOT), "SESSION_COOKIE_SECURE": "0", # so http://127.0.0.1 cookies stick "JOB_WORKER_ENABLED": "false", # don't fire (sudo-requiring) l4d2ctl + "LOG_CAPTURE_DIR": str(DEV_ROOT / "captures"), }) print(f"==> Migrating {DB_FILE} to head", flush=True)