diff --git a/CHANGELOG.md b/CHANGELOG.md index f007589..f5892f5 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -9,6 +9,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Added +- The Grafana dashboard has a Page row, from ipx-web's new request log, and a Directory row: snapshots, feed checks and failures, and requests by token (#210). - `ipx-directory`, a directory of public podcasts that ipx servers share: each sends the public feeds its people subscribe to, and any server with a token browses them. Tokens are in its config file, each read-only, read-write or admin, and revoked one at a time (#204). ### Changed diff --git a/crates/directory/src/lib.rs b/crates/directory/src/lib.rs index 20e394c..23846da 100644 --- a/crates/directory/src/lib.rs +++ b/crates/directory/src/lib.rs @@ -183,6 +183,8 @@ pub async fn refresher(dir: Shared) { } } if !due.is_empty() { + // One line a round, for the dashboard's refresher panel (#210); failures have their own. + tracing::info!(checked = due.len(), "feeds checked"); continue; } } diff --git a/grafana/dashboard.py b/grafana/dashboard.py index 86910eb..8b0a776 100644 --- a/grafana/dashboard.py +++ b/grafana/dashboard.py @@ -1,4 +1,5 @@ -"""The iPX dashboard in Grafana, from Loki (the container's log, shipped by Alloy) and Tempo. +"""The iPX dashboard in Grafana, from Loki (the containers' logs, shipped by Alloy) and Tempo: +ipx, and since #210 ipx-web and ipx-directory. python3 grafana/dashboard.py > /mnt/fast/arcane/projects/monitoring/grafana-provisioning/dashboards/ipx.json @@ -23,6 +24,16 @@ HTTP = SEL + ' |= "\\"target\\":\\"ipx::http\\"" | json | __error__="" | path != BAD = SEL + ' | json | __error__="" | level =~ "WARN|ERROR"' TEXT = ' | line_format "{{.level}} {{.target}}: {{.message}}"' TRACES = '{resource.service.name="ipx" && resource.deployment.environment.name="production"' +# The directory's JSON log (#204): a line a request (method, path, status, duration_ms, token), a +# line a snapshot (instance, accepted, refused_*), a line a refresher round (checked) and one a +# failed feed check (feed, error). +DIR = '{container="ipx-directory"} | json | __error__=""' +DIR_HTTP = '{container="ipx-directory"} |= "ipx_directory::http" | json | __error__=""' +# ipx-web's Caddy access log (#203, #210): request.uri, status, duration in seconds. The page and +# its files only: /api and /media are ipx's, and in its own log already. +WEB = ('{container="ipx-web"} |= "http.log.access" | json | __error__=""' + ' | request_uri !~ "/(api|media)/.*"') +OTHERS_BAD = '{container=~"ipx-web|ipx-directory"} | json | __error__="" | level =~ "(?i)warn|error"' def status(field): @@ -145,6 +156,45 @@ table("Busiest routes", [loki(f'topk(15, sum by (method, route) (count_over_time 12, rename={"method": "Method", "route": "Route", "Value": "Requests"}, sort=[{"displayName": "Requests", "desc": True}]) y += 8 +# ---- Page, from ipx-web's log +row("Page") +ts("Page and file requests by status", [loki(f'sum by (status) (count_over_time({WEB} [$__interval]))', legend="{{status}}")], + 0, bars=True, stack=True, desc="What Caddy served itself: the app, the admin and sign-in pages, scripts, styles, icons. " + "A page answered 401 or 403 is ipx refusing it in /api/page-check.") +ts("Page response time", [loki(f'quantile_over_time(0.95, {WEB} | unwrap duration [$__interval]) by ()', legend="95th percentile"), + loki(f'max_over_time({WEB} | unwrap duration [$__interval]) by ()', ref="B", legend="slowest")], + 12, unit="s", desc="A page waits on ipx's /api/page-check before it is sent.") +y += 8 + +# ---- Directory, from ipx-directory's log +row("Directory") +stat("Feeds shared", 'sum(max by (instance) (max_over_time(' + DIR + ' | message="snapshot" | unwrap accepted [6h])))', 0, + desc="The feeds each server's latest snapshot gave, added up: the same feed from two servers counts twice.") +stat("Snapshots", f'sum(count_over_time({DIR} | message="snapshot" [$__range])) or vector(0)', 4, + desc="ipx sends one when what it shares changes, and every half hour (#211).") +stat("Refused as private", f'sum(sum_over_time({DIR} | message="snapshot" | unwrap refused_private [$__range])) or vector(0)', 8, + thresholds=[{"color": "green", "value": None}, {"color": "red", "value": 1}], + desc="Feeds a server sent that the directory caught as private. Not 0 means a server's own check missed one.") +stat("Feed checks", f'sum(sum_over_time({DIR} | message="feeds checked" | unwrap checked [$__range])) or vector(0)', 12) +stat("Failed feed checks", f'sum(count_over_time({DIR} | message="feed check failed" [$__range])) or vector(0)', 16, + thresholds=[{"color": "green", "value": None}, {"color": "orange", "value": 1}], + desc="Mostly the publishers': a feed gone or moved.") +stat("Requests refused", f'sum(count_over_time({DIR_HTTP} | status =~ "401|403" [$__range])) or vector(0)', 20, + thresholds=[{"color": "green", "value": None}, {"color": "orange", "value": 100}], + desc="Without a token, or with one that has not the access asked for. Now and then is someone trying a public address.") +y += 4 +ts("Directory requests", [loki(f'sum by (status, token) (count_over_time({DIR_HTTP} [$__interval]))', legend="{{status}} {{token}}")], + 0, bars=True, stack=True) +ts("Feed checks", [loki(f'sum(sum_over_time({DIR} | message="feeds checked" | unwrap checked [$__interval]))', legend="checked"), + loki(f'sum(count_over_time({DIR} | message="feed check failed" [$__interval]))', ref="B", legend="failed")], + 12, bars=True, desc="Each feed every six hours, 25 at a time; a burst follows a snapshot with new feeds.") +y += 8 +table("Directory: failing feeds", [loki(f'sum by (feed, error) (count_over_time({DIR} | message="feed check failed" [$__range]))', instant=True)], + 0, rename={"feed": "Feed id", "error": "Error", "Value": "Failures"}, sort=[{"displayName": "Failures", "desc": True}]) +table("Snapshots by server", [loki(f'sum by (instance) (count_over_time({DIR} | message="snapshot" [$__range]))', instant=True)], + 12, rename={"instance": "Token", "Value": "Snapshots"}, sort=[{"displayName": "Snapshots", "desc": True}]) +y += 8 + # ---- Daemon, from Prometheus: what the daemon holds between requests (#194) row("Daemon") # Open connections stay open, idle, for ten minutes after a burst, so open at the max is not @@ -221,6 +271,9 @@ row("Log") panel("logs", "Warnings and errors", 24, 10, 0, [loki(BAD + TEXT)], options={"showTime": True, "wrapLogMessage": True, "sortOrder": "Descending", "enableLogDetails": True}) y += 10 +panel("logs", "Page and directory: warnings and errors", 24, 8, 0, [loki(OTHERS_BAD + ' | line_format "{{.container}} {{.level}}: {{.message}}{{.msg}}"')], + options={"showTime": True, "wrapLogMessage": True, "sortOrder": "Descending", "enableLogDetails": True}) +y += 8 panel("logs", "Log", 24, 12, 0, [loki(SEL + ' | json | __error__="" | path != "/api/events" | ev != "feed_skip" | ev != "status"' ' | message != "-> {\\"cmd\\":\\"status\\"}"' + TEXT)], diff --git a/web/Caddyfile b/web/Caddyfile index dc8f25d..72d7939 100644 --- a/web/Caddyfile +++ b/web/Caddyfile @@ -8,11 +8,41 @@ { admin off auto_https off + # Everything else Caddy logs, its errors among them, which carry the request too: the same + # filter as the access log's below. + log default { + output stderr + format filter { + wrap json + fields { + request>uri query { + delete token + } + request>headers delete + } + } + } } http://{$WEB_BIND::8080} { root * {$WEB_ROOT:/srv} + # One JSON line a request on stdout, for Loki and the dashboard's Page row (#210). Not the + # shared token a ?token= link carries, nor the request's headers, which hold the session + # cookie and Cloudflare Access's token. + log { + output stdout + format filter { + wrap json + fields { + request>uri query { + delete token + } + request>headers delete + } + } + } + # Before anything else, so no page or API call sees them: only ipx sets these. @forged not remote_ip {$TUNNEL_PEER:255.255.255.255} request_header @forged -Cf-Access-Authenticated-User-Email