Turns telemetry into the log an operator reads: one line per request, plus the render lifecycle behind it.

Attached once from AudioProxy.Application.start/2. Nothing else in the tree calls Logger for request outcomes — a plug that wants its verdict logged says so in conn.assigns, and the render action says so by emitting AudioProxy.Telemetry events.

The request line

Driven by Bandit's own [:bandit, :request, :stop], which is one event per request with a real monotonic duration and the byte count as sent on the wire. Plug.Logger would cost two lines per request and could not see either. What the line says comes from conn.assigns, stashed upstream:

render 200 opts=br:96/f:opus src=local://piece.wav cache=MISS 18 bytes in 3.2ms
render 200 opts=f:mp3 src=local://long.wav cache=COALESCED 9600567 bytes in 3.1ms
render 422 invalid_options 61 bytes in 0.4ms
health 200 45 bytes in 0.1ms

The endpoint class leads (AudioProxy.Router assigns it), the error class follows the status when a request failed (AudioProxy.ErrorJSON assigns it), and the normalized options string, canonical source and coalescing status appear once the chain has got far enough to know them — a 401 knows none of them, and says so by omission rather than with placeholders. The second line above is why cache= is worth a column: it is a request that attached to a render already in flight, and without the field its duration reads as an impossibly fast encode. The request id is not in the line: Plug.RequestId puts it in Logger metadata, which the formatter renders on every line including the render lifecycle's, so correlation works across all of them rather than only this one.

Levels

2xx–4xx at info: a client error is a normal outcome for a public endpoint and an operator paging on 401s would learn to ignore the log. 5xx and timeouts at warning — those are the proxy's fault. /health, /ready and /metrics at debug, filtered here by endpoint class: probes every second and a scrape every fifteen would otherwise be the entire log, and splitting the router to avoid it would buy the same silence for more moving parts. That covers /ready's 503 too — a node declining work is the mechanism doing its job, not an incident.

AP_LOG_LEVEL sets the floor (AudioProxy.Config), so warning silences the happy path wholesale.

What is deliberately not attached

[:bandit, :request, :exception] — the mid-stream abort case. The render action has already emitted [:audio_proxy, :render, :exception] with the failure class, format and source by the time it exits, and Bandit logs the exit itself; a third line for one event would be noise. The cost is that a plug crash unrelated to a render produces Bandit's error report and no request line, which is a bug report either way.

A handler that raises is a handler that stops existing

:telemetry detaches a handler that raises, permanently and silently — so one malformed event does not lose one line, it loses every line for the life of the VM, and nothing says so. That makes total-ness the property this module cares about most, and it is defended twice.

Nothing here reads a field it has not proved is there: statuses that are not integers render as -, durations that are not integers as ?ms, absent metadata falls back rather than raising. Integer.to_string/1 on a status was the concrete bug — Bandit emits [:bandit, :request, :stop] with a conn but no status when a request dies of a protocol or transport error (Bandit.Pipeline's error path), and conn.status >= 500 did not even fail loudly on it: in Elixir's term order an atom sorts above every number, so nil >= 500 is true and a status-less request was already being levelled as a server error.

Behind that, handle_event/4 rescues anything it did not anticipate and logs a terse line about itself instead of dying. Swallowing an exception is normally the wrong instinct; here the alternative is losing the log wholesale, and the rescue still says what happened.

Redaction

detail on a render exception is the one field carrying text this application did not construct — an ffmpeg stderr tail. Today's inputs are local paths, but the S3 backend hands ffmpeg presigned URLs, and a diagnostic that echoed one would put a live X-Amz-Signature into log storage. redact/1 runs over every tail before it is logged, so the guarantee holds by construction rather than by an assumption about what ffmpeg prints. Everything else in a line is built from AudioProxy.Telemetry's metadata, which carries the canonical source and never the ffmpeg input.