feat(log-streaming): enable srcds log streaming + temp UDP capture listener

Every managed server now auto-injects log on / mp_logdetail 3 / logaddress_add
into its generated server.cfg, streaming HL Log Standard events to a UDP
listener bundled with l4d2web. The listener is deliberately capture-only —
raw packets land in flat files per source address — so we can observe what
L4D2 actually emits on our servers before committing to a schema or event
vocabulary. Match/round/event model is a Phase 2 plan informed by that data.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
This commit is contained in:
mwiegand 2026-05-19 23:22:00 +02:00
parent 188fe546ed
commit 730ef09967
No known key found for this signature in database
7 changed files with 391 additions and 2 deletions

View file

@ -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 <addr>` 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 2701527050
- Steam client range 2700027015
- Steam master server range 2701027050
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 `<ip>-<port>.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><STEAM_1:0: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-<srcport>.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 ~37 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.

View file

@ -28,6 +28,7 @@ from l4d2web.services.job_worker import (
start_state_poller, start_state_poller,
) )
from l4d2web.services.live_state_poller import start_live_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 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) start_state_poller(app)
if not app.config.get("TESTING"): if not app.config.get("TESTING"):
start_live_state_poller(app) start_live_state_poller(app)
start_log_listener(app)
@app.get("/health") @app.get("/health")
def health(): def health():

View file

@ -21,6 +21,10 @@ DEFAULT_CONFIG: dict[str, object] = {
"STUCK_SESSION_SECONDS": 60, "STUCK_SESSION_SECONDS": 60,
"STEAM_PROFILE_TTL_SECONDS": 86400, "STEAM_PROFILE_TTL_SECONDS": 86400,
"STEAM_WEB_API_KEY": "", "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")), "STUCK_SESSION_SECONDS": int(os.getenv("STUCK_SESSION_SECONDS", "60")),
"STEAM_PROFILE_TTL_SECONDS": int(os.getenv("STEAM_PROFILE_TTL_SECONDS", "86400")), "STEAM_PROFILE_TTL_SECONDS": int(os.getenv("STEAM_PROFILE_TTL_SECONDS", "86400")),
"STEAM_WEB_API_KEY": os.getenv("STEAM_WEB_API_KEY", ""), "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"),
} }

View file

@ -1,7 +1,7 @@
from dataclasses import dataclass from dataclasses import dataclass
import json import json
from pathlib import Path
from flask import current_app
from sqlalchemy import select from sqlalchemy import select
from l4d2web.db import session_scope from l4d2web.db import session_scope
@ -33,6 +33,7 @@ def build_server_spec_payload(
overlay_rows: list[tuple[int, str, bool]], overlay_rows: list[tuple[int, str, bool]],
*, *,
resolved_hostname: str = "", resolved_hostname: str = "",
log_listener_addr: str = "",
) -> dict: ) -> dict:
overlays: list[dict] = [] overlays: list[dict] = []
for overlay_id, path, expose in overlay_rows: 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). # nor hostname can override it (Source's cvar semantics are last-wins).
if server.rcon_password: if server.rcon_password:
config_lines.append(f'rcon_password "{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 { return {
"port": server.port, "port": server.port,
"overlays": overlays, "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) user = db.get(User, server.user_id)
resolved_hostname = f"{user.username} {server.name}" 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( 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: try:
host_commands.run_command( host_commands.run_command(

View file

@ -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)

View file

@ -411,6 +411,41 @@ def test_build_server_spec_payload_omits_hostname_when_empty() -> None:
assert not line.startswith("hostname ") 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( def test_initialize_server_resolves_fallback_hostname(
monkeypatch: pytest.MonkeyPatch, server_with_blueprint, monkeypatch: pytest.MonkeyPatch, server_with_blueprint,
) -> None: ) -> None:

View file

@ -126,6 +126,7 @@ def main():
"LEFT4ME_ROOT": str(DEV_ROOT), "LEFT4ME_ROOT": str(DEV_ROOT),
"SESSION_COOKIE_SECURE": "0", # so http://127.0.0.1 cookies stick "SESSION_COOKIE_SECURE": "0", # so http://127.0.0.1 cookies stick
"JOB_WORKER_ENABLED": "false", # don't fire (sudo-requiring) l4d2ctl "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) print(f"==> Migrating {DB_FILE} to head", flush=True)