docs(log-streaming): record that L4D2 logaddress UDP emit is dead

Investigation 2026-05-20: deployed listener captures nothing in
production. Diagnostics (strace + tcpdump) prove srcds makes ZERO
sendto calls toward registered logaddress destinations even though
the cvar API reports "logging to udp" and logaddress_list shows
the entry. File and console sinks work fine; the UDP path is
silently stubbed at the engine level (same family as broken L4D2
SourceTV). Listener and cfg injection retained for a future
SourceMod bridge that uses LogMessage() — that path does reach
UDP destinations on other Source 1 games.

Also drops mp_logdetail 3 (CS-only; L4D2 prints "Unknown command").

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
This commit is contained in:
mwiegand 2026-05-20 00:19:50 +02:00
parent 730ef09967
commit 46bba0d134
No known key found for this signature in database
4 changed files with 97 additions and 16 deletions

View file

@ -232,13 +232,78 @@ End-to-end smoke test, on the dev box first:
filename, that's enough for now.
- Long-running stability past a few days — listener is temp.
## Post-deploy verification findings (2026-05-20)
The plan above describes what we INTENDED to ship; this section
documents what we ACTUALLY learned after deployment.
Listener was deployed and confirmed bound (`ss -ulnp` showed
`gunicorn:28000`). Servers were re-initialized, `server.cfg`
inspected and confirmed correct — `log on`, `logaddress_add
127.0.0.1:28000` at the bottom, after `rcon_password`. The listener
was proven healthy end-to-end with a local `nc` probe writing a
capture file. **Yet captures stayed empty even during active play.**
Diagnostic steps:
1. `logaddress_list` via RCON → `1 entry: 127.0.0.1:28000`
2. `log` via RCON → `currently logging to: file, console, udp`
3. Local `.log` files in
`/var/lib/left4me/runtime/<n>/merged/left4dead2/logs/` grow
normally; rich gameplay events show in `journalctl -u
left4me-server@<n>` (bot connect, team join, spawn, character
pick — full HL-Log-Standard verbosity) ✓
4. `tcpdump -i lo udp port 28000` during rcon say/echo/status bursts
**0 packets**
5. `tcpdump -i any host 127.0.0.1 and udp` → still 0 ✗
6. Toggle `log off` / `log on` live → engine confirms cycle, no
effect ✗
7. `sv_logflush 1` live → no effect ✗
8. Suspected `SocketBindAllow=udp:27000-27999` was blocking the
implicit ephemeral bind of a separate log socket. Added drop-in
`SocketBindAllow=udp:32768-60999`, daemon-reloaded, restarted
server → still 0 packets ✗. Drop-in rolled back.
9. `strace -p <srcds_linux> -e sendto,sendmsg` while triggering
events → **zero sendto/sendmsg calls toward 127.0.0.1:28000**.
Only one unrelated TLS sendmsg (Steam) ✗.
**Verdict:** L4D2's vanilla UDP logaddress emit path is
stubbed/broken at the engine level. The cvar API and registration
paths are intact (data-structure ops); the emit path simply doesn't
make the syscalls. Logs reach the **file** and **console** sinks
(the latter is what `journalctl` captures from srcds_run's stdout)
but never the **udp** sink, despite all three being listed in the
`log` cvar status. Same family of issue as L4D2's broken SourceTV
(see `shqke/sourcetvsupport`).
**Implications for the roadmap:**
- The current listener captures nothing in production. The cfg
injection of `log on` / `logaddress_add` does no harm and is kept
for a future bridge to attach to.
- Phase 2 path A (recommended): **SourceMod bridge plugin** in
`l4d2host/`. Subscribes to L4D2 game events and calls
`LogMessage()` from inside srcds. The explicit `LogMessage()`
path is implemented separately from the autonomous engine emit
and DOES reach UDP destinations on every Source 1 game stat
trackers have used in production. This proves out the listener.
- Phase 2 path B (interim, no plugin): **parse the journal**.
`journalctl -u "left4me-server@*.service" -f` already streams
every HL-Log-Standard line as captured srcds stdout. A reducer
that follows journald + matches the `srcds_run[*]: L ...` lines
produces structured events today without any srcds-side change.
Less clean than UDP-to-listener (we'd hop through journald) but
available immediately.
- `mp_logdetail` was removed from the cfg injection: it is a
CS-only cvar (L4D2 prints `Unknown command "mp_logdetail"` at
startup).
## 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.
- **Phase 2:** pick Path A (SourceMod bridge) vs Path B (journald
follower). A is cleaner long-term; B is faster to ship.
- Once events flow somehow: design `RawLogLine` / `LogEvent` /
`MatchSession` / `Round` schema based on what we actually see.
- 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.
- `sv_logsecret` becomes relevant only once the listener is
reachable beyond loopback (currently moot).

View file

@ -55,13 +55,18 @@ 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.
# HL-Log-Standard UDP streaming registration. Investigation on 2026-05-20
# established that L4D2's vanilla logaddress UDP emit path is stubbed/broken:
# `log` cvar reports "logging to: file, console, udp" and `logaddress_list`
# shows the registration, but srcds_linux makes ZERO sendto/sendmsg calls
# toward the destination (proven by strace + tcpdump showing 0 packets).
# Local file logging works fine. So the listener currently captures nothing
# in production. The cvars are kept registered for a future SourceMod
# bridge plugin that will call LogMessage() directly — those messages DO
# flow through logaddress destinations on every Source 1 game including L4D2.
# `mp_logdetail` was removed: it is a CS-only cvar (`Unknown command` on L4D2).
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,

View file

@ -6,6 +6,17 @@ server into flat files under LOG_CAPTURE_DIR — one file per source
reducer. The goal is to observe what L4D2 actually emits on our
servers before we commit to a schema or event vocabulary.
KNOWN-DEAD AS OF 2026-05-20: L4D2's vanilla logaddress UDP emit path
is stubbed/broken at the engine level. srcds reports
"currently logging to: file, console, udp" and logaddress_list shows
our address, but strace + tcpdump confirmed srcds_linux makes ZERO
sendto/sendmsg calls toward the destination. Local file logging works
fine; only UDP broadcast is dead. This matches the broken-SourceTV
pattern in L4D2 see docs/superpowers/plans/2026-05-19-...md for the
full investigation. The listener is therefore a no-op in production
until a SourceMod bridge plugin is deployed that calls LogMessage()
directly (those messages DO flow through logaddress destinations).
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)

View file

@ -424,11 +424,12 @@ def test_build_server_spec_payload_injects_log_cvars() -> None:
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).
# 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
# mp_logdetail is CS-only; L4D2 rejects it with "Unknown command".
assert "mp_logdetail 3" not 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"
@ -442,7 +443,6 @@ def test_build_server_spec_payload_omits_log_cvars_when_addr_empty() -> None:
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)