Commit Graph
11 Commits
Author SHA1 Message Date
peter 3c16012524 build(backend): close the lint gaps the E32 audit measured
ruff gains RUF100, PLW1510 and flake8-bugbear, every hit fixed rather than
ignored. B008 stays on with FastAPI's Depends/Query declared immutable.
basedpyright moves to standard mode, pytest to --strict-markers, and a hand
run of pytest now requires the database unless SIFTLODE_TEST_REQUIRE_DB=0.

PLW1510 found a real bug: the three ffprobe probes in plex/stream.py never
looked at the exit status, so a probe that failed was read as the file's
truth (an HDR source sent down the HW-safe path, a multi-audio file collapsed
to one track, a subtitle offset taken from garbage) and the warning each
except branch promises never fired. They now run with check=True.
2026-10-03 16:04:06 +02:00
peter 89c77ae6b5 fix(logs): deep-review round 3 — a failure nobody could record is one scrubbed line
- The download and edit failure lines go back after their DB write: a job the
  write could not fail is not a failed job, and the worker's child_exit line
  already says it failed.
- The download child's runner is the last stop before Python's hook: an
  escaping exception is one download.child.failed line with its chain scrubbed,
  then exit 1, instead of a raw stderr traceback carrying the URL.
- A crash the database will not record carries its stack once, and the
  fail-write line has an event code.
- The job's own generic-extractor name is taken out as a literal (formats.hiding),
  so brackets and colons in a direct link's file name no longer leak; the
  pattern stays as the fallback. `Downloading just the video <id>` is covered.
- Tests: scrubbed_stack's cause, suppress, unprintable and text-format paths,
  the image steps' failure kinds, the watchdog error through the real
  _fail_running, exact poster/storyboard messages, ffmpeg skip marker.
2026-09-18 23:44:42 +02:00
peter 54d19cc386 fix(logs): deep-review round 1 — say each failure once, and scrub it everywhere
- yt-dlp's text is scrubbed wherever it is logged, not only in the adapter:
  `formats.log_safe` takes out the URL, the `[extractor] <id>:` prefix and
  file paths, and the job-failed, refused, edit-failed and backfill lines use
  it. Done lines log the asset id, not the title-built path. The PII contract
  now bans `rel`/`rel_path`/`title`.
- A traceback goes with a download/edit failure only when it is our own code
  failing; for yt-dlp's DownloadError, our RuntimeErrors and OSErrors its foot
  is the unscrubbed message.
- yt-dlp's `error` maps to WARNING: it fires on attempts the fallback client
  set recovers from; the job's verdict is `download.job.failed`.
- The sink groups a bare `%s` pass-through by its text (numbers folded), and
  a process's last batch closes the repeat window, so a short-lived download
  child still reports what it dropped.
- Worker-side failures (stall, wall-clock, no asset, cached asset error) log
  `download.job.failed` with a cause; they left no line at all before. The
  crash, supervisor-error and non-zero-exit lines carry the code too.
- An edit failure is one coded line in `_fail_edit`, for every path.
- `logs.get_logger("__main__")` resolves to the `-m` module, so the worker
  and the download child keep their names.
- TRACE lines carrying user content are gated on `logs.consented_trace()`,
  not on the process level; a contract test pins it.
- The OAuth token refresh goes through `_upstream_failure`; transport errors
  carry reason `transport`. Subscribe recognises a duplicate by reason code
  only (the prose fallback was dead).
- Once-only guards for a stale sysconfig override and a refusing HLS session
  directory; item_detail splits Plex failures from our own parse bugs.
- The playlist breaker line names the playlist and the action; comments that
  were false (runner noqa, `_merge_vtt`, sink grouping) are corrected.
2026-09-18 03:16:15 +02:00
peter 0cff964ff2 refactor(logs): name every logger after its module, and hold it there
25 literal names covered 34 modules. plex/client.py, plex/stream.py,
plex/subtitles.py, plex/sync.py and two Plex route modules all called themselves
`siftlode.plex`; downloads/pipeline.py called itself `siftlode.worker`;
routes/channels.py called itself `siftlode.api`. The `logger` column is in every
stored row so E22.6's console can filter on it, and so an operator can pin a level
to one part of the system — neither works when six modules share a name.

`logs.get_logger(__name__)` derives it: app/plex/sync.py -> siftlode.plex.sync.
One name per module, and it cannot drift from the file it sits in.
tests/test_logger_names.py pins the derivation, that everything stays under the
one `siftlode` tree the handler and the tests attach to, and that no module
hand-rolls a name again unless the line says why (`# logger-name-ok: <why>`).
Two do: get_logger's own call, and `siftlode.http`, which is named for the traffic
it carries rather than the module it lives in — it replaced uvicorn's access log
and is what an operator pins when they want request lines and nothing else.

app/scheduler.py called its logger `logger`; every other module calls it `log`.

ruff gains LOG, G, T20, TRY400, TRY401 and S112. Four findings cleared with them:
worker.py logged `str(exc)[:120]` where the traceback was the whole question, and
three prints/f-strings that are deliberate now say so on the line. S110 and BLE001
stay off until S3 — 23 handlers are outstanding and each is a judgement about one
of them; enabling the rules first would just mean 23 blanket noqas.
2026-09-18 00:57:57 +02:00
peter b59fd38a9c feat: store warnings and request lines in log_events
The log now has a stored, queryable copy for the diagnostics console:
every WARNING and above plus the request line of every request, kept
for log_retention_days (default 7, no "forever") and pruned hourly by
the new log_gc job.

Rows are built on the logging thread from the same redacted fields as
the stdout line, queued without blocking and written in batches by one
background thread on its own connection. A full queue or a failed write
drops and reports instead of retrying. Flood control keeps 30 of any
one message per minute plus a count of the rest; anonymous request
lines are capped at 60 a minute per client, and the client address is
never stored. Deleting an account deletes its stored events.

Measured on prod first: a YouTube RSS outage wrote 11k warnings in four
hours, one per channel per poll. The poll now writes one warning with
per-reason counts and a few examples, and a failure on our side gets
one traceback per poll instead of one per channel.
2026-09-17 00:20:14 +02:00
peter 6c63df6704 feat: one structured log for every process, with a request id
A deployment printed four different log formats and none of them could be
joined up: uvicorn's log_config.json for the API, a hand-rolled StreamHandler in
main.py for anything not started by uvicorn, logging.basicConfig() in the worker
and in the download child (no timestamp at all), and alembic's fileConfig.
app/logs.py replaces all four with one JSON line per event (OpenTelemetry's log
data model, no SDK): ts, level, severity, source, logger, event code, message,
attributes, plus the correlation the context carries — request id, account,
download job.

Redaction is applied at the HANDLER, not at the call sites: every message, every
attribute and every traceback is scrubbed on the way out, so a secret cannot
leak by being forgotten at one of ~125 call sites. Passwords, tokens, cookies,
secret config values and email addresses never reach a line.

The access log is ours now (`http.request`): the route template instead of the
concrete path, the status, the duration and the account — and never the query
string, which uvicorn's access log printed on every single request (`?account=`,
`?source=`, the `?token=` of a share link). A well-formed client request id is
accepted and echoed in X-Request-Id, so a browser line and a server line join up.
The account comes from `request.state`, filled by the auth dependency: the
middleware is the outermost one, so it runs outside SessionMiddleware and in a
different task context.

`log_level` becomes an admin knob (sysconfig), applied without a restart and
re-applied at startup — best-effort on purpose, since a logging knob must never
be what stops the app from booting. Every compose service gets bounded json-file
logs (3×50 MB): Docker keeps every line forever by default, and the API now
writes one line per request.

Verified on the localdev stack: JSON everywhere including alembic and the
worker, the query strings gone, a supplied X-Request-Id echoed and logged, and
three /healthz hits of which only the one made while the level was DEBUG
produced a line.
2026-09-16 01:37:02 +02:00
peter bc33b2ed16 feat(downloads): per-user, per-host yt-dlp cookie/auth support (S6)
Each user stores their own login cookies (Netscape cookies.txt) for an
auth-walled download host (Facebook, Instagram, X, TikTok, Reddit) in
Settings; a download of an auth-walled link on that host is retried with
the acting user's cookie.

Two load-bearing security controls, both in downloads.credentials as the
single source of truth so enqueue and the worker can't drift:
- cache privacy: a cookie-authed download salts its MediaAsset format_sig
  with the user id, so the authed asset is private and never cache-served
  to another user. The worker attaches a cookie ONLY when the asset it is
  downloading into IS that private, salted identity.
- host scope (SEC-12): a cookie is resolved only for a URL whose netloc
  the credential owns (netloc-scoped _host_is); a look-alike/unrelated
  host gets none.

cookies_enc is Fernet-encrypted at rest, only decrypted in-worker into a
0600 file under staging/.auth/ (survives the retry wipe + _produced_file
scan) and unlinked in finally. The blob is never returned by a route,
logged, audited, or written to a job's error/snapshot. cookiefile is set
after the adapter's extra merge so an adapter can't clobber it. Settings
UI is write-only (host + set/updated only, never echoed). New
download_credentials table + migration 0074; per-user routes; HU+EN i18n.

Tests: host-scope, cache-privacy (no cross-user serve), encrypt-at-rest,
write-only API, worker attach-gate; FE dom test for the write-only field.
2026-08-28 03:53:04 +02:00
peter 9ae6c47d6c perf(downloads): de-prioritize worker transcodes + idle-back-off polls to stop LAN slowdown
The download/edit child (yt-dlp + ffmpeg) shares one LAN box with the API,
Postgres, and Plex playback. A CPU re-encode pegged every core for ~30s and
starved web requests + playback until it finished. Full-scope S4 mitigations:

- Child self-de-prioritizes at startup (inherited by every ffmpeg/yt-dlp
  descendant): CPU nice increment + best-effort idle ionice class + an
  OMP_NUM_THREADS budget, all config-gated and independently disable-able.
- Cap the browser-safe re-encode's encoder threads (`-threads`) so a transcode
  reserves a core for foreground work instead of claiming all of them.
- Throttle the retention GC's whole-tree orphan sweep (yield IO after each
  batch of files) so its rglob can't monopolize disk IO in the API process.
- Idle-back-off the Download Center (2s→15s when nothing queued/running) and
  UsageBar (2s→15s when running_jobs is 0) polls; both snap back to 2s on the
  next fetch after an enqueue (invalidateDownloads refetches immediately).

Tests: encode_thread_cap (pin/reserve-core/edge), -threads flag presence,
_deprioritize (nice/ionice/OMP branches), GC sweep throttle batching.
2026-08-28 02:37:56 +02:00
peter b1832afd18 style: apply ruff format across backend + scripts (line-length 100)
Mechanical, whole-tree `ruff format` pass — no behaviour change. Recorded in
.git-blame-ignore-revs (next commit) so git blame skips it.
2026-08-23 07:43:06 +02:00
peter b2013a079a refactor(downloads): split worker.py parent/child into pipeline.py + jobdb.py (E3 S2, B-sub-9)
worker.py (~1090 L) mixed the PARENT supervisor (claim + supervise + the process
loop) with the CHILD pipeline (the yt-dlp/ffmpeg download+edit that runs in the
spawned subprocess). Extract them:

  worker.py  1090 -> 475   parent: claim/supervise/loop
  downloads/pipeline.py  (new 592)  the child pipeline (_download/_process_edit +
                                    hooks/progress/ffmpeg helpers + _Aborted)
  downloads/jobdb.py     (new  73)  the short-lived-session helpers both sides
                                    share (_set_job/_job_status/_touch_job/
                                    _requeue_if_running/_reset_asset_pending +
                                    the staging-dir paths)

The graph is one-directional (runner -> pipeline -> jobdb; worker -> jobdb; no
worker<->pipeline edge) — the parent never calls the child directly, it spawns
runner.py as a subprocess. Consumers rewired: runner import, and two tests follow
the moved symbols (_media_info/_produced_file -> pipeline; the ffmpeg-callback
patches target pipeline where the names are looked up).

Pure code motion, verbatim bodies. ruff clean, full lane 363 pass (unchanged).
2026-08-18 21:58:23 +02:00
peter 0ed82fe6b6 feat(downloads): run each download/edit in a supervised child process with a hard-kill watchdog
Defense-in-depth after the ReDoS incident. The heavy work (yt-dlp download / ffmpeg edit)
now runs in a child process (app.downloads.runner) supervised by the worker thread, not in
the thread itself. A thread can't be killed and a C-level spin can't even be cooperatively
cancelled, so one wedged download used to pin a core, hold the GIL and freeze the whole
queue; a child process can be SIGTERM/SIGKILLed.

The supervisor kills the child (and its process group, so ffmpeg grandchildren die too)
when: a route pauses/cancels the job, it makes no progress for download_stall_timeout_seconds
(150s), it runs past download_wall_clock_max_seconds (2h), the worker is shutting down, or
the child crashes without setting state. On a kill it frees the asset and fails the job with
a retryable network error (stalls are not auto-requeued). A clean exit is left alone — the
child already wrote the terminal state, including a cooperative pause via the progress hook.

- config.py: stall / wall-clock / supervisor-poll / kill-grace settings.
- worker.py: _run_supervised + _spawn_download_child / _job_liveness / _stop_child /
  _cleanup_staging; _process_job claims the asset, then hands the heavy work to the child.
- app/downloads/runner.py: the child entrypoint.
- docker-compose.localdev.yml: init:true on the worker so tini (PID 1) reaps orphaned
  ffmpeg grandchildren left by a hard-kill (the worker reaps its own direct children).
- tests: watchdog decision logic + SIGTERM->SIGKILL escalation (fake proc, no real subprocess).
2026-08-12 22:39:17 +02:00