Files
silo-server/internal/audiobooks/abs/play_response.go
203a18ae83 feat(observability): OpenTelemetry logs+traces with secret redaction and slog standardization (#290)
* feat(observability): OpenTelemetry logs+traces with secret redaction

Part of #265. Adds opt-in OpenTelemetry (logs + traces) alongside the existing
stderr + opslog pipeline, plus secret redaction on all sinks. Default-off: with
no OTEL_* / SILO_OTEL_ENABLED config, behavior is unchanged.

Bootstrap (internal/telemetry):
- Setup() builds one shared resource, a TracerProvider (parent-based trace-id
  ratio sampler), a LoggerProvider, and the W3C TraceContext+Baggage propagator
  from env. It installs NO MeterProvider — metrics stay on Prometheus, and the
  built-in no-op global MeterProvider keeps the trace instrumentation libs from
  double-emitting. Shutdown is deferred with a flush timeout.
- Logs are bridged via otelslog fan-out (slog.MultiHandler), level-gated by the
  shared LevelVar and best-effort so a failing collector can't break the console
  or DB branches. stderr + opslog stay untouched.

Secret redaction (internal/logredact):
- A slog.Handler masks secret-keyed attributes (password, token, api_key,
  authorization, cookie, ...) — including .With-bound attrs, nested groups,
  secret-keyed group subtrees, and values behind a LogValuer — on the console
  and OTLP sinks, with a no-op fast path when a record has no secret keys.
  opslog.shouldRedact delegates to logredact.SecretKey so all sinks share one
  marker list.

Rotation is infra-managed (no custom file sink): container runtime for stderr,
collector/backend for OTLP, opslog partition-pruning for the DB. Documented in
docs/architecture/observability.md.

Verification: go build ./..., go vet, gofmt -l — clean; go test
./internal/telemetry/ ./internal/logredact/ -race pass.

AI-use disclosure: implemented with AI assistance (Claude Code), including
adversarial reviews that hardened the bootstrap and fixed two redaction leak
paths; reviewed by the author.

* refactor(observability): slog context+component sweep, sloglint gate (phase 3)

Part of #265. Builds on the OTel bootstrap + redaction commit.

Standardizes every log call site onto the context-carrying slog variants so
records correlate with the active OpenTelemetry trace, and locks the standard
in with a machine gate so future code (human- or AI-authored) can't drift back.

- Call-site sweep: converted the remaining slog.<Level>(...) calls to the
  slog.<Level>Context(ctx, ...) form wherever a context.Context is in scope
  (background/init calls with no ctx are left as-is), across 183 files. Applied
  via a type-aware AST codemod. Log levels and message strings are preserved
  verbatim; a component attr (canonical per-package name) is added to direct
  package-level slog calls. Bound-logger calls keep their existing .With
  bindings. The main.go and telemetry package conversions rode with their file
  in the previous commit to keep each file within a single commit.
- Enforcement (.golangci.yml): enable sloglint with context=scope, static-msg,
  key-naming-case=snake, no-mixed-args. After the sweep all four report zero
  violations repo-wide (tests included), so make lint / CI now blocks any
  regression to the non-context form. The gate ships with the sweep because it
  cannot be green until the legacy sites are converted.

Metrics remain on Prometheus; no behavior change to /metrics or Grafana.

Verification: go build ./..., go vet ./..., gofmt -l — clean; sloglint (all 4
rules) 0 violations repo-wide; log levels verified unchanged.

AI-use disclosure: implemented with AI assistance (Claude Code), including the
codemod; reviewed by the author.

* fix(observability): honor per-signal OTLP protocol and secret WithGroup names

Two Codex review findings on PR #290:

- telemetry: OTEL_EXPORTER_OTLP_{TRACES,LOGS}_PROTOCOL now override the
  generic OTEL_EXPORTER_OTLP_PROTOCOL per signal, so mixed collector
  setups (e.g. HTTP logs + gRPC traces) build the right exporter.
- logredact: entering a group whose name is secret-bearing (e.g.
  WithGroup("authorization")) now masks every leaf in that subtree,
  matching how slog.Group("authorization", ...) is masked as a whole.

* fix(observability): address review feedback on telemetry bootstrap

- Telemetry setup failure no longer kills boot: Setup returns usable
  no-op providers alongside the error and main logs and continues with
  telemetry disabled, honoring the best-effort contract.
- Honor OTEL_TRACES_SAMPLER (always_on/off, traceidratio, parentbased_*
  variants); unsupported values fall back to parentbased_traceidratio.
- Attach node identity as semconv service.instance.id instead of the
  non-semconv node.name.
- Rename opslog retention-scope log attrs to target_component/target_level
  so they no longer collide with the canonical component routing key, and
  tag those lines with component=opslog.
- Fix stale levelGated comment casing; use WarnContext in the telemetry
  shutdown defer; document the LogValuer double-resolve on the redaction
  slow path.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>

---------

Co-authored-by: Quick <31828688+Quick104@users.noreply.github.com>
Co-authored-by: Claude Fable 5 <noreply@anthropic.com>
2026-07-09 08:53:52 -04:00

536 lines
16 KiB
Go

package abs
import (
"context"
"log/slog"
"net/http"
"path/filepath"
"strconv"
"strings"
"time"
"unicode"
"github.com/go-chi/chi/v5"
"github.com/oklog/ulid/v2"
"github.com/Silo-Server/silo-server/internal/models"
)
// handlePlayStart handles POST /abs/api/items/{libraryItemId}/play.
//
// Real ABS clients hit this endpoint to start a playback session and get back
// a manifest of audio tracks with signed contentUrls. The response includes
// the full playbackSession shape the mobile player reads to seed the audio
// element: currentTime (resume position), audioTracks, mediaMetadata,
// libraryItem, chapters, etc.
//
// Silo's implementation:
// - Looks up the audiobook via MediaStore.GetAudiobookByID.
// - Loads all media files via MediaStore.GetMediaFiles (sorted by ID ASC).
// - Synthesises a ULID session ID (in-memory; no play-session table yet).
// - Builds contentUrls that point at the session-scoped public track route,
// avoiding bearer tokens in URLs while preserving ABS DirectPlay behavior.
// - Returns a JSON playbackSession matching the shape real ABS emits, with
// enough fields populated that the official mobile client plays without
// entering "spinner forever" mode.
func (h *Handler) handlePlayStart(w http.ResponseWriter, r *http.Request) {
a, ok := absAuthFrom(r)
if !ok || a.UserID == "" {
http.Error(w, "unauthorized", http.StatusUnauthorized)
return
}
contentID := chi.URLParam(r, "libraryItemId")
access, err := h.accessFilterForAuth(r.Context(), a)
if err != nil {
http.Error(w, "resolve access: "+err.Error(), http.StatusForbidden)
return
}
item, err := h.deps.MediaStore.GetAudiobookByID(r.Context(), contentID, access)
if err != nil || item == nil {
http.Error(w, "item not found", http.StatusNotFound)
return
}
files, err := h.deps.MediaStore.GetMediaFiles(r.Context(), contentID, access)
if err != nil {
http.Error(w, "load files failed", http.StatusInternalServerError)
return
}
// currentTime seeds the audio element's initial position so cross-device
// resume works. Lookup is best-effort: any error returns position 0,
// which is always correct for a first listen.
//
// Note: we deliberately do NOT emit a "progress" (0.0-1.0) field on the
// play session response. The canonical continuum-plugin handler omits it
// too — "progress" belongs to /me/progress responses, not playbackSession.
// The spec's Phase 0 row mentioning "currentTime AND progress fields" was
// over-specified; matching the canonical wire shape is the load-bearing
// requirement.
var currentTime float64
currentTime, err = resolveResumeTime(r.Context(), h.deps.ProgressStore, a.UserID, a.ProfileID, contentID)
if err != nil {
slog.DebugContext(r.Context(), "play: progress lookup failed", "component", "audiobooks", "user", a.UserID, "item", contentID, "err", err)
// currentTime is already 0 on error path; safe to continue.
}
// The {ino} parameter used by handleFileStream is a 0-based file index, but
// we want iOS clients to resolve it via the stable MD5 derivation. Emit inos
// that handleFileStream can reverse without a database lookup.
baseURL := h.absBaseURL(r)
sessionID := ulid.Make().String()
if nativeSession, err := h.startNativePlaybackSession(r, a, files, currentTime); err != nil {
writeNativePlaybackStartError(w, err)
return
} else if nativeSession != nil {
sessionID = nativeSession.ID
}
// Persist the session row so subsequent PATCH /session/{sid} heartbeats
// and POST /session/{sid}/close can find it. Without this, the session
// ID is returned to the client but every sync/close lookup 404s.
if h.deps.PlaybackSessionStore != nil {
sess := ABSPlaybackSession{
ID: sessionID,
UserID: a.UserID,
ProfileID: a.ProfileID,
ContentID: contentID,
CurrentPositionSeconds: currentTime,
}
if len(files) > 0 {
fid := files[0].ID
sess.MediaFileID = &fid
}
if err := h.deps.PlaybackSessionStore.InsertPlaybackSession(r.Context(), sess); err != nil {
// Non-fatal: log but still return the manifest so the client
// can play. Heartbeat/close calls will fail with 404 until the
// next play_start lands cleanly.
slog.WarnContext(r.Context(), "abs play: persist session failed", "component", "audiobooks",
"session_id", sessionID, "content_id", contentID, "err", err)
}
}
audioTracks := buildSiloAudioTracks(contentID, files, baseURL, sessionID)
totalDuration := float64(0)
for _, t := range audioTracks {
totalDuration += t.Duration
}
chapters := buildSiloChapters(files)
mediaMetadata := buildSiloPlayMediaMetadata(item)
libraryItem := buildSiloPlayLibraryItem(item, contentID, mediaMetadata, audioTracks, chapters, totalDuration, baseURL)
displayTitle := item.Title
displayAuthor := ""
if v, ok := mediaMetadata["authorName"].(string); ok {
displayAuthor = v
}
now := time.Now()
nowMs := now.UnixMilli()
dateStr := now.UTC().Format("2006-01-02")
dayOfWeek := now.UTC().Weekday().String()
playbackSession := map[string]any{
"id": sessionID,
"userId": a.UserID,
"libraryId": VirtualLibraryID,
"libraryItemId": contentID,
"bookId": contentID,
"episodeId": nil,
"mediaType": LibraryMediaType,
"mediaMetadata": mediaMetadata,
"chapters": chapters,
"displayTitle": displayTitle,
"displayAuthor": displayAuthor,
"coverPath": baseURL + "/api/items/" + contentID + "/cover",
"duration": totalDuration,
"playMethod": 0, // DIRECTPLAY
"mediaPlayer": "exo-player",
"deviceInfo": map[string]any{
"deviceId": "unknown",
"manufacturer": "Unknown",
"model": "Unknown",
"sdkVersion": 0,
"clientVersion": "0.0.0",
},
"serverVersion": ServerVersion,
"date": dateStr,
"dayOfWeek": dayOfWeek,
"timeListening": 0,
"startTime": currentTime,
"currentTime": currentTime,
"startedAt": nowMs,
"updatedAt": nowMs,
"audioTracks": audioTracks,
"libraryItem": libraryItem,
}
writeJSON(w, http.StatusOK, playbackSession)
}
// buildSiloAudioTracks converts silo media_files into the ABS AudioTrack
// slice. Each track's contentUrl points at the short-lived session public
// track route so bearer tokens are never embedded in URLs.
func buildSiloAudioTracks(
contentID string,
files []*models.MediaFile,
baseURL string,
sessionID string,
) []AudioTrack {
tracks := make([]AudioTrack, 0, len(files))
startOffset := float64(0)
for i, f := range files {
ino := trackInoFor(contentID, i)
ext := strings.ToLower(filepath.Ext(f.FilePath))
format := strings.TrimPrefix(ext, ".")
mimeType := audioContentType(ext)
if mimeType == "" {
mimeType = "audio/mpeg"
}
filename := filepath.Base(f.FilePath)
// ABS wire index is 1-based to match the real server's convention.
// Our ino uses 0-based internally; handleFileStream resolves via ino.
wireIndex := i + 1
contentURL := baseURL + "/abs/public/session/" + sessionID + "/track/" + strconv.Itoa(wireIndex)
duration := float64(f.Duration) // f.Duration is in seconds (int)
var bitRate int
if f.Bitrate > 0 {
bitRate = f.Bitrate * 1000 // kbps → bps
} else {
bitRate = 128000
}
channels := f.AudioChannels
if channels == 0 {
channels = 2
}
codec := f.CodecAudio
channelLayout := "stereo"
if channels > 2 {
channelLayout = "surround"
}
nowMs := time.Now().UnixMilli()
track := AudioTrack{
Index: wireIndex,
Ino: ino,
Metadata: &AudioTrackMetadata{
Filename: filename,
Ext: ext,
Path: f.FilePath,
RelPath: filename,
Size: f.FileSize,
MtimeMs: 0,
CtimeMs: 0,
BirthtimeMs: 0,
},
AddedAt: nowMs,
UpdatedAt: nowMs,
TrackNumFromMeta: nil,
DiscNumFromMeta: nil,
TrackNumFromFilename: nil,
DiscNumFromFilename: nil,
ManuallyVerified: false,
Exclude: false,
Error: nil,
Format: format,
Duration: duration,
BitRate: bitRate,
Language: nil,
Codec: codec,
TimeBase: "1/14112000",
Channels: channels,
ChannelLayout: channelLayout,
Chapters: []ChapterABS{},
EmbeddedCoverArt: nil,
MetaTags: map[string]string{},
MimeType: mimeType,
Title: filename,
StartOffset: startOffset,
ContentURL: contentURL,
}
tracks = append(tracks, track)
startOffset += duration
}
return tracks
}
// buildSiloChapters extracts chapters from the first media file that has them.
// ABS expects chapters as a flat list spanning the whole book; for multi-file
// audiobooks we only use the first file's chapters (most single-file M4B
// audiobooks have embedded chapters; multi-MP3 sets rarely do).
func buildSiloChapters(files []*models.MediaFile) []map[string]any {
for _, f := range files {
if len(f.Chapters) == 0 {
continue
}
chapters := make([]map[string]any, 0, len(f.Chapters))
for i, c := range f.Chapters {
chapters = append(chapters, map[string]any{
"id": i,
"start": c.StartSeconds,
"end": c.EndSeconds,
"title": c.Title,
})
}
return chapters
}
return []map[string]any{}
}
// buildSiloPlayMediaMetadata builds the playbackSession.mediaMetadata object
// from a silo MediaItem. The mobile player reads this for the "Now Playing"
// widget and playback history; missing keys cause the audio loader to abort.
func buildSiloPlayMediaMetadata(item *models.MediaItem) map[string]any {
title := item.Title
authors := make([]map[string]any, 0)
authorNames := make([]string, 0)
narrators := make([]string, 0)
for _, p := range item.People {
switch p.Kind {
case models.PersonKindAuthor:
authors = append(authors, map[string]any{
"id": strconv.FormatInt(p.ID, 10),
"name": p.Name,
})
authorNames = append(authorNames, p.Name)
case models.PersonKindNarrator:
narrators = append(narrators, p.Name)
}
}
authorName := strings.Join(authorNames, ", ")
lastFirsts := make([]string, len(authorNames))
for i, n := range authorNames {
lastFirsts[i] = toLastFirst(n)
}
authorNameLF := strings.Join(lastFirsts, ", ")
publishedYear := ""
if item.Year > 0 {
publishedYear = strconv.Itoa(item.Year)
}
genres := item.Genres
if genres == nil {
genres = []string{}
}
series := make([]map[string]any, 0, len(item.AudiobookSeries))
seriesNames := make([]string, 0, len(item.AudiobookSeries))
for _, membership := range item.AudiobookSeries {
name := strings.TrimSpace(membership.Name)
if name == "" {
continue
}
obj := map[string]any{"id": name, "name": name}
if membership.Index != nil {
obj["sequence"] = strconv.FormatFloat(*membership.Index, 'f', -1, 64)
}
series = append(series, obj)
seriesNames = append(seriesNames, name)
}
var publisher any
if len(item.Studios) > 0 && strings.TrimSpace(item.Studios[0]) != "" {
publisher = strings.TrimSpace(item.Studios[0])
}
return map[string]any{
"title": title,
"titleIgnorePrefix": titleIgnorePrefix(title),
"subtitle": nil,
"authors": authors,
"authorName": authorName,
"authorNameLF": authorNameLF,
"narrators": narrators,
"narratorName": strings.Join(narrators, ", "),
"series": series,
"seriesName": strings.Join(seriesNames, ", "),
"genres": genres,
"tags": []string{},
"publishedYear": publishedYear,
"publishedDate": nil,
"publisher": publisher,
"description": nilIfEmpty(item.Overview),
"descriptionPlain": nilIfEmpty(stripHTML(item.Overview)),
"isbn": nil,
"asin": nil,
"language": "en",
"explicit": false,
"abridged": false,
}
}
// buildSiloPlayLibraryItem builds the playbackSession.libraryItem nested
// object. The mobile player reads libraryItem.media.tracks /
// libraryItem.media.metadata / libraryItem.libraryFiles for offline download
// decisions and UI rendering.
func buildSiloPlayLibraryItem(
item *models.MediaItem,
contentID string,
mediaMetadata map[string]any,
audioTracks []AudioTrack,
chapters []map[string]any,
totalDuration float64,
baseURL string,
) map[string]any {
firstIno := contentID
if len(audioTracks) > 0 {
firstIno = audioTracks[0].Ino
}
totalSize := int64(0)
libraryFiles := make([]map[string]any, 0, len(audioTracks))
for _, t := range audioTracks {
nowMs := time.Now().UnixMilli()
libraryFiles = append(libraryFiles, map[string]any{
"ino": t.Ino,
"metadata": t.Metadata,
"isSupplementary": false,
"addedAt": nowMs,
"updatedAt": nowMs,
"fileType": "audio",
})
if t.Metadata != nil {
totalSize += t.Metadata.Size
}
}
addedAtMs := int64(0)
if item.AddedAt != nil {
addedAtMs = item.AddedAt.UnixMilli()
}
updatedAtMs := item.UpdatedAt.UnixMilli()
return map[string]any{
"id": contentID,
"ino": firstIno,
"oldLibraryItemId": nil,
"libraryId": VirtualLibraryID,
"folderId": VirtualFolderID,
"path": contentID,
"relPath": contentID,
"isFile": true,
"mtimeMs": nil,
"ctimeMs": nil,
"birthtimeMs": nil,
"addedAt": addedAtMs,
"updatedAt": updatedAtMs,
"lastScan": addedAtMs,
"scanVersion": ServerVersion,
"isMissing": false,
"isInvalid": false,
"mediaType": LibraryMediaType,
"media": map[string]any{
"id": contentID,
"libraryItemId": contentID,
"metadata": mediaMetadata,
"coverPath": baseURL + "/api/items/" + contentID + "/cover",
"tags": []any{},
"audioFiles": audioTracks,
"chapters": chapters,
"ebookFile": nil,
"duration": totalDuration,
"size": totalSize,
"tracks": audioTracks,
},
"libraryFiles": libraryFiles,
// size on the outer libraryItem is a STRING in real ABS wire format —
// mobile sort comparators string-compare it.
"size": strconv.FormatInt(totalSize, 10),
}
}
// ---------------------------------------------------------------------------
// Play response helpers
// ---------------------------------------------------------------------------
// nilIfEmpty returns nil when s is blank, otherwise the string itself.
// This mirrors the plugin's pattern: ABS clients treat null and ""
// differently on some fields (publisher, description, isbn, etc.).
func nilIfEmpty(s string) any {
if strings.TrimSpace(s) == "" {
return nil
}
return s
}
// titleIgnorePrefix strips leading articles for sort-key purposes,
// matching real ABS LibraryItemController behaviour.
func titleIgnorePrefix(title string) string {
lower := strings.ToLower(title)
for _, p := range []string{"the ", "a ", "an "} {
if strings.HasPrefix(lower, p) {
return title[len(p):]
}
}
return title
}
// toLastFirst converts "First Last" → "Last, First" for the authorNameLF
// field the mobile "Now Playing" widget renders.
func toLastFirst(name string) string {
parts := strings.Fields(name)
if len(parts) < 2 {
return name
}
return parts[len(parts)-1] + ", " + strings.Join(parts[:len(parts)-1], " ")
}
// stripHTML removes HTML angle-bracket tags from a description so the mobile
// "Now Playing" body renderer doesn't have to. Cheap and good enough for
// the descriptions silo metadata sources produce.
func stripHTML(s string) string {
if s == "" {
return ""
}
var b strings.Builder
inTag := false
for _, r := range s {
switch {
case r == '<':
inTag = true
case r == '>':
inTag = false
case !inTag:
if !unicode.IsControl(r) {
b.WriteRune(r)
}
}
}
return strings.TrimSpace(b.String())
}
// resolveResumeTime returns the persisted currentTime for (userID, profileID,
// contentID) from the progress store, or 0 when no row exists / store is nil.
// Returned error is propagated so callers can log it; the caller is expected
// to fall back to 0 on error (a fresh-listen start is always correct).
func resolveResumeTime(ctx context.Context, store ProgressStore, userID, profileID, contentID string) (float64, error) {
if store == nil {
return 0, nil
}
row, err := store.GetProgress(ctx, userID, profileID, contentID)
if err != nil {
return 0, err
}
if row == nil {
return 0, nil
}
return row.CurrentSeconds, nil
}