Brandyn / Techy
6f7fb29ae0
Both Beats already wrote to the same Elasticsearch, but a metric event carried container.name while a log event carried service.name and vanguard.category, so nothing joined them and a dashboard could only show the two side by side. Metricbeat now runs add_docker_metadata and the same copy_fields, giving both sides @timestamp, host.name, container.name, service.name and vanguard.category. LOGGING.md documents the join keys and the one Kibana step that makes it work: a single data view over filebeat-*,metricbeat-* so one filter applies to metric panels and log panels together. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
169 lines
12 KiB
Markdown
169 lines
12 KiB
Markdown
# 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 |
|
||
|---|---|---|
|
||
| `elasticsearch` | 9200 | one store for **both** logs and metrics. 2 GB heap, single node, security off (loopback only) |
|
||
| `kibana` | 5601 | the single pane: Discover for logs, dashboards, alerting. Served at the root of `diag.BASE` |
|
||
| `filebeat` | — | container logs (autodiscover) + our journal units |
|
||
| `metricbeat` | — | host + Docker metrics (retires node_exporter and cAdvisor) + MediaMTX and Caddy Prometheus endpoints |
|
||
|
||
**Logs and metrics correlate because both Beats write the same fields into the same store.** That is what makes
|
||
one dashboard able to show a CPU spike next to the errors that caused it, rather than two dashboards side by
|
||
side:
|
||
|
||
| field | set by | use |
|
||
|---|---|---|
|
||
| `@timestamp` | both (ECS) | every panel shares the dashboard's time range |
|
||
| `host.name` | both | one box today, but the field is there |
|
||
| `container.name` | both | per-service metrics joined to that service's log lines |
|
||
| `service.name` | both, from the `vanguard.service` label | the name you actually think in |
|
||
| `vanguard.category` | both, from the label | filter a whole area at once: stream, media, auth, intake, deploy |
|
||
|
||
To get a dashboard that filters across both, make **one data view** spanning `filebeat-*,metricbeat-*` in
|
||
Kibana (Stack Management → Data Views). A single filter such as `service.name: mediamtx` then applies to the
|
||
metric panels and the log panel together. Metricbeat also ships its own system and Docker dashboards, which are
|
||
a good starting point to copy panels from.
|
||
|
||
Retention is one edit in Kibana rather than config: Stack Management → Index Lifecycle Policies → the beats
|
||
policy → add a delete phase. Doing it there rather than in a file keeps it adjustable without a redeploy.
|
||
|
||
### Old notes
|
||
|
||
|
||
(superseded 2026-11-03 — the Victoria/vmalert/Alertmanager shape, kept for the reasoning)
|
||
|
||
| 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.
|