Field report: 7 bugs on a live 1.10.1-rc.1 — OpenSubtitles auth expiry kills downloads, HI-modifier cleanup data loss, job timeouts don't cancel work (+4 more, with root causes)

[Svnow132]

Summary

Deep investigation of a live install found 7 distinct bugs — most seriously: the OpenSubtitles JWT is obtained once at boot and never refreshed, so every download 401s ~24h after start while searches keep working; language_filter parses the ".hi" hearing-impaired suffix as Hindi and would mass-delete English HI subtitles; and a scheduler job that hits its timeout keeps running anyway (observed 16h of disk reads after "timed out", surviving a UI pause).

What actually happened?

Everything below was verified against the running container: log forensics, direct SQLite reads of sublarr.db, dry-run executor calls inside the container, and reading the shipped code in /app. Line numbers refer to the 1.10.1-rc.1 image. I know AI-assisted debugging is part of your workflow, so each bug carries exact file/line references, verbatim log lines, and a falsifiable repro.

(Not re-reported: the 1-req/sec budget floor — already fixed in v1.11.0-rc.1. Bug 5 is the next gate on that same path.)

---

Bug 1 — OpenSubtitles downloads permanently 401 after ~24 h: expired JWT reused, no re-login on 401 (critical)

For ~24 h after container start, downloads work. After that, every download fails and never recovers, while searches keep succeeding (search needs only the Api-Key header; /download additionally needs the 24h-lifetime user JWT — that asymmetry masks the failure):

[ERROR] providers.download_manager: Download from opensubtitles failed: Authentication failed for https://api.opensubtitles.com/api/v1/download: HTTP 401
[WARNING] circuit_breaker: CircuitBreaker[opensubtitles]: CLOSED → OPEN (5 consecutive failures)

Over a 3-day window: 29 successful searches, 64 failed downloads, provider_stats.successful_downloads = 0, subtitle_downloads empty.

Natural-experiment timeline proving token age is the only variable:

When (local)	Event
Day 0, 01:46	OpenSubtitles: logged in as <user> — the ONLY login for 3 days
Day 1, 23:45	nightly wanted-search: every download HTTP 401, breaker opens
Day 2, 23:45	same — 401 ×5, breaker opens again
Day 3, 03:00	container restarted (unrelated reason)
Day 3, 03:01:30	fresh logged in as <user>
Day 3, 03:01:33	4/4 downloads succeed within 3 s of the fresh login

Root cause in code:

• providers/opensubtitles.py — _login() has exactly one call site: provider init (~line 142). JWT written into the session Authorization header once; no TTL tracking, no refresh anywhere.
• providers/http_session.py — raises ProviderAuthError(f"Authentication failed for {url}: HTTP {resp.status_code}") on 401/403 (the exact logged message). OpenSubtitlesProvider.download() has a 406/quota branch but no 401 branch.
• providers/download_manager.py download_subtitle() ~line 137 — the ProviderAuthError dies in a generic except Exception: ... breaker.record_failure(); return None.

No code path can re-authenticate after init; an expired token is unrecoverable without a process restart.

---

Bug 2 — language_filter parses .hi (hearing-impaired) as language Hindi → would mass-delete English HI subtitles (high, data loss)

Dry run with {"keep_languages": ["en"]} reported 1,387 deletions, including 621 .en.hi.srt English hearing-impaired sidecars, each "reason": "lang:hi":

'....ja.hi.srt', 'size_bytes': 120435, 'reason': 'lang:hi'
'....en.hi.srt', ... 'reason': 'lang:hi'   <- English file, would be deleted

Library suffix census: .en 839 · .en.hi 621 · .ja.hi 209 · .hi 197 · .und 144 · .eng 79 · .ja 78 · …

Root cause: execute_language_filter (services/cleanup_executors.py ~line 322) reads the last suffix token as the language, so Show.en.hi.srt (standard Bazarr naming) parses as Hindi → not in keep list → delete. execute_format_upgrade in the same file (~line 570) already documents and strips forced/sdh/hi/cc/sign as modifiers — language_filter lacks that.

---

Bug 3 — Job timeout abandons the future but the work keeps running; sweep then grinds for hours and survives a UI pause (high)

subtitle_health_sweep (daily, 3600 s ceiling) timed out on 6 of its last 7 runs:

[ERROR] services.scheduler.ticks: scheduler: subtitle_health_sweep timed out after 3600s
Traceback (most recent call last):
  File "/app/services/scheduler/ticks.py", line 280, in _runner
    future.result(timeout=spec.timeout_s)
  File "/usr/local/lib/python3.12/concurrent/futures/_base.py", line 458, in result
    raise TimeoutError()
TimeoutError

scheduler_job_runs: subtitle_health_sweep → 1 ok, 1 error, 6 timeout (subtitle_automation shows the same pattern at its 600 s ceiling: 6 timeouts).

The work does NOT stop at timeout: the sweep was still emitting subtitle_health: raw extract failed ... s:N warnings 16 hours after its scheduled start, advancing one stream index per tick. Pausing the job in the scheduler UI did not stop the in-flight run — a tick fired 7 minutes after the pause (scheduler_admin_action logged). Only a container restart killed it. Net effect here: 8 days of continuous library reads, 10,640 subtitle_health_findings rows, 0 fixes applied.

Root cause: future.result(timeout=...) in _runner raises for the scheduler's bookkeeping, but concurrent.futures cannot cancel a running thread — the job thread runs on. Pause only removes future scheduled runs.

---

Bug 4 — Cleanup stats endpoint always fails: fromisoformat: argument must be str (medium)

[ERROR] error_utils: Cleanup stats failed: fromisoformat: argument must be str

54 occurrences. Confirmed traceback:

File "/app/db/repositories/cleanup.py", line 594, in get_disk_stats
    trend_rows = self.session.execute(trend_stmt).all()
...
File "lib/sqlalchemy/cyextension/processors.pyx", line 51, in sqlalchemy.cyextension.processors.str_to_date
TypeError: fromisoformat: argument must be str

SQLAlchemy's str_to_date result processor receives a non-str for a Date/DateTime-typed column in the get_disk_stats trend query (SQLite). Same family as the quality-trends and upgrade-scan datetime bugs already fixed — this is the cleanup-stats variant, still present in 1.10.1-rc.1.

---

Bug 5 — Keyless/free providers are skipped unless a provider_account_pools row exists (medium-high; was masked by the floor bug fixed in v1.11.0-rc.1)

With the floor worked around (provider_budget_safety_margin_pct=0), every provider without a pool row still skips on every search:

[WARNING] providers.search_coordinator: gestdown: no usable key in pool (all exhausted, 429-cooling, or pool row deleted). Add a pool row via Settings → Providers, or set provider_budget_enabled=false to bypass the gate for this provider.

956 such warnings for providers that need no credentials (gestdown, podnapisi, tvsubtitles, the subliminal_* wrappers, embedded, …). In _submit_provider_searches, after budget.check() passes, get_key_selector().pick(name, ...) returns None for a provider with zero pool rows → skipped as no_pool_key. Measured impact: with provider_budget_enabled=false, one search went from 2 participating providers to 23 with zero skips.

---

Bug 6 — Webhook handler warns it lacks HMAC verification, once per event (low)

[WARNING] auth: Webhook request to /api/v1/webhook/sonarr from 172.24.x.x has no X-Signature header — ensure the handler implements HMAC verification

219 occurrences since arming Sonarr/Radarr webhooks — the warning is a note-to-self that verification isn't implemented, and it fires on every event.

---

Bug 7 — metadata refiner never loads: No module named 'enzyme' (low, packaging)

At every boot:

[ERROR] stevedore.extension: Could not load 'metadata': No module named 'enzyme'

The subliminal metadata refiner needs enzyme, which isn't in the image, so embedded-metadata refinement silently never participates.

---

Minor observation (no fix requested)

Search timed out after NNs: N provider(s) still running (...) fires ~50×/day — AnimeTosho routinely needs 17–20 s while the computed ceiling lands at ~18 s, so its results get discarded on slower searches. The dynamic-timeout floor may deserve a per-provider minimum above observed p95.

### What should have happened?

## What should have happened?*

~~~markdown
1. **Bug 1:** A 401 from `/download` should invalidate the cached token, re-login once, and retry — downloads keep working indefinitely; the circuit breaker only opens on genuinely bad credentials. (Optionally: proactive refresh before the 24 h expiry.)
2. **Bug 2:** `Show.en.hi.srt` should parse as English + hearing-impaired modifier (as `execute_format_upgrade` already does) and be KEPT under `keep_languages=["en"]`.
3. **Bug 3:** A job that hits its timeout (or is paused) should actually stop — cooperative cancellation checked between work units — and the UI should not imply the work stopped when its thread is still running.
4. **Bug 4:** `/cleanup/stats` returns data; the trend bucket is cast so SQLAlchemy's date processor always receives a string.
5. **Bug 5:** Providers that require no account should run without a hand-created pool row (treat an empty pool as anonymous/singleton credentials, or auto-seed rows for keyless providers).
6. **Bug 6:** Either implement the intended webhook signature verification or demote the warning to once-per-boot.
7. **Bug 7:** `enzyme` ships in the image, or the metadata refiner is excluded so it doesn't error every start.

Steps to reproduce

Steps to reproduce

**Bug 1:** Configure OpenSubtitles with valid key + user/pass. Start the container, confirm one `logged in as` line. Wait >24 h without restart. Trigger any download (wanted search or manual) → every attempt logs `Authentication failed for .../download: HTTP 401`; breaker opens after 5. Restart the container → same download succeeds immediately.

**Bug 2:** Create `Test.en.hi.srt` next to any video file. Run a `language_filter` dry run with `{"keep_languages": ["en"]}` → the file appears in the delete list with `reason: lang:hi`.

**Bug 3:** Library large enough that `subtitle_health_sweep` exceeds 3600 s. Let the daily run fire → `timed out after 3600s` logged, but `services.subtitle_health.scan` lines keep appearing for hours afterwards. Pause the job in Settings → System → Scheduler while it grinds → warnings continue. `docker restart` → they stop.

**Bug 4:** GET `/api/v1/cleanup/stats` (with API key) on a SQLite install that has cleanup history → `Cleanup stats failed: fromisoformat: argument must be str` in the log, no data returned.

**Bug 5:** Fresh install (or any install without hand-created pool rows), budget enabled, floor fix applied. Run any search → all keyless providers log `no usable key in pool` and are skipped; only providers with pool rows participate.

**Bug 6:** Arm a Sonarr webhook at `/api/v1/webhook/sonarr`, import anything → one `no X-Signature header` warning per event.

**Bug 7:** `docker logs <container> | grep enzyme` after any start.

Sublarr version

1.10.1-rc.1 (pulled as ghcr.io/abrechen2/sublarr:latest)

Deployment

Docker (ghcr.io image)

Database

SQLite (default)

Logs / Support Export

Key lines are quoted inline per bug above (verbatim, secrets scrubbed). Happy to attach the full Support Export bundle or raw log/DB extracts on request — this instance reproduces everything listed.

Additional context

Instance shape: ~3,000 video files, ~2,450 sidecar subtitles, English-only language profile, OpenSubtitles free account (valid consumer key + user/pass, verified working when the token is fresh), AnimeTosho anonymous.

Local workarounds currently in place (so repro reports from this instance make sense):
- `provider_budget_safety_margin_pct = 0` and `provider_budget_enabled = false` (Bug 5 / pre-1.11 floor)
- `subtitle_health_sweep` paused + container restarted to kill the in-flight run (Bug 3)
- `language_filter` deliberately NOT enabled (Bug 2)
- Bug 1 currently "worked around" only by the incidental restarts above

If you'd rather have these as separate issues, say the word and I'll split them — kept as one report since Bugs 1/5 share the provider pipeline and Bugs 3/4 share the scheduler/cleanup area, and the cross-references matter for diagnosis.

[Abrechen2]

Thank you — this is the most useful bug report this project has had. Every claim was reproducible, and the file/line references cut the investigation down to minutes. All seven are addressed in v1.11.0, released today.

Bug 1 (OpenSubtitles 401) — fixed. A 401 on /download now clears the cached token, re-authenticates once and retries. Your natural-experiment timeline was what made the cause unambiguous. Concurrent downloads share one refresh, and persistent 401s still open the breaker, so genuinely bad credentials stay visible.

Bug 2 (.hi read as Hindi) — fixed, and thank you for the dry-run output; the 621 .en.hi files made the severity obvious. The parser was modifier-aware already, but the anchor handed to it removed only one suffix token, so Show.en.hi resolved against Show.en and hi was all that remained. Two consequences worth naming: .en.forced.srt now reads as English (so it becomes deletable when English is not kept), and a bare Show.S01E01.hi.srt is now left unclassified — one token cannot be both a language and a modifier, and declining to guess keeps the file.

Bug 3 (timeout does not cancel) — fixed as far as it can be. A thread cannot be killed safely, so cancellation is cooperative: jobs check between work units and stop there. Every long-running job has a check point now, and — this is the part your report made clear was needed — a run that was asked to stop and did not is recorded as timeout_abandoned rather than timeout, because "timeout" read as "the work ended" and you acted on that reasonably. Pausing now reaches a running job too.

Bug 4 (fromisoformat) — fixed. CAST(... AS DATE) on SQLite yields numeric affinity; the query now buckets on a text cast, matching the fix already used for the quality-trends variant.

Bug 5 (keyless providers gated) — fixed. pick() returned None both for "pool exhausted" and "no pool because none is needed", and the call site could not tell the two apart. Providers declaring no required credentials now search without a pool row; an exhausted pool still skips. This also explains a symptom on our own instance (~69 daily skips for animetosho) that we had been treating as unrelated.

Bug 6 (webhook warning) — fixed, now once per path per start.

Bug 7 (enzyme) — was already fixed before your report reached us; it ships in 1.11.0.

Not addressed: the AnimeTosho search-timeout observation. It is real and recorded, but a per-provider minimum needs data we do not have yet.

The three feature requests you filed alongside this are all implemented in the same release; see the individual issues for details and one honest limitation on the provider test.