"""The iPX dashboard in Grafana: the three containers of the Arcane project ipx (ipx, ipx-web, ipx-directory) and Tower under them, from Prometheus, Loki (their logs, shipped by Alloy) and Tempo. python3 grafana/dashboard.py > /mnt/fast/arcane/projects/monitoring/grafana-provisioning/dashboards/ipx.json Grafana reads that file on its own within a minute; edits made in Grafana are refused. Rows go top-down as a request does: an overview, Tower, then each container (ipx-web, ipx's API, its worker and its process, the directory), then traces and logs. Prometheus scrapes ipx's /metrics (job ipx, #194) and Tower's node exporter (job node); nothing scrapes the containers themselves, so ipx-web and the directory are read from their logs. The log panels read fields: ipx's (web.rs access_log, ipc.rs log_event), the directory's and Caddy's; renaming one has to be matched here. `dashboard.py queries` prints each Loki query, to try against Loki. """ import json, sys LOKI = {"type": "loki", "uid": "${loki}"} TEMPO = {"type": "tempo", "uid": "${tempo}"} PROM = {"type": "prometheus", "uid": "${prometheus}"} SEL = '{container="iPX"}' # ipx logs one JSON object a line (IPX_LOG_FORMAT=json). Each scan and download event carries its # fields (ev, feed, new, bytes, msg, error.type, ...); each request its method, path, route, status # and duration_ms. Events are logged under ipx::scan, the healthcheck's status under ipx::io, so # the filter is on the ev field, not the target. EV = SEL + ' |= "\\"ev\\":\\"" | json | __error__="" | ev != ""' HTTP = SEL + ' |= "\\"target\\":\\"ipx::http\\"" | json | __error__="" | path != "/api/events"' BAD = SEL + ' | json | __error__="" | level =~ "WARN|ERROR"' TEXT = ' | line_format "{{.level}} {{.target}}: {{.message}}"' # Every production span: ipx-web's, ipx's and the directory's, one trace from the page to the # directory where a request goes that far (#213). A daemon run by hand has no such tag. TRACES = '{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)/.*" | request_remote_ip != "127.0.0.1"') # not its healthcheck # Less what Caddy says at every start, by design: no admin endpoint, and no HTTPS or HTTP/3 # behind the tunnel; and its goodbye on a restart. OTHERS_BAD = ('{container=~"ipx-web|ipx-directory"} | json | __error__="" | level =~ "(?i)warn|error"' ' | msg !~ "admin endpoint disabled|automatic HTTPS is completely disabled|HTTP/[23] skipped.*|exiting; byeee.*"') QUERIES = {} panels, y = [], 0 pid = 0 def panel(kind, title, w, h, x, targets, **extra): global pid pid += 1 p = {"id": pid, "type": kind, "title": title, "gridPos": {"x": x, "y": y, "w": w, "h": h}, "datasource": targets[0].get("datasource", LOKI), "targets": targets} p.update(extra) panels.append(p) return p def loki(expr, ref="A", legend=None, instant=False, kind=None): QUERIES[expr] = instant t = {"refId": ref, "datasource": LOKI, "expr": expr, "queryType": "instant" if instant else "range"} if legend: t["legendFormat"] = legend return t def prom(expr, ref="A", legend=None): # ipx's /metrics (#194), scraped by Prometheus as job ipx. t = {"refId": ref, "datasource": PROM, "expr": expr} if legend: t["legendFormat"] = legend return t def row(title): global y, pid pid += 1 panels.append({"id": pid, "type": "row", "title": title, "collapsed": False, "gridPos": {"x": 0, "y": y, "w": 24, "h": 1}, "panels": []}) y += 1 def stat(title, target, x, unit="short", color="blue", thresholds=None, desc=None): """target: loki(..., instant=True) or prom(...).""" steps = thresholds or [{"color": color, "value": None}] return panel("stat", title, 4, 4, x, [target], description=desc or "", fieldConfig={"defaults": {"unit": unit, "color": {"mode": "thresholds"}, "thresholds": {"mode": "absolute", "steps": steps}}, "overrides": []}, options={"reduceOptions": {"calcs": ["lastNotNull"], "fields": "", "values": False}, "colorMode": "value", "graphMode": "none", "textMode": "value"}) def ts(title, targets, x, w=12, h=8, unit="short", bars=False, stack=False, desc=""): custom = {"drawStyle": "bars" if bars else "line", "fillOpacity": 60 if bars else 10, "lineWidth": 1, "showPoints": "never", "stacking": {"mode": "normal" if stack else "none"}} return panel("timeseries", title, w, h, x, targets, description=desc, fieldConfig={"defaults": {"unit": unit, "custom": custom}, "overrides": []}, options={"legend": {"displayMode": "list", "placement": "bottom"}, "tooltip": {"mode": "multi", "sort": "desc"}}) def table(title, targets, x, w=12, h=8, rename=None, sort=None, desc=""): return panel("table", title, w, h, x, targets, description=desc, transformations=[{"id": "labelsToFields", "options": {"mode": "columns"}}, {"id": "organize", "options": { "excludeByName": {"Time": True, "container": True, "compose_project": True, "service_name": True}, "renameByName": rename or {}}}], options={"showHeader": True, "sortBy": sort or []}, fieldConfig={"defaults": {}, "overrides": []}) GOOD_BAD = [{"color": "green", "value": None}, {"color": "orange", "value": 1}] # Caddy's line for each request, what kind it is by its address. WEB_ALL = ('{container="ipx-web"} |= "http.log.access" | json | __error__="" | request_remote_ip != "127.0.0.1"' ' | label_format kind=`{{ if hasPrefix "/api/" .request_uri }}API{{ else if hasPrefix "/media/" .request_uri }}' 'media{{ else }}page and files{{ end }}`') LOG_OPTS = {"showTime": True, "wrapLogMessage": True, "sortOrder": "Descending", "enableLogDetails": True} def bar_overrides(*names): return [{"matcher": {"id": "byName", "options": n}, "properties": [{"id": "unit", "value": "short"}, {"id": "custom.axisPlacement", "value": "right"}, {"id": "custom.drawStyle", "value": "bars"}, {"id": "custom.fillOpacity", "value": 60}]} for n in names] # ---- Overview: is each part up, and is anything wrong row("Overview") stat("ipx", prom('max(up{job="ipx"})'), 0, thresholds=[{"color": "red", "value": None}, {"color": "green", "value": 1}], desc="Prometheus reaching ipx's /metrics: 1 is up. Its healthcheck asks the daemon and the database too.")["fieldConfig"]["defaults"]["mappings"] = [ {"type": "value", "options": {"0": {"text": "down"}, "1": {"text": "up"}}}] stat("Feeds", prom('max(ipx_feeds{job="ipx"})'), 4) stat("Waiting to download", prom('max(ipx_downloads_pending{job="ipx"})'), 8) stat("Since the last scan", prom('max(ipx_last_scan_age_seconds{job="ipx"})'), 12, unit="s", thresholds=[{"color": "green", "value": None}, {"color": "orange", "value": 600}, {"color": "red", "value": 1800}], desc="Over ten minutes means the worker may be stuck; the healthcheck still passes.") stat("Page and API errors", loki(f'sum(count_over_time({WEB_ALL} | status >= 500 [$__range])) or vector(0)', instant=True), 16, thresholds=GOOD_BAD, desc="Answers of 500 and up from ipx-web, for the page or passed on from ipx: 502 is ipx not answering.") stat("Warnings and errors", loki(f'sum(count_over_time({BAD} [$__range])) + sum(count_over_time({OTHERS_BAD} [$__range])) or vector(0)', instant=True), 20, thresholds=[{"color": "green", "value": None}, {"color": "orange", "value": 1}, {"color": "red", "value": 50}], desc="All three containers, in the time range.") y += 4 stat("Feed failures", loki(f'sum(count_over_time({EV} | ev="feed_error" [$__range])) or vector(0)', instant=True), 0, thresholds=GOOD_BAD, desc="Failed feed checks in the time range.") stat("Download failures", loki(f'sum(count_over_time({EV} | ev="download_error" [$__range])) or vector(0)', instant=True), 4, thresholds=GOOD_BAD) stat("Downloaded", prom('max(ipx_files_downloaded{job="ipx"})'), 8, color="green") stat("ipx running for", prom('max(ipx_uptime_seconds{job="ipx"})'), 12, unit="s") stat("Directory: feeds shared", loki('sum(max by (instance) (max_over_time(' + DIR + ' | message="snapshot" | unwrap accepted [6h])))', instant=True), 16, desc="The feeds each server's latest snapshot gave, added up.") stat("Directory: refused as private", loki(f'sum(sum_over_time({DIR} | message="snapshot" | unwrap refused_private [$__range])) or vector(0)', instant=True), 20, 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.") y += 4 # ---- Tower: the host all three run on, from the node exporter row("Tower") ts("Load", [prom('node_load1{job="node"}', legend="1 minute"), prom('node_load15{job="node"}', ref="B", legend="15 minutes")], 0, w=8, desc="Twelve threads. Load far above that with little CPU used is processes waiting on a disk or the user shares (shfs).") ts("CPU", [prom('sum by (mode) (rate(node_cpu_seconds_total{job="node", mode=~"user|system|iowait"}[$__rate_interval]))', legend="{{mode}}")], 8, w=8, stack=True, desc="Cores busy, by kind. Much system time with little user time is the kernel, often FUSE (shfs).") ts("Memory available", [prom('node_memory_MemAvailable_bytes{job="node"}', legend="available")], 16, w=8, unit="bytes") y += 8 ts("Disk busy", [prom('rate(node_disk_io_time_seconds_total{job="node", device=~"nvme.*|md.*"}[$__rate_interval])', legend="{{device}}")], 0, w=12, unit="percentunit", desc="nvme1n1 is /mnt/fast (appdata, Postgres's data); md* are the array's disks behind /mnt/user (downloads).") ts("Network", [prom('sum(rate(node_network_receive_bytes_total{job="node", device!~"lo|veth.*|docker.*|br-.*"}[$__rate_interval]))', legend="in"), prom('sum(rate(node_network_transmit_bytes_total{job="node", device!~"lo|veth.*|docker.*|br-.*"}[$__rate_interval]))', ref="B", legend="out")], 12, w=12, unit="Bps") y += 8 # ---- ipx-web: Caddy, the way in. Serves the page itself, passes /api and /media to ipx row("ipx-web") ts("Requests by kind", [loki(f'sum by (kind) (count_over_time({WEB_ALL} [$__interval]))', legend="{{kind}}")], 0, w=8, bars=True, stack=True, desc="Everything through Caddy, from the LAN and the tunnel. The API and media go on to ipx.") ts("Page and files by status", [loki(f'sum by (status) (count_over_time({WEB} [$__interval]))', legend="{{status}}")], 8, w=8, bars=True, stack=True, desc="What Caddy served itself. 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")], 16, w=8, unit="s", desc="A page waits on ipx's /api/page-check before it is sent.") y += 8 # ---- ipx: the API it answers behind ipx-web row("ipx: API") ts("Requests by status", [loki(f'sum by (status) (count_over_time({HTTP} [$__interval]))', legend="{{status}}")], 0, bars=True, stack=True, desc="The event stream the page keeps open is left out.") ts("Response time", [loki(f'quantile_over_time(0.5, {HTTP} | unwrap duration_ms [$__interval]) by ()', legend="median"), loki(f'quantile_over_time(0.95, {HTTP} | unwrap duration_ms [$__interval]) by ()', ref="B", legend="95th percentile"), loki(f'max_over_time({HTTP} | unwrap duration_ms [$__interval]) by ()', ref="C", legend="slowest")], 12, unit="ms") y += 8 table("Slowest routes", [loki(f'topk(15, avg_over_time({HTTP} | route != "" | unwrap duration_ms [$__range]) by (method, route))', instant=True)], 0, w=8, rename={"method": "Method", "route": "Route", "Value": "Average ms"}, sort=[{"displayName": "Average ms", "desc": True}]) table("Busiest routes", [loki(f'topk(15, sum by (method, route) (count_over_time({HTTP} | route != "" [$__range])))', instant=True)], 8, w=8, rename={"method": "Method", "route": "Route", "Value": "Requests"}, sort=[{"displayName": "Requests", "desc": True}]) ts("Open connections", [prom('max(ipx_http_requests_in_flight{job="ipx"})', legend="requests in flight"), prom('max(ipx_event_listeners{job="ipx"})', ref="B", legend="live-update listeners"), prom('max(ipx_event_queue{job="ipx"})', ref="C", legend="live updates unread"), prom('sum(increase(ipx_events_missed_total{job="ipx"}[$__rate_interval]))', ref="D", legend="live updates missed")], 16, w=8, desc="Each open page holds one live-update listener. Missed updates mean a page fell behind and reloads its lists.") y += 8 # ---- ipx: the worker, one job at a time: scans, downloads, DeadAir row("ipx: worker") ts("Worker", [prom('max by (kind) (ipx_worker_job_seconds{job="ipx"})', legend="on a {{kind}} for"), prom('max(ipx_last_scan_age_seconds{job="ipx"})', ref="B", legend="since the last scan finished")], 0, w=8, unit="s", desc="A job's time that only climbs, or no scan for over 10 minutes, means the worker is stuck; the healthcheck still passes.") ts("Jobs done", [prom('sum by (kind) (increase(ipx_jobs_total{job="ipx"}[$__rate_interval]))', legend="{{kind}}")], 8, w=8, bars=True, stack=True) ts("Time on jobs", [prom('sum by (kind) (increase(ipx_job_seconds_total{job="ipx"}[$__rate_interval]))', legend="{{kind}}")], 16, w=8, unit="s", bars=True, stack=True, desc="Seconds the worker spent on each kind of job in each interval.") y += 8 ts("Waiting", [prom('ipx_worker_queue{job="ipx"}', legend="commands for the worker"), prom('ipx_downloads_pending{job="ipx"}', ref="B", legend="downloads"), prom('max(ipx_feed_retries{job="ipx"})', ref="C", legend="feeds to retry a lookup"), prom('max(ipx_deadair_backlog{job="ipx"})', ref="D", legend="files for DeadAir")], 0, w=8, desc="A queue that only grows means the worker is stuck or behind.") ts("Feeds checked and new items", [loki(f'sum(sum_over_time({EV} | ev="scan_done" | unwrap feeds [$__interval]))', legend="feeds checked"), loki(f'sum(sum_over_time({EV} | ev="feed_done" | unwrap new [$__interval]))', ref="B", legend="new items")], 8, w=8, bars=True, desc="Feeds that were due and fetched; the rest were skipped as not due.") ts("Downloads", [loki(f'sum(count_over_time({EV} | ev="download_done" [$__interval]))', legend="saved"), loki(f'sum(count_over_time({EV} | ev="download_error" [$__interval]))', ref="B", legend="failed"), prom('max(ipx_downloads_active{job="ipx"})', ref="C", legend="at once"), prom('2 - max(ipx_torrent_slots_free{job="ipx"})', ref="D", legend="torrents")], 16, w=8, bars=True) y += 8 ts("Download speed", [prom('sum(rate(ipx_download_bytes_total{job="ipx"}[$__rate_interval]))', legend="downloading")], 0, w=8, unit="Bps") ts("Feeds fetching at once", [prom('max(ipx_scan_feeds_fetching{job="ipx"})', legend="fetching")], 8, w=8) ts("DeadAir on a file", [prom('max(ipx_deadair_busy_seconds{job="ipx"})', legend="for"), prom('max(ipx_deadair_playing{job="ipx"})', ref="B", legend="playing through DeadAir")], 16, w=8, unit="s", desc="How long DeadAir has been on the file it is analysing; a few seconds each.")["fieldConfig"]["overrides"] = [ {"matcher": {"id": "byName", "options": "playing through DeadAir"}, "properties": [{"id": "unit", "value": "short"}, {"id": "custom.axisPlacement", "value": "right"}]}] y += 8 table("Failing feeds", [loki(f'sum by (feed, msg) (count_over_time({EV} | ev="feed_error" [$__range]))', instant=True)], 0, rename={"feed": "Feed", "msg": "Error", "Value": "Failures"}, sort=[{"displayName": "Failures", "desc": True}]) table("Failed downloads", [loki(f'sum by (feed, msg) (count_over_time({EV} | ev="download_error" [$__range]))', instant=True)], 12, rename={"feed": "Feed", "msg": "Error", "Value": "Failures"}, sort=[{"displayName": "Failures", "desc": True}]) y += 8 # ---- ipx: the process, what it holds between requests and jobs (#194) row("ipx: process") # Open connections stay open, idle, for ten minutes after a burst, so open at the max is not # pressure; drawn as a line of its own it read as the pool maxing out (#199). ts("Database connections", [prom('max(max_over_time(ipx_db_connections{job="ipx", state="in_use"}[$__interval]))', legend="in use"), prom('sum(ipx_db_connections{job="ipx"})', ref="B", legend="open"), prom('max(ipx_db_connections_max{job="ipx"})', ref="C", legend="most the pool opens")], 0, w=8, desc="In use reaching the most the pool opens means requests and scans are waiting for a connection. " "Open connections stay open, idle, for ten minutes after a burst.")["fieldConfig"]["overrides"] = [ {"matcher": {"id": "byName", "options": "open"}, "properties": [{"id": "custom.lineStyle", "value": {"fill": "dash", "dash": [4, 4]}}, {"id": "custom.fillOpacity", "value": 0}, {"id": "color", "value": {"mode": "fixed", "fixedColor": "#8e8e8e"}}]}] ts("Memory", [prom('ipx_process_resident_bytes{job="ipx"}', legend="resident")], 8, w=8, unit="bytes") ts("Open files and sockets", [prom('ipx_process_open_fds{job="ipx"}', legend="open")], 16, w=8) y += 8 ts("Runtime", [prom('ipx_runtime_tasks{job="ipx"}', legend="tasks"), prom('ipx_runtime_queue{job="ipx"}', ref="B", legend="tasks waiting for a thread"), prom('ipx_runtime_workers{job="ipx"}', ref="C", legend="threads")], 0, w=12, desc="Tasks waiting for a thread for long means something is blocking the runtime.") ts("Artwork", [prom('max(ipx_art_cache_bytes{job="ipx"}) / max(ipx_art_cache_limit_bytes{job="ipx"})', legend="full"), prom('sum(increase(ipx_art_requests_total{job="ipx", result="hit"}[$__rate_interval])) / ' 'sum(increase(ipx_art_requests_total{job="ipx"}[$__rate_interval]))', ref="B", legend="hit rate"), prom('sum(increase(ipx_art_evicted_total{job="ipx"}[$__rate_interval]))', ref="C", legend="images evicted")], 12, w=12, unit="percentunit", desc="Full sits near 100% once the cache has filled, since each sweep trims it to fit. Hit rate is the share served from disk: " "the rest was fetched from the publisher. Evicted, on the right, is images each sweep threw out to stay under the " "limit: many at every sweep, with a falling hit rate, means the limit is too small.")["fieldConfig"]["overrides"] = bar_overrides("images evicted") y += 8 # ---- ipx-directory: public at directory.ipxreader.app, shared by ipx servers (#204) row("ipx-directory") stat("Snapshots", loki(f'sum(count_over_time({DIR} | message="snapshot" [$__range])) or vector(0)', instant=True), 0, desc="ipx sends one when what it shares changes, and every half hour (#211).") stat("Feed checks", loki(f'sum(sum_over_time({DIR} | message="feeds checked" | unwrap checked [$__range])) or vector(0)', instant=True), 4, desc="Each feed every six hours, 25 at a time.") stat("Failed feed checks", loki(f'sum(count_over_time({DIR} | message="feed check failed" [$__range])) or vector(0)', instant=True), 8, thresholds=GOOD_BAD, desc="Mostly the publishers': a feed gone or moved.") stat("Requests", loki(f'sum(count_over_time({DIR_HTTP} [$__range])) or vector(0)', instant=True), 12) stat("Requests refused", loki(f'sum(count_over_time({DIR_HTTP} | status =~ "401|403" [$__range])) or vector(0)', instant=True), 16, 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.") stat("Slowest request", loki(f'max(max_over_time({DIR_HTTP} | unwrap duration_ms [$__range])) or vector(0)', instant=True), 20, unit="ms") y += 4 ts("Requests by token", [loki(f'sum by (status, token) (count_over_time({DIR_HTTP} [$__interval]))', legend="{{status}} {{token}}")], 0, bars=True, stack=True) ts("Feed checks over time", [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="A burst follows a snapshot with new feeds.") y += 8 table("Failing feeds in the directory", [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 # ---- Traces: all three send them to Tempo (#213) row("Traces") for x, title, q in [(0, "Recent", TRACES + "}"), (8, "Slow (over 2s)", TRACES + " && duration > 2s}"), (16, "Failed", TRACES + " && status = error}")]: panel("table", title, 8, 10, x, [{"refId": "A", "datasource": TEMPO, "queryType": "traceql", "query": q, "limit": 50, "tableType": "traces"}], fieldConfig={"defaults": {}, "overrides": []}) y += 10 # ---- Logs row("Logs") panel("logs", "ipx: warnings and errors", 12, 10, 0, [loki(BAD + TEXT)], options=LOG_OPTS) panel("logs", "ipx-web and ipx-directory: warnings and errors", 12, 10, 12, [loki(OTHERS_BAD + ' | line_format "{{.container}} {{.level}}: {{.message}}{{.msg}}"')], options=LOG_OPTS) y += 10 panel("logs", "ipx log", 24, 12, 0, [loki(SEL + ' | json | __error__="" | path != "/api/events" | ev != "feed_skip" | ev != "status"' ' | message != "-> {\\"cmd\\":\\"status\\"}"' + TEXT)], description="Without the event stream's requests, not-due skips and healthcheck status calls.", options=LOG_OPTS) y += 12 dash = { "uid": "ipx", "title": "iPX", "tags": ["ipx"], "timezone": "browser", "schemaVersion": 39, "time": {"from": "now-24h", "to": "now"}, "refresh": "1m", "editable": True, "templating": {"list": [ {"name": "loki", "label": "Logs", "type": "datasource", "query": "loki", "current": {}, "hide": 0}, {"name": "tempo", "label": "Traces", "type": "datasource", "query": "tempo", "current": {}, "hide": 0}, {"name": "prometheus", "label": "Metrics", "type": "datasource", "query": "prometheus", "current": {}, "hide": 0}, ]}, "links": [{"title": "iPX", "type": "link", "url": "https://ipodderx.sdf1.net", "targetBlank": True}], "panels": panels, } if sys.argv[1:] == ["queries"]: for q, instant in QUERIES.items(): print(json.dumps([q, instant])) else: print(json.dumps(dash, indent=2))