diff --git a/CLAUDE.md b/CLAUDE.md index 50b1984..5ed5c16 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -14,6 +14,7 @@ This file provides guidance to Claude Code (claude.ai/code) when working with co - **WAF body inspection**: `python3 scripts/test-waf-body-inspection.py` - offline (runs in the image build); pins `option http-buffer-request`, the `X-WHP-WAF-Body` complete/partial stamp (strip -> stamp -> SPOE -> strip), `tune.bufsize` against the 100 ms SPOE fail-open budget and the 65535-byte SPOP frame cap, and Coraza's body limits in `coraza-spoa/config.yaml`. Run it after touching the Coraza block, `tune.bufsize`, or the SPOE engine. - **Superseded-cert retirement**: covered by the same file (`TestRetirementRules`, `TestSanOverlapRetirement`). A new bundle retires any OTHER pem/lineage sharing ANY name (CN or SAN) with it - the pem moved to `cert-retired/`, the lineage's live+archive+renewal moved TOGETHER to `/etc/letsencrypt/retired//` (leaving archive/ behind makes certbot refuse the name forever), never deleted; the bundle's own `--cert-name` lineage is `live/` exactly and is never retired - unless that cert is still the only valid one for a name this edge serves (`retirement_blockers()`). `GET /api/capabilities` advertises this to WHP, which must not use whole-site re-bundling without it. Expired pems already in the crt dir are moved to `cert-retired/` by `cert_retire_expired_pems` (never the last pem, never `default_self_signed_cert.pem`). Expired lineages are never published (`cert_is_expired` in `cert-publish-lib.sh`, `leaf_is_expired()` in Python). Fixtures: `scripts/test-fixtures/san-certs/`. - **Default splash**: `python3 scripts/test-default-splash.py` - offline (runs in the image build); unrouted hosts (server hostname, bare IP, unknown names) are answered by `http-request return ... file /haproxy/errors/default-splash.html` BEFORE the Coraza SPOE call, never for a routed host (`routed_hosts.list`/`routed_wildcards.list`, written by `generate_config()` from the routing rows and in the rollback set), never for ACME/blocked/suspended. Run it after touching the splash block, the routing ACL templates, or the domain loops in `generate_config()`. See README "Default Splash". +- **Access log receiver**: `python3 scripts/test-access-log-receiver.py` - offline (runs in the image build); one datagram = one line (PRI stripped, control chars neutralised), size cap + gzip generations, write errors drop without raising, real UNIX-socket path. Run it after touching `haproxy-log-receiver.py` or the `log` line in `hap_header.tpl`. - **Manual Testing**: Run `curl` commands against `http://localhost:8000` endpoints as shown in README.md ### Reading stick tables (and why it is easy to get silently wrong) @@ -29,8 +30,10 @@ columns; the first token is an allocation pointer (`0x...:`), not the key. Parse by NAME, and treat a missing field as an ERROR — never default it to `0`. The `web` table stores only `conn_cur`, `conn_rate`, `http_req_rate`, `http_err_rate`; it holds **no history and no counter of past blocks**. What was -actually denied/tarpitted is in the edge access log on the **host** at -`/var/log/haproxy.log` (shipped 2026.08.8), not in any stick table. +actually denied/tarpitted is in the edge access log, since 2026.11.2 INSIDE the +container at `/var/log/haproxy/access.log` (in-container receiver, volume +`haproxy-logs`; README "Access Log"), not in any stick table. (2026.08.8-2026.11.1 +sent it to host rsyslog on 172.18.0.1:514, which had no listener on the fleet.) This is written down because `/api/security/stats` and `show-tarpit-ips.sh` reported "Scan Count"/"BLOCKED" figures parsed from `gpc0`/`gpc1` — fields no diff --git a/Dockerfile b/Dockerfile index dce0ce3..f176241 100644 --- a/Dockerfile +++ b/Dockerfile @@ -106,6 +106,7 @@ RUN python3 /haproxy/scripts/test-wpadmin-gate.py \ && python3 /haproxy/scripts/test-trusted-proxy-gate.py \ && python3 /haproxy/scripts/test-xmlrpc-rate-limit.py \ && python3 /haproxy/scripts/test-default-splash.py \ + && python3 /haproxy/scripts/test-access-log-receiver.py \ && python3 /haproxy/scripts/test-config-rollback.py \ && python3 /haproxy/scripts/test-cert-write-safety.py \ && python3 /haproxy/scripts/test-cert-scripts.py \ @@ -113,7 +114,7 @@ RUN python3 /haproxy/scripts/test-wpadmin-gate.py \ && python3 /haproxy/scripts/test-gunicorn-socket-timeouts.py \ && python3 /haproxy/scripts/validate-rendered-config.py # Create log directories -RUN mkdir -p /var/log && touch /var/log/haproxy-manager.log /var/log/haproxy-manager-errors.log +RUN mkdir -p /var/log/haproxy && touch /var/log/haproxy-manager.log /var/log/haproxy-manager-errors.log RUN chmod 755 /var/log/haproxy-manager.log /var/log/haproxy-manager-errors.log # Set up cron for certificate renewal with proper permissions and environment RUN mkdir -p /var/spool/cron/crontabs && \ diff --git a/README.md b/README.md index eae6db6..1feb108 100644 --- a/README.md +++ b/README.md @@ -383,12 +383,17 @@ tail -f /var/log/haproxy-manager-errors.log ## Default Splash (unrouted hosts) -Since 2026.11.1, any request whose Host is **not routed to a site** -- the +Since 2026.11.1 (404-everywhere + robots since 2026.11.2), any request whose Host is **not routed to a site** -- the server's own hostname (registered cert-only, no backend), a bare IP, a stale or unknown name, a request with no Host at all -- is answered by HAProxy itself with the static page `errors/default-splash.html` (`http-request -return ... file`): `200` for `/`, `404` with the same page for any other -path, `cache-control: no-store`, `x-content-type-options: nosniff`. The page +return ... file`): `404` on EVERY path (including `/`) so search engines never +index the server's IP or hostname as a site, with `cache-control: no-store`, +`x-robots-tag: noindex, nofollow, noarchive` and `x-content-type-options: +nosniff`; `/robots.txt` is `200 text/plain` `User-agent: *` / `Disallow: /` +(`errors/robots-unrouted.txt`). Monitors pointed at the bare server hostname +on 80/443 must accept 404 (WHP's own probes -- healthcheck.sh, the watchdog -- +accept any status). The page names no version, echoes nothing from the request (it is loaded with `file`, not `lf-file`), and links nowhere -- in particular not to the control panel. @@ -434,7 +439,8 @@ volume, no WHP-side change. Verify after the recreate: ```bash docker exec haproxy-manager grep -c default-splash.html /etc/haproxy/haproxy.cfg # 2 docker exec haproxy-manager cat /etc/haproxy/routed_hosts.list # every site -curl -sk -o /dev/null -w '%{http_code}\n' https:/// # 200, splash +curl -skI https:/// # 404 + x-robots-tag noindex +curl -sk https:///robots.txt # User-agent: * / Disallow: / curl -sk -o /dev/null -w '%{http_code}\n' https:/// # unchanged ``` @@ -445,6 +451,47 @@ Covered by `scripts/test-default-splash.py` (template order/conditions, the page, list generation) and the `splash-off` scenario of `scripts/validate-rendered-config.py`. +## Access Log (in-container, since 2026.11.2) + +HAProxy logs (`log /log.sock ... format rfc5424`, `hap_header.tpl`) to a UNIX +datagram socket inside its chroot (`/var/lib/haproxy/log.sock`). +`scripts/haproxy-log-receiver.py`, started and supervised by `start-up.sh` (a +restart loop: back within ~2 s), writes one line per request to +`/var/log/haproxy/access.log`, rotated at 40 MB with 4 gzip generations +(worst case 200 MB; `HAPROXY_ACCESS_LOG_MAX_BYTES`, `HAPROXY_ACCESS_LOG_BACKUPS`). +No network listener anywhere. Fields: client/real IP (`cip=`), Host, status, +termination state, request id, UA, SNI, HTTP version, WAF body stamp and the +Coraza `wrule=/wrules=/wscore=` fields (unchanged `log-format`). + +* **Never blocks HAProxy.** Sends are non-blocking: a dead or stalled receiver, + or a full disk, only drops log lines (counted as `DroppedLogs` in + `echo "@1 show info" | socat stdio /tmp/haproxy-cli`). Lab: with the + receiver SIGSTOPped, 2500/2500 requests still answered 200 in ~1 s; + 1025 lines queued, 1475 dropped and counted. +* **Not in `docker logs`.** The receiver prints no log lines (WHP's AI log + monitor reads `docker logs haproxy-manager`; a per-request firehose there + would storm it). Only its start line and rate-limited errors go to stderr. +* **Persistence.** Mount a named volume at `/var/log/haproxy` (WHP: + `-v haproxy-logs:/var/log/haproxy`) or the log resets on every recreate. + Give the container `--sysctl net.unix.max_dgram_qlen=1024` (a netns starts + at 10) for burst headroom. +* `HAPROXY_SYSLOG_TARGET=:` still overrides the target for a remote + collector. The old default `172.18.0.1:514` (host rsyslog) is gone. + +Reading it: + +```bash +docker exec haproxy-manager tail -f /var/log/haproxy/access.log +docker exec haproxy-manager grep ' 403 ' /var/log/haproxy/access.log | tail +docker exec haproxy-manager sh -c 'zcat /var/log/haproxy/access.log.*.gz' | grep +docker cp haproxy-manager:/var/log/haproxy/ ./edge-logs/ # or the volume's _data dir on the host +``` + +Rollout: image bump + recreate with the volume and sysctl (WHP's +`lib-edge-container.sh` adds both). The receiver, its script and the template +are in the image, outside the `/etc/haproxy` named volume, so nothing can be +shadowed; `haproxy.cfg` is regenerated on start with the new `log` line. + ## Default Backend Configuration With the default splash on (above), unrouted hosts no longer reach this page; it still serves the blocked-IP and suspended pages, and serves unrouted hosts again when `HAPROXY_DEFAULT_SPLASH=off`. diff --git a/VERSION b/VERSION index 92848b9..b2cbf7e 100644 --- a/VERSION +++ b/VERSION @@ -1 +1 @@ -2026.11.1 +2026.11.2 diff --git a/errors/robots-unrouted.txt b/errors/robots-unrouted.txt new file mode 100644 index 0000000..1f53798 --- /dev/null +++ b/errors/robots-unrouted.txt @@ -0,0 +1,2 @@ +User-agent: * +Disallow: / diff --git a/haproxy_manager.py b/haproxy_manager.py index 88bc8bd..395c25d 100644 --- a/haproxy_manager.py +++ b/haproxy_manager.py @@ -138,6 +138,9 @@ CORAZA_SPOE_BACKUP_PATH = '/etc/haproxy/coraza-spoe.cfg.backup' # Hosts the frontend routes to a site (default splash, hap_listener.tpl). The # paths are hardcoded in the template's `-f` ACLs, like blocked_ips.map, and # written by generate_config() from the same rows as the routing ACLs. +# HAProxy's access-log target: the receiver's socket, CHROOT-RELATIVE +# (hap_header.tpl `chroot /var/lib/haproxy`), i.e. /var/lib/haproxy/log.sock. +DEFAULT_LOG_TARGET = '/log.sock' ROUTED_HOSTS_PATH = '/etc/haproxy/routed_hosts.list' ROUTED_HOSTS_BACKUP_PATH = '/etc/haproxy/routed_hosts.list.backup' ROUTED_WILDCARDS_PATH = '/etc/haproxy/routed_wildcards.list' @@ -3145,15 +3148,14 @@ def generate_config(): except Exception as e: logger.error(f"Failed to create {suspended_list_path}: {e}") - # Access-log destination for the `log` line in the global section. - # Default 172.18.0.1:514 is the docker bridge gateway for WHP's - # `client-net`, i.e. the host, where rsyslog's imudp listener is bound - # by setup-haproxy-logrotate.sh. Overridable so this image stays usable - # on standalone/home deployments with a different bridge subnet or a - # remote log collector -- set HAPROXY_SYSLOG_TARGET to `:`. - # UDP, so an absent listener drops log lines and never affects request - # handling. - syslog_target = os.environ.get('HAPROXY_SYSLOG_TARGET', '172.18.0.1:514').strip() + # Access-log destination for the `log` line in the global section: + # the in-container receiver's UNIX socket (scripts/haproxy-log-receiver.py), + # given relative to haproxy's chroot (/var/lib/haproxy) -- see + # hap_header.tpl. HAPROXY_SYSLOG_TARGET overrides it (`:` for + # a remote collector). The old default, 172.18.0.1:514 (host rsyslog on + # the docker bridge), had no listener on the fleet. + syslog_target = (os.environ.get('HAPROXY_SYSLOG_TARGET', '').strip() + or DEFAULT_LOG_TARGET) # Default splash for unrouted hosts (server hostname, bare IP, unknown # names) answered by HAProxy before the WAF -- see hap_listener.tpl. diff --git a/scripts/haproxy-log-receiver.py b/scripts/haproxy-log-receiver.py new file mode 100644 index 0000000..d41fd57 --- /dev/null +++ b/scripts/haproxy-log-receiver.py @@ -0,0 +1,264 @@ +#!/usr/bin/env python3 +"""In-container receiver for the HAProxy access log. + +HAProxy sends its access log (`log ... format rfc5424`, hap_header.tpl) +as datagrams to a UNIX socket inside this container. This process is the only +reader: it writes one line per datagram to a size-capped, rotating file in the +haproxy-logs volume (default /var/log/haproxy/access.log). + +Why it looks the way it does +---------------------------- +* UNIX DATAGRAM socket, no network listener. Nothing is exposed on the host + or on client-net (the old target was the host's rsyslog on the docker + bridge, 172.18.0.1:514, which had no listener on the fleet). +* HAProxy never waits for us. Its log sends are non-blocking: a dead receiver + (ECONNREFUSED/ENOENT) or a full socket buffer (EAGAIN) drops that line and + HAProxy carries on. So a crash, a stall or a full disk here can only lose + log lines, never slow or fail a request. That is the intended direction. +* Bounded on disk: the live file is rotated at MAX_BYTES and BACKUPS gzip + generations are kept, so the worst case (incompressible data) is + (1 + BACKUPS) * MAX_BYTES -- 5 * 40 MB = 200 MB by default. Compression runs + in a thread so a rotation does not stall reading. +* A full disk (ENOSPC) or any write error drops lines and is reported at most + once a minute; the file is reopened on the next attempt. +* Lines go to the FILE ONLY, never stdout: `docker logs haproxy-manager` is a + source of WHP's AI log monitor, and a per-request firehose there would storm + it (see the WHP note on audit/firehose sources). Our own status messages are + rare and go to stderr. +* Control characters inside a datagram are replaced so one datagram is always + exactly one line (a crafted header cannot forge extra log lines). + +Supervised by start-up.sh (restart loop), started before HAProxy. + +Environment +----------- + HAPROXY_LOG_SOCKET socket path (default /var/lib/haproxy/log.sock) + HAPROXY_ACCESS_LOG file path (default /var/log/haproxy/access.log) + HAPROXY_ACCESS_LOG_MAX_BYTES rotate size (default 41943040 = 40 MiB) + HAPROXY_ACCESS_LOG_BACKUPS gzip generations kept (default 4) +""" + +import gzip +import os +import shutil +import socket +import sys +import threading +import time + +# HAProxy sends at most `len` (2048) bytes per line; leave headroom. +MAX_DATAGRAM = 65535 +FLUSH_INTERVAL = 1.0 +ERROR_REPORT_INTERVAL = 60.0 +# Kernel receive buffer to absorb bursts while a write is slow. +RCVBUF = 4 * 1024 * 1024 + +_CTRL = {c: ' ' for c in range(0x20) if c != 0x09} +_CTRL[0x7f] = ' ' + + +def _env_int(name, default, minimum): + try: + value = int(os.environ.get(name, default)) + except ValueError: + value = default + return max(minimum, value) + + +def clean_line(datagram): + """One datagram -> one log line (str, no trailing newline). + + Drops the RFC 5424 `` prefix (constant for our single facility) and + replaces any control character so the datagram cannot span lines. + """ + text = datagram.decode('utf-8', 'replace').rstrip('\r\n\x00') + if text.startswith('<'): + end = text.find('>', 1, 6) + if end > 0 and text[1:end].isdigit(): + text = text[end + 1:] + return text.translate(_CTRL) + + +class RotatingWriter: + """Size-capped writer: live file + `backups` gzip generations.""" + + def __init__(self, path, max_bytes, backups, report=None): + self.path = path + self.max_bytes = max_bytes + self.backups = backups + self.report = report or (lambda msg: None) + self.fh = None + self.size = 0 + self.dirty = False + self.dropped = 0 + self._compressor = None + self._last_error = 0.0 + + # -- file handling -------------------------------------------------- + def _open(self): + os.makedirs(os.path.dirname(self.path) or '.', exist_ok=True) + self.fh = open(self.path, 'a', encoding='utf-8', buffering=65536) + os.chmod(self.path, 0o640) + self.size = self.fh.tell() + + def _error(self, what, exc): + self.dropped += 1 + try: + if self.fh: + self.fh.close() + except OSError: + pass + self.fh = None + now = time.monotonic() + if now - self._last_error >= ERROR_REPORT_INTERVAL: + self._last_error = now + self.report(f'{what} failed ({exc}); dropping access-log lines ' + f'(dropped so far: {self.dropped})') + + def _gen(self, n): + return f'{self.path}.{n}.gz' + + def _compress(self, src, dst): + tmp = dst + '.tmp' + try: + with open(src, 'rb') as fin, gzip.open(tmp, 'wb', compresslevel=6) as fout: + shutil.copyfileobj(fin, fout, 1024 * 1024) + os.replace(tmp, dst) + os.chmod(dst, 0o640) + except OSError as exc: + self.report(f'compressing {src} failed ({exc}); removing it to keep the size cap') + for leftover in (tmp,): + try: + os.unlink(leftover) + except OSError: + pass + finally: + try: + os.unlink(src) + except OSError: + pass + + def rotate(self): + if self._compressor is not None: + self._compressor.join() + self._compressor = None + if self.fh: + try: + self.fh.close() + except OSError: + pass + self.fh = None + if self.backups <= 0: + try: + os.unlink(self.path) + except OSError: + pass + else: + try: + os.unlink(self._gen(self.backups)) + except OSError: + pass + for n in range(self.backups - 1, 0, -1): + if os.path.exists(self._gen(n)): + os.replace(self._gen(n), self._gen(n + 1)) + staged = f'{self.path}.1' + if os.path.exists(self.path): + os.replace(self.path, staged) + self._compressor = threading.Thread( + target=self._compress, args=(staged, self._gen(1)), daemon=True) + self._compressor.start() + self.size = 0 + + # -- public --------------------------------------------------------- + def write(self, line): + data = line + '\n' + try: + if self.fh is None: + self._open() + if self.size and self.size + len(data) > self.max_bytes: + self.rotate() + self._open() + self.fh.write(data) + self.size += len(data.encode('utf-8')) + self.dirty = True + except OSError as exc: + self._error('writing ' + self.path, exc) + + def flush(self): + if self.fh and self.dirty: + try: + self.fh.flush() + self.dirty = False + except OSError as exc: + self._error('flushing ' + self.path, exc) + + def close(self): + self.flush() + if self._compressor is not None: + self._compressor.join() + if self.fh: + try: + self.fh.close() + except OSError: + pass + + +def bind_socket(path): + sock = socket.socket(socket.AF_UNIX, socket.SOCK_DGRAM) + try: + sock.setsockopt(socket.SOL_SOCKET, socket.SO_RCVBUF, RCVBUF) + except OSError: + pass + os.makedirs(os.path.dirname(path) or '.', exist_ok=True) + try: + os.unlink(path) # stale socket from a previous (crashed) receiver + except FileNotFoundError: + pass + sock.bind(path) + # HAProxy's workers run as user haproxy (hap_header.tpl `user haproxy`). + os.chmod(path, 0o666) + sock.settimeout(FLUSH_INTERVAL) + return sock + + +def serve(sock, writer, stop=None): + last_flush = time.monotonic() + while stop is None or not stop.is_set(): + try: + datagram = sock.recv(MAX_DATAGRAM) + except socket.timeout: + datagram = None + except OSError: + if stop is not None and stop.is_set(): + break + raise + if datagram: + writer.write(clean_line(datagram)) + now = time.monotonic() + if now - last_flush >= FLUSH_INTERVAL: + writer.flush() + last_flush = now + + +def main(): + sock_path = os.environ.get('HAPROXY_LOG_SOCKET', '/var/lib/haproxy/log.sock') + log_path = os.environ.get('HAPROXY_ACCESS_LOG', '/var/log/haproxy/access.log') + max_bytes = _env_int('HAPROXY_ACCESS_LOG_MAX_BYTES', 40 * 1024 * 1024, 64 * 1024) + backups = _env_int('HAPROXY_ACCESS_LOG_BACKUPS', 4, 0) + + def report(msg): + sys.stderr.write(f'haproxy-log-receiver: {msg}\n') + sys.stderr.flush() + + writer = RotatingWriter(log_path, max_bytes, backups, report) + sock = bind_socket(sock_path) + report(f'listening on {sock_path} -> {log_path} ' + f'(rotate at {max_bytes} bytes, keep {backups} gz)') + try: + serve(sock, writer) + finally: + writer.close() + + +if __name__ == '__main__': + main() diff --git a/scripts/monitor-attacks.sh b/scripts/monitor-attacks.sh index 329264a..15f42d7 100755 --- a/scripts/monitor-attacks.sh +++ b/scripts/monitor-attacks.sh @@ -20,13 +20,13 @@ # against. # # Usage: monitor-attacks.sh [live] -# Env: LOG_FILE= access log to read (default /var/log/haproxy.log) +# Env: LOG_FILE= access log to read (default /var/log/haproxy/access.log) # LOG_LINES= how many trailing log lines to scan (default 500) set -uo pipefail SCRIPT_DIR="$(cd -- "$(dirname -- "${BASH_SOURCE[0]}")" && pwd)" -LOG_FILE="${LOG_FILE:-/var/log/haproxy.log}" +LOG_FILE="${LOG_FILE:-/var/log/haproxy/access.log}" LOG_LINES="${LOG_LINES:-500}" # --- Section 1: current rates (real stick-table data) ----------------------- @@ -47,12 +47,12 @@ show_recent_blocks() { syslog on the DOCKER HOST, and the file lives on the host, not in here. Read it from the host instead: - grep -aE ' (PT|PR)--' /var/log/haproxy.log | tail -20 # tarpit / deny - grep -aE ' (429|403) ' /var/log/haproxy.log | tail -20 # rate-limited / blocked - grep -a 'cip=' /var/log/haproxy.log | tail -50 # one client IP - grep -a 'id=' /var/log/haproxy.log # one request reference + grep -aE ' (PT|PR)--' /var/log/haproxy/access.log | tail -20 # tarpit / deny + grep -aE ' (429|403) ' /var/log/haproxy/access.log | tail -20 # rate-limited / blocked + grep -a 'cip=' /var/log/haproxy/access.log | tail -50 # one client IP + grep -a 'id=' /var/log/haproxy/access.log # one request reference # (the UUID on the block page) - tail -f /var/log/haproxy.log | grep -aE ' (PT|PR)--' # live + tail -f /var/log/haproxy/access.log | grep -aE ' (PT|PR)--' # live Or point this script at a copy: LOG_FILE=/path/to/haproxy.log $0 MSG diff --git a/scripts/show-tarpit-ips.sh b/scripts/show-tarpit-ips.sh index 6b22be9..f3cca1f 100755 --- a/scripts/show-tarpit-ips.sh +++ b/scripts/show-tarpit-ips.sh @@ -12,9 +12,9 @@ # # The stick table also keeps NO history, so nothing in it can identify who was # tarpitted. Real enforcement events live in the access log ON THE DOCKER HOST -# at /var/log/haproxy.log (it does not exist inside this container): -# grep -aE ' (PT|PR)--' /var/log/haproxy.log | tail -20 # tarpit / deny -# grep -aE ' (429|403) ' /var/log/haproxy.log | tail -20 # rate-limit / block +# at /var/log/haproxy/access.log (inside this container since 2026.11.2): +# grep -aE ' (PT|PR)--' /var/log/haproxy/access.log | tail -20 # tarpit / deny +# grep -aE ' (429|403) ' /var/log/haproxy/access.log | tail -20 # rate-limit / block # # What IS knowable from the stick table — the current per-IP rates — is printed # by show-edge-ip-rates.sh, which this shim now runs. @@ -25,8 +25,8 @@ cat >&2 <<'NOTE' NOTE: show-tarpit-ips.sh is deprecated and cannot report tarpits. The HAProxy stick table stores no history and no gpc0/gpc1 counters, so the old "Scan Count"/"BLOCKED" columns were fabricated numbers. - Actual tarpit/deny events are in /var/log/haproxy.log ON THE HOST: - grep -aE ' (PT|PR)--' /var/log/haproxy.log | tail -20 + Actual tarpit/deny events are in /var/log/haproxy/access.log (in this container since 2026.11.2): + grep -aE ' (PT|PR)--' /var/log/haproxy/access.log | tail -20 Running show-edge-ip-rates.sh instead (current rates, real values): NOTE diff --git a/scripts/start-up.sh b/scripts/start-up.sh index 170dd26..ba0c403 100755 --- a/scripts/start-up.sh +++ b/scripts/start-up.sh @@ -55,6 +55,24 @@ if [ ! -f /etc/haproxy/wpadmin_gate_exempt.list ]; then fi fi +# HAProxy access log receiver (see scripts/haproxy-log-receiver.py and the +# `log` line in hap_header.tpl). HAProxy sends datagrams to a UNIX socket +# inside its chroot; this process writes them to a size-capped, rotating +# /var/log/haproxy/access.log (WHP mounts the haproxy-logs volume there). +# Started BEFORE init.py so haproxy's first lines land. Supervised by a +# restart loop: if it dies it is back within 2s, and while it is down HAProxy +# just drops log lines (non-blocking sends), it never blocks on them. +# stdout is discarded on purpose -- it never prints log lines, and +# `docker logs` must not carry a per-request firehose (WHP's AI monitor reads +# it); its rare status/error lines go to stderr. +mkdir -p /var/log/haproxy /var/lib/haproxy +( + while true; do + python /haproxy/scripts/haproxy-log-receiver.py >/dev/null || true + sleep 2 + done +) & + cron & # Phase 1: container init diff --git a/scripts/test-access-log-receiver.py b/scripts/test-access-log-receiver.py new file mode 100644 index 0000000..7afd850 --- /dev/null +++ b/scripts/test-access-log-receiver.py @@ -0,0 +1,178 @@ +#!/usr/bin/env python3 +"""Tests for scripts/haproxy-log-receiver.py (in-container access log). + +Pins: one datagram == one line (PRI stripped, control chars neutralised), +the size cap (live file + N gzip generations, oldest dropped), a write error +(full disk / unwritable dir) drops lines without raising, and an end-to-end +datagram path through a real UNIX socket. + +Running +------- + python3 scripts/test-access-log-receiver.py +""" + +import gzip +import importlib.util +import os +import shutil +import socket +import tempfile +import threading +import time +import unittest + +HERE = os.path.dirname(os.path.abspath(__file__)) +_spec = importlib.util.spec_from_file_location( + 'haproxy_log_receiver', os.path.join(HERE, 'haproxy-log-receiver.py')) +rx = importlib.util.module_from_spec(_spec) +_spec.loader.exec_module(rx) + + +class CleanLine(unittest.TestCase): + + def test_strips_pri_and_trailing_newline(self): + self.assertEqual(rx.clean_line(b'<150>1 2026-11-08T00:00:00Z h haproxy 7 - - GET /\n'), + '1 2026-11-08T00:00:00Z h haproxy 7 - - GET /') + + def test_embedded_newlines_cannot_forge_lines(self): + out = rx.clean_line(b'<150>1 x ua=evil\r\nFAKE 200 line\x1b[2J') + self.assertNotIn('\n', out) + self.assertNotIn('\r', out) + self.assertNotIn('\x1b', out) + self.assertIn('FAKE 200 line', out) + + def test_invalid_utf8_does_not_raise(self): + self.assertIn('�', rx.clean_line(b'<150>1 \xff\xfe')) + + def test_non_pri_angle_bracket_kept(self): + self.assertEqual(rx.clean_line(b' x'), ' x') + + +class Rotation(unittest.TestCase): + + def setUp(self): + self.dir = tempfile.mkdtemp(prefix='hlr-test-') + self.path = os.path.join(self.dir, 'access.log') + + def tearDown(self): + shutil.rmtree(self.dir, ignore_errors=True) + + def _files(self): + return sorted(os.listdir(self.dir)) + + def test_size_cap_and_generations(self): + max_bytes, backups = 4096, 3 + w = rx.RotatingWriter(self.path, max_bytes, backups) + line = 'x' * 99 # 100 bytes with newline + for i in range(1000): # ~100 KB -> ~24 rotations + w.write(f'{i:05d}' + line[5:]) + w.close() + files = self._files() + self.assertEqual(files, ['access.log', 'access.log.1.gz', + 'access.log.2.gz', 'access.log.3.gz'], files) + self.assertLessEqual(os.path.getsize(self.path), max_bytes) + total = sum(os.path.getsize(os.path.join(self.dir, f)) for f in files) + self.assertLessEqual(total, (1 + backups) * max_bytes) + # newest generation holds the lines written just before the live file + with gzip.open(os.path.join(self.dir, 'access.log.1.gz'), 'rt') as fh: + gen1 = fh.read().splitlines() + with open(self.path) as fh: + live = fh.read().splitlines() + self.assertEqual(int(gen1[-1][:5]) + 1, int(live[0][:5])) + self.assertEqual(live[-1][:5], '00999') + for l in gen1: + self.assertEqual(len(l), 99) + + def test_zero_backups_keeps_only_live_file(self): + w = rx.RotatingWriter(self.path, 1024, 0) + for _ in range(100): + w.write('y' * 63) + w.close() + self.assertEqual(self._files(), ['access.log']) + self.assertLessEqual(os.path.getsize(self.path), 1024) + + def test_reopens_existing_file_and_counts_its_size(self): + with open(self.path, 'w') as fh: + fh.write('z' * 1000 + '\n') + w = rx.RotatingWriter(self.path, 1500, 2) + w.write('a' * 600) # 1001 + 601 > 1500 -> rotate first + w.close() + self.assertIn('access.log.1.gz', self._files()) + with open(self.path) as fh: + self.assertEqual(fh.read(), 'a' * 600 + '\n') + + def test_write_error_drops_and_never_raises(self): + blocker = os.path.join(self.dir, 'not-a-dir') + with open(blocker, 'w') as fh: + fh.write('') + msgs = [] + w = rx.RotatingWriter(os.path.join(blocker, 'access.log'), 4096, 2, msgs.append) + for _ in range(50): + w.write('line') + w.flush() + w.close() + self.assertEqual(w.dropped, 50) + self.assertEqual(len(msgs), 1, msgs) # rate-limited report + + +class EndToEnd(unittest.TestCase): + + def test_datagrams_become_lines(self): + d = tempfile.mkdtemp(prefix='hlr-e2e-') + try: + sock_path = os.path.join(d, 'log.sock') + log_path = os.path.join(d, 'logs', 'access.log') + sock = rx.bind_socket(sock_path) + self.assertEqual(os.stat(sock_path).st_mode & 0o777, 0o666) + w = rx.RotatingWriter(log_path, 1 << 20, 2) + stop = threading.Event() + t = threading.Thread(target=rx.serve, args=(sock, w, stop), daemon=True) + t.start() + cl = socket.socket(socket.AF_UNIX, socket.SOCK_DGRAM) + cl.setblocking(False) + for i in range(20): + msg = f'<150>1 t h haproxy 1 - - req {i} host=a.example cip=192.0.2.1'.encode() + # The default net.unix.max_dgram_qlen is 10 per netns: a full + # queue is EAGAIN (HAProxy drops the line); here, retry. + for _ in range(100): + try: + cl.sendto(msg, sock_path) + break + except BlockingIOError: + time.sleep(0.01) + deadline = time.time() + 5 + lines = [] + while time.time() < deadline: + time.sleep(0.2) + w.flush() + if os.path.exists(log_path): + with open(log_path) as fh: + lines = fh.read().splitlines() + if len(lines) == 20: + break + stop.set() + t.join(3) + sock.close() + w.close() + self.assertEqual(len(lines), 20, lines) + self.assertTrue(lines[0].startswith('1 t h haproxy 1 - - req 0 host=a.example')) + finally: + shutil.rmtree(d, ignore_errors=True) + + def test_sender_to_dead_receiver_fails_fast_nonblocking(self): + """What HAProxy sees when the receiver is down: an immediate error, + never a block (HAProxy then just counts a dropped log line).""" + d = tempfile.mkdtemp(prefix='hlr-dead-') + try: + cl = socket.socket(socket.AF_UNIX, socket.SOCK_DGRAM) + cl.setblocking(False) + start = time.monotonic() + with self.assertRaises(OSError): + cl.sendto(b'x', os.path.join(d, 'log.sock')) + self.assertLess(time.monotonic() - start, 0.5) + finally: + shutil.rmtree(d, ignore_errors=True) + + +if __name__ == '__main__': + unittest.main(verbosity=2) diff --git a/scripts/test-default-splash.py b/scripts/test-default-splash.py index 8716282..03367d8 100644 --- a/scripts/test-default-splash.py +++ b/scripts/test-default-splash.py @@ -67,7 +67,7 @@ def render_listener(**kw): def return_rules(cfg): return [l.strip() for l in cfg.splitlines() if l.strip().startswith('http-request return') - and 'default-splash.html' in l] + and ('default-splash.html' in l or 'robots-unrouted.txt' in l)] class Template(unittest.TestCase): @@ -77,19 +77,32 @@ class Template(unittest.TestCase): self.assertNotIn('default-splash', cfg) self.assertNotIn('splash_routed_host', cfg) - def test_two_return_rules_root_200_other_404(self): + def test_404_everywhere_robots_txt_200(self): + """Josh 2026-11-08: unrouted hosts are 404 on EVERY path (incl. "/") + so search engines never index the server IP/hostname; /robots.txt is + the one 200 and disallows everything.""" rules = return_rules(render_listener()) self.assertEqual(len(rules), 2, rules) - self.assertTrue(rules[0].startswith('http-request return status 200 ')) - self.assertTrue(rules[0].endswith(' splash_root')) - self.assertTrue(rules[1].startswith('http-request return status 404 ')) - self.assertTrue(rules[1].endswith(' !splash_root')) + robots, splash = rules + self.assertTrue(robots.startswith('http-request return status 200 content-type "text/plain')) + self.assertIn(' file /haproxy/errors/robots-unrouted.txt ', robots) + self.assertTrue(robots.endswith(' splash_robots')) + self.assertTrue(splash.startswith('http-request return status 404 content-type "text/html')) + self.assertTrue(splash.endswith(' !splash_robots')) + self.assertNotIn('splash_root', render_listener()) + self.assertRegex(render_listener(), r'acl splash_robots path /robots\.txt\n') + + def test_noindex_and_no_store_headers_on_both(self): + for rule in return_rules(render_listener()): + self.assertIn('hdr x-robots-tag "noindex, nofollow, noarchive"', rule) + self.assertIn('hdr cache-control "no-store"', rule) + self.assertIn('hdr x-content-type-options "nosniff"', rule) def test_static_file_not_lf_file(self): """`file` (verbatim), never `lf-file`: nothing from the request may be expanded into the page (Host echo, unique-id, ...).""" for rule in return_rules(render_listener()): - self.assertIn(' file /haproxy/errors/default-splash.html ', rule) + self.assertRegex(rule, r' file /haproxy/errors/(default-splash\.html|robots-unrouted\.txt) ') self.assertNotIn('lf-file', rule) def test_conditions_keep_acme_blocked_and_suspended_out(self): @@ -118,7 +131,7 @@ class Template(unittest.TestCase): def test_splash_runs_before_waf_and_after_ip_block_and_suspension(self): for susp in (False, True): cfg = render_listener(suspension_enabled=susp) - first_return = cfg.index('file /haproxy/errors/default-splash.html') + first_return = cfg.index('file /haproxy/errors/robots-unrouted.txt') self.assertLess(first_return, cfg.index('http-request send-spoe-group coraza')) self.assertLess(first_return, cfg.index('filter spoe engine coraza')) self.assertGreater(first_return, cfg.index('acl is_blocked_ip')) @@ -150,6 +163,13 @@ class Page(unittest.TestCase): self.assertNotIn('%[', self.text) +class Robots(unittest.TestCase): + + def test_robots_disallows_everything(self): + with open(os.path.join(MODULE_DIR, 'errors', 'robots-unrouted.txt')) as fh: + self.assertEqual(fh.read(), 'User-agent: *\nDisallow: /\n') + + class RoutedLists(unittest.TestCase): def test_render_sorted_dedup_lower(self): @@ -248,6 +268,29 @@ class GenerateConfigWritesLists(unittest.TestCase): self.assertIn(base.lower(), self._lines(hm.ROUTED_WILDCARDS_PATH)) self.assertIn('default-splash.html', cfg) + def test_default_log_target_is_the_in_container_socket(self): + """Access log goes to the receiver's UNIX socket (chroot-relative), + never the old host bridge target 172.18.0.1:514.""" + os.environ.pop('HAPROXY_SYSLOG_TARGET', None) + hm.generate_config() + with open(hm.HAPROXY_CONFIG_PATH) as fh: + cfg = fh.read() + self.assertRegex(cfg, r'\n log /log\.sock len 2048 format rfc5424 local2 info\n') + self.assertIn('chroot /var/lib/haproxy', cfg) + log_lines = [l for l in cfg.splitlines() if l.strip().startswith('log ') + and 'global' not in l] + self.assertEqual(len(log_lines), 1, log_lines) + self.assertNotIn('172.18.0.1', log_lines[0]) + + def test_log_target_env_override(self): + os.environ['HAPROXY_SYSLOG_TARGET'] = '192.0.2.5:514' + try: + hm.generate_config() + finally: + os.environ.pop('HAPROXY_SYSLOG_TARGET', None) + with open(hm.HAPROXY_CONFIG_PATH) as fh: + self.assertIn('log 192.0.2.5:514 len 2048', fh.read()) + def test_lists_written_even_with_splash_off(self): os.environ['HAPROXY_DEFAULT_SPLASH'] = 'off' hm.generate_config() diff --git a/scripts/validate-rendered-config.py b/scripts/validate-rendered-config.py index 6a400c0..33658a3 100644 --- a/scripts/validate-rendered-config.py +++ b/scripts/validate-rendered-config.py @@ -130,6 +130,7 @@ STUB_FILES = { '/haproxy/errors/403-waf.html': 'blocked %[unique-id]\n', # `file` on the default-splash return rules; loaded at parse time too. '/haproxy/errors/default-splash.html': 'splash\n', + '/haproxy/errors/robots-unrouted.txt': 'User-agent: *\nDisallow: /\n', } # (suspension_enabled, coraza_spoe_backend) combinations to render + validate. diff --git a/templates/hap_header.tpl b/templates/hap_header.tpl index 31513ae..f4fef85 100644 --- a/templates/hap_header.tpl +++ b/templates/hap_header.tpl @@ -2,42 +2,33 @@ # Global settings #--------------------------------------------------------------------- global - # ACCESS LOG DESTINATION. + # ACCESS LOG DESTINATION: a UNIX datagram socket INSIDE this container. # - # This used to be `log 127.0.0.1 local2`, which was a silent black hole: - # 127.0.0.1 is the CONTAINER's own loopback, nothing has ever listened on - # udp/514 in the container netns, and there is no /dev/log in the image. - # Every access log line -- ~1.5M/day across the whole edge -- was written - # to a socket with no receiver and dropped. Nothing errored, nothing - # warned, and `haproxy -c` was perfectly happy. The cost only shows up - # during an incident: per-IP 429s, tarpits, wp-admin gate redirects, - # WAF 403s and `silent-drop`s left no record anywhere, so the edge could - # not be asked what it had rejected. Only aggregate stick-table counters - # survived. + # scripts/haproxy-log-receiver.py (supervised by start-up.sh) reads it and + # writes a size-capped, rotating /var/log/haproxy/access.log in the + # haproxy-logs volume. No network listener anywhere. # - # Now points at the DOCKER BRIDGE GATEWAY, where the host's rsyslog has an - # imudp listener bound (installed idempotently by WHP's - # setup-haproxy-logrotate.sh, which also writes the logrotate stanza). - # The host writes local2 to /var/log/haproxy.log and stops it there, so it - # does not also flood /var/log/messages or the Graylog forwarder. + # History: `log 127.0.0.1 local2` was a black hole (nothing listened in + # the container netns); its successor, the docker bridge gateway + # 172.18.0.1:514 with a host rsyslog imudp listener, had no listener on + # the fleet either (probable cause, not measured: rsyslog binds that + # address once at boot, before docker has created the bridge, and does + # not retry). Either way per-IP + # 429s, tarpits, gate redirects and WAF 403s left no record. # - # WHY NOT `log stdout format raw local0`: it is INCOMPATIBLE with the - # `daemon` keyword below, and incompatible SILENTLY. Verified on the - # pinned 3.0.11 binary: with `daemon` set, a `log stdout` config serves - # traffic normally and emits ZERO log lines, and `haproxy -c` returns 0 - # with no error and no warning -- so the CI config gate - # (scripts/validate-rendered-config.py) cannot catch it either. Making it - # work means dropping `daemon` / adding -db so haproxy stays in the - # foreground, which in turn breaks the three synchronous - # `subprocess.run(['haproxy', '-W', ...], check=True)` launch sites in - # haproxy_manager.py (they would block until the 180s timeout and then be - # killed). That is a change to the exact code path whose failure mode is - # "container Up, ports 80/443 never bound, every site down, /health still - # 200". Not worth it for a logging change. + # WHY NOT `log stdout`: silently emits NOTHING with `daemon` (below) on + # the pinned 3.0.11 (`haproxy -c` still passes), and dropping `daemon` + # breaks the synchronous `haproxy -W` launch sites in haproxy_manager.py. + # Also, `docker logs haproxy-manager` feeds WHP's AI log monitor, which + # must not get a per-request firehose. # - # UDP means a dead listener degrades to dropped log lines, never to a - # stalled or failing request path -- the correct failure direction for an - # edge fronting ~60 customer sites. + # The path is relative to the `chroot` below: HAProxy resolves it after + # chrooting, so `/log.sock` here is /var/lib/haproxy/log.sock on disk, + # which is where the receiver binds (HAPROXY_LOG_SOCKET). + # + # Sends are non-blocking: a dead receiver or a full socket buffer drops + # log lines, never stalls a request. HAPROXY_SYSLOG_TARGET still + # overrides the target (`:` for a remote collector). # # len 2048 accommodates the enriched log-format in hap_listener.tpl # (URL + User-Agent + UUID); the default 1024 would truncate long ones. diff --git a/templates/hap_listener.tpl b/templates/hap_listener.tpl index 34ad209..ccd850a 100644 --- a/templates/hap_listener.tpl +++ b/templates/hap_listener.tpl @@ -646,15 +646,16 @@ frontend web # Kept OUT of the splash: ACME http-01 (the server hostname's own cert is # issued through it), blocked IPs (blocked-ip page) and suspended hosts # (suspended page). Rate limits, the IP block and the wp-* gates above - # still apply. "/" is 200 (monitors and humans), any other path 404 with - # the same page (what the old default page did for unknown paths). + # still apply. EVERY path is 404 with the same page, plus + # X-Robots-Tag noindex and /robots.txt "Disallow: /", so search engines + # never index the server's IP or hostname as a site. # Disable with HAPROXY_DEFAULT_SPLASH=off (back to default-backend). acl splash_routed_host req.hdr(host),field(1,:),lower -f /etc/haproxy/routed_hosts.list acl splash_routed_host req.hdr(host),field(1,:),lower -m end -f /etc/haproxy/routed_wildcards.list acl splash_acme path_beg /.well-known/acme-challenge/ - acl splash_root path / - http-request return status 200 content-type "text/html; charset=utf-8" hdr cache-control "no-store" hdr x-content-type-options "nosniff" file /haproxy/errors/default-splash.html if !splash_routed_host !splash_acme !is_blocked_ip{% if suspension_enabled %} !is_suspended_domain{% endif %} splash_root - http-request return status 404 content-type "text/html; charset=utf-8" hdr cache-control "no-store" hdr x-content-type-options "nosniff" file /haproxy/errors/default-splash.html if !splash_routed_host !splash_acme !is_blocked_ip{% if suspension_enabled %} !is_suspended_domain{% endif %} !splash_root + acl splash_robots path /robots.txt + http-request return status 200 content-type "text/plain; charset=utf-8" hdr cache-control "no-store" hdr x-robots-tag "noindex, nofollow, noarchive" hdr x-content-type-options "nosniff" file /haproxy/errors/robots-unrouted.txt if !splash_routed_host !splash_acme !is_blocked_ip{% if suspension_enabled %} !is_suspended_domain{% endif %} splash_robots + http-request return status 404 content-type "text/html; charset=utf-8" hdr cache-control "no-store" hdr x-robots-tag "noindex, nofollow, noarchive" hdr x-content-type-options "nosniff" file /haproxy/errors/default-splash.html if !splash_routed_host !splash_acme !is_blocked_ip{% if suspension_enabled %} !is_suspended_domain{% endif %} !splash_robots {%- endif %} # CVE-2026-109618 (GHSA-w8hw-w9fx-j79w, PHP "RCE via OOM corruption"),