feat(api): tag each error with a ref and count errors by service

Every structured error carries a short ref, appended to its message and logged with the request; /api/dashboard/status gains per-service error counts. Gzip now compresses in place.
This commit is contained in:
imSp4rky
2026-10-21 14:39:37 -06:00
parent 39ec591c48
commit afaff8e070
9 changed files with 107 additions and 29 deletions
+6 -1
View File
@@ -43,7 +43,7 @@ All are `GET`.
| Path | Returns |
|------|---------|
| `/api/dashboard/status` | Version, `code_hash`, bind host and port, `mode` (`full`, `api_only`, `remote_only`), uptime, `requests_total`, `requests_rejected` (401s), `requests_by_key` (label → count), configured service count (the same services as `/api/dashboard/services`), session count, `max_sessions` (`null` when the operator configured no limit), `session_ttl`, job counts by status. The service count includes services that failed to import - use `/api/dashboard/services` for the number that loaded. |
| `/api/dashboard/status` | Version, `code_hash`, bind host and port, `mode` (`full`, `api_only`, `remote_only`), uptime, `requests_total`, `requests_rejected` (401s), `requests_by_key` (label → count), `errors` (error counts by service tag, then by `error_code`), configured service count (the same services as `/api/dashboard/services`), session count, `max_sessions` (`null` when the operator configured no limit), `session_ttl`, job counts by status. The service count includes services that failed to import - use `/api/dashboard/services` for the number that loaded. |
| `/api/dashboard/sessions` | Every live remote session: `id`, `owner` (username or masked key), `creator_ip`, `service`, `title_id`, `titles`, `tracks`, `title` (the display name of the title the client is on: the last one it asked tracks for, else the first resolved title), `auth_status`, `auth_error`, `server_account` (the server profile lent to the remote session, else `null`), `server_cdm` (`false` when the client's own device licenses the remote session), `server_cdm_max_height` (the tallest video the server CDM licenses live, else `null`), `client`, `actions`, `created_at` and `last_accessed` (ISO 8601) with `created_ts` and `last_accessed_ts` (Unix epoch, the same clock as log `ts`), `age_seconds`, `idle_seconds`, `log_seq`. `client` is whatever the remote client sent as `client` in its session create request. The CLI sends `version`, `code_hash` (the commit the client runs, `null` when its source cannot be read), `platform` and `argv`. `argv` is the command line the user ran: proxy and URL userinfo, secret query parameters and credential values become `***`, home and install paths shorten as in the logs, and the line is cut at 3000 characters. An older client sends less or nothing and the field is `{}`. `log_seq` is the last sequence number in the remote session's service log - poll `/api/dashboard/sessions/{id}/logs` when it changes. `actions` is the session's request log, newest last, capped at 500: `ts`, `method`, `action` (`titles`, `tracks`, `segments`, `license`, `prompt`, …), `query`, `status`, `ms`, `bytes_in`, `bytes_out`. |
| `/api/dashboard/jobs` | Every download job with full detail, regardless of owner. Empty in `--remote-only` mode. |
| `/api/dashboard/logs` | `{"seq": N, "records": [...]}`: the last 1000 log records. `?since=<seq>` returns only newer records; `?level=WARNING` sets the minimum level; `?logger=serve` keeps one logger and its children (`aiohttp.access` is the noisiest). `ts` is a Unix epoch in seconds. |
@@ -54,6 +54,11 @@ All are `GET`.
| `/api/dashboard/health` | Preflight: whether this instance could finish a download. Cached 30 seconds. |
| `/api/dashboard/events` | Server-Sent Events stream. With `?since=<seq>` it returns `{"seq", "stats", "events": [...]}` instead: every event after `seq` (the server keeps the last 20000, log records included, so a poll every few seconds is safe even under a busy access log) as one JSON burst, so a UI that polls every few seconds still sees a remote session that opened and closed in between. |
`errors` counts every structured error response since the server started, for example
`{"EXAMPLE": {"SERVICE_ERROR": 4}, "-": {"SESSION_NOT_FOUND": 1}}`. The service is the one of
the remote session, else the `service` field of the JSON body. `-` holds an error with no
installed service. Each error also logs its [`ref`](errors.md#find-an-error-from-its-ref).
`requests_rejected` counts 401 responses; those never appear in `requests_by_key`. The
label is the `username` from the `users` entry when one is set, else the first four
characters of the API key.
+15 -2
View File
@@ -25,7 +25,8 @@ A structured error is always a JSON object with `status` set to the literal stri
{
"status": "error",
"error_code": "INVALID_PARAMETERS",
"message": "vcodec must be one of: H264, H265, ...",
"message": "vcodec must be one of: H264, H265, ... (ref 7f3a2c)",
"ref": "7f3a2c",
"timestamp": "2026-07-03T12:34:56.789012+00:00",
"details": { "field": "vcodec" },
"retryable": true,
@@ -40,7 +41,8 @@ A structured error is always a JSON object with `status` set to the literal stri
|---|---|---|---|
| `status` | string | Yes | Always the literal `"error"`. Lets a client distinguish an error body from a success body at a glance. |
| `error_code` | string | Yes | A stable, machine-readable code from the [catalogue below](#error-code-catalogue). Match on this, not on `message`. |
| `message` | string | Yes | A human-readable description of what went wrong. Wording may change between versions, so do not parse it. |
| `message` | string | Yes | A human-readable description of what went wrong, followed by `(ref <ref>)`. Wording may change between versions, so do not parse it. |
| `ref` | string | Yes | A short random reference for this one error. The server logs it with the request, so an operator can find the record from a user's report. |
| `timestamp` | string | Yes | ISO 8601 timestamp (UTC) of when the error response was built. |
| `details` | object | Only when non-empty | Structured, error-specific context (for example the invalid field, a list of available titles, or the set of currently active jobs). |
| `retryable` | boolean | Only when `true` | Present and set to `true` when retrying the same request may succeed later (network blips, rate limiting, transient outages). Absent otherwise. |
@@ -52,6 +54,17 @@ A structured error is always a JSON object with `status` set to the literal stri
every code maps to a default status (see the catalogue), and the pairing is
stable across releases.
### Find an error from its `ref`
For each error response, the server logs one `WARNING` line on the `api` logger:
```text
Error ref 7f3a2c: SERVICE_ERROR 422 POST /api/session/<id>/license service=EXAMPLE user=alice: Licence request failed: ...
```
Search the server log for `Error ref <ref>`. The handler's traceback, when there is one,
is directly above that line. The [developer dashboard](dashboard.md) log view also shows it.
### The `details` object
When present, `details` carries extra context specific to the error. It is only
+1 -1
View File
@@ -61,4 +61,4 @@ def test_compresses_large_json_when_accepted() -> None:
assert resp.headers.get("Content-Encoding") == "gzip"
decompressed = gzip.decompress(resp.body)
assert json.loads(decompressed) == big
assert resp.headers["Content-Length"] == str(len(resp.body))
assert resp.content_length == len(resp.body)
+3 -3
View File
@@ -73,7 +73,7 @@ def test_build_error_response_from_api_error() -> None:
body = _body(resp)
assert body["status"] == "error"
assert body["error_code"] == "SESSION_NOT_FOUND"
assert body["message"] == "no such session"
assert body["message"] == f"no such session (ref {body['ref']})"
assert body["details"] == {"session_id": "abc"}
assert "retryable" not in body
assert "debug_info" not in body
@@ -91,7 +91,7 @@ def test_build_error_response_from_generic_exception() -> None:
assert resp.status == 500
body = _body(resp)
assert body["error_code"] == "INTERNAL_ERROR"
assert body["message"] == "oops"
assert body["message"] == f"oops (ref {body['ref']})"
def test_build_error_response_debug_mode_includes_traceback() -> None:
@@ -188,6 +188,6 @@ def test_error_contract_apierror_passthrough_full_shape() -> None:
assert resp.status == 429
body = _body(resp)
assert body["error_code"] == "RATE_LIMITED"
assert body["message"] == "slow down"
assert body["message"] == f"slow down (ref {body['ref']})"
assert body["details"] == {"retry_after": 5}
assert body["retryable"] is True
+30 -1
View File
@@ -9,6 +9,7 @@ from __future__ import annotations
import asyncio
import json
from collections import Counter, defaultdict
import pytest
from aiohttp import web
@@ -132,7 +133,7 @@ async def test_api_handler_maps_apierror(aiohttp_client) -> None:
body = await resp.json()
assert body["status"] == "error"
assert body["error_code"] == "NOT_FOUND"
assert body["message"] == "nope"
assert body["message"] == f"nope (ref {body['ref']})"
assert body["details"] == {"x": 1}
@@ -180,6 +181,7 @@ async def test_heartbeat_late_error_counts_as_rejected(aiohttp_client, monkeypat
monkeypatch.setattr(routes, "HEARTBEAT_INTERVAL", 0.05)
monkeypatch.setattr(stats, "keys", {})
monkeypatch.setattr(stats, "errors", defaultdict(Counter))
@heartbeat
async def slow_fail(request: web.Request) -> web.Response:
@@ -195,6 +197,33 @@ async def test_heartbeat_late_error_counts_as_rejected(aiohttp_client, monkeypat
sent = len(await resp.read())
(entry,) = stats.keys.values()
assert resp.status == 200 and entry.rejected == 1 and entry.bytes_out >= sent > 0
assert stats.errors == {"-": {"SERVICE_ERROR": 1}}
@pytest.mark.parametrize(("service", "counted_as"), [("EXAMPLE", "EXAMPLE"), ("NOT_INSTALLED", "-")])
async def test_error_is_counted_by_service_and_logged_with_its_ref(
aiohttp_client, monkeypatch: pytest.MonkeyPatch, caplog: pytest.LogCaptureFixture, service: str, counted_as: str
) -> None:
"""A gzipped error still reaches the stats: counted under an installed service only, and logged with its ref."""
from unshackle.core.api.stats import stats, stats_middleware
monkeypatch.setattr(stats, "errors", defaultdict(Counter))
@api_handler
async def fail(request: web.Request) -> web.Response:
await request.json()
raise APIError(APIErrorCode.SERVICE_ERROR, "denied", details={"pad": "x" * 300})
app = web.Application(middlewares=[stats_middleware, compression_middleware])
app["debug_api"] = False
app.router.add_post("/fail", fail)
client = await aiohttp_client(app)
resp = await client.post("/fail", json={"service": service}, headers={"Accept-Encoding": "gzip"})
body = await resp.json()
assert resp.headers["Content-Encoding"] == "gzip"
assert stats.errors == {counted_as: {"SERVICE_ERROR": 1}}
assert f"Error ref {body['ref']}: SERVICE_ERROR 422 POST /fail service={counted_as}" in caplog.text
async def test_heartbeat_client_disconnect_is_quiet(
+3 -9
View File
@@ -49,12 +49,6 @@ async def compression_middleware(request: web.Request, handler) -> web.StreamRes
if not level:
return response
compressed = gzip.compress(body, compresslevel=level)
headers = dict(response.headers)
headers["Content-Encoding"] = "gzip"
headers["Content-Length"] = str(len(compressed))
return web.Response(
body=compressed,
status=response.status,
headers=headers,
)
response.body = gzip.compress(body, compresslevel=level)
response.headers["Content-Encoding"] = "gzip"
return response
+10 -2
View File
@@ -7,6 +7,7 @@ and optional debug information for the unshackle REST API.
from __future__ import annotations
import secrets
import traceback
from datetime import datetime, timezone
from enum import Enum
@@ -114,6 +115,9 @@ def build_error_response(
"""
Assemble a structured JSON error response.
Each error gets a short ``ref``, also appended to ``message`` so that every client prints it.
The stats middleware logs the ref with the request, so a reported ref finds the server-side record.
Args:
error: APIError or generic Exception to convert to response
debug_mode: Whether to include technical debug information
@@ -135,10 +139,12 @@ def build_error_response(
http_status = 500
retryable = False
ref = secrets.token_hex(3)
response_data: dict[str, Any] = {
"status": "error",
"error_code": error_code,
"message": message,
"message": f"{message} (ref {ref})",
"ref": ref,
"timestamp": datetime.now(timezone.utc).isoformat(),
}
@@ -161,7 +167,9 @@ def build_error_response(
response_data["debug_info"] = debug_info
return web.json_response(response_data, status=http_status)
response = web.json_response(response_data, status=http_status)
response["error"] = {"code": error_code, "ref": ref, "message": message}
return response
def categorize_exception(
+3 -2
View File
@@ -147,6 +147,7 @@ def heartbeat(handler: Handler) -> Handler:
log.exception(f"Error in {request.path}")
result = handle_api_exception(e, debug_mode=debug_mode)
response["late_status"] = result.status
response["error"] = result.get("error")
body = result.body if isinstance(result, web.Response) else None
await response.write(bytes(body) if isinstance(body, (bytes, bytearray)) else b"{}")
await response.write_eof()
@@ -2581,8 +2582,8 @@ async def dashboard_status(request: web.Request) -> web.Response:
---
summary: Dashboard server status
description: >
Version, uptime, bind address, mode, request counters per API key, and counts of
services, remote sessions and jobs. Every /api/dashboard/ route needs
Version, uptime, bind address, mode, request counters per API key, error counts by
service and error code, and counts of services, remote sessions and jobs. Every /api/dashboard/ route needs
`serve.dashboard.key` in X-Secret-Key; a user key never passes, and the routes do not
exist without a dashboard key.
tags: [Dashboard]
+36 -8
View File
@@ -7,7 +7,7 @@ import hashlib
import json
import logging
import time
from collections import Counter, deque
from collections import Counter, defaultdict, deque
from dataclasses import dataclass, field
from functools import lru_cache
from typing import Any, Deque, Dict, List, Optional, Tuple
@@ -143,6 +143,7 @@ class ServerStats:
requests_total: int = 0
requests_rejected: int = 0
keys: Dict[str, KeyStats] = field(default_factory=dict)
errors: Dict[str, Counter] = field(default_factory=lambda: defaultdict(Counter)) # service -> error_code -> count
def key_stats(self, key: Optional[str]) -> KeyStats:
"""The counters for an API key, created on first sight."""
@@ -194,6 +195,7 @@ class ServerStats:
"requests_total": self.requests_total,
"requests_rejected": self.requests_rejected,
"requests_by_key": dict(self.requests_by_key),
"errors": {service: dict(codes) for service, codes in self.errors.items()},
}
@@ -203,16 +205,18 @@ stats = ServerStats()
@web.middleware
async def stats_middleware(request: web.Request, handler: Any) -> web.StreamResponse:
from unshackle.core.api.handlers import request_secret_key
from unshackle.core.api.sanitize import sanitize_log
stats.requests_total += 1
started = time.perf_counter()
response = await handler(request)
status = response.get("late_status", response.status)
bytes_out = getattr(response, "content_length", None) or response.body_length
key = None if status == 401 else configured_key(request_secret_key(request))
if status == 401:
stats.requests_rejected += 1
else:
entry = stats.key_stats(configured_key(request_secret_key(request)))
entry = stats.key_stats(key)
entry.requests += 1
entry.last_seen = time.time()
entry.bytes_out += bytes_out
@@ -235,9 +239,33 @@ async def stats_middleware(request: web.Request, handler: Any) -> web.StreamResp
"bytes_out": bytes_out,
},
)
error = response.get("error")
if error:
service = await _request_service(request, session_id)
stats.errors[service][error["code"]] += 1
logging.getLogger("api").warning(
f"Error ref {error['ref']}: {error['code']} {status} {request.method} {sanitize_log(request.path)} "
f"service={service} user={sanitize_log(mask_key(key))}: {sanitize_log(error['message'])}"
)
return response
async def _request_service(request: web.Request, session_id: Optional[str]) -> str:
"""The installed service tag a request is for, from its remote session or its JSON body; ``-`` if none.
Only an installed tag counts, so a caller cannot grow ``stats.errors`` with made-up names.
"""
from unshackle.core.api.session_store import get_session_store
from unshackle.core.services import Services
entry = get_session_store().peek(session_id) if session_id else None
service = entry.service_tag if entry is not None else (await _consumed_json(request)).get("service")
if not isinstance(service, str):
return "-"
tag = Services.get_tag(service)
return tag if tag in Services.get_tags() else "-"
class SeqRing:
"""Keep the last N records in memory, each with a ``seq`` one above the record before it."""
@@ -347,20 +375,20 @@ def _reply_json(response: Any) -> Dict[str, Any]:
return data if isinstance(data, dict) else {}
async def _request_session_id(request: web.Request) -> Any:
"""The ``session_id`` of the JSON request body, when the handler consumed it: aiohttp caches that read.
async def _consumed_json(request: web.Request) -> Dict[str, Any]:
"""The JSON object of the request body when the handler consumed it (aiohttp caches that read), else ``{}``.
A body nobody read belongs to a call refused before the handler, a 401 or a 429. It stays
unread: reading it would spend time and memory on an unauthenticated caller, and wait on a
body that never finishes arriving.
"""
if not request.content.at_eof():
return None
return {}
try:
body = await request.json()
except Exception:
return None
return body.get("session_id") if isinstance(body, dict) else None
return {}
return body if isinstance(body, dict) else {}
async def _cdm_record(request: web.Request, drm: str, op: str, outcome: Any) -> Dict[str, Any]:
@@ -388,7 +416,7 @@ async def _cdm_record(request: web.Request, drm: str, op: str, outcome: Any) ->
elif op == "close":
session_id = request.match_info.get("session_id")
else:
session_id = await _request_session_id(request)
session_id = (await _consumed_json(request)).get("session_id")
return {
"drm": drm,
"op": op,