From ee7ab36730d6172812f1343fe36781e2ec760f2e Mon Sep 17 00:00:00 2001 From: rays Date: Mon, 12 Oct 2026 16:04:26 +0000 Subject: [PATCH] prod-check: every container, Tower and the monitoring, each with its checks ipx-web logs every request now (#210) and the directory a line a refresher round, so each gets its own queries; Tower's node metrics and the monitoring's own health get sections after 2026-10-12, when load passed 200 and Prometheus did not come back after Docker restarted. Co-Authored-By: Claude Opus 5.5 --- .claude/skills/ipx-prod-check/SKILL.md | 166 +++++++++++++++++++------ 1 file changed, 128 insertions(+), 38 deletions(-) diff --git a/.claude/skills/ipx-prod-check/SKILL.md b/.claude/skills/ipx-prod-check/SKILL.md index 77ee5f0..cb6bd36 100644 --- a/.claude/skills/ipx-prod-check/SKILL.md +++ b/.claude/skills/ipx-prod-check/SKILL.md @@ -1,14 +1,23 @@ --- name: ipx-prod-check -description: Look for problems in production ipx (the iPX, ipx-web and ipx-directory containers on Tower) from its logs in Loki, its traces in Tempo and its metrics in Prometheus, and file what is found as Gitea issues. Use when asked to check on production, look for issues or errors in ipx, see why something is slow or failing in production, review the logs, or investigate a report about the live site. +description: Look for problems in production ipx (the ipx-web, iPX and ipx-directory containers on Tower, Tower itself and the monitoring that watches them) from their logs in Loki, ipx's traces in Tempo and the metrics in Prometheus, and file what is found as Gitea issues. Use when asked to check on production, look for issues or errors in ipx, see why something is slow or failing in production, review the logs, or investigate a report about the live site. --- # Checking production ipx -Production logs one JSON object a line (`IPX_LOG_FORMAT=json`), which Alloy ships to Loki under -`{container="iPX"}`, and sends traces to Tempo tagged -`resource.deployment.environment.name="production"`. Anything without that tag is a daemon run by -hand, not production. Loki and Tempo publish no query port, so use the script beside this file: +Production is three containers in the Arcane project `ipx` on Tower +(`/mnt/fast/arcane/projects/ipx/compose.yaml`), one request passing through them in this order: + +| container | what | logs, in Loki | traces, in Tempo | metrics, in Prometheus | +|---|---|---|---|---| +| `ipx-web` | Caddy: serves the page, passes `/api` and `/media` to ipx (#203). Port 8099, the LAN and the tunnel | `{container="ipx-web"}`, JSON: a line a request (`http.log.access`), its own errors | none | none | +| `iPX` | the daemon: API, scans, downloads, DeadAir | `{container="iPX"}`, JSON (`IPX_LOG_FORMAT=json`) | yes, tagged `resource.deployment.environment.name="production"` | `job="ipx"`, its `/metrics` | +| `ipx-directory` | the directory of public podcasts, `ipx-dir.sdf1.net` (#204) | `{container="ipx-directory"}`, JSON (`DIRECTORY_LOG_FORMAT=json`) | none | none | + +Under them, Tower itself: `job="node"` (the node exporter: load, CPU, memory, disks). The Grafana +dashboard `iPX` draws all of it in that order (`grafana/dashboard.py`). A trace without the +production tag is a daemon run by hand, not production. Alloy ships the logs; Loki, Tempo and +Prometheus publish no query port to this machine, so use the script beside this file: ```sh Q=.claude/skills/ipx-prod-check/query.py @@ -20,13 +29,24 @@ $Q prom '' [since] # Prometheus, now; $range becomes `sinc ``` `since` is `30m`, `1h`, `24h`, `7d`. Default to `24h`; widen it to see whether something is new. -"Since the last deploy" is since the container started: +"Since the last deploy" is since that container started (each deploys on its own): ```sh -S=$(docker inspect iPX -f '{{.State.StartedAt}}'); echo $(( ($(date +%s) - $(date -d "$S" +%s)) / 60 + 1 ))m +for c in iPX ipx-web ipx-directory; do S=$(docker inspect $c -f '{{.State.StartedAt}}'); echo "$c $(( ($(date +%s) - $(date -d "$S" +%s)) / 60 + 1 ))m"; done ``` -## What the log carries +Start every check by seeing that all three run, since Loki cannot see a container that is not: + +```sh +docker ps -a --filter name=iPX --filter name=ipx-web --filter name=ipx-directory --format '{{.Names}} {{.Status}}' +``` + +All three should be `(healthy)`. Then work through ipx (the checks below), the page, the +directory, Tower and the monitoring itself, in that order. + +## ipx + +### What the log carries Every line has `timestamp`, `level`, `message` and `target`; lines inside a span have `span` (the innermost: `{"name":"feed","feed":"x"}`). Loki's `| json` flattens it to `span_name`, `span_feed`. @@ -59,7 +79,7 @@ Filter on the text before `| json` where you can (`|= "\"ev\":\"feed_error\""`): cheaper than parsing every line. Lines before 2026-09-29 14:00 UTC are text, not JSON, and `| json | __error__=""` drops them. -## What Prometheus carries +### What Prometheus carries The daemon's own state between requests, which no log line or trace holds (#194): ipx serves `/metrics` on `[web] metrics_bind` (production: `192.168.1.130:9187`, LAN only), on a thread and @@ -88,7 +108,7 @@ from 2026-10-11 15:15 UTC. All gauges: | `ipx_art_evicted_total`, `ipx_art_requests_total{result="hit"\|"miss"}` | counters: images the sweep threw out to stay under the limit, and artwork served from disk or fetched from the publisher; many evicted at every sweep with a falling hit rate means the limit is too small | | `ipx_feeds`, `ipx_downloads_pending`, `ipx_files_downloaded` | the library, as the healthcheck last counted it (every 30 s) | -## The checks +### The checks Run these, then read the lines behind whatever stands out. Most of the time is in the reading: a count says something happened, the lines and traces say why. @@ -198,44 +218,112 @@ a count says something happened, the lines and traces say why. the minified `app.js`, so match the message to `web/src`. `play_start` over 2000 ms, or a `stall`, is worth a trace: was it the server, Cloudflare, or the network. -Also check the container itself, since Loki cannot see a daemon that is not running: +`docker logs --since 10m iPX 2>&1 | tail -5` shows the newest lines when Loki is behind. + +## ipx-web, the page + +Caddy logs one JSON line a request (#210), logger `http.log.access.log0`: Loki's `| json` gives +`request_uri`, `request_method`, `request_remote_ip`, `status`, `duration` (seconds, not ms), `size`. +The request's headers and a `?token=` are filtered out before it is written. Its healthcheck +requests come from `127.0.0.1` every 30 s; leave them out. `/api` and `/media` pass on to ipx and +are in ipx's own access log too, with ipx's time; Caddy's `duration` for them adds the hop. ```sh -docker ps --filter name=iPX --format '{{.Status}}' -docker logs --since 10m iPX 2>&1 | tail -5 +W='{container="ipx-web"} |= "http.log.access" | json | __error__="" | request_remote_ip != "127.0.0.1"' +$Q metric "sum by (status) (count_over_time($W [\$range]))" +$Q metric "sum by (request_uri) (count_over_time($W | status >= 500 [\$range]))" +$Q metric "topk(10, quantile_over_time(0.95, $W | request_uri !~ \"/(api|media)/.*\" | unwrap duration [\$range]) by (request_uri))" +$Q logs '{container="ipx-web"} | json | __error__="" | level=~"warn|error" | msg !~ "admin endpoint disabled|automatic HTTPS is completely disabled|HTTP/[23] skipped.*|exiting; byeee.*"' ``` -## The directory +A 502 is ipx not answering Caddy: a restart (match the deploy) or ipx down; Caddy's error line +names it (`dial tcp ...:8099: connect: connection refused`). The page itself (`/`, `/admin`) +waits on `/api/page-check` before it is sent, so a slow page is usually a slow page-check: look it +up in ipx's access log. 401 and 303 on `/` are people signed out being sent to `/login`, not a +problem. Caddy's own notices at each start (no admin endpoint, no HTTPS or HTTP/3, its goodbye on +SIGTERM) are by design and filtered out above. -`ipx-directory`, in the same Arcane project, is the directory of public podcasts ipx servers share -(docs/directory.md), public at `ipx-dir.sdf1.net`. It logs JSON to Loki under -`{container="ipx-directory"}`: a line a request, with the `token`'s name and never the token, and -a line for each snapshot and each feed check that failed. +Who reaches it: `request_remote_ip` is `192.168.64.1` for the tunnel and anything else on Tower +(Docker's gateway), `192.168.1.130` for Tower itself, a LAN address for the LAN. Caddy passes +Cloudflare Access's headers on only from `192.168.64.1` (`TUNNEL_PEER`), and ipx trusts them only +from Caddy, with a valid signed token. Testing sign-in from Tower proves nothing about the tunnel +(#209): send it from a container on another network. + +## ipx-directory + +It logs a line a request (`target` `ipx_directory::http`: `method`, `path`, `status`, +`duration_ms`, `token`, the token's name and never the token), a line a snapshot (`message` +`snapshot`: `instance`, `accepted`, `refused_private`, `refused_blocked`, `refused_invalid`), a +line a refresher round (`feeds checked`: `checked`), a line a failed feed check (`feed check +failed`: `feed`, the directory's id, and `error`), the admin's actions (`feed removed and +blocked`, `feed unblocked`, `snapshot dropped`, each with `by`), and `config read again` when its +token file changes. It sends no traces and has no metrics. ```sh -docker ps --filter name=ipx-directory --format '{{.Status}}' -$Q metric 'sum by (status, token) (count_over_time({container="ipx-directory"} |= "ipx_directory::http" | json | __error__="" [$range]))' -$Q logs '{container="ipx-directory"} | json | level=~"WARN|ERROR"' -$Q logs '{container="ipx-directory"} |= "\"message\":\"snapshot\""' 7d +D='{container="ipx-directory"} | json | __error__=""' +$Q metric "sum by (status, token) (count_over_time({container=\"ipx-directory\"} |= \"ipx_directory::http\" | json | __error__=\"\" [\$range]))" +$Q metric "topk(5, max_over_time({container=\"ipx-directory\"} |= \"ipx_directory::http\" | json | __error__=\"\" | unwrap duration_ms [\$range]) by (path))" +$Q logs "$D | level=~\"WARN|ERROR\"" +$Q logs "$D | message=\"snapshot\"" 7d +$Q metric "sum(count_over_time($D | message=\"snapshot\" [\$range])) by (instance)" +$Q metric "sum by (feed, error) (count_over_time($D | message=\"feed check failed\" [\$range]))" 7d +$Q metric "sum(sum_over_time($D | message=\"feeds checked\" | unwrap checked [\$range]))" 24h ``` -A burst of 401s with an empty `token` is someone without a token trying it, which is expected now -and then from a public address; a steady stream is worth an issue, since Cloudflare can rate-limit -it. A snapshot whose `refused_private` is not 0 means an ipx server tried to send a feed that looks -private: find which in that server's log, since the directory refuses it but the sender should not -have sent it. Many `feed check failed` lines for one feed are the publisher's, not the directory's. +Expect a snapshot from each server when what it shares changes and every half hour, so about 48 a +day each; one every half minute is ipx resending what has not changed (#211, fixed). A burst of +401s with an empty `token` is someone without a token trying the public address, expected now and +then; a steady stream is worth an issue, since Cloudflare can rate-limit it. A snapshot whose +`refused_private` is not 0 means an ipx server tried to send a feed that looks private: find which +in that server's log, since the directory refuses it but the sender should not have sent it. Many +`feed check failed` lines for one feed are the publisher's, not the directory's. Each feed is +checked every six hours, 25 at a time, so `feeds checked` over a day should be about four times +the feeds listed; none for over six hours means the refresher is stuck. `could not store a feed +check` or `could not read which feeds are due` is its database (`ipx_directory` on the +`databases` project's Postgres). A config that does not load (`config changed but does not +load`) keeps the old tokens: worth fixing before someone's new token is needed. -## The page +## Tower -`ipx-web` (Caddy) serves the page and passes the API to ipx (#203). It logs only its own start and -errors, not requests: ipx's access log still has every API call, and a page that fails to load -shows there as `/api/page-check` answering something other than 204, 303 or 302. +The three share Tower with everything else, so a slow or failing ipx can be the host. The node +exporter (`job="node"`) has the history; twelve threads. ```sh -docker ps --filter name=ipx-web --format '{{.Status}}' -docker logs --since 24h ipx-web 2>&1 | grep -v '"level":"info"' | tail +$Q prom 'max_over_time(node_load1{job="node"}[$range])' 24h +$Q prom 'min_over_time(node_memory_MemAvailable_bytes{job="node"}[$range]) / 1e9' 24h +$Q prom 'sum by (mode) (rate(node_cpu_seconds_total{job="node", mode=~"user|system|iowait"}[$range]))' 1h +$Q prom 'max by (device) (rate(node_disk_io_time_seconds_total{job="node", device=~"nvme.*|md.*"}[$range]))' 1h ``` +For when, step back with `offset`: `max_over_time(node_load1[10m] offset 60m)`. Load far above +twelve with little CPU busy is processes waiting, on a disk or on the user shares: on 2026-10-12 +debug builds linking through `/mnt/user` (shfs, FUSE) took load to 248 with mostly system time and +stalled everything on the shares, ipx's downloads included. Available memory near nothing makes +it worse. Disk busy near 100% on `nvme1n1` is `/mnt/fast`, appdata and Postgres's data; on `md*` +the array behind `/mnt/user`, the downloads. Say what was running at the time if you can tell +(`docker stats --no-stream`); a host problem is the user's, not an ipx issue, unless ipx caused it. + +## The monitoring itself + +A quiet dashboard can be a dead exporter. Check what Prometheus scrapes and that each +container's lines are reaching Loki: + +```sh +curl -s http://192.168.1.130:9090/api/v1/targets | python3 -c 'import json,sys +for t in json.load(sys.stdin)["data"]["activeTargets"]: print(t["health"], t["labels"]["job"], t["scrapeUrl"], t.get("lastError","")[:80])' +for c in iPX ipx-web ipx-directory; do echo "$c $($Q metric "sum(count_over_time({container=\"$c\"} [1h]))" 1h | tail -1)"; done +docker ps -a --filter label=com.docker.compose.project=monitoring --format '{{.Names}} {{.Status}}' +``` + +`ipx` and `node` should be `up`. Every monitoring container should be running; after Docker +restarts, one can be left `Exited (255)` though its policy is `unless-stopped` (Prometheus, on +2026-10-12, when Docker lost its exit during an overload): `docker start` it and say so. blocky +and nut on 192.168.2.21 are another machine, not ipx's; leave them. A container with no lines in +an hour while it runs means Alloy is not shipping it; Alloy can take a few minutes to pick up a +container after a deploy. + +## Rules + `docker logs` and `docker exec iPX ipx ...` are fine. Do not query production's Postgres directly: ask the user if a question needs the database. @@ -256,12 +344,14 @@ Put in each issue what would let someone pick it up cold: the LogQL or TraceQL t trace id, the first time it was seen and how often. A publisher's dead feed is worth one issue saying so (the user may want to unsubscribe or find its new address); a single 503 is not. -Finish with a short report to the user: what is healthy, what is wrong (with the issue numbers), -and anything you could not tell from logs and traces alone. Do not fix things unless asked; the +Finish with a short report to the user, a line for each of ipx-web, ipx, the directory, Tower and +the monitoring: what is healthy, what is wrong (with the issue numbers), and anything you could +not tell from logs, traces and metrics alone. Do not fix things unless asked; the check is for finding them. ## When the checks come back empty -Check that there is data before concluding all is well: `$Q metric 'sum(count_over_time({container="iPX"} [1h]))' 1h` -should be in the hundreds or more. Nothing at all means Alloy is not shipping (it can take a few -minutes to pick up a container after a deploy), or the container is down. +Check that there is data before concluding all is well (the monitoring section's per-container +count): iPX should have hundreds of lines an hour or more, ipx-web at least its healthchecks' +120, ipx-directory a few dozen. Nothing at all means Alloy is not shipping it, or the container +is down.