feat(scheduler): a channel's "get full history" backfill is a recorded run, and a row knows its last three runs

The one-channel deep backfill ran as a FastAPI BackgroundTask: what it fetched, what it spent and
how it failed reached only the log. It is now a one-shot run on the scheduler (`channel_backfill`,
trigger ad_hoc, actor = the user, target = the channel) with its quota tagged to the run. Its
per-channel exclusion with the scheduled backfill and the two-run cap are unchanged, and a run
they turn away says why in its result instead of returning nothing. A failure is no longer
swallowed: the run records it.

The scheduler snapshot carries each job's last three runs (one windowed query), so the page can
show an interrupted or skipped run instead of the latest outcome alone.
This commit is contained in:
2026-10-18 01:05:24 +02:00
parent 911527a548
commit 27c2fcbd2e
8 changed files with 256 additions and 55 deletions
+14 -4
View File
@@ -82,14 +82,24 @@ def interrupt_leftovers() -> int:
return res.rowcount if isinstance(res, CursorResult) else 0
def last_runs(db: Session) -> dict[str, JobRun]:
"""Each job's most recent run (any trigger), by job id."""
def recent_runs(db: Session, per_job: int) -> dict[str, list[JobRun]]:
"""Each job's last `per_job` runs, newest first, by job id — one query (a window per job)."""
ranked = select(
JobRun.id,
func.row_number()
.over(partition_by=JobRun.job, order_by=(JobRun.started_at.desc(), JobRun.id.desc()))
.label("rank"),
).subquery()
rows = db.execute(
select(JobRun)
.distinct(JobRun.job)
.join(ranked, ranked.c.id == JobRun.id)
.where(ranked.c.rank <= per_job)
.order_by(JobRun.job, JobRun.started_at.desc(), JobRun.id.desc())
).scalars()
return {r.job: r for r in rows}
out: dict[str, list[JobRun]] = {}
for r in rows:
out.setdefault(r.job, []).append(r)
return out
def gc(db: Session, retention_days: int) -> int:
+13 -8
View File
@@ -3,15 +3,16 @@ hidden, tags) and per-channel sync state. Local reads/writes plus YouTube-side w
(subscribe / unsubscribe) that require the optional write scope."""
from datetime import datetime, timezone
from functools import partial
from fastapi import APIRouter, BackgroundTasks, Depends
from fastapi import APIRouter, Depends
from pydantic import BaseModel
from sqlalchemy import Select, func, select, update
from sqlalchemy.orm import Session
from app.collation import collated, sorted_words
from app.mailtext import lang_for_user
from app import logs, quota
from app import logs, quota, scheduler
from app.auth import admin_user, current_user, require_write_scope
from app.db import get_db
from app.models import (
@@ -481,7 +482,6 @@ class ChannelUpdateIn(BaseModel):
def update_channel(
channel_id: str,
body: ChannelUpdateIn,
background: BackgroundTasks,
user: User = Depends(current_user),
db: Session = Depends(get_db),
) -> dict:
@@ -508,12 +508,17 @@ def update_channel(
with quota.attribute(user.id, quota.QuotaAction.VIDEOS_BACKFILL_RECENT):
run_recent_backfill(db, [channel], max_channels=1)
# …and kick the FULL deep backfill for this one channel immediately in the background, so the
# whole catalogue lands in seconds instead of over the scheduler's paced 10-minute ticks. The
# request returns right away; the channel page's live poll shows the count climb. The scheduler
# still finishes a very large channel's tail on its normal runs (deep_requested stays set).
# …and kick the FULL deep backfill for this one channel immediately, as a recorded run of its own,
# so the whole catalogue lands in seconds instead of over the scheduler's paced 10-minute ticks.
# The request returns right away; the channel page's live poll shows the count climb. The
# scheduler still finishes a very large channel's tail on its normal runs (deep_requested stays set).
if deep_turned_on:
background.add_task(backfill_channel_now, channel_id, user.id)
scheduler.run_ad_hoc(
scheduler.CHANNEL_BACKFILL,
partial(backfill_channel_now, channel_id, user.id),
actor_id=user.id,
target=channel_id,
)
return {
"ok": True,
+81 -13
View File
@@ -174,26 +174,35 @@ def _run(db, name: str, fn, run_id: int, actor_id: int | None) -> None:
return
with progress.bind(sink):
result = fn(db)
summary = _summarize(result)
data = _result_data(result)
log.info("job %s -> %s", name, result)
jobruns.finish(run_id, RunStatus.OK, summary=summary, result=data)
summary, data = _finish_ok(name, run_id, result)
if actor_id is not None:
_notify_done(db, actor_id, name, "ok", summary, data)
except Exception as exc:
db.rollback()
log.exception("job %s failed", name, extra=logs.event("scheduler.job.failed", job=name))
err = str(exc) or exc.__class__.__name__
# A failure the job named (progress.JobFailed) rides along as data, as a result does, so the
# client says it in the reader's language; `err` stays the English line.
failure = (
{"failure": exc.reason, **exc.params} if isinstance(exc, progress.JobFailed) else None
)
jobruns.finish(run_id, RunStatus.ERROR, error=err, failure=failure)
err, failure = _finish_error(run_id, exc)
if actor_id is not None:
_notify_done(db, actor_id, name, "error", err, failure)
def _finish_ok(name: str, run_id: int, result) -> tuple[str | None, dict | None]:
"""Close a run that returned: its result on the row, as data and as the English one-liner."""
summary = _summarize(result)
data = _result_data(result)
log.info("job %s -> %s", name, result)
jobruns.finish(run_id, RunStatus.OK, summary=summary, result=data)
return summary, data
def _finish_error(run_id: int, exc: Exception) -> tuple[str, dict | None]:
"""Close a run that raised. A failure the job named (progress.JobFailed) rides along as data, as
a result does, so the client says it in the reader's language; the error stays the English line."""
err = str(exc) or exc.__class__.__name__
failure = {"failure": exc.reason, **exc.params} if isinstance(exc, progress.JobFailed) else None
jobruns.finish(run_id, RunStatus.ERROR, error=err, failure=failure)
return err, failure
# A skipped run's result, in the same shape as a job's own `{"skipped": …}`.
_PAUSED = {"skipped": "sync paused"}
@@ -240,11 +249,12 @@ def scheduler_snapshot(db) -> dict:
live_intervals[job.id] = round(iv.total_seconds() / 60)
with _activity_lock:
acts = {k: dict(v) for k, v in _activity.items()}
last = jobruns.last_runs(db)
recent = jobruns.recent_runs(db, RECENT_RUNS)
jobs = []
for job_id, default_interval in JOB_INTERVALS.items():
a = acts.get(job_id, {})
run = last.get(job_id)
runs = recent.get(job_id, [])
run = runs[0] if runs else None
# A run still going has no outcome yet: only an ended run says how it went.
ended = run if run is not None and run.status != RunStatus.RUNNING else None
jobs.append(
@@ -264,11 +274,27 @@ def scheduler_snapshot(db) -> dict:
"last_run_id": run.id if run else None,
"quota_units": ended.quota_units if ended else None,
"progress": a.get("progress"),
# The last few runs, newest first, for the row's history dots.
"recent": [_run_brief(r) for r in runs],
}
)
return {"running_here": running_here, "enabled": settings.scheduler_enabled, "jobs": jobs}
# How many past runs a Scheduler row shows as dots; the full history is the run list.
RECENT_RUNS = 3
def _run_brief(run) -> dict:
return {
"id": run.id,
"status": run.status,
"trigger": run.trigger,
"started_at": _iso(run.started_at),
"finished_at": _iso(run.finished_at),
}
def _outcome_data(run) -> dict | None:
if run is None:
return None
@@ -509,6 +535,48 @@ def trigger_all(actor_id: int | None = None) -> list[str]:
return started
# Work a user starts on one target outside the job list — today the "get full history" backfill of
# one channel. It runs on the same scheduler as a recorded run (trigger `ad_hoc`), so what it did and
# spent is in `job_runs` like any job's, not a background task only the log ever heard of.
CHANNEL_BACKFILL = "channel_backfill"
def run_ad_hoc(job: str, fn: Callable[[], dict], *, actor_id: int, target: str) -> None:
"""Run `fn` now as `actor_id`'s run of `job` on `target`, a one-shot job on the scheduler. Its
own exclusion (if any) lives in `fn`, which says so in its result; one id per job and target, so
a second request before the first has even started is that same run."""
sched = _scheduler
if sched is None:
# Only between shutdown and exit: start_scheduler runs at every API startup.
raise RuntimeError("the scheduler is not running")
try:
sched.add_job(
_ad_hoc,
"date",
args=(job, fn, actor_id, target),
id=f"{job}@{target}",
misfire_grace_time=None,
)
# silent-ok: not a failure — the run for this target is already queued, and it does this work.
except ConflictingIdError:
log.info("ad-hoc %s for %s already queued", job, target)
def _ad_hoc(job: str, fn: Callable[[], dict], actor_id: int, target: str) -> None:
try:
run_id = jobruns.start(job, RunTrigger.AD_HOC, actor_id, target)
except Exception:
# No row to tell it in: the database is what failed. The log is the record.
log.exception("ad-hoc %s for %s not started: its run could not be recorded", job, target)
return
with logs.bind(run_id=run_id):
try:
_finish_ok(job, run_id, fn())
except Exception as exc:
log.exception("job %s failed", job, extra=logs.event("scheduler.job.failed", job=job))
_finish_error(run_id, exc)
# Room for every job at once (a "run all") beside a few ad-hoc runs: APScheduler's default pool of
# 10 would queue a scheduled fire behind long manual runs.
_POOL_SIZE = len(JOB_FUNCS) + 8
+22 -21
View File
@@ -437,7 +437,7 @@ def run_deep_backfill(db: Session, max_channels: int = 10, max_pages: int = 5) -
# Channels being deep-backfilled RIGHT NOW by EITHER path — the interactive backfill_channel_now (a
# FastAPI BackgroundTasks threadpool thread) OR the scheduler's run_deep_backfill (its own thread).
# one-shot run on the scheduler's pool, see scheduler.run_ad_hoc) OR the scheduler's run_deep_backfill.
# BOTH register the channel they're paging (under the lock) so the other skips it: no two runs page
# the same channel's `backfill_cursor` concurrently, whichever started first. `_immediate_running`
# counts only the interactive path, capped so one user's burst can't drain the shared budget (the
@@ -448,9 +448,9 @@ _backfill_lock = threading.Lock()
_MAX_CONCURRENT_IMMEDIATE = 2
def backfill_channel_now(channel_id: str, user_id: int, max_pages: int = 400) -> None:
"""User-initiated "get full history": deep-backfill ONE channel to completion right now, in a
background task with its OWN session, so the full catalogue lands in seconds instead of over the
def backfill_channel_now(channel_id: str, user_id: int, max_pages: int = 400) -> dict:
"""User-initiated "get full history": deep-backfill ONE channel to completion right now, as its
own recorded run with its OWN session, so the full catalogue lands in seconds instead of over the
paced scheduler's 10-minute ticks (max_pages=5/channel/tick). max_pages is high enough to finish
any realistic channel in a single run (400 pages = 20 000 videos; e.g. BBC Earth's ~3400 = 69
pages — the old 60-page cap stopped one page short of large channels, so their tail dribbled in
@@ -459,34 +459,35 @@ def backfill_channel_now(channel_id: str, user_id: int, max_pages: int = 400) ->
Quota-guarded, capped to _MAX_CONCURRENT_IMMEDIATE interactive runs so one user can't drain the
shared backfill budget by opting many channels in at once (the overflow, and any channel too large
to finish under the reserve, is finished by the scheduler since deep_requested stays set), and
mutually excluded per-channel with the scheduler via _backfill_in_progress. Best-effort — logs and
swallows failures."""
mutually excluded per-channel with the scheduler via _backfill_in_progress.
Returns what the run did, as a job result: the counts, or `{"skipped": <why>}` when it left the
channel to the scheduler. A failure raises — the run that wraps this records it."""
global _immediate_running
with _backfill_lock:
if channel_id in _backfill_in_progress or _immediate_running >= _MAX_CONCURRENT_IMMEDIATE:
return # already backfilling this channel, or too many interactive runs — leave it to the scheduler
if channel_id in _backfill_in_progress:
return {"skipped": "channel busy"}
if _immediate_running >= _MAX_CONCURRENT_IMMEDIATE:
return {"skipped": "at capacity"}
_backfill_in_progress.add(channel_id)
_immediate_running += 1
try:
with SessionLocal() as db:
user = get_service_user(db)
if user is None:
return
return {"skipped": "no service user"}
channel = db.get(Channel, channel_id)
if channel is None or channel.backfill_done or not channel.uploads_playlist_id:
return
return {"skipped": "nothing to do"}
if quota.backfill_reserve_reached():
return
try:
# Attribute the spend to the requesting user under the full-backfill action, so it
# shows up correctly in the usage breakdown (not the default OTHER/system bucket).
with quota.attribute(user_id, quota.QuotaAction.VIDEOS_BACKFILL_FULL):
with YouTubeClient(db, user) as yt:
backfill_channel_deep(db, yt, channel, max_pages)
reconcile_full_history(db)
except Exception:
db.rollback()
log.exception("Immediate backfill failed for channel %s", channel_id)
return {"skipped": "low quota"}
# Attribute the spend to the requesting user under the full-backfill action, so it
# shows up correctly in the usage breakdown (not the default OTHER/system bucket).
with quota.attribute(user_id, quota.QuotaAction.VIDEOS_BACKFILL_FULL):
with YouTubeClient(db, user) as yt:
added = backfill_channel_deep(db, yt, channel, max_pages)
reconciled = reconcile_full_history(db)
return {"videos_added": added, "reconciled_full": reconciled}
finally:
with _backfill_lock:
_backfill_in_progress.discard(channel_id)
+51 -7
View File
@@ -107,22 +107,32 @@ def _setup_channel_and_sub(db, *, email):
def _patch_deep_requested(db, monkeypatch, override_dep, user):
submitted: list[tuple] = []
calls: list[tuple] = []
# background.add_task runs after the response in TestClient; record what would be scheduled.
# Record the run the route submits, and what its work would call, instead of running it.
monkeypatch.setattr(
channels_route.scheduler,
"run_ad_hoc",
lambda job, fn, **kw: submitted.append((job, kw)) or fn(),
)
monkeypatch.setattr(channels_route, "backfill_channel_now", lambda *a, **k: calls.append(a))
monkeypatch.setattr(state, "_configured_cache", True)
override_dep(get_db, db.info["request"])
override_dep(current_user, lambda: user)
resp = TestClient(app).patch("/api/channels/UC_wire", json={"deep_requested": True})
return resp, calls
return resp, submitted, calls
def test_deep_request_schedules_immediate_backfill(db, monkeypatch, override_dep):
def test_deep_request_starts_the_backfill_as_the_users_run_of_that_channel(
db, monkeypatch, override_dep
):
"""It was a BackgroundTask: what it did, spent or failed with reached only the log."""
ch, me = _setup_channel_and_sub(db, email="wire@example.com")
resp, calls = _patch_deep_requested(db, monkeypatch, override_dep, me)
resp, submitted, calls = _patch_deep_requested(db, monkeypatch, override_dep, me)
assert resp.status_code == 200, resp.text
assert resp.json()["deep_requested"] is True
# scheduled exactly once, with (channel_id, user_id) — the args backfill_channel_now needs.
assert submitted == [("channel_backfill", {"actor_id": me.id, "target": ch.id})]
# its work runs exactly once, with (channel_id, user_id) — the args backfill_channel_now needs.
assert calls == [(ch.id, me.id)]
@@ -148,15 +158,49 @@ class TestImmediateBackfillGuard:
def test_a_second_call_for_an_in_flight_channel_is_a_noop(self, monkeypatch):
runner._backfill_in_progress.add("UC_busy")
monkeypatch.setattr(runner, "SessionLocal", self._boom_session)
runner.backfill_channel_now("UC_busy", 1) # returns immediately; _boom_session never runs
# returns at once — _boom_session never runs — and the run says why it did nothing.
assert runner.backfill_channel_now("UC_busy", 1) == {"skipped": "channel busy"}
assert runner._backfill_in_progress == {"UC_busy"} # the in-flight entry is untouched
def test_over_the_concurrency_cap_falls_back_to_the_scheduler(self, monkeypatch):
runner._immediate_running = runner._MAX_CONCURRENT_IMMEDIATE
monkeypatch.setattr(runner, "SessionLocal", self._boom_session)
runner.backfill_channel_now("UC_new", 1) # over the cap → no-op, scheduler will handle it
# over the cap → no-op, the scheduler will handle it
assert runner.backfill_channel_now("UC_new", 1) == {"skipped": "at capacity"}
assert "UC_new" not in runner._backfill_in_progress
@staticmethod
def _one_channel(db, monkeypatch, cid):
ch = Channel(id=cid, title=cid, uploads_playlist_id="UU" + cid, backfill_done=False)
me = User(email=f"{cid}@example.com")
db.add_all([ch, me])
db.commit()
monkeypatch.setattr(runner, "get_service_user", lambda _db: me)
monkeypatch.setattr(runner.quota, "backfill_reserve_reached", lambda: False)
monkeypatch.setattr(runner, "YouTubeClient", lambda *a, **k: _NullYt())
return ch, me
def test_a_failure_reaches_its_run_and_still_frees_the_channel(self, db, monkeypatch):
"""The failure was logged and swallowed, so the run that now wraps it would read "ok"."""
ch, me = self._one_channel(db, monkeypatch, "UC_fail")
def boom(*_a):
raise RuntimeError("playlistItems 500")
monkeypatch.setattr(runner, "backfill_channel_deep", boom)
with pytest.raises(RuntimeError, match="playlistItems 500"):
runner.backfill_channel_now(ch.id, me.id)
assert runner._backfill_in_progress == set() and runner._immediate_running == 0
def test_a_finished_backfill_says_what_it_added(self, db, monkeypatch):
ch, me = self._one_channel(db, monkeypatch, "UC_ok")
monkeypatch.setattr(runner, "backfill_channel_deep", lambda *_a: 7)
monkeypatch.setattr(runner, "reconcile_full_history", lambda _db: 1)
assert runner.backfill_channel_now(ch.id, me.id) == {
"videos_added": 7,
"reconciled_full": 1,
}
def test_scheduler_deep_pass_skips_an_in_flight_channel(self, db, monkeypatch):
# A channel the scheduler's query WOULD pick (deep-requested, recent-synced, not done)…
ch = Channel(
+67
View File
@@ -146,6 +146,28 @@ def test_the_last_run_survives_a_restart(db):
assert plex["last_finished"] is not None
def test_a_row_shows_its_last_three_runs_newest_first_an_interrupted_one_included(db):
"""The row said only how the LAST run went; an interrupted run read as "no run recorded"."""
oldest = jobruns.start("shorts", RunTrigger.SCHEDULED, None)
jobruns.interrupt_leftovers()
scheduler._job("shorts", lambda _db: {"probed": 1})
scheduler._job("shorts", lambda _db: {"probed": 2})
scheduler._job("shorts", lambda _db: 1 / 0)
scheduler._job("rss_poll", lambda _db: {"new": 0}) # another job's run stays on its own row
recent = _snapshot_job(db, "shorts")["recent"]
assert [r["status"] for r in recent] == ["error", "ok", "ok"]
assert oldest not in [r["id"] for r in recent] # the fourth-newest is not shown
assert recent[0]["trigger"] == "scheduled" and recent[0]["finished_at"] is not None
assert [r["status"] for r in _snapshot_job(db, "rss_poll")["recent"]] == ["ok"]
jobruns.start("shorts", RunTrigger.SCHEDULED, None)
jobruns.interrupt_leftovers()
shorts = _snapshot_job(db, "shorts")
assert shorts["status"] == "interrupted"
assert [r["status"] for r in shorts["recent"]] == ["interrupted", "error", "ok"]
def test_a_paused_sync_is_a_skipped_run(db):
state.set_sync_paused(db, True)
db.commit()
@@ -286,6 +308,51 @@ def test_run_now_goes_through_the_scheduler_even_with_interval_jobs_off(
assert (run.trigger, run.actor_id, run.result) == ("manual", admin.id, {"probed": 3})
def test_an_ad_hoc_run_is_the_users_run_of_its_target_with_its_spend_and_failure(
db, make_user, live_scheduler
):
"""The one-channel deep backfill ran as a BackgroundTask nothing recorded: its spend counted as
nobody's run and a failure lived only in the log."""
user = make_user("adhoc@example.com")
def work():
quota.record_usage(3)
return {"videos_added": 50}
scheduler.run_ad_hoc(scheduler.CHANNEL_BACKFILL, work, actor_id=user.id, target="UC_a")
run = _wait_finished(db, "channel_backfill")
assert (run.trigger, run.actor_id, run.target) == ("ad_hoc", user.id, "UC_a")
assert (run.status, run.result, run.quota_units) == ("ok", {"videos_added": 50}, 3)
def fail():
raise RuntimeError("quota exceeded")
scheduler.run_ad_hoc(scheduler.CHANNEL_BACKFILL, fail, actor_id=user.id, target="UC_b")
deadline = time.monotonic() + 10
while time.monotonic() < deadline and len(_finished(db, "channel_backfill")) < 2:
time.sleep(0.05)
failed = next(r for r in _runs(db, "channel_backfill") if r.target == "UC_b")
assert (failed.status, failed.error) == ("error", "quota exceeded")
def _finished(db, job) -> list[JobRun]:
return [r for r in _runs(db, job) if r.status != "running"]
def test_a_second_ad_hoc_request_before_the_first_starts_is_that_same_run(
db, make_user, live_scheduler
):
user = make_user("twice@example.com")
live_scheduler.pause() # hold the one-shots so the second request finds the first pending
for target in ("UC_x", "UC_x", "UC_y"):
scheduler.run_ad_hoc(scheduler.CHANNEL_BACKFILL, dict, actor_id=user.id, target=target)
assert sorted(j.id for j in live_scheduler.get_jobs()) == [
"channel_backfill@UC_x",
"channel_backfill@UC_y",
]
live_scheduler.remove_all_jobs() # never run: a run finishing after the test would land in the next
def test_a_manual_run_leaves_no_actor_behind_on_its_thread(db, make_user):
"""The scheduler's pool threads are reused: an actor a manual run left set made the next
scheduled run on that thread an admin's "manual" run, with a notice in their inbox."""
+4 -1
View File
@@ -185,7 +185,10 @@
"syncpaused": "sync paused",
"lowquota": "low quota",
"noreadscope": "no YouTube read access",
"busy": "another sync is running"
"busy": "another sync is running",
"channelbusy": "this channel is already being backfilled",
"atcapacity": "two full-history backfills are already running — the scheduler finishes this one",
"nothingtodo": "nothing left to fetch"
},
"failure": {
"rss_all_failed_one": "The RSS feed did not answer for the one channel, {{channel}}: {{cause}}. Read through the API instead: {{read}}.",
+4 -1
View File
@@ -185,7 +185,10 @@
"syncpaused": "a szinkron szünetel",
"lowquota": "kevés a kvóta",
"noreadscope": "nincs YouTube-olvasási jogosultság",
"busy": "egy másik szinkron fut"
"busy": "egy másik szinkron fut",
"channelbusy": "ennek a csatornának a betöltése már fut",
"atcapacity": "már két teljes előzmény-betöltés fut — ezt az ütemező fejezi be",
"nothingtodo": "nincs több letöltendő"
},
"failure": {
"rss_all_failed_one": "Az RSS-hírcsatorna az egyetlen csatornánál sem válaszolt ({{channel}}): {{cause}}. Az API-n át beolvasva helyette: {{read}}.",