Files
Media-Server-Setup/LOGGING.md
Brandyn / Techy cea02d2ee8 Phase 13 integration: install.sh, configure.py, and a deadman that degrades cleanly
install.sh: the three data dirs with correct owners (uid 1000 for the VictoriaMetrics pair, 65534 for
alertmanager), /var/lib/vanguard, the deadman script and timer, and /etc/vanguard/alert-webhook as a FILE —
compose bind-mounts it, so without it Docker creates a directory and alertmanager will not start.

configure.py: --full now asks for the alert webhook and stores it; --show says plainly when none is set; the
webhook lands at 0640 root:65534 rather than world-readable, since it is a credential for that channel.

The deadman no longer assumes a webhook. It trims and validates the file (the previous -s test passed on the
newline configure.py writes), skips delivery when there is none, still logs every finding, and exits non-zero
only when it found something it could not report — so the unit state is the signal. Verified for a missing
file, a newline-only file, a junk value, and the healthy case.

check.sh validates all five observability configs; confirmed it catches a deliberate break.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
2026-11-03 15:56:49 -06:00

122 lines
8.5 KiB
Markdown
Raw Blame History

This file contains ambiguous Unicode characters

This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

# Logging framework
Decided 2026-11-01, and the store chosen on 2026-11-03: **VictoriaLogs**, on the `diag.BASE` host with its UI
at `/logs` (Phase 14 in `CommunityDiscordMedia.md`). Everything upstream of the store was fixed first, so
adopting it is a collector config rather than a code change.
## Where the lines come from (the only two taps a collector needs)
| Tap | Holds | Read with |
|---|---|---|
| **journald** | our systemd units: `dumpd`, `normalize-sweep`, `trash-purge`, `deploy-pending`, `vgdeband` (transient), `deploy.sh` output | `journalctl -u <unit>`; collectors: Alloy `loki.source.journal`, Vector `journald`, VictoriaLogs journald ingestion, Netdata's journal plugin |
| **Docker json-file logs** | every container (`docker-compose.yml`), rotated 5 × 50 MB each | `docker logs <name>`; collectors read `/var/lib/docker/containers/*/*-json.log` and get the container **labels** below for free |
Every collector on the shortlist reads both. Metrics are the same story: see the taps table below — all four endpoints are on now, on loopback.
## Metrics taps (all Prometheus text format, loopback only — scrape them with Alloy, vmagent or Netdata)
| endpoint | what | from |
|---|---|---|
| `http://127.0.0.1:9100/metrics` | host: CPU, RAM, disk space + I/O, network, load, md RAID | node_exporter (host network, pid host) |
| `http://127.0.0.1:9101/metrics` | per container: CPU, memory, network, block I/O — labelled with `vanguard.service` / `vanguard.category` | cAdvisor |
| `http://127.0.0.1:9998/metrics` | MediaMTX: per path bytes/s, readers, publishers, WebRTC/HLS/RTMP sessions, dropped packets | MediaMTX `metrics: yes` |
| `http://127.0.0.1:2019/metrics` | Caddy: requests by host/status, durations, TLS | Caddy admin API (`servers { metrics }`) |
None of these are reachable from outside (loopback binds; nothing in the firewall). Nothing evaluates them yet:
metric alerting needs VictoriaMetrics scraping them plus vmalert, and log alerting needs vmalert against
VictoriaLogs' stats endpoints with Alertmanager for delivery (Phase 14). Thresholds to start with: disk on
`/srv` > 85 %, load > cores for 15 min, a container restarting, MediaMTX dropped packets rising on a live path.
## Container labels (set in `docker-compose.yml`, `x-logging` anchor + `labels:`)
`vanguard.service` = the service name, `vanguard.category` = one of the categories below. A collector turns these
into stream labels without parsing a single line.
## Categories = the questions people ask
| category | services / components | correlation key |
|---|---|---|
| `stream` | mediamtx (path ready/closed, recorder, WebRTC sessions, the on-ready hook's `event=mirror`), dumpd `publish_allow` / `publish_deny`, sweep `event=published` | `stream` = `user/Title` |
| `auth` | caddy access logs (status, `X-Authentik-Username`), authentik-server/worker events, gitea OIDC | `user` |
| `media` | sweep verdicts / timecode / deband / failed, vgdeband, jellyfin, copyparty | `file` |
| `intake` | syncthing (`folder.id`), dumpd `clips_setup`, `quota_*` | `folder` = `clips-<user>` |
| `infra` | mariadb, caddy TLS/ACME, container restarts, disk | host only |
| `deploy` | deploy.sh, dumpd `deploy_*`, `bot_deploy_*` and `bot_env_*` (the bot's CI posting a release bundle and its settings), act_runner | `rev` |
| `code`, `bot` | gitea, discord-bot | — |
## Labels vs fields
- **Labels** (low cardinality, what you filter by): `service`, `category`, `level`, `unit`. A dozen values each.
- **Fields** (parsed at query time, what you search in): `stream`, `user`, `file`, `folder`, `session`, `status`, `ip`, `event`.
Thousands of values — fine as fields, ruinous as labels (Loki). VictoriaLogs indexes every word anyway.
## Our own line format: logfmt, one event per line
ts=2026-11-01T19:52:14-06:00 level=info component=sweep event=published stream="techy2493/Vanguard_Training" file="/srv/media/streams/…" verdict=encode
- `ts` ISO-8601 with offset · `level` info|warn|error · `component` dumpd|sweep|vgdeband|deploy|on-ready · `event` a verb/noun in snake_case · then `key=value`, values with spaces or quotes double-quoted.
- Same key means the same thing everywhere: `stream` (user/Title), `user`, `file`, `folder`, `rev`, `ip`, `reason`.
- Implemented by: `log()` in `bin/dumpd.py`, `vglog` in `bin/normalize-sweep.sh` and `bin/vgdeband.sh`, `log()` in `deploy.sh` (`msg=` only), `bin/mtx-on-ready.sh` (MediaMTX prefixes its own path/time).
Events today: dumpd `publish_allow publish_deny dump clips_setup quota_paused quota_resumed quota_* deploy_* bot_deploy_start bot_deploy_exit bot_deploy_bad_signature bot_deploy_refused bot_env_applied bot_env_failed`;
sweep `verdict timecode deband fill_gaps published done failed skip`; vgdeband `deband done failed skip`; hook `mirror`.
A future alert script watches `level=error`, `event=failed`, `event=publish_deny` bursts, `event=quota_paused`, plus disk.
## Third-party formats a collector must parse
| source | format | stage |
|---|---|---|
| caddy | JSON (`logger`, `level`, `msg`; access logs: `request.*`, `status`, `request.headers.X-Authentik-Username`) | json |
| authentik | JSON (`event`, `user`, `action`) | json |
| syncthing | key=value after a `date time:` prefix (`folder.id=… log.pkg=model`) | logfmt |
| mediamtx | `YYYY/MM/DD HH:MM:SS LVL [component] [session|path x] message` | one regex → component, id, msg |
| jellyfin | `[HH:MM:SS.mmm] [LVL] [thread] Logger.Class: message` + stack-trace continuation lines | **multiline** (join lines not starting with `[`) then regex |
| gitea, mariadb, copyparty | plain text | level regex only |
## Caddy access logs
On for every site block (`CADDY_LOG` in `configure.py`): JSON to stderr; `Cookie`, `Authorization` and
`X-Stream-Auth` request headers are deleted before logging, the `X-Authentik-*` identity headers are kept — that is the
"who downloaded what" audit trail for the files host.
## Retention
One global retention period in VictoriaLogs (`-retentionPeriod`); start at 30 days and watch the disk. Keeping
`auth` and `deploy` longer than the rest would need separate tenants, which is not worth it unless an audit does.
## As built (Phase 13)
| container | port | job |
|---|---|---|
| `victorialogs` | 9428 | store, 30 d, `-http.pathPrefix=/logs` so Caddy passes the prefix through unchanged |
| `vector` | — | `docker_logs` + `journald` → VictoriaLogs (elasticsearch bulk). **Holds the Docker socket** |
| `victoriametrics` | 8428 | 90 d, scrapes the taps above (`observability/scrape.yml`) |
| `vmalert-metrics` | 8880 | `observability/alerts-metrics.yml` against VictoriaMetrics |
| `vmalert-logs` | 8881 | `observability/alerts-logs.yml` (LogsQL) against VictoriaLogs' stats endpoints |
| `alertmanager` | 9093 | groups, inhibits, posts to Discord (`webhook_url_file`, never in the config) |
Published only through `diag.BASE`, gated on `DIAG_REQUIRE_GROUP` (`media-admins`): `/logs`, `/metrics-db`,
`/alerts`, `/rules-metrics`, `/rules-logs`, and an index at `/`.
**The deadman** (`bin/vanguard-deadman.sh`, host timer, 5 min) is deliberately outside all of it: curl only, it
checks each component answers, that the always-firing `Watchdog` alert is still arriving through
vmalert → Alertmanager → dumpd `/heartbeat`, and the disks. It speaks on change, announces recovery once, and
with no webhook configured still logs and exits non-zero so `systemctl is-failed vanguard-deadman.service` is
a signal. Nothing inside the stack can report its own death; this can.
`ALERT_WEBHOOK_URL` in `.env` → `/etc/vanguard/alert-webhook` (0640 root:65534). Empty means log-only, which
is a working configuration, not an error.
## Wiring sketches (the options that were weighed)
- **Grafana + Loki**: `alloy` container with `loki.source.journal` + `loki.source.docker` (labels from the container
labels above) → `loki` on loopback → `grafana` behind Authentik OIDC (third provider, like Jellyfin/Gitea).
Metrics: Alloy scrapes the four taps above → Prometheus or VictoriaMetrics, same Grafana.
- **VictoriaLogs** (chosen): single container on `127.0.0.1:9428`, run with `-http.pathPrefix=/logs`; Vector
ships journald and the Docker logs. Its built-in UI sits behind the Caddy forward-auth gate on `diag.BASE`
(`media-admins`). VictoriaMetrics beside it would consume the four metric taps.
- **Netdata**: single container, host + container metrics and alerts (Discord) out of the box, journald viewer;
behind the Caddy gate. Weakest at log search.
- **ELK**: rejected — JVM heap and index disk on a box doing x264; our data is structured records (→ MariaDB) and a
single host's logs.