amber-backend/docs/telemetry-contract.md
Claude 2e5ae66662 Telemetry contract: a session the app never saw end
Documents the amber-app change that records a film whose TV is switched off
with it on screen. session_summary gains ended (closed | unseen), lastSeenAt
and playedOn; a session held on disk and never closed is written once at the
next launch, with its one health row; a new error row, session_hold_failed,
records a hold that could not be written, released or read.

Includes the measurement that ruled out a lifecycle hook: on the kids' box
ff3bcf, 13 of 13 films in 14 days left no summary, with no callback at their
end and 0 of 3572 api_usage rows delivered late.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
2026-09-13 21:25:53 +02:00

9 KiB

Client diagnostics (client_logs)

Background diagnostics from prod devices (feedback 2 §4). The family runs Amber on hardware that can't be debugged directly, so the app batches a low-volume stream of events to the client_logs collection. Designed to be invisible on the device (in-memory ring buffer, slow best-effort flush, never on a playback thread) and safe (owner-create-only, superuser-read-only, redacted at source).

Collection client_logs

Migration 1788000000_client_logs.js. Fields: user (relation), kind, event, message, meta (json), appVersion, platform, device, ts (device clock), created (server clock).

Rules: create = owner (user = @request.auth.id); list/view/update/delete = null (superusers only). Retention: client_logs.pb.js cron trims rows older than 14 days nightly.

Event kinds

kind event meta
error uncaught {library} — Flutter framework errors
player exo_error {host, anime} — native player error
player av_delay_applied {audioMs, host} — user dialed in an audio offset (the "a track falls behind" signal)
session session_summary one row per playback — see below. Written only by SessionFeedbackService._write.
error session_hold_failed {op, sessionId} — an open session could not be held on disk; see below
qa qa_session {sid, lines[], truncated?} — the QA decision log for one playback (issue #92), off by default
source source_select one row per source sheet — timings and counts, see below
source source_pick what was chosen and what it beat — see below

host is only the stream's scheme://hostnever a full signed URL or an addon token (redacted client-side in TelemetryService.redactUrl before write).

source_pick — the row that answers "why did it play that one"

Added 2026-09-09, because a real complaint could not be answered without it. "Continue played a 1080p when a 4K was there" took an hour of reading the ranker and reproducing its arithmetic in a test; source_select records how long each stage took and how many candidates there were, and says nothing about which one won.

One row per automatic pick:

field meaning
stage known (a candidate was already probed) or the probing stage
outcome chosen / none
wonOn the term it beat the runner-up onlanguage, resolutionMatch, quality, identity… or only_candidate
res, resMeasured the winner's height, and whether that was measured or read off the filename
lang the winner's SourceRanker.languageTier: 5 confirmed primary audio · 4 claimed · 3 subtitles or fallback · 2 probed-unsuitable · 1 unprobed
czech dub / sub / absent, as the addon tagged it
quality, provider bitrate estimate; which addon it came from
prefHeight what the viewer asked for, so the pick can be judged against their preference rather than an assumption
alt* the best candidate it did NOT choose: altRes, altResMeasured, altLang, altProbed

altProbed=false with a higher altRes is the signature of the whole class: the better file existed and had not been measured yet, so it lost on language (unprobed is tier 1) before resolution was ever consulted.

It is not gated on QA logging, unlike qa_session. It used to be, to save re-scoring the field for the runner-up; that saving cost an hour of reconstruction the first time somebody asked a question it would have answered. The pass is arithmetic over a few dozen candidates, once per pick.

session_summary, and the two numbers that are not the same

{sessionId, title, probeKey, host, durationS, watchedS, positionS, stalls, droppedFrames, renderedFrames, maxConsecutiveDropped, problemAtS[], promptOutcome, rating?, ended, lastSeenAt?, playedOn?} plus the player's provenance fields (forcedAudio, sideloadedSubs, resumed, seeks, seekStormMax, codec/height/bitrate). ended and the two after it are explained in A session the app never saw end.

  • watchedS is elapsed watch-clock time. positionS is where playback got to. They differ whenever someone seeks, rewatches, or stares at a spinner — a session that never started reads watchedS: 48, positionS: 0.
  • sessionId is on every row, and is what joins a summary to its qa_session lines and to the amber-api health record.

Before 2026-08-07 this was written twice per Android playback, by the native player and by the feedback service, and the two disagreed: the extra row had no sessionId, title or probeKey, and put the position in watchedS. In one 14-day window that was 542 rows of which only 294 were real. Any aggregate over this collection computed before that date counts Android sessions twice, and rows older than the fix still carry the duplicate. sessionId:isset = true is the filter that excludes them.

A session the app never saw end (ended: unseen)

Added 2026-09-13 (amber-app, first in the build after 1.3.0+38). Until then the summary and the amber-api health row were written only when the player closed, and a box whose television is switched off with the film on screen never closes it. Measured on the kids' box Xiaomi MIBOX4 · ff3bcf: 13 of 13 films in 14 days left no summary and no health row. At the end of every one the 5 s position save ran at full rate up to the last 45 s api_usage tick and then stopped, and no row from the hide/pause flush arrived, then or at any later launch (0 of 3572 api_usage rows were delivered late). That box gives the app no callback, so a write on AppLifecycleState.paused would have recovered none of them.

Now both players hold the open session on disk every 10 s (<appSupport>/open_sessions/<sessionId>.json). A normal close writes as before and deletes the copy once the summary is in the telemetry spool. The next launch writes whatever is still held, through the same single writer, with:

field meaning
ended closed: the player closed and wrote it. unseen: a later launch wrote it from the held copy. Absent on older builds.
lastSeenAt unseen only. When the session was last held, device clock, UTC. The row's own ts and created are the later launch, often the next day.
playedOn unseen only, and only when it differs: the appVersion gitSha that played it, because a row is stamped with the build that sends it.

Reading an unseen row:

  • The counters stop at lastSeenAt, at most 10 s before the end, and promptOutcome is notShown.
  • It does not say how the session ended (TV switched off, power cut, crash, killed in the background), only that the app did not see it.
  • It arrives when the box is next started. A complaint made before that start has no row yet.
  • Its amber-api health row is sent at the same moment, once. A session that was held and then closed normally sends one health row, at the close.
  • A session killed within its first 10 s was never held and still leaves nothing.

kind: error, event: session_hold_failed, meta: {op, sessionId} records a hold that could not be written (put), let go of (release), read back (unreadable, the copy is deleted) or listed (recover). One row per session per op, so a full disk is one row, not one per tick.

How Claude queries it

Superuser token (same as releases publishing), then filter/sort the collection:

TOKEN=$(...auth as superuser...)
# recent player errors + desync signals across the fleet, newest first
curl -s "$PB/api/collections/client_logs/records?perPage=100&sort=-created&filter=$(python3 -c '
import urllib.parse;print(urllib.parse.quote("kind='"'"'player'"'"'"))')" \
  -H "Authorization: $TOKEN" | python3 -m json.tool

Useful filters: kind='player' (errors + desync), event='av_delay_applied' (who's fighting sync and by how much — the reported "track falls behind" bug), kind='session' && meta.stalls > 3 (hitchy playback). Group by device / platform / appVersion to see which hardware struggles.

What it deliberately does NOT capture (yet)

True per-track A/V PTS drift needs native instrumentation on both players (ExoPlayer exposes one clock; mpv would need audio-pts/video-pts sampling). v1 uses proxies: buffering-stall counts and the manual audio-delay the user applies to fix desync — which directly answers "is a track falling behind, on which sources/devices, and by how much". Deeper PTS sampling is a follow-up if the proxies point somewhere specific.

Privacy / kill switch

On by default; a per-device Settings toggle ("Diagnostika") disables it and drops the pending buffer. Only sends while signed in. No addon credential or full stream URL ever leaves the device.