Files
Media-Server-Setup/LOGGING.md
Brandyn / Techy 6f77764fec Propagate this build's lessons into the scripts and every runbook
addCommunityMediaServer.sh asks for the diag hostname, DNS-checks it and passes it to --hosts, so a rebuild
sets it up like every other host instead of leaving it to be discovered missing.

HOSTNAME-CHANGE.md gains §D, adding a new host, which is where the hour went: --apply is stateless and reads
hostnames back out of the Caddyfile, so it silently omits a role that is not already there and the name ends
up with no certificate. README and the Phase 13 checklist now point at --full or --hosts instead of --apply,
and the plan's risks section carries the same warning plus the path-prefix cascade.

LOGGING.md collects the four traps this produced so none of them is rediscovered. FRESH-INSTALL gains an
ordered §7b and appendix M for the diag host, including that running without a webhook is correct rather than
half-configured; the old Afterwards section is relettered N.

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

137 lines
9.8 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: `configure.py` generates `observability/alertmanager.yml` with the
Discord notifier omitted, so nothing is half-configured and nothing fails to load.
## Gotchas this build produced (all fixed; here so they are not rediscovered)
- **`-http.pathPrefix` applies to EVERY endpoint, not just the UI.** With VictoriaLogs behind `/logs`, the
ingestion path is `/logs/insert/elasticsearch/`, the health probe is `/logs/health` and the scrape is
`/logs/metrics`. It rejects a write to the unprefixed path with a message naming the missing flag.
- **Every proxied UI needs its own prefix set**, or it loads at the sub-path and then fetches its assets from
the domain root and renders broken. VictoriaMetrics and vmalert use `-http.pathPrefix`; Alertmanager uses
`--web.route-prefix` plus `--web.external-url`. Setting those also moves their metrics and health paths.
- **Vector's `current_boot_only: false` is rejected on systemd 250–257.** Only the current boot is shipped;
earlier entries are still on the host for `journalctl --boot=-1`.
- **A Caddy `respond` body is placeholder-expanded**, so `{...}` in CSS or JSON is eaten. Serve a page as a
file (`diag/index.html`, mounted like the gateway and dock pages) instead of inlining it.
- **`configure.py --apply` cannot introduce a new host** — see HOSTNAME-CHANGE.md §D.
## 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.