diff --git a/CHANGELOG.md b/CHANGELOG.md index a6fe27d8..eec53d1c 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,6 +7,32 @@ edit the release notes and re-run the generator. Upgrading, pinning a version and rolling back: [docs/self-hosting.md](docs/self-hosting.md#upgrading). +## 0.91.0 — 2026-09-19 + +What a test run on the live instance turned up, fixed: new videos keep arriving while YouTube's feeds are down, an open tab survives a release, and Back returns to what you left. + +### Features + +- A card's menu (right-click or long press) now offers the card's own actions — watched, save, hide, reset — beside the comfort-shelf pin. +- Settings → Account shows your role and your last sign-in. 0.88 announced the last sign-in in your account panel; it is actually there now. + +### Fixes + +- When YouTube's feed for a channel stays dark for hours, as it did for 393 of 396 channels on 18–19 September, the channel's newest uploads are read through the YouTube API instead, at most once every 2 hours per channel (adjustable by an administrator, 0 turns it off). +- A tab left open across a release no longer falls to the crash screen when it opens something it had not loaded yet: it reloads onto the new version once. +- Back from a request's lines in the Server log returns to the view the pivot was made from, search text included, as 0.90 promised. +- Back to Home keeps the question you asked (the time budget and the hero you rerolled to), and the keyboard lands on the card you opened, even when the rail's cards moved or several share a name. +- Browser tabs are named after the page again: signed out, and on the privacy and terms pages. +- On a phone, the feed and Plex toolbars wrap instead of running past the edge, and so do notifications. +- The countdown of a raised diagnostics level counts from the moment it was raised, not from when the page was opened. +- The download box's placeholder names every site it takes, Facebook included. + +### Internal + +- The screens' own polling reads (the unread badges, the download list, the scheduler) are logged at debug level in the server's log and in the browser's copy of it, where they made up about 95% of the lines. +- An account with no YouTube channel no longer writes a warning every six hours, and a scheduler job that fails carries an event code. +- Two adversarial review rounds: 15 findings raised, 11 survived, all fixed, and every regression test was proven to fail with its own fix removed. + ## 0.90.0 — 2026-09-19 The server's log gets a screen of its own: an admin can now read what the API, the downloader and the browsers wrote down, filter it, and follow one request or job from start to end. diff --git a/VERSION b/VERSION index ae02209b..8f63f4f9 100644 --- a/VERSION +++ b/VERSION @@ -1 +1 @@ -0.90.0 +0.91.0 diff --git a/backend/alembic/versions/0088_channels_feed_fallback_at.py b/backend/alembic/versions/0088_channels_feed_fallback_at.py new file mode 100644 index 00000000..8680606c --- /dev/null +++ b/backend/alembic/versions/0088_channels_feed_fallback_at.py @@ -0,0 +1,30 @@ +"""add channels.feed_fallback_at — when a channel's uploads were last read through the API because +its RSS feed would not answer + +Revision ID: 0088_channels_feed_fallback_at +Revises: 0087_users_diagnostics_level +Create Date: 2026-09-19 + +YouTube's RSS feeds go dark for hours at a time, per channel (2026-09-18/19: 393 of 396 answered 404 +for four hours; the same channel answers 404 to every retry). The RSS poll then reads the newest +uploads through the Data API instead, at a quota cost, and at most once per `rss_fallback_hours` per +channel: this column is that clock. NULL = never needed it. +""" + +import sqlalchemy as sa +from alembic import op + +revision: str = "0088_channels_feed_fallback_at" +down_revision: str | None = "0087_users_diagnostics_level" +branch_labels: str | None = None +depends_on: str | None = None + + +def upgrade() -> None: + op.add_column( + "channels", sa.Column("feed_fallback_at", sa.DateTime(timezone=True), nullable=True) + ) + + +def downgrade() -> None: + op.drop_column("channels", "feed_fallback_at") diff --git a/backend/app/config.py b/backend/app/config.py index 2b2ad824..2490b51a 100644 --- a/backend/app/config.py +++ b/backend/app/config.py @@ -119,6 +119,9 @@ class Settings(BaseSettings): # Recent-first backfill: how far back to fetch on the first pass per channel. backfill_recent_max_videos: int = 100 backfill_recent_max_days: int = 365 + # A channel whose RSS feed has not answered for this many hours gets its newest uploads read + # through the Data API instead (1 unit), at most once per this many hours. 0 = never. + rss_fallback_hours: int = 2 # Shorts are confirmed by probing youtube.com/shorts/. Only videos at or below # this duration (and not livestreams) are probed; longer videos are never Shorts. diff --git a/backend/app/logs.py b/backend/app/logs.py index cfb49e7c..565030c8 100644 --- a/backend/app/logs.py +++ b/backend/app/logs.py @@ -644,6 +644,27 @@ _REQUEST_ID_RE = re.compile(r"^[A-Za-z0-9._-]{8,64}$") # — this lowers the floor, it does not hide. _QUIET_PREFIXES = ("/healthz", "/assets/", "/static/", "/api/admin/logs") +# The reads the frontend POLLS (a `useLiveQuery`, the `me` heartbeat, the sync status, the subtitle +# progress), by route template, GET only — logged at DEBUG like the prefixes above. One open tab asked +# for the two unread counts, `/api/me` and the download index every 30 s, and at INFO those were ~95% +# of the stored log (measured on prod 2026-09-19): 11k lines a day per tab burying every line someone +# caused. The same route answered with a failure still logs at WARNING/ERROR. +_POLLED_ROUTES = frozenset( + { + "/api/me", + "/api/me/notifications/unread_count", + "/api/messages/unread_count", + "/api/downloads", + "/api/downloads/index", + "/api/downloads/usage", + "/api/sync/my-status", + "/api/admin/scheduler", + "/api/admin/downloads", + "/api/admin/downloads/storage", + "/api/plex/subtitle/{rating_key}/{sub_ord}/status", + } +) + # Not `siftlode.logs`: this is the replacement for uvicorn's ACCESS log, and `siftlode.http` is # what an operator pins a level on when they want request lines and nothing else. The module it # happens to live in is not what the name is about. @@ -689,7 +710,9 @@ async def log_requests(request, call_next): raise duration_ms = round((time.perf_counter() - started) * 1000, 1) status = response.status_code - quiet = request.url.path.startswith(_QUIET_PREFIXES) + quiet = request.url.path.startswith(_QUIET_PREFIXES) or ( + request.method == "GET" and _route_template(request) in _POLLED_ROUTES + ) if status >= 500: level = logging.ERROR elif status >= 400: @@ -715,6 +738,10 @@ async def log_requests(request, call_next): extra={**event("http.request", **attrs), **_request_owner(request, level)}, ) response.headers["X-Request-Id"] = rid + # The browser logs its own copy of this line (frontend lib/http.ts) and must pick the same level: + # it learns "this one is quiet" here instead of keeping a second copy of the polled-route list. + if level == logging.DEBUG: + response.headers["X-Log-Quiet"] = "1" # The template, so the browser's copy of this line groups the same way (frontend lib/http.ts). # Only a MATCHED route's: a template never carries a path parameter's value (a share token stays # `{token}`), while the raw-path fallback of an unmatched request could — the browser then diff --git a/backend/app/models.py b/backend/app/models.py index 173d4b8a..b4273184 100644 --- a/backend/app/models.py +++ b/backend/app/models.py @@ -241,6 +241,9 @@ class Channel(Base, TimestampMixin): details_synced_at: Mapped[datetime | None] = mapped_column(DateTime(timezone=True)) recent_synced_at: Mapped[datetime | None] = mapped_column(DateTime(timezone=True)) last_rss_at: Mapped[datetime | None] = mapped_column(DateTime(timezone=True)) + # When the newest uploads were last read through the Data API because the RSS feed would not + # answer (`sync/runner.py` `run_feed_fallback`): the once-per-`rss_fallback_hours` clock. + feed_fallback_at: Mapped[datetime | None] = mapped_column(DateTime(timezone=True)) backfill_cursor: Mapped[str | None] = mapped_column(String(128)) backfill_done: Mapped[bool] = mapped_column(Boolean, default=False, server_default="false") # True when this channel only entered the catalog because a live YouTube search diff --git a/backend/app/quota.py b/backend/app/quota.py index e630a34c..c7d91b38 100644 --- a/backend/app/quota.py +++ b/backend/app/quota.py @@ -37,6 +37,7 @@ class QuotaAction: PLAYLISTS_DELETE = "playlists_delete" VIDEOS_BACKFILL_RECENT = "videos_backfill_recent" VIDEOS_BACKFILL_FULL = "videos_backfill_full" + VIDEOS_FEED_FALLBACK = "videos_feed_fallback" VIDEOS_ENRICH = "videos_enrich" VIDEOS_LOOKUP = "videos_lookup" VIDEOS_SEARCH = "videos_search" diff --git a/backend/app/routes/me.py b/backend/app/routes/me.py index eb586a22..74b15360 100644 --- a/backend/app/routes/me.py +++ b/backend/app/routes/me.py @@ -23,6 +23,7 @@ from app import logs from app import sysconfig from app.db import get_db from app.models import Invite, User +from app.utils import iso router = APIRouter(prefix="/api/me", tags=["me"]) @@ -138,6 +139,9 @@ def get_me( user.google_email if user.google_email and user.google_email != user.email else None ), "has_password": user.password_hash is not None, + # The account's latest sign-in on any device — shown in Settings → Account, so a sign-in the + # user does not recognise is something they can see (null: none since 0.88, or the demo). + "last_login_at": iso(user.last_login_at), # Instance-wide: whether Google sign-in / YouTube connect is available at all (the UI hides # YouTube-access affordances and the onboarding nudge when it isn't configured). "google_enabled": google_enabled(db), diff --git a/backend/app/scheduler.py b/backend/app/scheduler.py index ec2e8309..c3e24d12 100644 --- a/backend/app/scheduler.py +++ b/backend/app/scheduler.py @@ -208,7 +208,7 @@ def _job(name: str, fn) -> None: _audit_run(db, actor_id, name, "ok", summary, result) except Exception as exc: db.rollback() - log.exception("job %s failed", name) + log.exception("job %s failed", name, extra=logs.event("scheduler.job.failed", job=name)) err = str(exc) or exc.__class__.__name__ _record(name, status="error", last_finished=_now_iso(), last_error=err, progress=None) if actor_id is not None: diff --git a/backend/app/sync/playlists.py b/backend/app/sync/playlists.py index 056c7a9d..2a889234 100644 --- a/backend/app/sync/playlists.py +++ b/backend/app/sync/playlists.py @@ -670,11 +670,19 @@ def sync_all_playlists(db: Session) -> dict: try: with quota.attribute(user.id, quota.QuotaAction.PLAYLISTS_PULL): total += sync_user_playlists(db, user).get("synced", 0) - except YouTubeError: + except YouTubeError as exc: db.rollback() - log.warning("Playlist sync failed for user %s", user.id) + log.warning( + "Playlist sync failed for user %s", + user.id, + extra=logs.event("sync.playlists.failed", user_id=user.id, reason=exc.reason), + ) except Exception: db.rollback() - log.exception("Playlist sync crashed for user %s", user.id) + log.exception( + "Playlist sync crashed for user %s", + user.id, + extra=logs.event("sync.playlists.crashed", user_id=user.id), + ) progress.report(i, len(users), "playlist_sync") return {"users": len(users), "playlists_synced": total} diff --git a/backend/app/sync/runner.py b/backend/app/sync/runner.py index 7220620c..28fa2cb4 100644 --- a/backend/app/sync/runner.py +++ b/backend/app/sync/runner.py @@ -9,8 +9,9 @@ import logging import threading from collections import Counter from concurrent.futures import ThreadPoolExecutor, as_completed +from datetime import datetime, timedelta, timezone -from sqlalchemy import select +from sqlalchemy import func, or_, select, update from sqlalchemy.orm import Session from app import logs, progress, quota, sysconfig @@ -25,11 +26,13 @@ from app.sync.videos import ( backfill_channel_deep, backfill_channel_recent, enrich_pending, + insert_stubs, reconcile_full_history, refresh_live, run_shorts_classification, + stub_from_playlist_item, ) -from app.youtube.client import YouTubeClient +from app.youtube.client import YouTubeClient, YouTubeError, is_quota_refusal from app.youtube.rss import RssError, fetch_channel_feed # RSS feeds are free and network-bound, so fetch many at once; DB writes stay single-threaded. @@ -85,6 +88,9 @@ def run_rss_poll(db: Session, channels: list[Channel] | None = None) -> dict[str # of 2026-09-16 into 11k warnings in four hours; each channel's own line is DEBUG now. reasons: Counter[str] = Counter() examples: list[str] = [] + # Channels whose FEED would not answer (not those whose rows failed to apply: the API would + # hand the same rows to the same broken write) — the feed fallback's candidates. + unread: list[str] = [] def fail(reason: str, detail: str, *, unexpected: str | None = None) -> None: """Count a channel that did not get polled. `unexpected` is the message for a failure that @@ -120,6 +126,7 @@ def run_rss_poll(db: Session, channels: list[Channel] | None = None) -> dict[str except RssError as exc: log.debug("RSS poll skipped for channel %s: %s", channel.id, exc) fail(exc.reason, f"{channel.id}: {exc}") + unread.append(channel.id) # silent-ok: `fail(unexpected=…)` is the report — it logs at ERROR with the # traceback, once per reason per poll, which is the flood control this loop needs. except Exception as exc: # noqa: BLE001 — one channel must not stop the poll @@ -143,17 +150,24 @@ def run_rss_poll(db: Session, channels: list[Channel] | None = None) -> dict[str # One place that advances the counter, whatever happened above. done += 1 progress.report(done, total, "rss_poll") + fallback = run_feed_fallback(db, unread) if failed: + # The fallback's count rides on this line because this is the one the stored log keeps (an + # INFO line outside a request never reaches `log_events`): the console should show whether + # the uploads came in another way. log.warning( - "RSS poll: %d/%d channels could not be polled", + "RSS poll: %d/%d channels could not be polled; %d read through the API instead", failed, total, + fallback["read"], extra=logs.event( "sync.rss.failed", failed=failed, total=total, reasons=dict(reasons), examples=examples, + fallback_read=fallback["read"], + fallback_new=fallback["new"], ), ) if total and failed == total: @@ -164,8 +178,115 @@ def run_rss_poll(db: Session, channels: list[Channel] | None = None) -> dict[str # subscriptions "all channels failed" is also what ONE dead feed id looks like, and a red # card the user can't act on is its own kind of dishonest. `channel: HTTP 404` says # "fix this subscription"; `Connection refused` says "the egress is down". - raise RuntimeError(f"RSS poll failed for all {total} channels — first: {first_error}") - return {"new": new, "failed": failed} + # The fallback's count rides along: a red card during an RSS outage should still say + # whether the uploads are arriving another way. + raise RuntimeError( + f"RSS poll failed for all {total} channels — first: {first_error}" + f" (read through the API instead: {fallback['read']})" + ) + return {"new": new + fallback["new"], "failed": failed, "fallback": fallback["read"]} + + +def run_feed_fallback(db: Session, channel_ids: list[str]) -> dict[str, int]: + """Read the newest uploads through the Data API for the channels among `channel_ids` whose feed + has not answered for `rss_fallback_hours` — and that were not read this way within as long. + + YouTube's RSS goes dark per channel for hours at a time (2026-09-18/19: 393 of 396 feeds answered + 404 for four hours, and a retry of the same channel gets the same 404), and nothing else reads a + followed channel's new uploads: recent backfill runs once per channel, ever. One page of the + uploads playlist is 1 unit, so a whole day of total outage costs 12 units per channel at the + default 2 hours; it yields to the backfill reserve like every other background read. The clock is + `last_rss_at` or `feed_fallback_at`, whichever is later, so a channel is read at most once per + window whether its feed came back in between or not. A read the API REFUSED stamps the clock + too: a terminated channel's uploads playlist answers 404 for good, and without the stamp it + would be charged again on every 20-minute poll instead of once per window. A failure that is not + about the channel (no connection, no token, the quota spent) stamps nothing and ends the round.""" + hours = sysconfig.get_int(db, "rss_fallback_hours") + if hours <= 0 or not channel_ids: + return {"read": 0, "new": 0, "failed": 0} + now = datetime.now(timezone.utc) + last_read = func.greatest(Channel.last_rss_at, Channel.feed_fallback_at) + due = ( + db.execute( + select(Channel) + .where( + Channel.id.in_(channel_ids), + Channel.uploads_playlist_id.is_not(None), + or_(last_read.is_(None), last_read < now - timedelta(hours=hours)), + ) + .order_by(Channel.id) + ) + .scalars() + .all() + ) + user = get_service_user(db) if due else None + if user is None: + return {"read": 0, "new": 0, "failed": 0} + read = new = failed = 0 + with ( + quota.attribute(None, quota.QuotaAction.VIDEOS_FEED_FALLBACK), + YouTubeClient(db, user) as yt, + ): + for channel in due: + if quota.backfill_reserve_reached(): + break + try: + data = yt.get_playlist_items(channel.uploads_playlist_id, None) + # silent-ok: counted, and the one summary line below names the count — the client + # already logged the call's own failure (`youtube.api.error`). + except YouTubeError as exc: + failed += 1 + # Not an answer about THIS channel — no connection, no token, no quota: every + # further channel would fail the same way, and none of them has used its window. + if exc.path != "playlistItems" or is_quota_refusal(exc): + break + _stamp_fallback_attempt(db, channel.id) + continue + rows = [ + s + for s in (stub_from_playlist_item(it, channel.id) for it in data.get("items", [])) + if s is not None + ] + try: + new += insert_stubs(db, rows) + channel.feed_fallback_at = datetime.now(timezone.utc) + db.add(channel) + db.commit() + except Exception: # noqa: BLE001 — one channel must not stop the rest + db.rollback() + log.exception( + "Feed fallback could not store channel %s", + channel.id, + extra=logs.event("sync.rss.fallback_failed"), + ) + failed += 1 + _stamp_fallback_attempt(db, channel.id) + continue + read += 1 + log.info( + "Feed fallback: read %d of %d channels through the API, %d new videos", + read, + len(due), + new, + extra=logs.event("sync.rss.fallback", read=read, due=len(due), new=new, failed=failed), + ) + return {"read": read, "new": new, "failed": failed} + + +def _stamp_fallback_attempt(db: Session, channel_id: str) -> None: + """Start a channel's fallback window after a read that did not land, so it waits the window out + like a read that did. Its own commit: the failure already rolled the channel's work back.""" + try: + db.execute( + update(Channel) + .where(Channel.id == channel_id) + .values(feed_fallback_at=datetime.now(timezone.utc)) + ) + db.commit() + # silent-ok: the failure that brought us here was already logged and counted; an unstamped + # channel is only read again at the next poll. + except Exception: # noqa: BLE001 + db.rollback() def run_enrich(db: Session, max_batches: int = 200, floor: int = 200) -> int: diff --git a/backend/app/sysconfig.py b/backend/app/sysconfig.py index 8b2f49b3..41f1b7bd 100644 --- a/backend/app/sysconfig.py +++ b/backend/app/sysconfig.py @@ -91,6 +91,7 @@ SPECS: tuple[ConfigSpec, ...] = ( ConfigSpec( "backfill_recent_max_days", "int", "backfill", "backfill_recent_max_days", min=1, max=36_500 ), + ConfigSpec("rss_fallback_hours", "int", "backfill", "rss_fallback_hours", min=0, max=168), # --- Shorts probe --- ConfigSpec( "shorts_probe_max_seconds", "int", "shorts", "shorts_probe_max_seconds", min=1, max=3_600 diff --git a/backend/app/youtube/client.py b/backend/app/youtube/client.py index 260aff31..381da7a9 100644 --- a/backend/app/youtube/client.py +++ b/backend/app/youtube/client.py @@ -6,6 +6,7 @@ so they don't depend on a specific user's token; subscriptions.list?mine=true al uses OAuth. """ +import logging from collections.abc import Iterator from datetime import datetime, timedelta, timezone @@ -25,11 +26,15 @@ class YouTubeError(Exception): `reason` is the API's own error reason code (`quotaExceeded`, `subscriptionDuplicate`, `videoNotFound`, …) when the body carried one. Branch on THAT, never on the message: the - message is prose, it changes under us, and it is deliberately the poorer of the two here.""" + message is prose, it changes under us, and it is deliberately the poorer of the two here. - def __init__(self, message: str, *, reason: str = ""): + `path` is the API endpoint that ANSWERED with the failure (`playlistItems`); empty when no + endpoint did — the request never got through (`transport`) or the token step refused first.""" + + def __init__(self, message: str, *, reason: str = "", path: str = ""): super().__init__(message) self.reason = reason + self.path = path def _error_reason(resp: httpx.Response) -> str: @@ -50,7 +55,9 @@ def _error_reason(resp: httpx.Response) -> str: return reasons or "" -def _upstream_failure(method: str, path: str, resp: httpx.Response) -> YouTubeError: +def _upstream_failure( + method: str, path: str, resp: httpx.Response, expected: frozenset[str] = frozenset() +) -> YouTubeError: """Report one upstream failure and build the error to raise. Every YouTube response that is not a success goes through here — the Data API's reads, writes and deletes and the OAuth token refresh — so what may appear in a log line cannot drift apart between them, and the @@ -59,7 +66,11 @@ def _upstream_failure(method: str, path: str, resp: httpx.Response) -> YouTubeEr response at all is `_send`'s, with the reason `transport`.) The body is logged only under the requesting user's own Teljes consent: it is the request quoted back.""" reason = _error_reason(resp) - log.warning( + # A reason the caller named as an answer rather than a failure (`channelNotFound` on a `mine` + # read: the account simply has no channel) is still raised, but it is not a warning — it came + # back every six hours for an account that will never have one. + log.log( + logging.DEBUG if reason in expected else logging.WARNING, "YouTube %s %s -> %s (%s)", method, path, @@ -80,7 +91,21 @@ def _upstream_failure(method: str, path: str, resp: httpx.Response) -> YouTubeEr # log-pii-ok: only under this user's own Teljes consent, which is what it is for extra=logs.event("youtube.api.body", body=resp.text[:500]), ) - return YouTubeError(f"{method} {path} -> {resp.status_code}: {reason}", reason=reason) + return YouTubeError( + f"{method} {path} -> {resp.status_code}: {reason}", reason=reason, path=path + ) + + +# The `mine` reads' answer for a Google account that has no YouTube channel. +_NO_CHANNEL = frozenset({"channelNotFound"}) + +# The reasons that mean the project's quota is spent: every further call today gets the same answer. +_QUOTA_REASONS = frozenset({"quotaExceeded", "dailyLimitExceeded"}) + + +def is_quota_refusal(exc: YouTubeError) -> bool: + """Whether the API refused for want of quota. `reason` can list several codes, comma-joined.""" + return any(r in _QUOTA_REASONS for r in exc.reason.split(",")) def _chunks(items: list, size: int) -> Iterator[list]: @@ -167,7 +192,14 @@ class YouTubeClient: return access # --- core request --- - def _get(self, path: str, params: dict, cost: int = 1, allow_key: bool = True) -> dict: + def _get( + self, + path: str, + params: dict, + cost: int = 1, + allow_key: bool = True, + expected: frozenset[str] = frozenset(), + ) -> dict: p = dict(params) headers = {} api_key = sysconfig.get_str(self.db, "youtube_api_key") @@ -178,7 +210,7 @@ class YouTubeClient: resp = self._send("GET", f"{API_BASE}/{path}", params=p, headers=headers) quota.record_usage(cost) if resp.status_code != 200: - raise _upstream_failure("GET", path, resp) + raise _upstream_failure("GET", path, resp, expected) return resp.json() # --- endpoints --- @@ -218,7 +250,14 @@ class YouTubeClient: params = {"part": "snippet,contentDetails", "mine": "true", "maxResults": 50} if page_token: params["pageToken"] = page_token - data = self._get("playlists", params, cost=1, allow_key=False) + try: + data = self._get("playlists", params, cost=1, allow_key=False, expected=_NO_CHANNEL) + except YouTubeError as exc: + # A Google account without a YouTube channel has no playlists, and YouTube says + # so as a 404. That is an empty list, not a failed sync. + if exc.reason in _NO_CHANNEL: + return + raise for item in data.get("items", []): sn = item.get("snippet", {}) yield { diff --git a/backend/tests/test_feed_fallback.py b/backend/tests/test_feed_fallback.py new file mode 100644 index 00000000..54d7bb89 --- /dev/null +++ b/backend/tests/test_feed_fallback.py @@ -0,0 +1,150 @@ +"""The RSS poll's API fallback (`sync/runner.run_feed_fallback`), DB-lane: which channels are read +through the Data API when their feed stays dark, and how often.""" + +from datetime import datetime, timedelta, timezone + +import pytest + +from app import sysconfig +from app.models import Channel, Video +from app.sync import runner +from app.youtube.client import YouTubeError + +NOW = datetime.now(timezone.utc) +_PUB = datetime(2020, 1, 1, tzinfo=timezone.utc) + + +class _FakeYt: + # playlist id -> the reason its read fails with (the tests put entries here) + failing: dict[str, str] = {} + + def __init__(self, calls): + self.calls = calls + + def __enter__(self): + return self + + def __exit__(self, *exc): + return False + + def get_playlist_items(self, playlist_id, page_token=None): + self.calls.append(playlist_id) + if playlist_id in self.failing: + reason = self.failing[playlist_id] + # A request that never got through has no endpoint that answered. + path = "" if reason == "transport" else "playlistItems" + raise YouTubeError("refused", reason=reason, path=path) + cid = "UC" + playlist_id[2:] + return { + "items": [ + { + "contentDetails": {"videoId": f"{cid}-v1", "videoPublishedAt": NOW.isoformat()}, + "snippet": {"title": "new upload"}, + } + ] + } + + +@pytest.fixture +def calls(monkeypatch): + made: list[str] = [] + monkeypatch.setattr(runner, "get_service_user", lambda db: object()) + monkeypatch.setattr(runner, "YouTubeClient", lambda db, user: _FakeYt(made)) + monkeypatch.setattr(runner.quota, "backfill_reserve_reached", lambda: False) + monkeypatch.setattr(_FakeYt, "failing", {}) + return made + + +def _channel(db, cid, *, rss=None, fallback=None, uploads=True): + ch = Channel( + id=cid, + title=cid, + published_at=_PUB, + uploads_playlist_id=("UU" + cid[2:]) if uploads else None, + last_rss_at=rss, + feed_fallback_at=fallback, + ) + db.add(ch) + db.commit() + return ch + + +def test_a_feed_dark_past_the_window_is_read_through_the_api(db, calls): + _channel(db, "UCdark", rss=NOW - timedelta(hours=3)) + + out = runner.run_feed_fallback(db, ["UCdark"]) + + assert out == {"read": 1, "new": 1, "failed": 0} + assert calls == ["UUdark"] + assert db.get(Video, "UCdark-v1") is not None + assert db.get(Channel, "UCdark").feed_fallback_at is not None + + +@pytest.mark.parametrize( + ("rss", "fallback"), + [ + (NOW - timedelta(minutes=30), None), # the feed answered recently: a blip, not an outage + (NOW - timedelta(hours=5), NOW - timedelta(minutes=30)), # already read this window + ], +) +def test_a_channel_read_within_the_window_is_left_alone(db, calls, rss, fallback): + _channel(db, "UCrecent", rss=rss, fallback=fallback) + + assert runner.run_feed_fallback(db, ["UCrecent"])["read"] == 0 + assert calls == [] + + +def test_the_window_is_the_admins_and_zero_turns_it_off(db, calls): + _channel(db, "UCdark", rss=NOW - timedelta(hours=3)) + + sysconfig.set_value(db, "rss_fallback_hours", 4) + db.commit() + assert runner.run_feed_fallback(db, ["UCdark"])["read"] == 0 + + sysconfig.set_value(db, "rss_fallback_hours", 0) + db.commit() + _channel(db, "UCnever") + assert runner.run_feed_fallback(db, ["UCdark", "UCnever"])["read"] == 0 + assert calls == [] + + +def test_only_the_named_channels_and_only_those_with_an_uploads_playlist(db, calls): + _channel(db, "UCdark") + _channel(db, "UCother") + _channel(db, "UCnolist", uploads=False) + + assert runner.run_feed_fallback(db, ["UCdark", "UCnolist"])["read"] == 1 + assert calls == ["UUdark"] + + +def test_it_yields_to_the_backfill_reserve(db, calls, monkeypatch): + _channel(db, "UCdark") + monkeypatch.setattr(runner.quota, "backfill_reserve_reached", lambda: True) + + assert runner.run_feed_fallback(db, ["UCdark"])["read"] == 0 + assert calls == [] + + +def test_a_read_that_fails_waits_the_window_out_too(db, calls): + # A terminated channel: its feed 404s and so does its uploads playlist, for good. Without a + # stamp it was charged on every 20-minute poll instead of once per window. + _channel(db, "UCgone", rss=NOW - timedelta(hours=3)) + _FakeYt.failing["UUgone"] = "playlistNotFound" + + assert runner.run_feed_fallback(db, ["UCgone"]) == {"read": 0, "new": 0, "failed": 1} + assert db.get(Channel, "UCgone").feed_fallback_at is not None + assert runner.run_feed_fallback(db, ["UCgone"])["failed"] == 0 + assert calls == ["UUgone"] + + +@pytest.mark.parametrize("reason", ["quotaExceeded", "transport"]) +def test_a_failure_not_about_the_channel_ends_the_round_and_costs_no_window(db, calls, reason): + # Out of quota, or no connection: every further channel would fail the same way, and a channel + # that was never answered about keeps its turn for the next poll. + _channel(db, "UCa") + _channel(db, "UCb") + _FakeYt.failing["UUa"] = reason + + assert runner.run_feed_fallback(db, ["UCa", "UCb"])["failed"] == 1 + assert calls == ["UUa"] + assert db.get(Channel, "UCa").feed_fallback_at is None diff --git a/backend/tests/test_followed_channels.py b/backend/tests/test_followed_channels.py index 798b972f..5b914695 100644 --- a/backend/tests/test_followed_channels.py +++ b/backend/tests/test_followed_channels.py @@ -27,7 +27,7 @@ def test_the_rss_poll_skips_channels_nobody_follows(db, make_user, monkeypatch): polled: list[str] = [] monkeypatch.setattr(runner, "fetch_channel_feed", lambda cid: polled.append(cid) or []) monkeypatch.setattr(runner, "apply_rss_feed", lambda db, ch, entries: 0) - assert runner.run_rss_poll(db) == {"new": 0, "failed": 0} + assert runner.run_rss_poll(db) == {"new": 0, "failed": 0, "fallback": 0} assert sorted(polled) == ["UC_explored", "UC_sub"] diff --git a/backend/tests/test_last_login.py b/backend/tests/test_last_login.py index b2a48d6d..8b6b2973 100644 --- a/backend/tests/test_last_login.py +++ b/backend/tests/test_last_login.py @@ -95,3 +95,13 @@ def test_the_admin_user_list_carries_last_login(as_user, db, make_user): assert rows["boss@example.com"]["last_login_at"].startswith("2026-09-16T08:30") assert rows[never.email]["last_login_at"] is None + + +def test_the_account_sees_its_own_last_sign_in(client, db, make_user): + # Settings → Account shows it (prod UAT 2026-09-19: only the admin's user list did). + make_user(email="me@example.com", password=_PW) + client.post("/auth/password-login", json={"email": "me@example.com", "password": _PW}) + + stamp = client.get("/api/me").json()["last_login_at"] + + assert _recent(datetime.fromisoformat(stamp)) diff --git a/backend/tests/test_logs.py b/backend/tests/test_logs.py index a01403fb..86363f67 100644 --- a/backend/tests/test_logs.py +++ b/backend/tests/test_logs.py @@ -219,6 +219,14 @@ def _client() -> TestClient: raise HTTPException(status_code=400, detail={"code": "bad_cursor"}) return {"ok": True} + @app.get("/api/messages/unread_count") + def _unread(): + return {"count": 0} + + @app.post("/api/messages/unread_count") + def _unread_write(): + return {"ok": True} + @app.get("/boom") def _boom(): raise RuntimeError("kaboom") @@ -323,6 +331,33 @@ def test_the_log_consoles_own_reads_are_debug_but_its_failures_are_not(sink): assert sink.objects()[-1]["level"] == "WARNING" +def test_a_polled_read_is_debug_a_write_to_the_same_route_is_not(sink): + # One open tab polled the unread counts, /api/me and the download index every 30 s: at INFO + # that was ~95% of the stored log on prod. + http = logging.getLogger("siftlode.http") + http.setLevel(logs.TRACE) + client = _client() + r = client.get("/api/messages/unread_count") + assert sink.objects()[-1]["level"] == "DEBUG" + # ...and says so, for the browser's copy of the line (frontend lib/http.ts). + assert r.headers["X-Log-Quiet"] == "1" + r = client.post("/api/messages/unread_count") + assert sink.objects()[-1]["level"] == "INFO" + assert "X-Log-Quiet" not in r.headers + client.get("/api/videos/abc") + assert sink.objects()[-1]["level"] == "INFO" + + +def test_every_polled_route_is_a_route_the_app_has(): + # The list names route TEMPLATES; one renamed on the router side would silently fall back to + # INFO, so the list is held to the app's own routes. + from app.main import app + + # The schema, not `app.routes`: FastAPI 0.141 keeps an included router behind a wrapper there. + gets = {path for path, ops in app.openapi()["paths"].items() if "get" in ops} + assert logs._POLLED_ROUTES - gets == set() + + def test_a_failing_request_is_logged_by_status_and_an_unhandled_error_is_logged_at_all(sink): client = _client() client.get("/api/videos/missing/deeper") # 404 from the router diff --git a/backend/tests/test_sync_guards.py b/backend/tests/test_sync_guards.py index b36ce352..824f62d9 100644 --- a/backend/tests/test_sync_guards.py +++ b/backend/tests/test_sync_guards.py @@ -112,11 +112,15 @@ class TestRssPollResult: def _run(self, monkeypatch, *, fetch, apply_, channels=("UC1", "UC2")): monkeypatch.setattr(runner, "fetch_channel_feed", fetch) monkeypatch.setattr(runner, "apply_rss_feed", apply_) + # The API fallback has its own DB-lane tests (test_feed_fallback.py); here it reads nothing. + monkeypatch.setattr( + runner, "run_feed_fallback", lambda db, ids: {"read": 0, "new": 0, "failed": 0} + ) return runner.run_rss_poll(_StubDb(), [_StubChannel(c) for c in channels]) def test_a_healthy_run_reports_no_failures(self, monkeypatch): out = self._run(monkeypatch, fetch=lambda cid: [{"id": "v"}], apply_=lambda db, ch, e: 1) - assert out == {"new": 2, "failed": 0} + assert out == {"new": 2, "failed": 0, "fallback": 0} def test_unreadable_feeds_are_counted(self, monkeypatch): # One dead channel among healthy ones: counted, but the run itself is still a run. @@ -128,7 +132,7 @@ class TestRssPollResult: out = self._run( monkeypatch, fetch=fetch, apply_=lambda db, ch, e: 1, channels=("UC1", "UC_dead") ) - assert out == {"new": 1, "failed": 1} + assert out == {"new": 1, "failed": 1, "fallback": 0} def test_apply_failures_are_counted_too(self, monkeypatch): # A per-row write failure (a constraint clash on one channel) while the rest store fine. @@ -143,7 +147,9 @@ class TestRssPollResult: apply_=apply_, channels=("UC1", "UC_bad"), ) - assert out == {"new": 1, "failed": 1}, "an unstored channel must not read as ok" + assert out == {"new": 1, "failed": 1, "fallback": 0}, ( + "an unstored channel must not read as ok" + ) def test_many_failures_write_one_warning_with_counts_not_one_per_channel( self, monkeypatch, caplog @@ -163,7 +169,7 @@ class TestRssPollResult: caplog.set_level(logging.DEBUG, logger="siftlode.sync") out = self._run(monkeypatch, fetch=fetch, apply_=lambda db, ch, e: 1, channels=channels) - assert out == {"new": 5, "failed": 35} + assert out == {"new": 5, "failed": 35, "fallback": 0} warnings = [r for r in caplog.records if r.levelno >= logging.WARNING] assert len(warnings) == 1 assert warnings[0].event == "sync.rss.failed" @@ -195,7 +201,11 @@ class TestRssPollResult: def test_a_quiet_hour_is_distinguishable_from_an_outage(self, monkeypatch): quiet = self._run(monkeypatch, fetch=lambda cid: [], apply_=lambda db, ch, e: 0) - assert quiet == {"new": 0, "failed": 0} # same "new", different "failed" — that's the point + assert quiet == { + "new": 0, + "failed": 0, + "fallback": 0, + } # same "new", different "failed" — that's the point def test_a_total_outage_raises_instead_of_returning_ok(self, monkeypatch): # Every feed unreachable (the tinyproxy-lost-the-boot-race incident). Returning a result @@ -225,10 +235,43 @@ class TestRssPollResult: with pytest.raises(RuntimeError, match="read-only transaction"): self._run(monkeypatch, fetch=lambda cid: [{"id": "v"}], apply_=boom) + def test_only_the_unreadable_feeds_go_to_the_api_and_what_it_reads_counts( + self, monkeypatch, caplog + ): + # A feed that answered 404 is the fallback's; a channel whose rows failed to STORE is not — + # the API would hand the same rows to the same broken write. + seen = [] + + def fetch(cid): + if cid == "UC_dark": + raise rss.RssError("404", "http_404") + return [{"id": "v"}] + + def apply_(db, ch, entries): + if ch.id == "UC_badrow": + raise RuntimeError("constraint") + return 1 + + def fallback(db, ids): + seen.extend(ids) + return {"read": 1, "new": 3, "failed": 0} + + monkeypatch.setattr(runner, "fetch_channel_feed", fetch) + monkeypatch.setattr(runner, "apply_rss_feed", apply_) + monkeypatch.setattr(runner, "run_feed_fallback", fallback) + out = runner.run_rss_poll( + _StubDb(), [_StubChannel(c) for c in ("UC_ok", "UC_dark", "UC_badrow")] + ) + assert seen == ["UC_dark"] + assert out == {"new": 4, "failed": 2, "fallback": 1} + # ...and the one line the stored log keeps says so (an INFO line outside a request is not). + (warning,) = [r for r in caplog.records if getattr(r, "event", None) == "sync.rss.failed"] + assert warning.attrs["fallback_read"] == 1 and warning.attrs["fallback_new"] == 3 + def test_no_channels_at_all_is_not_an_outage(self, monkeypatch): # A fresh instance with nothing subscribed must not report an error every poll. out = self._run(monkeypatch, fetch=lambda cid: [], apply_=lambda db, ch, e: 0, channels=()) - assert out == {"new": 0, "failed": 0} + assert out == {"new": 0, "failed": 0, "fallback": 0} class TestRssErrorVsEmpty: diff --git a/backend/tests/test_youtube_no_channel.py b/backend/tests/test_youtube_no_channel.py new file mode 100644 index 00000000..a3c3d10f --- /dev/null +++ b/backend/tests/test_youtube_no_channel.py @@ -0,0 +1,38 @@ +"""A Google account without a YouTube channel: its `mine` playlists read answers 404 +`channelNotFound`. That is an empty list, not a failed sync — it came back as a warning every six +hours on prod for an account that will never have a channel.""" + +import logging + +import httpx +import pytest + +from app.youtube import client as yt + + +def _client(monkeypatch, status: int, reason: str) -> yt.YouTubeClient: + resp = httpx.Response( + status, + json={"error": {"code": status, "errors": [{"reason": reason, "message": "prose"}]}}, + request=httpx.Request("GET", f"{yt.API_BASE}/playlists"), + ) + c = yt.YouTubeClient.__new__(yt.YouTubeClient) # no HTTP client: `_send` is the stub + c.db = None + monkeypatch.setattr(yt.sysconfig, "get_str", lambda db, key: "") + monkeypatch.setattr(yt.quota, "record_usage", lambda cost: None) + monkeypatch.setattr(c, "_access_token", lambda: "t") + monkeypatch.setattr(c, "_send", lambda *a, **k: resp) + return c + + +def test_no_channel_is_an_empty_playlist_list_and_no_warning(monkeypatch, caplog): + caplog.set_level(logging.DEBUG, logger="siftlode") + assert list(_client(monkeypatch, 404, "channelNotFound").iter_my_playlists()) == [] + assert not [r for r in caplog.records if r.levelno >= logging.WARNING] + + +def test_any_other_failure_still_raises_and_warns(monkeypatch, caplog): + caplog.set_level(logging.DEBUG, logger="siftlode") + with pytest.raises(yt.YouTubeError): + list(_client(monkeypatch, 403, "quotaExceeded").iter_my_playlists()) + assert [r for r in caplog.records if r.levelno == logging.WARNING] diff --git a/frontend/src/components/AccountPanel.tsx b/frontend/src/components/AccountPanel.tsx index b93377e4..fd4eff9e 100644 --- a/frontend/src/components/AccountPanel.tsx +++ b/frontend/src/components/AccountPanel.tsx @@ -5,6 +5,7 @@ import { Check, Clock, Copy, Globe, KeyRound, LogIn, Mail, Send, ShieldAlert } f import Modal from "./ui/Modal"; import { LoadingState, StateMessage } from "./ui/QueryState"; import { api } from "../lib/api"; +import { displayName } from "../lib/api/account"; import { qk } from "../lib/queryKeys"; import { notify } from "../lib/notifications"; import { notifyActionError } from "../lib/actionErrors"; @@ -101,12 +102,7 @@ export default function AccountPanel({ const a: AdminUserAccess | undefined = q.data; return ( - +
{user.email}
{q.isError && !a ? ( diff --git a/frontend/src/components/AdminLogs.dom.test.tsx b/frontend/src/components/AdminLogs.dom.test.tsx index 8e6891cd..d342bda4 100644 --- a/frontend/src/components/AdminLogs.dom.test.tsx +++ b/frontend/src/components/AdminLogs.dom.test.tsx @@ -124,6 +124,46 @@ describe("AdminLogs", () => { expect([url.get("lreq"), url.get("lgrp"), url.get("lq")]).toEqual(["req-00000001", null, null]); }); + it("Back from a request's lines returns to the view the pivot was made from", async () => { + window.history.replaceState({ sfPage: "logs" }, "", "/?page=logs&lgrp=error&lq=boom"); + const depth = window.history.length; + logsMock.mockResolvedValue({ items: [row(1)], accounts: {}, next_cursor: null }); + renderConsole(); + await waitFor(() => expect(lines()).toHaveLength(1)); + fireEvent.click(lines()[0]!); + fireEvent.click(screen.getByRole("button", { name: "req-00000001" })); + await waitFor(() => + expect(screen.getByText("adminLogs.pivotRequest:req-00000001")).toBeTruthy(), + ); + expect(window.history.length).toBe(depth + 1); + + await act(async () => { + const landed = new Promise((resolve) => + window.addEventListener("popstate", resolve, { once: true }), + ); + window.history.back(); + await landed; + }); + + await waitFor(() => + expect(logsMock).toHaveBeenLastCalledWith( + expect.objectContaining({ + request_id: undefined, + levels: ["ERROR", "CRITICAL"], + q: "boom", + }), + null, + ), + ); + expect(screen.queryByText("adminLogs.pivotRequest:req-00000001")).toBeNull(); + const url = new URLSearchParams(window.location.search); + expect([url.get("lreq"), url.get("lgrp"), url.get("lq")]).toEqual([null, "error", "boom"]); + // Neither jump waited out the typing debounce: no read ever mixed one view's filters with the + // other's search text (the request with "boom", or the restored view without it). + const mixed = logsMock.mock.calls.filter(([q]) => (q.request_id != null) === (q.q === "boom")); + expect(mixed).toEqual([]); + }); + it("keeps the account in use offered when the facets no longer count it", async () => { window.history.replaceState(null, "", "/?page=logs&lu=7"); logsMock.mockResolvedValue({ items: [], accounts: {}, next_cursor: null }); diff --git a/frontend/src/components/AdminLogs.tsx b/frontend/src/components/AdminLogs.tsx index 1f5754db..f991f6ab 100644 --- a/frontend/src/components/AdminLogs.tsx +++ b/frontend/src/components/AdminLogs.tsx @@ -1,4 +1,4 @@ -import { useMemo, useRef, useState } from "react"; +import { useEffect, useMemo, useRef, useState } from "react"; import { useTranslation } from "react-i18next"; import { keepPreviousData, @@ -11,6 +11,7 @@ import { Copy, Radio, Search, X } from "lucide-react"; import { api, type LogFacet, type LogQuery, type ServerLogRow } from "../lib/api"; import { copyText } from "../lib/clipboard"; import { formatDateTime } from "../lib/format"; +import { nextNavId, notifyNav, rememberNavPosition } from "../lib/history"; import { LEVEL_GROUPS, type LevelGroup } from "../lib/log"; import { DEFAULT_LOGS_STATE, @@ -23,6 +24,7 @@ import { import { notify } from "../lib/notifications"; import { qk } from "../lib/queryKeys"; import { useDebounced } from "../lib/useDebounced"; +import { urlWithParams } from "../lib/urlState"; import { useUrlMirror } from "../lib/useUrlMirror"; import LogLine from "./LogLine"; import NavGrid from "./ui/NavGrid"; @@ -80,8 +82,21 @@ export default function AdminLogs() { setLiveState(on); }; const [open, setOpen] = useState(null); - const q = useDebounced(state.q, 300); + // Bumped when the view changes by a jump (a pivot, Back/Forward) rather than by typing: the + // search box's text then applies at once instead of after the typing debounce. + const [jumps, setJumps] = useState(0); + const q = useDebounced(state.q, 300, jumps); useUrlMirror(logsParamUpdates(state)); + // Back/Forward lands on another view of the console (a pivot pushed one, below): read it back. + useEffect(() => { + const onPop = () => { + setOpen(null); + setJumps((n) => n + 1); + setState(logsParamsToState(new URLSearchParams(window.location.search))); + }; + window.addEventListener("popstate", onPop); + return () => window.removeEventListener("popstate", onPop); + }, []); const update = (patch: Partial) => { setOpen(null); @@ -184,9 +199,19 @@ export default function AdminLogs() { return facets.data ? sum(levels.filter((f) => inGroup.includes(f.value))) : undefined; }; + // A pivot follows a link to another view, so it is its own history entry and Back returns to the + // view it was made from. The other filters are adjustments of the view on screen and replace it. const pivot = (patch: Pick) => { setLive(false); - update({ ...PIVOT_RESET, ...patch }); + const next = { ...state, ...PIVOT_RESET, ...patch }; + window.history.pushState( + { ...rememberNavPosition(), sfScroll: nextNavId() }, + "", + urlWithParams(logsParamUpdates(next)), + ); + notifyNav(); + setJumps((n) => n + 1); + update(next); }; // "Any", then what the facet counted. The value in use stays offered even at zero — under the diff --git a/frontend/src/components/AdminUsers.tsx b/frontend/src/components/AdminUsers.tsx index 27ee9011..1a9a5ee3 100644 --- a/frontend/src/components/AdminUsers.tsx +++ b/frontend/src/components/AdminUsers.tsx @@ -23,6 +23,7 @@ import { type Me, type PendingAccessRow, } from "../lib/api"; +import { displayName } from "../lib/api/account"; import { notify } from "../lib/notifications"; import { formatDateTime, relativeTime } from "../lib/format"; import { invalidateUserAccess } from "../lib/adminUsers"; @@ -234,7 +235,7 @@ function UsersRoles({ me }: { me: Me }) { className="selectable cursor-pointer min-w-0 flex-1 text-left rounded-lg -m-1 p-1" >
- {u.display_name ?? u.email.split("@")[0]} + {displayName(u)} {self && · {t("users.roles.you")}}
{u.email}
diff --git a/frontend/src/components/ComfortPinMenu.tsx b/frontend/src/components/ComfortPinMenu.tsx index 7a3c5e73..b7aefc2e 100644 --- a/frontend/src/components/ComfortPinMenu.tsx +++ b/frontend/src/components/ComfortPinMenu.tsx @@ -1,7 +1,10 @@ import { useTranslation } from "react-i18next"; +import { Bookmark, BookmarkX, Check, Eye, EyeOff, RotateCcw, Undo2 } from "lucide-react"; -import { type PlexCard, type Video } from "../lib/api"; +import { type PlexCard, type Video, type VideoStatus } from "../lib/api"; +import { isResettable } from "../lib/api/feed"; import { pinPlex, pinVideo, useComfortPin, type PinTarget } from "./comfortPin"; +import { type ActionMenuItem } from "./ui/ActionMenu"; import { ContextMenu } from "./ui/ContextMenu"; import { type ContextMenuController } from "./ui/useContextMenu"; @@ -44,7 +47,63 @@ export function PlexPinMenu({ menu }: { menu: ContextMenuController }) return c.title} />; } -/** The YouTube video lists (the feed grid, the Home rails). */ -export function VideoPinMenu({ menu }: { menu: ContextMenuController