diff --git a/CHANGELOG.md b/CHANGELOG.md index fe84175e..a6fe27d8 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,6 +7,27 @@ 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.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. + +### Features + +- Admin → Server log: the stored log, newest first, with a search, level chips, and source, account, event and period filters. A line opens in place to its full record; its request id or job id narrows the list to everything that request or job wrote. +- Filters live in the address bar, so a filtered view is a link, and Back brings the previous view back. +- Live follows the newest lines every few seconds; Copy puts the loaded lines on the clipboard, oldest first. A failed read says so instead of quietly freezing the list. +- Both log viewers (Server log and My log) can be walked with j/k and a line opened with Enter. + +### Fixes + +- New videos no longer arrive late from channels whose YouTube feed answers 404 or 500 now and then: a feed is tried again before the channel counts as failed. +- A % or _ typed into a search is searched for as itself, not as a wildcard. + +### Internal + +- The console's own reads are logged at debug level, so watching the log does not fill it. +- Two adversarial review rounds: 19 findings raised, 12 survived, all fixed, and every regression test was proven to fail with its own fix removed. + ## 0.89.0 — 2026-09-19 A release for the log rather than for the screen: what the server writes down when something fails is now complete, said once, and free of what you downloaded or searched for. diff --git a/VERSION b/VERSION index 5aee1345..ae02209b 100644 --- a/VERSION +++ b/VERSION @@ -1 +1 @@ -0.89.0 +0.90.0 diff --git a/backend/app/feedquery.py b/backend/app/feedquery.py index 35cd8cfd..b4e17c9d 100644 --- a/backend/app/feedquery.py +++ b/backend/app/feedquery.py @@ -30,7 +30,7 @@ from app.models import ( Video, VideoState, ) -from app.utils import iso, to_tsquery_str +from app.utils import iso, like_escape, to_tsquery_str def _channel_url(channel_id: str, handle: str | None) -> str: @@ -272,8 +272,9 @@ def filtered_query( # `unaccent(channels.title) ILIKE '%q%'` straight into the per-video predicate defeated the # search_vector GIN — the planner detoasted every non-matching tsvector to test the `@@` # (~2.6s/search on the prod-sized set); channel_id.in_(...) keeps the GIN as a BitmapOr branch - # (PERF-12). Empty match -> false() so the OR collapses to the text match alone. - like = func.unaccent(f"%{q}%") + # (PERF-12). Empty match -> false() so the OR collapses to the text match alone. The query + # is a literal inside the pattern: `_` in `my_channel` is not a wildcard. + like = func.unaccent(f"%{like_escape(q)}%") matching_channel_ids = ( db.execute(select(Channel.id).where(func.unaccent(Channel.title).ilike(like))) .scalars() diff --git a/backend/app/logs.py b/backend/app/logs.py index 013076ed..cfb49e7c 100644 --- a/backend/app/logs.py +++ b/backend/app/logs.py @@ -638,9 +638,11 @@ def current_source() -> str: _REQUEST_ID_RE = re.compile(r"^[A-Za-z0-9._-]{8,64}$") # Paths whose success is logged at DEBUG rather than INFO: the container healthcheck runs every 15s -# (5.7k lines/day saying nothing) and hashed static assets are served by the hundred per page load. -# A FAILURE on either still logs at WARNING/ERROR — this lowers the floor, it does not hide. -_QUIET_PREFIXES = ("/healthz", "/assets/", "/static/") +# (5.7k lines/day saying nothing), hashed static assets are served by the hundred per page load, and +# the admin log console reads the stored log — its live tail every few seconds, so at INFO the log +# would fill with the console watching itself. A FAILURE on any of them still logs at WARNING/ERROR +# — this lowers the floor, it does not hide. +_QUIET_PREFIXES = ("/healthz", "/assets/", "/static/", "/api/admin/logs") # 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 diff --git a/backend/app/main.py b/backend/app/main.py index 5896a885..bf0e4708 100644 --- a/backend/app/main.py +++ b/backend/app/main.py @@ -32,6 +32,7 @@ from app.plex import stream as plex_stream from app.plex import subtitles as plex_subtitles from app.routes import ( admin, + admin_logs as admin_logs_routes, audit as audit_routes, auth as auth_routes, channels, @@ -285,6 +286,7 @@ app.include_router(admin.router) app.include_router(config_routes.router) app.include_router(scheduler_routes.router) app.include_router(audit_routes.router) +app.include_router(admin_logs_routes.router) app.include_router(quota.router) app.include_router(version.router) app.include_router(setup_routes.router) diff --git a/backend/app/plex/query.py b/backend/app/plex/query.py index 20abd28b..406ffe8c 100644 --- a/backend/app/plex/query.py +++ b/backend/app/plex/query.py @@ -298,10 +298,6 @@ class LibraryFilters: } -def like_escape(s: str) -> str: - return s.replace("\\", "\\\\").replace("%", "\\%").replace("_", "\\_") - - # --- Watch-state scope (shared by the /library grid AND the /facets aggregation) --------------- # # The `show` scope (all | watched | in_progress | unwatched) filters the browse result by per-user diff --git a/backend/app/routes/admin_logs.py b/backend/app/routes/admin_logs.py new file mode 100644 index 00000000..43ae3c65 --- /dev/null +++ b/backend/app/routes/admin_logs.py @@ -0,0 +1,234 @@ +"""The admin diagnostics console's read side (E22.6): query `log_events`, the server's stored log. + +Admin-only and read-only — rows leave the table through the retention job (`log_retention_days`), +never through here. Reading is not audited: it changes nothing, and the console's live tail polls, +so a row per read would bury the audit log's real entries. + +What a row holds was redacted when it was written (`logs.record_fields`, and the ingest route for a +browser's rows), so this serves the columns as they are; a value the redactor took out reads as +`[redacted]` / `[email]`, which is the point — the console shows that something was there. + +Paging is a keyset over `(ts desc, id desc)`: a browser row's `ts` is clamped into its consent +window, so `ts` alone is not unique, and an offset would skip or repeat rows while the writer adds +new ones at the top. The live tail re-reads the first page rather than asking for "ids after N": +several processes write this table, and a batch's ids are taken when it inserts, not when it +commits, so a slower batch can land below an id the tail already passed — and would never show. +""" + +import base64 +import binascii +import json +from dataclasses import dataclass +from datetime import datetime, timezone +from typing import Literal + +from fastapi import APIRouter, Depends, HTTPException, Query +from sqlalchemy import Text, and_, cast, func, or_, select +from sqlalchemy.orm import Session + +from app.auth import admin_user +from app.db import get_db +from app.models import LogEvent, User +from app.utils import iso, like_escape + +router = APIRouter(prefix="/api/admin/logs", tags=["admin"]) + +PAGE_MAX = 200 +# A facet list is a chip row, not a report: past this many distinct events the rest are reachable +# through the free-text search, and the response stays small whatever a self-host logs. +FACET_EVENTS_MAX = 100 + +Level = Literal["TRACE", "DEBUG", "INFO", "WARNING", "ERROR", "CRITICAL"] +# The filters a facet can leave out of its own count (`LogFilters.conditions`). +Facet = Literal["levels", "sources", "user", "event"] +# `none` selects the rows that have no account / no event code (a scheduler line, an anonymous +# request) — a real value to filter on, not the absence of a filter. +NONE = "none" + + +def _utc(value: datetime | None) -> datetime | None: + """A bound without a zone is UTC — the column is `timestamptz`, and a naive value would be read + in the database session's zone instead.""" + if value is None or value.tzinfo is not None: + return value + return value.replace(tzinfo=timezone.utc) + + +def _encode_cursor(row: LogEvent) -> str: + return base64.urlsafe_b64encode(json.dumps([row.ts.isoformat(), row.id]).encode()).decode() + + +def _decode_cursor(cursor: str) -> tuple[datetime, int]: + try: + ts, row_id = json.loads(base64.urlsafe_b64decode(cursor.encode())) + return _utc(datetime.fromisoformat(ts)), int(row_id) + except (binascii.Error, json.JSONDecodeError, ValueError, TypeError) as exc: + raise HTTPException(status_code=400, detail={"code": "bad_cursor"}) from exc + + +def _serialize(row: LogEvent) -> dict: + return { + "id": row.id, + "ts": iso(row.ts), + "level": row.level, + "source": row.source, + "logger": row.logger, + "event": row.event, + "msg": row.msg, + "attrs": row.attrs, + "exc": row.exc, + "request_id": row.request_id, + "user_id": row.user_id, + "job_id": row.job_id, + "debug_session_id": row.debug_session_id, + "version": row.version, + } + + +def _accounts(db: Session, user_ids: set[int]) -> dict[str, str]: + """The accounts a page names, by id → address. An id with no account left (erased after the + line was written) is simply absent, and the client shows the bare id.""" + if not user_ids: + return {} + rows = db.execute(select(User.id, User.email).where(User.id.in_(user_ids))).all() + return {str(uid): email for uid, email in rows} + + +@dataclass(frozen=True) +class LogFilters: + """The console's filters, shared by the page and its facet counts.""" + + levels: list[str] + sources: list[str] + user: str | None + event: str | None + request_id: str | None + job_id: int | None + q: str | None + since: datetime | None + until: datetime | None + + def conditions(self, skip: Facet | None = None) -> list: + """The WHERE conditions, ANDed by the caller. `skip` leaves one filter out: a facet counts + its own values under every OTHER filter, so picking a level does not zero the other + levels' counts (the way back), while a request pivot does narrow them (honest counts).""" + out = [] + if self.levels and skip != "levels": + out.append(LogEvent.level.in_(self.levels)) + if self.sources and skip != "sources": + out.append(LogEvent.source.in_(self.sources)) + if self.user is not None and skip != "user": + out.append( + LogEvent.user_id.is_(None) + if self.user == NONE + else LogEvent.user_id == int(self.user) + ) + if self.event is not None and skip != "event": + out.append( + LogEvent.event.is_(None) if self.event == NONE else LogEvent.event == self.event + ) + if self.request_id is not None: + out.append(LogEvent.request_id == self.request_id) + if self.job_id is not None: + out.append(LogEvent.job_id == self.job_id) + if self.since is not None: + out.append(LogEvent.ts >= _utc(self.since)) + if self.until is not None: + out.append(LogEvent.ts < _utc(self.until)) + if self.q and self.q.strip(): + like = f"%{like_escape(self.q.strip())}%" + out.append( + or_( + LogEvent.msg.ilike(like), + LogEvent.event.ilike(like), + LogEvent.request_id.ilike(like), + LogEvent.exc.ilike(like), + cast(LogEvent.attrs, Text).ilike(like), + ) + ) + return out + + +def log_filters( + levels: list[Level] = Query(default=[]), + sources: list[str] = Query(default=[], max_length=8), + user: str | None = Query(default=None, pattern=r"^(none|[0-9]{1,10})$"), + event: str | None = Query( + default=None, max_length=64, pattern=r"^(none|[a-z][a-z0-9_]*(\.[a-z0-9_]+)*)$" + ), + request_id: str | None = Query(default=None, pattern=r"^[A-Za-z0-9._-]{8,64}$"), + job_id: int | None = Query(default=None, ge=1), + q: str | None = Query(default=None, max_length=200), + since: datetime | None = None, + until: datetime | None = None, +) -> LogFilters: + return LogFilters(list(levels), list(sources), user, event, request_id, job_id, q, since, until) + + +@router.get("") +def list_logs( + filters: LogFilters = Depends(log_filters), + before: str | None = Query(default=None, max_length=200), + limit: int = Query(default=100, ge=1, le=PAGE_MAX), + _: User = Depends(admin_user), + db: Session = Depends(get_db), +) -> dict: + """One page of rows, newest first, matching every filter given (they AND together); `before` + continues from a previous page's `next_cursor`.""" + query = select(LogEvent).where(*filters.conditions()) + if before is not None: + ts, row_id = _decode_cursor(before) + # The `ts <=` conjunct is implied by the OR; it is there so the planner can bound the + # `ts` index scan instead of filtering every newer row first. + query = query.where( + and_( + LogEvent.ts <= ts, + or_(LogEvent.ts < ts, and_(LogEvent.ts == ts, LogEvent.id < row_id)), + ) + ) + + # One more than asked, to know whether there is a next page without a second count query. + rows = ( + db.execute(query.order_by(LogEvent.ts.desc(), LogEvent.id.desc()).limit(limit + 1)) + .scalars() + .all() + ) + more = len(rows) > limit + rows = rows[:limit] + return { + "items": [_serialize(r) for r in rows], + "accounts": _accounts(db, {r.user_id for r in rows if r.user_id is not None}), + "next_cursor": _encode_cursor(rows[-1]) if more else None, + } + + +@router.get("/facets") +def log_facets( + filters: LogFilters = Depends(log_filters), + _: User = Depends(admin_user), + db: Session = Depends(get_db), +) -> dict: + """What the filter chips offer, with counts: the levels, sources and accounts present, and the + most frequent events — each counted under every filter but its own (`LogFilters.conditions`). + `total` is the "all levels" count: every filter but the level one.""" + + def counts(col, skip: Facet, cap: int | None = None) -> list[dict]: + n = func.count().label("n") + stmt = select(col, n).where(*filters.conditions(skip)).group_by(col).order_by(n.desc(), col) + if cap is not None: + stmt = stmt.limit(cap) + return [ + {"value": NONE if value is None else value, "count": count} + for value, count in db.execute(stmt).all() + ] + + users = counts(LogEvent.user_id, "user") + total = select(func.count()).select_from(LogEvent).where(*filters.conditions("levels")) + return { + "levels": counts(LogEvent.level, "levels"), + "sources": counts(LogEvent.source, "sources"), + "events": counts(LogEvent.event, "event", FACET_EVENTS_MAX), + "users": [{**u, "value": str(u["value"])} for u in users], + "accounts": _accounts(db, {u["value"] for u in users if u["value"] != NONE}), + "total": db.scalar(total) or 0, + } diff --git a/backend/app/routes/plex/collections.py b/backend/app/routes/plex/collections.py index 5719cf3a..ada9eb92 100644 --- a/backend/app/routes/plex/collections.py +++ b/backend/app/routes/plex/collections.py @@ -24,7 +24,8 @@ from app.plex import sync as plex_sync from app.plex.cards import movie_card, show_card from app.plex.client import PlexClient, PlexError, PlexNotConfigured from app.plex.lookups import by_rating_key -from app.plex.query import content_libs, like_escape, runtime_by_key, top_art_keys +from app.plex.query import content_libs, runtime_by_key, top_art_keys +from app.utils import like_escape # The most-restrictive → least ordering used to pick a collection's effective content rating from its # members (Plex shows one cert on the collection; we don't store it, so derive it). diff --git a/backend/app/routes/search.py b/backend/app/routes/search.py index f06adedf..a2244657 100644 --- a/backend/app/routes/search.py +++ b/backend/app/routes/search.py @@ -38,6 +38,7 @@ from app.models import ( VideoState, ) from app.feedquery import feed_columns, serialize +from app.utils import like_escape from app.sync.subscriptions import apply_channel_details from app.sync.videos import insert_stubs, apply_video_details, parse_dt from app.youtube import search_scrape @@ -224,6 +225,25 @@ def _new_first(db: Session, user: User, ids: list[str]) -> list[str]: return [i for i in ids if i not in have] + [i for i in ids if i in have] +def _fold_term(db: Session, video_ids: list[str], term: str) -> None: + """Append `term` to each video's space-joined `search_terms`, unless it is already one of them. + + "Already one of them" is a whole-term match, as a literal: a substring test skipped `cat` on a + video already found for `category`, and an unescaped one read the `_` in `my_channel` as a + wildcard — either way the term was never folded in, and local search lost that relevance.""" + padded = func.concat(" ", func.coalesce(Video.search_terms, ""), " ") + db.execute( + update(Video) + .where(Video.id.in_(video_ids)) + .where(padded.notilike(f"% {like_escape(term)} %")) + .values( + search_terms=func.trim( + func.coalesce(Video.search_terms, "").op("||")(" ").op("||")(term) + ) + ) + ) + + @router.get("/youtube") def search_youtube( q: str | None = None, @@ -364,16 +384,7 @@ def search_youtube( .values([{"user_id": user.id, "video_id": vid} for vid in ordered]) .on_conflict_do_nothing(index_elements=["user_id", "video_id"]) ) - db.execute( - update(Video) - .where(Video.id.in_(ordered)) - .where(func.coalesce(Video.search_terms, "").notilike(f"%{term}%")) - .values( - search_terms=func.trim( - func.coalesce(Video.search_terms, "").op("||")(" ").op("||")(term) - ) - ) - ) + _fold_term(db, ordered, term) db.commit() ordered = _new_first(db, user, ordered) diff --git a/backend/app/utils.py b/backend/app/utils.py index 3128e4a8..248fb389 100644 --- a/backend/app/utils.py +++ b/backend/app/utils.py @@ -73,6 +73,14 @@ def to_tsquery_str(q: str) -> str | None: return " & ".join(tokens) +def like_escape(s: str) -> str: + """`s` as a LITERAL inside a LIKE/ILIKE pattern: `%` and `_` are wildcards there, and `\\` is + Postgres's default escape character, so all three are escaped. Every pattern built from text a + person typed goes through this — unescaped, a search for `100%` or `my_channel` matches rows it + should not.""" + return s.replace("\\", "\\\\").replace("%", "\\%").replace("_", "\\_") + + def normalize_description(text: str | None) -> str | None: """Strip whitespace-only lines from a CHANNEL description before storing. YouTube channel descriptions pad their contact/link blocks with runs of blank lines; keeping them wastes storage, diff --git a/backend/app/youtube/rss.py b/backend/app/youtube/rss.py index e4624e76..510bc13d 100644 --- a/backend/app/youtube/rss.py +++ b/backend/app/youtube/rss.py @@ -1,6 +1,7 @@ """Free per-channel RSS feed reader (no API quota). Returns the channel's most recent ~15 uploads as lightweight stubs for fast fresh-video detection.""" +import time from datetime import datetime, timezone import feedparser @@ -8,6 +9,18 @@ import httpx RSS_URL = "https://www.youtube.com/feeds/videos.xml?channel_id={channel_id}" +# The waits before a second and a third try. YouTube's feed endpoint answers the SAME channel with +# 404, 500 and 200 in turn (measured 2026-09-19: 15 of 24 channels failed a first request, 16 of them +# had succeeded by the fifth, one second apart), so one failure is not an answer. A feed that is +# really gone costs two more requests per poll. A TIMEOUT is not tried again: the flaky endpoint +# answers fast, and a request that hung for `TIMEOUT` says the way out is hanging — three of them +# per channel would stretch a poll over a dead egress to three times its interval. +RETRY_DELAYS = (1.0, 2.0) +TIMEOUT = 20.0 +# A 404 is in the set because that is how the flaky endpoint fails most often; a 403/410 is not, +# and neither is anything else that says the request itself is wrong. +_RETRYABLE_STATUS = frozenset({404, 429, 500, 502, 503, 504}) + class RssError(Exception): """The feed could not be read (transport failure or a non-200 answer). @@ -24,21 +37,36 @@ class RssError(Exception): self.reason = reason -def fetch_channel_feed(channel_id: str) -> list[dict]: - """The channel's recent uploads as stubs. `[]` means the feed really is empty; a failure - raises RssError so the caller can leave the channel un-stamped and log it.""" +def _get_feed(channel_id: str) -> bytes: + """The feed's body, after up to `1 + len(RETRY_DELAYS)` tries; the LAST failure is raised.""" url = RSS_URL.format(channel_id=channel_id) - try: - resp = httpx.get(url, timeout=20.0, headers={"User-Agent": "Siftlode/1.0"}) - except httpx.HTTPError as exc: - raise RssError(f"RSS fetch failed for {channel_id}: {exc}", "transport") from exc - if resp.status_code != 200: - raise RssError( + for attempt in range(len(RETRY_DELAYS) + 1): + if attempt: + time.sleep(RETRY_DELAYS[attempt - 1]) + try: + resp = httpx.get(url, timeout=TIMEOUT, headers={"User-Agent": "Siftlode/1.0"}) + # silent-ok: not silent — the last failure is raised after the final try. + except httpx.HTTPError as exc: + error = RssError(f"RSS fetch failed for {channel_id}: {exc}", "transport") + error.__cause__ = exc + if isinstance(exc, httpx.TimeoutException): + break + continue + if resp.status_code == 200: + return resp.content + error = RssError( f"RSS fetch for {channel_id} returned HTTP {resp.status_code}", f"http_{resp.status_code}", ) + if resp.status_code not in _RETRYABLE_STATUS: + break + raise error - parsed = feedparser.parse(resp.content) + +def fetch_channel_feed(channel_id: str) -> list[dict]: + """The channel's recent uploads as stubs. `[]` means the feed really is empty; a failure + (after the retries) raises RssError so the caller can leave the channel un-stamped and log it.""" + parsed = feedparser.parse(_get_feed(channel_id)) out: list[dict] = [] for entry in parsed.entries: video_id = entry.get("yt_videoid") diff --git a/backend/tests/test_admin_logs.py b/backend/tests/test_admin_logs.py new file mode 100644 index 00000000..87660e41 --- /dev/null +++ b/backend/tests/test_admin_logs.py @@ -0,0 +1,191 @@ +"""The admin diagnostics console's query API (E22.6 S1), DB-lane.""" + +from datetime import datetime, timedelta, timezone + +import pytest +from sqlalchemy import insert + +from app.models import LogEvent + +T0 = datetime(2026, 9, 19, 12, 0, tzinfo=timezone.utc) + + +def _row(**kw) -> dict: + row = { + "ts": T0, + "level": "INFO", + "sev": 9, + "source": "api", + "logger": "siftlode.http", + "event": "http.request", + "msg": "GET /api/feed 200", + "attrs": None, + "exc": None, + "request_id": None, + "user_id": None, + "job_id": None, + "version": "0.90.0", + } + row.update(kw) + return row + + +def _add(db, *rows: dict) -> None: + db.execute(insert(LogEvent), list(rows)) + db.commit() + + +@pytest.fixture +def admin(db, make_user, as_user): + return as_user(make_user(email="admin@example.com", role="admin")) + + +def _msgs(resp) -> list[str]: + assert resp.status_code == 200, resp.text + return [it["msg"] for it in resp.json()["items"]] + + +def test_only_an_admin_reads_the_log(db, make_user, as_user, client): + _add(db, _row()) + assert as_user(make_user()).get("/api/admin/logs").status_code == 403 + assert as_user(make_user()).get("/api/admin/logs/facets").status_code == 403 + assert client.get("/api/admin/logs").status_code == 401 + + +def test_newest_first_and_every_row_once_across_pages_even_on_equal_timestamps(db, admin): + # A browser row's `ts` is clamped, so several rows share one: the id breaks the tie. + _add(db, *[_row(msg=f"same {i}") for i in range(5)], _row(ts=T0 - timedelta(1), msg="older")) + + seen, cursor = [], None + while True: + resp = admin.get( + "/api/admin/logs", params={"limit": 2, "before": cursor} if cursor else {"limit": 2} + ) + seen += _msgs(resp) + cursor = resp.json()["next_cursor"] + if cursor is None: + break + + assert seen == ["same 4", "same 3", "same 2", "same 1", "same 0", "older"] + + +@pytest.mark.parametrize( + ("params", "expected"), + [ + ({"levels": ["ERROR", "WARNING"]}, {"err", "warn"}), + ({"sources": ["worker"]}, {"err"}), + ({"user": "1"}, {"mine"}), + ({"user": "none"}, {"err", "warn", "plain"}), + ({"event": "download.job.failed"}, {"err"}), + ({"event": "none"}, {"warn"}), + ({"request_id": "req-abcdef12"}, {"mine"}), + ({"job_id": 42}, {"err"}), + ({"q": "FORBIDDEN"}, {"err"}), # in attrs, any case + ({"q": "KeyError"}, {"warn"}), # in the stack + ({"q": "100%"}, {"plain"}), # a literal, not a wildcard + ({"since": (T0 - timedelta(hours=1)).isoformat()}, {"mine", "err", "warn"}), + ({"until": (T0 - timedelta(hours=1)).isoformat()}, {"plain", "decoy"}), + ({"levels": ["INFO"], "user": "none"}, {"plain"}), + ], +) +def test_each_filter_selects_exactly_its_rows(db, admin, make_user, params, expected): + # user 1 is the admin the fixture made + _add( + db, + _row(msg="mine", user_id=1, request_id="req-abcdef12"), + _row( + msg="err", + level="ERROR", + sev=17, + source="worker", + event="download.job.failed", + job_id=42, + attrs={"code": "forbidden"}, + ), + _row(msg="warn", level="WARNING", sev=13, event=None, exc="Traceback …\nKeyError: 'x'"), + _row(msg="plain", ts=T0 - timedelta(hours=2), attrs={"note": "100% done"}), + # Matched by no filter above but `until`: another account, and `100%` read as a pattern. + _row(msg="decoy", ts=T0 - timedelta(hours=3), attrs={"note": "1000 done"}, user_id=99), + ) + assert set(_msgs(admin.get("/api/admin/logs", params=params))) == expected + + +def test_a_page_names_its_accounts_and_leaves_an_erased_one_bare(db, admin): + _add(db, _row(user_id=1), _row(user_id=77)) + + assert admin.get("/api/admin/logs").json()["accounts"] == {"1": "admin@example.com"} + + +@pytest.mark.parametrize( + "params", + [ + {"before": "not-a-cursor"}, + {"before": "WyJ4IiwgMV0="}, # ["x", 1]: decodes, not a timestamp + ], +) +def test_a_bad_cursor_is_a_400_with_a_code(db, admin, params): + resp = admin.get("/api/admin/logs", params=params) + assert resp.status_code == 400 + assert resp.json()["detail"]["code"] == "bad_cursor" + + +def test_facets_count_the_window_and_name_the_rows_without_a_value(db, admin): + _add( + db, + _row(user_id=1), + _row(user_id=1, level="ERROR", sev=17, event="sync.rss.failed"), + _row(event=None), + _row(ts=T0 - timedelta(days=2), source="worker"), + ) + + body = admin.get( + "/api/admin/logs/facets", params={"since": (T0 - timedelta(days=1)).isoformat()} + ).json() + + assert body["total"] == 3 + assert body["levels"] == [{"value": "INFO", "count": 2}, {"value": "ERROR", "count": 1}] + assert body["sources"] == [{"value": "api", "count": 3}] + assert body["events"] == [ + {"value": "http.request", "count": 1}, + {"value": "sync.rss.failed", "count": 1}, + {"value": "none", "count": 1}, + ] + assert body["users"] == [{"value": "1", "count": 2}, {"value": "none", "count": 1}] + assert body["accounts"] == {"1": "admin@example.com"} + + +def test_a_facet_counts_under_every_other_filter_but_not_its_own(db, admin): + _add( + db, + _row(request_id="req-aaaaaaaa"), + _row(request_id="req-aaaaaaaa", level="ERROR", sev=17, source="worker"), + _row(request_id="req-bbbbbbbb", level="ERROR", sev=17), + _row(request_id="req-bbbbbbbb"), + ) + + body = admin.get( + "/api/admin/logs/facets", params={"request_id": "req-aaaaaaaa", "levels": ["ERROR"]} + ).json() + + # The pivot narrows every count; the picked level does not zero its sibling (the way back). + assert body["levels"] == [{"value": "ERROR", "count": 1}, {"value": "INFO", "count": 1}] + assert body["total"] == 2 + # Every other facet counts under the level filter too. + assert body["sources"] == [{"value": "worker", "count": 1}] + + +@pytest.mark.parametrize( + ("params", "facet", "expected"), + [ + ({"sources": ["worker"]}, "sources", {"api", "worker"}), + ({"user": "1"}, "users", {"1", "none"}), + ({"event": "sync.rss.failed"}, "events", {"http.request", "sync.rss.failed"}), + ], +) +def test_every_facet_keeps_its_siblings_under_its_own_filter(db, admin, params, facet, expected): + # The way back from a pick: the picked facet still offers the values it was picked from. + _add(db, _row(user_id=1), _row(source="worker", event="sync.rss.failed")) + + body = admin.get("/api/admin/logs/facets", params=params).json() + + assert {f["value"] for f in body[facet]} == expected diff --git a/backend/tests/test_like_literals.py b/backend/tests/test_like_literals.py new file mode 100644 index 00000000..217ee86d --- /dev/null +++ b/backend/tests/test_like_literals.py @@ -0,0 +1,81 @@ +"""What a person types is a literal inside a LIKE pattern, never a wildcard (DB-lane). + +`%` and `_` are LIKE wildcards. The feed's channel-name match and the live search's term fold both +built their pattern from the typed text as it was, so `my_channel` also matched `myXchannel`, and a +term already present as part of a longer word was never folded in. +""" + +from datetime import datetime, timezone + +from sqlalchemy import select + +from app.models import Channel, Subscription, Video +from app.routes.search import _fold_term + + +def _video(vid: str, ch: str, title: str, search_terms: str | None = None) -> Video: + return Video( + id=vid, + channel_id=ch, + published_at=datetime(2024, 1, 1, tzinfo=timezone.utc), + title=title, + is_short=False, + live_status="none", + via_search=False, + via_explore=False, + search_terms=search_terms, + ) + + +def test_an_underscore_in_a_feed_search_matches_only_itself(db, as_user, make_user): + user = make_user() + db.add_all( + [ + Channel(id="UCunder", title="build_log daily", subscriber_count=1), + Channel(id="UClookalike", title="buildXlog daily", subscriber_count=1), + ] + ) + db.add_all( + [ + Subscription(user_id=user.id, channel_id=ch, priority=0, hidden=False) + for ch in ("UCunder", "UClookalike") + ] + ) + db.add_all( + [ + _video("vidUnder", "UCunder", "Nothing in common"), + _video("vidLook", "UClookalike", "Nothing in common either"), + ] + ) + db.commit() + + resp = as_user(user).get("/api/feed?q=build_log&show=all&limit=50") + + assert resp.status_code == 200, resp.text + assert {it["id"] for it in resp.json()["items"]} == {"vidUnder"} + + +def test_a_term_is_folded_in_unless_it_is_already_a_whole_term(db): + db.add(Channel(id="UCfold", title="Fold", subscriber_count=1)) + db.add_all( + [ + _video("vidWord", "UCfold", "a", search_terms="category"), + _video("vidWild", "UCfold", "b", search_terms="catXdog"), + _video("vidHas", "UCfold", "c", search_terms="old cat_dog new"), + _video("vidNone", "UCfold", "d"), + ] + ) + db.commit() + + _fold_term(db, ["vidWord", "vidWild", "vidHas", "vidNone"], "cat") + _fold_term(db, ["vidWild", "vidHas"], "cat_dog") + db.commit() + db.expire_all() + + terms = dict(db.execute(select(Video.id, Video.search_terms)).all()) + assert terms == { + "vidWord": "category cat", + "vidWild": "catXdog cat cat_dog", + "vidHas": "old cat_dog new cat", + "vidNone": "cat", + } diff --git a/backend/tests/test_logs.py b/backend/tests/test_logs.py index 556db984..a01403fb 100644 --- a/backend/tests/test_logs.py +++ b/backend/tests/test_logs.py @@ -14,7 +14,7 @@ import logging from pathlib import Path import pytest -from fastapi import FastAPI, Request +from fastapi import FastAPI, HTTPException, Request from fastapi.testclient import TestClient from app import logs @@ -213,6 +213,12 @@ def _client() -> TestClient: def _health(): return {"ok": True} + @app.get("/api/admin/logs/facets") + def _log_console(fail: bool = False): + if fail: + raise HTTPException(status_code=400, detail={"code": "bad_cursor"}) + return {"ok": True} + @app.get("/boom") def _boom(): raise RuntimeError("kaboom") @@ -307,6 +313,16 @@ def test_the_healthcheck_is_logged_at_debug_so_it_cannot_drown_the_log(sink): assert len(sink.lines) == before +def test_the_log_consoles_own_reads_are_debug_but_its_failures_are_not(sink): + http = logging.getLogger("siftlode.http") + http.setLevel(logs.TRACE) + client = _client() + client.get("/api/admin/logs/facets") + assert sink.objects()[-1]["level"] == "DEBUG" + client.get("/api/admin/logs/facets?fail=1") + assert sink.objects()[-1]["level"] == "WARNING" + + 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 ef688baf..b36ce352 100644 --- a/backend/tests/test_sync_guards.py +++ b/backend/tests/test_sync_guards.py @@ -246,6 +246,61 @@ class TestRssErrorVsEmpty: ) monkeypatch.setattr(rss.httpx, "get", fake_get) + monkeypatch.setattr(rss.time, "sleep", lambda s: None) + + def _answers(self, monkeypatch, *answers): + """The endpoint answers each try with the next of `answers` (a status or an exception); + returns the list of tries made and the waits between them.""" + tries, waits = [], [] + queue = list(answers) + + def fake_get(url, **_): + answer = queue.pop(0) + tries.append(answer) + if isinstance(answer, Exception): + raise answer + body = self.FEED if answer == 200 else b"" + return httpx.Response(answer, content=body, request=httpx.Request("GET", url)) + + monkeypatch.setattr(rss.httpx, "get", fake_get) + monkeypatch.setattr(rss.time, "sleep", waits.append) + return tries, waits + + FEED = b""" + + abc123Hello + """ + + def test_a_feed_that_fails_and_then_answers_is_read(self, monkeypatch): + # The endpoint's measured behaviour: the same channel 404s, 500s, then answers. + tries, waits = self._answers(monkeypatch, 404, 500, 200) + assert [e["id"] for e in rss.fetch_channel_feed("UC_flaky")] == ["abc123"] + assert (len(tries), waits) == (3, list(rss.RETRY_DELAYS)) + + def test_a_dropped_connection_is_tried_again_too(self, monkeypatch): + tries, _ = self._answers(monkeypatch, httpx.ConnectError("reset"), 200) + assert rss.fetch_channel_feed("UC_blip") + assert len(tries) == 2 + + def test_a_timeout_is_not_tried_again(self, monkeypatch): + # A hung request already cost the full timeout; retrying it would triple a poll over a + # dead egress. + tries, waits = self._answers(monkeypatch, httpx.ReadTimeout("hung"), 200) + with pytest.raises(rss.RssError) as err: + rss.fetch_channel_feed("UC_hung") + assert (len(tries), waits, err.value.reason) == (1, [], "transport") + + def test_a_feed_that_keeps_failing_raises_its_last_failure(self, monkeypatch): + tries, _ = self._answers(monkeypatch, 500, 404, 404) + with pytest.raises(rss.RssError) as err: + rss.fetch_channel_feed("UC_gone") + assert (len(tries), err.value.reason) == (3, "http_404") + + def test_a_refusal_is_not_tried_again(self, monkeypatch): + tries, waits = self._answers(monkeypatch, 403) + with pytest.raises(rss.RssError) as err: + rss.fetch_channel_feed("UC_forbidden") + assert (len(tries), waits, err.value.reason) == (1, [], "http_403") def test_non_200_raises(self, monkeypatch): self._patch(monkeypatch, status=404) diff --git a/frontend/src/components/AdminLogs.dom.test.tsx b/frontend/src/components/AdminLogs.dom.test.tsx new file mode 100644 index 00000000..8e6891cd --- /dev/null +++ b/frontend/src/components/AdminLogs.dom.test.tsx @@ -0,0 +1,277 @@ +// @vitest-environment jsdom +// +// E22.6: the admin log console. A request id narrows the list to that request (and says so, in the +// filter row and the URL); a filter value the facets no longer count stays pickable; "Live" watches +// the newest page only, and stops on a failed read instead of re-raising it; a failed read is an +// error, not an empty log; Copy takes every loaded line, oldest first. +import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; +import { act, cleanup, fireEvent, render, screen, waitFor, within } from "@testing-library/react"; +import { QueryClient, QueryClientProvider } from "@tanstack/react-query"; + +import type { LogFacets, LogPage, LogQuery, ServerLogRow } from "../lib/api"; + +vi.mock("react-i18next", async (importOriginal) => { + const actual = await importOriginal(); + return { + ...actual, + useTranslation: () => ({ + t: (key: string, vars?: Record) => + vars?.id != null ? `${key}:${String(vars.id)}` : key, + i18n: { language: "en" }, + }), + }; +}); + +const logsMock = vi.fn<(query: LogQuery, before: string | null) => Promise>(); +const facetsMock = vi.fn<(query: LogQuery) => Promise>(); +vi.mock("../lib/api", async (importOriginal) => { + const actual = await importOriginal(); + return { + ...actual, + api: { + ...actual.api, + adminLogs: (query: LogQuery, before: string | null) => logsMock(query, before), + adminLogFacets: (query: LogQuery) => facetsMock(query), + }, + }; +}); + +const copied: string[] = []; +vi.mock("../lib/clipboard", () => ({ + copyText: (text: string) => { + copied.push(text); + return Promise.resolve(true); + }, +})); + +import AdminLogs from "./AdminLogs"; + +function row(id: number, extra: Partial = {}): ServerLogRow { + return { + id, + ts: new Date(Date.UTC(2026, 8, 19, 12, 0, id)).toISOString(), + level: "INFO", + source: "api", + logger: "siftlode.http", + event: "http.request", + msg: `GET /api/thing/${id} 200`, + attrs: null, + exc: null, + request_id: `req-${String(id).padStart(8, "0")}`, + user_id: 1, + job_id: null, + debug_session_id: null, + version: "0.90.0", + ...extra, + }; +} + +const FACETS: LogFacets = { + levels: [{ value: "INFO", count: 3 }], + sources: [{ value: "api", count: 3 }], + events: [{ value: "http.request", count: 3 }], + users: [{ value: "1", count: 3 }], + accounts: { "1": "admin@example.com" }, + total: 3, +}; + +function renderConsole() { + const qc = new QueryClient({ defaultOptions: { queries: { retry: false } } }); + return render( + + + , + ); +} + +// react-query hands its updates to React on a (real) timer tick, after the promise that caused them. +const settle = () => act(() => new Promise((resolve) => setTimeout(resolve, 20))); + +const lines = () => + within(screen.getByTestId("admin-logs-lines")) + .queryAllByRole("button") + .filter((b) => b.hasAttribute("aria-expanded")); + +beforeEach(() => { + window.history.replaceState(null, "", "/?page=logs"); + facetsMock.mockResolvedValue(FACETS); +}); +afterEach(() => { + vi.useRealTimers(); + cleanup(); + logsMock.mockReset(); + facetsMock.mockReset(); +}); + +describe("AdminLogs", () => { + it("a request id narrows the list to that request, with every other filter off", async () => { + window.history.replaceState(null, "", "/?page=logs&lgrp=error&lq=boom"); + 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(logsMock).toHaveBeenLastCalledWith( + expect.objectContaining({ request_id: "req-00000001", levels: undefined, q: undefined }), + null, + ), + ); + expect(screen.getByText("adminLogs.pivotRequest:req-00000001")).toBeTruthy(); + const url = new URLSearchParams(window.location.search); + expect([url.get("lreq"), url.get("lgrp"), url.get("lq")]).toEqual(["req-00000001", null, null]); + }); + + 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 }); + renderConsole(); + await waitFor(() => expect(facetsMock).toHaveBeenCalled()); + + fireEvent.click(screen.getByTestId("logs-user")); + + expect(await screen.findByTestId("logs-user-7")).toBeTruthy(); + expect(screen.getByTestId("logs-user-1")).toBeTruthy(); + }); + + it("Live watches the newest page only", async () => { + logsMock.mockImplementation(async (_q, before) => + before === null + ? { items: [row(3), row(2)], accounts: {}, next_cursor: "c1" } + : { items: [row(1)], accounts: {}, next_cursor: null }, + ); + renderConsole(); + await waitFor(() => expect(lines()).toHaveLength(2)); + fireEvent.click(screen.getByRole("button", { name: "adminLogs.older" })); + await waitFor(() => expect(lines()).toHaveLength(3)); + + fireEvent.click(screen.getByRole("button", { name: "adminLogs.live" })); + + await waitFor(() => expect(lines()).toHaveLength(2)); + expect( + screen.getByRole("button", { name: "adminLogs.live" }).getAttribute("aria-pressed"), + ).toBe("true"); + }); + + it("a page that lands after Live went on is dropped at the next tick", async () => { + let landOlder!: (page: LogPage) => void; + logsMock.mockImplementation((_q, before) => + before === null + ? Promise.resolve({ items: [row(3), row(2)], accounts: {}, next_cursor: "c1" }) + : new Promise((resolve) => (landOlder = resolve)), + ); + renderConsole(); + await waitFor(() => expect(lines()).toHaveLength(2)); + fireEvent.click(screen.getByRole("button", { name: "adminLogs.older" })); + await waitFor(() => expect(landOlder).toBeTypeOf("function")); + + vi.useFakeTimers({ toFake: ["setInterval", "clearInterval"] }); + fireEvent.click(screen.getByRole("button", { name: "adminLogs.live" })); + await act(async () => landOlder({ items: [row(1)], accounts: {}, next_cursor: null })); + await settle(); + expect(lines()).toHaveLength(3); + const olderReads = logsMock.mock.calls.filter(([, before]) => before !== null).length; + + await act(async () => vi.advanceTimersByTimeAsync(4000)); + await settle(); + + expect(lines()).toHaveLength(2); + expect(logsMock.mock.calls.filter(([, before]) => before !== null)).toHaveLength(olderReads); + }); + + it("a failed live read stops the polling and says the list may be old", async () => { + logsMock.mockResolvedValueOnce({ items: [row(1)], accounts: {}, next_cursor: null }); + renderConsole(); + await waitFor(() => expect(lines()).toHaveLength(1)); + + logsMock.mockRejectedValue(new Error("500")); + vi.useFakeTimers({ toFake: ["setInterval", "clearInterval"] }); + fireEvent.click(screen.getByRole("button", { name: "adminLogs.live" })); + await act(async () => vi.advanceTimersByTimeAsync(4000)); + await settle(); + + expect(screen.getByRole("alert").textContent).toContain("adminLogs.stale"); + expect(lines()).toHaveLength(1); + const reads = logsMock.mock.calls.length; + await act(async () => vi.advanceTimersByTimeAsync(12000)); + expect(logsMock.mock.calls.length).toBe(reads); + // The button says polling stopped, and pressing it reads again. + const liveButton = screen.getByRole("button", { name: "adminLogs.live" }); + expect(liveButton.getAttribute("aria-pressed")).toBe("false"); + fireEvent.click(liveButton); + await settle(); + expect(logsMock.mock.calls.length).toBe(reads + 1); + }); + + it("a failed older page says so, not that the list is out of date", async () => { + logsMock.mockImplementation(async (_q, before) => { + if (before !== null) throw new Error("500"); + return { items: [row(2)], accounts: {}, next_cursor: "c1" }; + }); + renderConsole(); + await waitFor(() => expect(lines()).toHaveLength(1)); + + fireEvent.click(screen.getByRole("button", { name: "adminLogs.older" })); + + expect((await screen.findByRole("alert")).textContent).toContain("adminLogs.olderFailed"); + }); + + it("offers no older page while a filter change loads", async () => { + let landErrors!: (page: LogPage) => void; + logsMock.mockImplementation((q) => + q.levels + ? new Promise((resolve) => (landErrors = resolve)) + : Promise.resolve({ items: [row(2)], accounts: {}, next_cursor: "c1" }), + ); + renderConsole(); + await waitFor(() => expect(lines()).toHaveLength(1)); + expect(screen.queryByRole("button", { name: "adminLogs.older" })).toBeTruthy(); + + fireEvent.click(screen.getByRole("button", { name: /settings\.myLog\.filters\.error/ })); + await waitFor(() => expect(landErrors).toBeTypeOf("function")); + + // The rows on screen are the previous filter's: their cursor is not this list's. + expect(screen.queryByRole("button", { name: "adminLogs.older" })).toBeNull(); + await act(async () => landErrors({ items: [row(1)], accounts: {}, next_cursor: null })); + }); + + it("copies every loaded line, oldest first", async () => { + logsMock.mockImplementation(async (_q, before) => + before === null + ? { items: [row(3), row(2)], accounts: {}, next_cursor: "c1" } + : { items: [row(1)], accounts: {}, next_cursor: null }, + ); + renderConsole(); + await waitFor(() => expect(lines()).toHaveLength(2)); + fireEvent.click(screen.getByRole("button", { name: "adminLogs.older" })); + await waitFor(() => expect(lines()).toHaveLength(3)); + + await act(async () => { + fireEvent.click(screen.getByRole("button", { name: "adminLogs.copy" })); + }); + + const ids = copied[copied.length - 1]!.split("\n").map((l) => JSON.parse(l).id); + expect(ids).toEqual([1, 2, 3]); + }); + + it("the keyboard can walk the lines and open one (NavGrid items)", async () => { + logsMock.mockResolvedValue({ items: [row(2), row(1)], accounts: {}, next_cursor: null }); + renderConsole(); + await waitFor(() => expect(lines()).toHaveLength(2)); + + const items = lines().map((b) => b.parentElement!); + expect(items.map((el) => el.getAttribute("data-nav-index"))).toEqual(["0", "1"]); + expect(lines().every((b) => b.hasAttribute("data-nav-open"))).toBe(true); + expect(screen.getByTestId("admin-logs-lines").querySelector("[data-nav-list]")).toBeTruthy(); + }); + + it("a failed read is an error with a retry, not an empty log", async () => { + logsMock.mockRejectedValue(new Error("502")); + renderConsole(); + + expect(await screen.findByRole("alert")).toBeTruthy(); + expect(screen.queryByText("adminLogs.empty")).toBeNull(); + }); +}); diff --git a/frontend/src/components/AdminLogs.tsx b/frontend/src/components/AdminLogs.tsx new file mode 100644 index 00000000..1f5754db --- /dev/null +++ b/frontend/src/components/AdminLogs.tsx @@ -0,0 +1,483 @@ +import { useMemo, useRef, useState } from "react"; +import { useTranslation } from "react-i18next"; +import { + keepPreviousData, + useInfiniteQuery, + useQuery, + useQueryClient, +} from "@tanstack/react-query"; +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 { LEVEL_GROUPS, type LevelGroup } from "../lib/log"; +import { + DEFAULT_LOGS_STATE, + logsParamsToState, + logsParamUpdates, + WINDOW_HOURS, + type LogsUrlState, + type LogWindow, +} from "../lib/logsUrlState"; +import { notify } from "../lib/notifications"; +import { qk } from "../lib/queryKeys"; +import { useDebounced } from "../lib/useDebounced"; +import { useUrlMirror } from "../lib/useUrlMirror"; +import LogLine from "./LogLine"; +import NavGrid from "./ui/NavGrid"; +import { Button } from "./ui/Button"; +import FilterChipGroup from "./ui/FilterChipGroup"; +import FilterSelect from "./ui/FilterSelect"; +import { Section } from "./ui/form"; +import { LoadingState, StateMessage } from "./ui/QueryState"; + +// Admin → Szervernapló: the server's stored log (`log_events`, E22.6). One list, newest first; a line +// opens in place to its full record, and its request id / job id narrow the list to that request or +// job. Filters live in the URL, so a filtered view is a link. "Élő" re-reads the newest page every +// few seconds while the tab is visible — the newest page only: live is watching the top, so paging +// into older rows turns it off. A failed read stops the polling (the request already reported it +// once) and marks the list as possibly stale, instead of re-raising the failure every few seconds. + +const LIVE_MS = 4000; +const GROUPS: readonly LevelGroup[] = ["all", "error", "warning", "info", "detail"]; +const WINDOWS: readonly LogWindow[] = ["1h", "24h", "7d"]; +// A pivot shows everything about one request or job: the other filters would only hide part of it. +const PIVOT_RESET: Omit = { + ...DEFAULT_LOGS_STATE, + window: "7d", +}; + +function sinceOf(window: LogWindow): string { + return new Date(Date.now() - WINDOW_HOURS[window] * 3_600_000).toISOString(); +} + +function toQuery(state: LogsUrlState, q: string): LogQuery { + return { + levels: state.group === "all" ? undefined : LEVEL_GROUPS[state.group], + sources: state.sources, + user: state.user ?? undefined, + event: state.event ?? undefined, + request_id: state.requestId ?? undefined, + job_id: state.jobId ?? undefined, + q: q.trim() || undefined, + }; +} + +export default function AdminLogs() { + const { t } = useTranslation(); + const qc = useQueryClient(); + const [state, setState] = useState(() => + logsParamsToState(new URLSearchParams(window.location.search)), + ); + const [live, setLiveState] = useState(false); + // Read by `getNextPageParam` when a page is fetched, not when it renders: while live, a refetch + // stops after the newest page, however many pages the cache holds — a "Load older" that lands + // after Live was switched on, or a filter set revisited with older pages still cached. + const liveRef = useRef(false); + const setLive = (on: boolean) => { + liveRef.current = on; + setLiveState(on); + }; + const [open, setOpen] = useState(null); + const q = useDebounced(state.q, 300); + useUrlMirror(logsParamUpdates(state)); + + const update = (patch: Partial) => { + setOpen(null); + setState((s) => ({ ...s, ...patch })); + }; + + const query = toQuery(state, q); + const key = qk.adminLogs({ ...query, window: state.window }); + const logs = useInfiniteQuery({ + queryKey: key, + queryFn: ({ pageParam }) => + api.adminLogs({ ...query, since: sinceOf(state.window) }, pageParam), + initialPageParam: null as string | null, + getNextPageParam: (last) => (liveRef.current ? undefined : (last.next_cursor ?? undefined)), + placeholderData: keepPreviousData, + refetchInterval: (q) => (live && q.state.status !== "error" ? LIVE_MS : false), + }); + const facets = useQuery({ + queryKey: qk.adminLogFacets({ ...query, window: state.window }), + queryFn: () => api.adminLogFacets({ ...query, since: sinceOf(state.window) }), + placeholderData: keepPreviousData, + refetchInterval: (q) => (live && q.state.status !== "error" ? LIVE_MS * 4 : false), + }); + // A failed read stops the polling (the intervals above); the button shows that, and pressing it + // again reads now. + const polling = live && !logs.isError; + // What "Load older" continues from — read off the data, since `hasNextPage` is off while live; not + // off placeholder rows, which are the previous filter's. + const olderCursor = logs.isPlaceholderData + ? null + : (logs.data?.pages[logs.data.pages.length - 1]?.next_cursor ?? null); + // A read that failed while lines were on screen: they are kept, and the message says what the + // failure means for them. (With no lines, the list's own error state says it.) + const failure = !logs.data + ? null + : logs.isFetchNextPageError + ? "olderFailed" + : logs.isError || (facets.isError && facets.data) + ? "stale" + : facets.isError + ? "countsFailed" + : null; + const retryFailed = () => { + if (logs.isFetchNextPageError) void logs.fetchNextPage(); + else if (logs.isError) void logs.refetch(); + if (facets.isError) void facets.refetch(); + }; + + const rows = useMemo(() => logs.data?.pages.flatMap((p) => p.items) ?? [], [logs.data]); + const accounts = useMemo( + () => + Object.assign( + {}, + facets.data?.accounts, + ...(logs.data?.pages.map((p) => p.accounts) ?? []), + ) as Record, + [facets.data, logs.data], + ); + const accountLabel = (id: string) => + id === "none" ? t("adminLogs.noAccount") : (accounts[id] ?? `#${id}`); + + const toggleLive = () => { + if (polling) { + setLive(false); + return; + } + // Watching the top: drop the older pages now; `liveRef` keeps each tick to the first page. + qc.setQueryData(key, (d) => + d ? { pages: d.pages.slice(0, 1), pageParams: d.pageParams.slice(0, 1) } : d, + ); + setLive(true); + if (logs.isError) void logs.refetch(); + if (facets.isError) void facets.refetch(); + }; + + const loadOlder = () => { + setLive(false); + void logs.fetchNextPage(); + }; + + const copy = async () => { + // Oldest first, as a log reads. + const text = [...rows] + .reverse() + .map((r) => JSON.stringify(r)) + .join("\n"); + const ok = await copyText(text); + notify( + ok + ? { level: "success", message: t("adminLogs.copied", { count: rows.length }) } + : { level: "error", message: t("adminLogs.copyFailed") }, + ); + }; + + const groupCount = (group: LevelGroup) => { + const levels = facets.data?.levels ?? []; + const sum = (list: readonly LogFacet[]) => list.reduce((n, f) => n + f.count, 0); + if (group === "all") return facets.data?.total; + const inGroup: readonly string[] = LEVEL_GROUPS[group]; + return facets.data ? sum(levels.filter((f) => inGroup.includes(f.value))) : undefined; + }; + + const pivot = (patch: Pick) => { + setLive(false); + update({ ...PIVOT_RESET, ...patch }); + }; + + // "Any", then what the facet counted. The value in use stays offered even at zero — under the + // other filters it may count nothing, and a menu without it would show no way back. + const facetOptions = ( + list: readonly LogFacet[] | undefined, + selected: string | null, + label: (v: string) => string, + ) => { + const facets = list ?? []; + const kept = + selected && !facets.some((f) => f.value === selected) ? [{ value: selected, count: 0 }] : []; + return [ + { value: "", label: t("adminLogs.any") }, + ...[...facets, ...kept].map((f) => ({ + value: f.value, + label: label(f.value), + count: f.count, + })), + ]; + }; + + return ( +
+
+

{t("adminLogs.intro")}

+ +
+
+ + update({ group })} + options={GROUPS.map((g) => ({ + value: g, + label: t(`settings.myLog.filters.${g}`), + count: groupCount(g), + }))} + /> +
+ +
+ v)} + selected={[state.sources[0] ?? ""]} + onChange={([source]) => update({ sources: source ? [source] : [] })} + testId="logs-source" + /> + update({ user: user || null })} + testId="logs-user" + /> + + v === "none" ? t("adminLogs.noEvent") : v, + )} + selected={[state.event ?? ""]} + onChange={([event]) => update({ event: event || null })} + testId="logs-event" + /> + ({ value: w, label: t(`adminLogs.windows.${w}`) }))} + selected={[state.window]} + onChange={([window]) => update({ window: window as LogWindow })} + testId="logs-window" + /> + + + + +
+ + {(state.requestId || state.jobId !== null) && ( +
+ {state.requestId && ( + update({ requestId: null })} + /> + )} + {state.jobId !== null && ( + update({ jobId: null })} + /> + )} +
+ )} + + {failure && ( + + {t(`adminLogs.${failure}`)} + + )} + +
+ {logs.isError && !logs.data ? ( + void logs.refetch()}> + {t("common.loadError")} + + ) : logs.isLoading ? ( + + ) : rows.length === 0 ? ( +

+ {t("adminLogs.empty")} +

+ ) : ( + + {rows.map((row, index) => ( + setOpen(open === row.id ? null : row.id)} + > + pivot({ requestId, jobId: null })} + onJob={(jobId) => pivot({ requestId: null, jobId })} + /> + + ))} + + )} +
+ +
+ {t("adminLogs.count", { count: rows.length })} + {olderCursor !== null && ( + + )} +
+
+
+
+ ); +} + +function PivotChip({ + label, + clearLabel, + onClear, +}: { + label: string; + clearLabel: string; + onClear: () => void; +}) { + return ( + + {label} + + + ); +} + +function RowDetail({ + row, + account, + onRequest, + onJob, +}: { + row: ServerLogRow; + account: string | null; + onRequest: (id: string) => void; + onJob: (id: number) => void; +}) { + const { t } = useTranslation(); + const pivotCls = + "font-mono text-accent underline decoration-dotted underline-offset-2 hover:decoration-solid"; + return ( +
+
+
{t("adminLogs.fields.when")}
+
{formatDateTime(row.ts)}
+
{t("adminLogs.fields.source")}
+
+ {row.source} · {row.logger} +
+
{t("adminLogs.fields.account")}
+
{account ?? "—"}
+ {row.request_id && ( + <> +
{t("adminLogs.fields.request")}
+
+ +
+ + )} + {row.job_id !== null && ( + <> +
{t("adminLogs.fields.job")}
+
+ +
+ + )} + {row.version && ( + <> +
{t("adminLogs.fields.version")}
+
{row.version}
+ + )} +
+ 
{row.msg}
+ {row.attrs && ( + 
{JSON.stringify(row.attrs, null, 2)}
+ )} + {row.exc && 
{row.exc}
} +
+ ); +} diff --git a/frontend/src/components/LogLine.tsx b/frontend/src/components/LogLine.tsx new file mode 100644 index 00000000..bb9ea5cc --- /dev/null +++ b/frontend/src/components/LogLine.tsx @@ -0,0 +1,77 @@ +import type { ReactNode } from "react"; + +import type { Level } from "../lib/log"; +import { navItemAttrs } from "../lib/listNav"; + +// One log line as both log viewers draw it — "Saját napló" (this tab's ring) and the admin +// diagnostics console (the server's stored log): time, level, event code, message, and the line opens +// in place to whatever detail its screen has. One component, so a level reads the same on both. +// Inside a NavGrid the keyboard walks the lines (`j`/`k`) and Enter opens one, as a click does. + +const LEVEL_TAG: Record = { + TRACE: { text: "TRACE", className: "text-muted opacity-80" }, + DEBUG: { text: "DEBUG", className: "text-muted" }, + INFO: { text: "INFO", className: "text-info" }, + WARNING: { text: "WARN", className: "text-warn" }, + ERROR: { text: "ERROR", className: "text-danger" }, + CRITICAL: { text: "FATAL", className: "text-danger" }, +}; + +/** `HH:MM:SS.mmm` in local time — a log is read to the millisecond. */ +function logClock(ts: string): string { + const d = new Date(ts); + const pad = (n: number, w = 2) => String(n).padStart(w, "0"); + return `${pad(d.getHours())}:${pad(d.getMinutes())}:${pad(d.getSeconds())}.${pad(d.getMilliseconds(), 3)}`; +} + +export default function LogLine({ + ts, + level, + event, + msg, + open, + onToggle, + title, + navIndex, + children, +}: { + ts: string; + level: Level; + event: string; + msg: string; + open: boolean; + onToggle: () => void; + /** The row button's tooltip — the admin console puts the full date there. */ + title?: string; + /** The line's place in its NavGrid. */ + navIndex: number; + /** The detail shown while the line is open. */ + children: ReactNode; +}) { + const tag = LEVEL_TAG[level]; + return ( +
+ + {open &&
{children}
} +
+ ); +} diff --git a/frontend/src/components/MyLogViewer.tsx b/frontend/src/components/MyLogViewer.tsx index dd14fe31..0f229e26 100644 --- a/frontend/src/components/MyLogViewer.tsx +++ b/frontend/src/components/MyLogViewer.tsx @@ -3,33 +3,24 @@ import { useTranslation } from "react-i18next"; import { Copy, Search } from "lucide-react"; import { copyText } from "../lib/clipboard"; -import { clear, events, subscribe, type Level, type LogEvent } from "../lib/log"; +import { + clear, + events, + LEVEL_GROUPS, + subscribe, + type LevelGroup as Filter, + type LogEvent, +} from "../lib/log"; import { notify } from "../lib/notifications"; +import LogLine from "./LogLine"; +import NavGrid from "./ui/NavGrid"; import { Button } from "./ui/Button"; import FilterChipGroup from "./ui/FilterChipGroup"; -type Filter = "all" | "error" | "warning" | "info" | "detail"; - -const FILTER_LEVELS: Record, readonly Level[]> = { - error: ["ERROR", "CRITICAL"], - warning: ["WARNING"], - info: ["INFO"], - detail: ["DEBUG", "TRACE"], -}; - // Rows rendered at once. The ring holds up to 2000 events; drawing all of them on every new event // would make the settings page the slowest thing in the app while it is watching the app. const ROWS_SHOWN = 500; -const LEVEL_TAG: Record = { - TRACE: { text: "TRACE", className: "text-muted opacity-80" }, - DEBUG: { text: "DEBUG", className: "text-muted" }, - INFO: { text: "INFO", className: "text-info" }, - WARNING: { text: "WARN", className: "text-warn" }, - ERROR: { text: "ERROR", className: "text-danger" }, - CRITICAL: { text: "FATAL", className: "text-danger" }, -}; - /** The ring, live: re-read at most once per animation frame however fast events arrive. */ function useLogEvents(): LogEvent[] { const [list, setList] = useState(events); @@ -73,12 +64,6 @@ const matches = (event: LogEvent, needle: string) => .toLowerCase() .includes(needle); -const clock = (ts: string) => { - const d = new Date(ts); - const pad = (n: number, w = 2) => String(n).padStart(w, "0"); - return `${pad(d.getHours())}:${pad(d.getMinutes())}:${pad(d.getSeconds())}.${pad(d.getMilliseconds(), 3)}`; -}; - // "Saját napló" — this tab's own client log (lib/log.ts), exactly what it would send while a raised // diagnostics level is on: newest first, filtered by level group and free text, a row opens to its // correlation id and attributes, and "Copy" puts the FILTERED events on the clipboard as JSON lines @@ -99,7 +84,7 @@ export default function MyLogViewer() { detail: 0, }; for (const e of all) { - for (const [group, levels] of Object.entries(FILTER_LEVELS)) { + for (const [group, levels] of Object.entries(LEVEL_GROUPS)) { if (levels.includes(e.level)) out[group as Filter] += 1; } } @@ -108,7 +93,7 @@ export default function MyLogViewer() { const shown = useMemo(() => { const needle = query.trim().toLowerCase(); - const levels = filter === "all" ? null : FILTER_LEVELS[filter]; + const levels = filter === "all" ? null : LEVEL_GROUPS[filter]; const out: LogEvent[] = []; for (let i = all.length - 1; i >= 0; i--) { const e = all[i]!; @@ -166,47 +151,35 @@ export default function MyLogViewer() { {all.length === 0 ? t("settings.myLog.emptyAll") : t("settings.myLog.empty")}

) : ( - shown.slice(0, ROWS_SHOWN).map((e) => { - const tag = LEVEL_TAG[e.level]; - const isOpen = open === e; - return ( -
- - {isOpen && ( - 
-                    {JSON.stringify(
-                      {
-                        event: e.event,
-                        msg: e.msg,
-                        request_id: e.request_id,
-                        ts: e.ts,
-                        tab_id: e.tab_id,
-                        attrs: e.attrs,
-                      },
-                      null,
-                      2,
-                    )}
-
- )} -
- ); - }) + + {shown.slice(0, ROWS_SHOWN).map((e, index) => ( + setOpen(open === e ? null : e)} + > + 
+                  {JSON.stringify(
+                    {
+                      event: e.event,
+                      msg: e.msg,
+                      request_id: e.request_id,
+                      ts: e.ts,
+                      tab_id: e.tab_id,
+                      attrs: e.attrs,
+                    },
+                    null,
+                    2,
+                  )}
+
+ + ))} + )} diff --git a/frontend/src/components/NavigationProvider.dom.test.tsx b/frontend/src/components/NavigationProvider.dom.test.tsx index 2a94c602..0d19f2ce 100644 --- a/frontend/src/components/NavigationProvider.dom.test.tsx +++ b/frontend/src/components/NavigationProvider.dom.test.tsx @@ -74,6 +74,17 @@ describe("NavigationProvider · setPage's same-page guard", () => { expect(result.current.page).toBe("plex"); }); + it("leaves every page's own URL keys behind, the log console's included", () => { + window.history.replaceState( + { sfPage: "logs" }, + "", + "/?page=logs&lgrp=error&lreq=req-abcdef12&pscope=movie&ctab=hidden&keep=1", + ); + const { result } = render(); + act(() => result.current.setPage("plex")); + expect(window.location.search).toBe("?page=plex&keep=1"); + }); + it("pushes nothing when it is already that page", () => { const { result } = render(); act(() => result.current.setPage("plex")); diff --git a/frontend/src/components/NavigationProvider.tsx b/frontend/src/components/NavigationProvider.tsx index c9c526a1..82faf9a8 100644 --- a/frontend/src/components/NavigationProvider.tsx +++ b/frontend/src/components/NavigationProvider.tsx @@ -1,6 +1,7 @@ import { useCallback, useEffect, useMemo, useRef, useState, type ReactNode } from "react"; import { useTranslation } from "react-i18next"; import { urlWithParams, type Page } from "../lib/urlState"; +import { LOGS_KEYS } from "../lib/logsUrlState"; import { pageTitleKey } from "../lib/pageMeta"; import { setAccountRaw } from "../lib/storage"; import { setNavigator } from "../lib/nav"; @@ -89,6 +90,7 @@ export function NavigationProvider({ children }: { children: ReactNode }) { ctab: null, csort: null, cf: null, + ...Object.fromEntries(LOGS_KEYS.map((k) => [k, null])), }), ); notifyNav(); diff --git a/frontend/src/components/moduleRegistry.tsx b/frontend/src/components/moduleRegistry.tsx index da3aff5f..464dbba3 100644 --- a/frontend/src/components/moduleRegistry.tsx +++ b/frontend/src/components/moduleRegistry.tsx @@ -32,6 +32,7 @@ const Scheduler = lazyWithPreload(() => import("./Scheduler")); const ConfigPanel = lazyWithPreload(() => import("./ConfigPanel")); const AdminUsers = lazyWithPreload(() => import("./AdminUsers")); const AuditLog = lazyWithPreload(() => import("./AuditLog")); +const AdminLogs = lazyWithPreload(() => import("./AdminLogs")); const SettingsPanel = lazyWithPreload(() => import("./SettingsPanel")); export type PageDef = { @@ -63,6 +64,7 @@ export const PAGE_CONTENT: Record = { config: { Component: ConfigPanel }, users: { Component: AdminUsers, maxWidth: "48rem" }, audit: { Component: AuditLog, fadeTop: false }, + logs: { Component: AdminLogs }, settings: { Component: SettingsPanel }, }; diff --git a/frontend/src/i18n/locales/en/adminLogs.json b/frontend/src/i18n/locales/en/adminLogs.json new file mode 100644 index 00000000..f121848a --- /dev/null +++ b/frontend/src/i18n/locales/en/adminLogs.json @@ -0,0 +1,43 @@ +{ + "title": "Server log", + "intro": "The server's stored log — lines from the API, the downloader and browsers, kept until the retention period ends. A line opens in place; click its request or job id to keep only that request's or job's lines.", + "search": "Search the message, code, stack…", + "levelLabel": "Filter by level", + "source": "Source", + "account": "Account", + "event": "Event", + "window": "Period", + "windows": { + "1h": "1 hour", + "24h": "24 hours", + "7d": "7 days" + }, + "any": "Any", + "noAccount": "No account", + "noEvent": "No code", + "live": "Live", + "copy": "Copy", + "copied_one": "Copied {{count}} line", + "copied_other": "Copied {{count}} lines", + "copyFailed": "Couldn't copy to the clipboard", + "pivotRequest": "request {{id}}", + "pivotJob": "job {{id}}", + "clearPivot": "Clear filter", + "showRequest": "Only this request's lines", + "showJob": "Only this job's lines", + "empty": "No lines match the filters.", + "stale": "The last refresh failed; what you see may be out of date.", + "olderFailed": "Couldn't load the older lines.", + "countsFailed": "The filter counts didn't load.", + "count_one": "{{count}} line loaded · newest first", + "count_other": "{{count}} lines loaded · newest first", + "older": "Load older", + "fields": { + "when": "Time", + "source": "Source", + "account": "Account", + "request": "Request", + "job": "Job", + "version": "Version" + } +} diff --git a/frontend/src/i18n/locales/en/header.json b/frontend/src/i18n/locales/en/header.json index 256a8888..19968222 100644 --- a/frontend/src/i18n/locales/en/header.json +++ b/frontend/src/i18n/locales/en/header.json @@ -35,6 +35,7 @@ "addAccount": "Add another account", "switchTo": "Switch to {{name}}", "audit": "Audit log", + "logs": "Server log", "googleAddress": "Google account: {{email}}" }, "sync": { diff --git a/frontend/src/i18n/locales/hu/adminLogs.json b/frontend/src/i18n/locales/hu/adminLogs.json new file mode 100644 index 00000000..e8ef112e --- /dev/null +++ b/frontend/src/i18n/locales/hu/adminLogs.json @@ -0,0 +1,43 @@ +{ + "title": "Szervernapló", + "intro": "A szerver tárolt naplója — az API, a letöltő és a böngészők sorai, amelyeket a megőrzési idő végéig tart meg. Egy sor a helyén nyílik ki; a kérés- vagy job-azonosítójára kattintva csak az ahhoz tartozó sorok maradnak.", + "search": "Keresés az üzenetben, a kódban, a hívási veremben…", + "levelLabel": "Szűrés szintre", + "source": "Forrás", + "account": "Fiók", + "event": "Esemény", + "window": "Időszak", + "windows": { + "1h": "1 óra", + "24h": "24 óra", + "7d": "7 nap" + }, + "any": "Bármi", + "noAccount": "Fiók nélkül", + "noEvent": "Kód nélkül", + "live": "Élő", + "copy": "Másolás", + "copied_one": "Kimásolva: {{count}} sor", + "copied_other": "Kimásolva: {{count}} sor", + "copyFailed": "Nem sikerült a vágólapra másolni", + "pivotRequest": "kérés {{id}}", + "pivotJob": "job {{id}}", + "clearPivot": "Szűrő törlése", + "showRequest": "Csak ennek a kérésnek a sorai", + "showJob": "Csak ennek a jobnak a sorai", + "empty": "Nincs a szűrésnek megfelelő sor.", + "stale": "Az utolsó frissítés nem sikerült, amit látsz, elavult lehet.", + "olderFailed": "Nem sikerült betölteni a régebbi sorokat.", + "countsFailed": "A szűrők számai nem töltődtek be.", + "count_one": "{{count}} sor betöltve · a legújabb felül", + "count_other": "{{count}} sor betöltve · a legújabb felül", + "older": "Régebbiek betöltése", + "fields": { + "when": "Időpont", + "source": "Forrás", + "account": "Fiók", + "request": "Kérés", + "job": "Job", + "version": "Verzió" + } +} diff --git a/frontend/src/i18n/locales/hu/header.json b/frontend/src/i18n/locales/hu/header.json index 3b5bb633..7aa1d217 100644 --- a/frontend/src/i18n/locales/hu/header.json +++ b/frontend/src/i18n/locales/hu/header.json @@ -35,6 +35,7 @@ "addAccount": "Másik fiók hozzáadása", "switchTo": "Váltás erre: {{name}}", "audit": "Auditnapló", + "logs": "Szervernapló", "googleAddress": "Google-fiók: {{email}}" }, "sync": { diff --git a/frontend/src/lib/api/admin.ts b/frontend/src/lib/api/admin.ts index 3585795e..d26533fb 100644 --- a/frontend/src/lib/api/admin.ts +++ b/frontend/src/lib/api/admin.ts @@ -1,6 +1,8 @@ // The admin surface: discovery purge, system configuration, users & roles, the audit log, the -// scheduler + maintenance controls, the demo-account whitelist, and access invites. Only touches -// core's req. (Grouped by sub-area below; kept in one module as the cohesive "admin" domain.) +// diagnostics console's server log, the scheduler + maintenance controls, the demo-account +// whitelist, and access invites. Only touches core's req. (Grouped by sub-area below; kept in one +// module as the cohesive "admin" domain.) +import type { Level } from "../log"; import { req } from "./core"; export interface DemoWhitelistEntry { @@ -115,6 +117,79 @@ export interface AuditListResult { returned: number; } +/** One stored log line (`log_events`), as the diagnostics console reads it. Values the server's + * redactor took out arrive as `[redacted]` / `[email]`. */ +export interface ServerLogRow { + id: number; + ts: string; + level: Level; + source: string; + logger: string; + event: string | null; + msg: string; + attrs: Record | null; + exc: string | null; + request_id: string | null; + user_id: number | null; + job_id: number | null; + debug_session_id: string | null; + version: string | null; +} + +/** The console's filters, as the API takes them. `none` picks the rows without an account / code. */ +export interface LogQuery { + levels?: readonly Level[]; + sources?: readonly string[]; + user?: string; + event?: string; + request_id?: string; + job_id?: number; + q?: string; + since?: string; +} + +export interface LogPage { + items: ServerLogRow[]; + /** The accounts this page names, by id; an erased one is absent. */ + accounts: Record; + next_cursor: string | null; +} + +export interface LogFacet { + value: string; + count: number; +} + +/** Each facet is counted under every filter but its own; `total` is the all-levels count. */ +export interface LogFacets { + levels: LogFacet[]; + sources: LogFacet[]; + events: LogFacet[]; + users: LogFacet[]; + accounts: Record; + total: number; +} + +function logParams(query: LogQuery, extra: Record = {}): string { + const p = new URLSearchParams(); + for (const level of query.levels ?? []) p.append("levels", level); + for (const source of query.sources ?? []) p.append("sources", source); + const single: Record = { + user: query.user, + event: query.event, + request_id: query.request_id, + job_id: query.job_id, + q: query.q, + since: query.since, + ...extra, + }; + for (const [key, value] of Object.entries(single)) { + if (value !== undefined && value !== null && value !== "") p.set(key, String(value)); + } + const s = p.toString(); + return s ? `?${s}` : ""; +} + export interface SchedulerJob { id: string; interval_minutes: number; @@ -172,6 +247,11 @@ export const adminApi = { // --- users & roles --- adminAudit: (limit = 500): Promise => req(`/api/admin/audit?limit=${limit}`), clearAudit: (): Promise<{ cleared: number }> => req("/api/admin/audit", { method: "DELETE" }), + // --- diagnostics console --- + adminLogs: (query: LogQuery, before: string | null): Promise => + req(`/api/admin/logs${logParams(query, { before })}`), + adminLogFacets: (query: LogQuery): Promise => + req(`/api/admin/logs/facets${logParams(query)}`), adminUsers: (): Promise => req("/api/admin/users"), setUserRole: (id: number, role: "user" | "admin"): Promise => req(`/api/admin/users/${id}/role`, { method: "PATCH", body: JSON.stringify({ role }) }), diff --git a/frontend/src/lib/api/adminLogs.dom.test.ts b/frontend/src/lib/api/adminLogs.dom.test.ts new file mode 100644 index 00000000..bfdb0998 --- /dev/null +++ b/frontend/src/lib/api/adminLogs.dom.test.ts @@ -0,0 +1,64 @@ +// @vitest-environment jsdom +// +// The log console's query strings. The console's DOM tests mock this slice, so nothing else in the +// suite looks at the URL that goes out — and a multi-level group is the case that breaks quietly: +// `levels` must repeat, or FastAPI's list reads only the last one. +import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; +import { adminApi } from "./admin"; + +const fetchMock = vi.fn(); + +beforeEach(() => { + fetchMock.mockReset().mockResolvedValue({ + ok: true, + status: 200, + headers: new Headers({ "content-type": "application/json" }), + json: async () => ({}), + text: async () => "{}", + }); + vi.stubGlobal("fetch", fetchMock); +}); +afterEach(() => vi.unstubAllGlobals()); + +const lastQuery = (): URLSearchParams => { + const calls = fetchMock.mock.calls; + return new URL(String(calls[calls.length - 1]?.[0]), "http://x").searchParams; +}; + +describe("adminApi log query strings", () => { + it("repeats the list filters and sends every single one it is given", async () => { + await adminApi.adminLogs( + { + levels: ["ERROR", "CRITICAL"], + sources: ["api", "worker"], + user: "none", + event: "sync.rss.failed", + request_id: "req-abcdef12", + job_id: 42, + q: "100% done", + since: "2026-09-19T11:00:00.000Z", + }, + "cursor-1", + ); + const p = lastQuery(); + expect(p.getAll("levels")).toEqual(["ERROR", "CRITICAL"]); + expect(p.getAll("sources")).toEqual(["api", "worker"]); + expect(Object.fromEntries([...p].filter(([k]) => k !== "levels" && k !== "sources"))).toEqual({ + user: "none", + event: "sync.rss.failed", + request_id: "req-abcdef12", + job_id: "42", + q: "100% done", + since: "2026-09-19T11:00:00.000Z", + before: "cursor-1", + }); + }); + + it("leaves out what is not set, and the facets carry no cursor", async () => { + await adminApi.adminLogs({ q: "", user: undefined }, null); + expect(String(fetchMock.mock.calls[0]?.[0])).toBe("/api/admin/logs"); + + await adminApi.adminLogFacets({ levels: ["WARNING"], since: "2026-09-19T11:00:00.000Z" }); + expect([...lastQuery().keys()]).toEqual(["levels", "since"]); + }); +}); diff --git a/frontend/src/lib/log.ts b/frontend/src/lib/log.ts index 7942ff70..d1c91d6b 100644 --- a/frontend/src/lib/log.ts +++ b/frontend/src/lib/log.ts @@ -31,6 +31,17 @@ export const SEVERITY: Record = { CRITICAL: 21, }; +/** How a log viewer groups the six levels into its filter chips — "Saját napló" and the admin + * console both read a log through these, so a level lands in the same chip on either screen. */ +export type LevelGroup = "all" | "error" | "warning" | "info" | "detail"; + +export const LEVEL_GROUPS: Record, readonly Level[]> = { + error: ["ERROR", "CRITICAL"], + warning: ["WARNING"], + info: ["INFO"], + detail: ["DEBUG", "TRACE"], +}; + export interface LogEvent { ts: string; level: Level; diff --git a/frontend/src/lib/logsUrlState.test.ts b/frontend/src/lib/logsUrlState.test.ts new file mode 100644 index 00000000..67c80712 --- /dev/null +++ b/frontend/src/lib/logsUrlState.test.ts @@ -0,0 +1,42 @@ +// The admin log console's filters in the address bar: a link carries them, a hand-edited value the +// API would refuse degrades to "no filter", and a filter at its default leaves no key behind. +import { describe, expect, it } from "vitest"; + +import { + DEFAULT_LOGS_STATE, + logsParamsToState, + logsParamUpdates, + type LogsUrlState, +} from "./logsUrlState"; + +const params = (updates: Record) => + new URLSearchParams(Object.entries(updates).filter((e): e is [string, string] => e[1] !== null)); + +describe("logsUrlState", () => { + it("round-trips every filter", () => { + const state: LogsUrlState = { + group: "error", + sources: ["worker"], + user: "none", + event: "download.job.failed", + requestId: "req-abcdef12", + jobId: 42, + q: "100% done", + window: "7d", + }; + expect(logsParamsToState(params(logsParamUpdates(state)))).toEqual(state); + }); + + it("leaves no key for a filter at its default", () => { + expect(Object.values(logsParamUpdates(DEFAULT_LOGS_STATE)).every((v) => v === null)).toBe(true); + }); + + it("drops a value the API would refuse instead of sending it", () => { + const state = logsParamsToState( + new URLSearchParams( + "lgrp=loud&lsrc=api,WORKER,x y&lu=me&lev=Not.A.Code&lreq=short&ljob=0&lwin=1y", + ), + ); + expect(state).toEqual({ ...DEFAULT_LOGS_STATE, sources: ["api"] }); + }); +}); diff --git a/frontend/src/lib/logsUrlState.ts b/frontend/src/lib/logsUrlState.ts new file mode 100644 index 00000000..3105af84 --- /dev/null +++ b/frontend/src/lib/logsUrlState.ts @@ -0,0 +1,80 @@ +// The admin diagnostics console's filters in the address bar (`?page=logs&lgrp=error&lreq=…`), so a +// filtered view — a request's lines, say — is a link. Keys are namespaced (`l…`) like the Plex and +// Channels ones; setPage clears them (LOGS_KEYS) and the console re-mirrors them while it is open. +import type { LevelGroup } from "./log"; + +export type LogWindow = "1h" | "24h" | "7d"; + +export interface LogsUrlState { + group: LevelGroup; + sources: string[]; + /** An account id, or `none` for the rows without one. */ + user: string | null; + /** An event code, or `none` for the rows without one. */ + event: string | null; + requestId: string | null; + jobId: number | null; + q: string; + window: LogWindow; +} + +export const DEFAULT_LOGS_STATE: LogsUrlState = { + group: "all", + sources: [], + user: null, + event: null, + requestId: null, + jobId: null, + q: "", + window: "24h", +}; + +export const LOGS_KEYS = ["lgrp", "lsrc", "lu", "lev", "lreq", "ljob", "lq", "lwin"] as const; + +export const WINDOW_HOURS: Record = { "1h": 1, "24h": 24, "7d": 24 * 7 }; + +const GROUPS: readonly LevelGroup[] = ["all", "error", "warning", "info", "detail"]; +// The same shapes the API validates: a link someone edited by hand degrades to "no filter" here +// instead of to a 422 on every request the console makes. +const USER_RE = /^(none|\d{1,10})$/; +const EVENT_RE = /^(none|[a-z][a-z0-9_]*(\.[a-z0-9_]+)*)$/; +const REQUEST_RE = /^[A-Za-z0-9._-]{8,64}$/; +const SOURCE_RE = /^[a-z]{1,16}$/; +const SOURCES_MAX = 8; +const Q_MAX = 200; + +const pick = (value: string | null, re: RegExp, max = 64) => + value && value.length <= max && re.test(value) ? value : null; + +export function logsParamsToState(params: URLSearchParams): LogsUrlState { + const group = params.get("lgrp"); + const window = params.get("lwin"); + const job = params.get("ljob"); + return { + group: GROUPS.includes(group as LevelGroup) ? (group as LevelGroup) : DEFAULT_LOGS_STATE.group, + sources: (params.get("lsrc") ?? "") + .split(",") + .filter((s) => SOURCE_RE.test(s)) + .slice(0, SOURCES_MAX), + user: pick(params.get("lu"), USER_RE), + event: pick(params.get("lev"), EVENT_RE), + requestId: pick(params.get("lreq"), REQUEST_RE), + jobId: job && /^\d{1,10}$/.test(job) && Number(job) > 0 ? Number(job) : null, + q: (params.get("lq") ?? "").slice(0, Q_MAX), + window: window && window in WINDOW_HOURS ? (window as LogWindow) : DEFAULT_LOGS_STATE.window, + }; +} + +/** The URL updates for a state: a filter at its default clears its key. */ +export function logsParamUpdates(state: LogsUrlState): Record { + return { + lgrp: state.group === DEFAULT_LOGS_STATE.group ? null : state.group, + lsrc: state.sources.length ? state.sources.join(",") : null, + lu: state.user, + lev: state.event, + lreq: state.requestId, + ljob: state.jobId === null ? null : String(state.jobId), + lq: state.q.trim() ? state.q : null, + lwin: state.window === DEFAULT_LOGS_STATE.window ? null : state.window, + }; +} diff --git a/frontend/src/lib/modules.ts b/frontend/src/lib/modules.ts index d1a119cb..3c9e91bd 100644 --- a/frontend/src/lib/modules.ts +++ b/frontend/src/lib/modules.ts @@ -8,6 +8,7 @@ import { ListVideo, MessageSquare, ScrollText, + FileSearch, Settings, SlidersHorizontal, Tv, @@ -108,6 +109,14 @@ const MODULES: readonly ModuleDef[] = [ system: true, gate: isAdmin, }, + { + id: "logs", + labelKey: "header.account.logs", + titleKey: "adminLogs.title", + icon: FileSearch, + system: true, + gate: isAdmin, + }, ]; // Settings is reachable (its own rail button + the ◀/▶ wrap target) but is not a primary module in diff --git a/frontend/src/lib/pageMeta.test.ts b/frontend/src/lib/pageMeta.test.ts index eea55f63..62614de7 100644 --- a/frontend/src/lib/pageMeta.test.ts +++ b/frontend/src/lib/pageMeta.test.ts @@ -19,6 +19,7 @@ const EXPECTED: Record = { config: "header.configuration", users: "header.users", audit: "audit.title", + logs: "adminLogs.title", settings: "settings.title", }; diff --git a/frontend/src/lib/queryKeys.ts b/frontend/src/lib/queryKeys.ts index deee4b24..eb1a8223 100644 --- a/frontend/src/lib/queryKeys.ts +++ b/frontend/src/lib/queryKeys.ts @@ -90,6 +90,10 @@ export const qk = { adminPendingAccess: () => ["admin-pending-access"] as const, adminConfig: () => ["admin-config"] as const, adminAudit: () => ["admin-audit"] as const, + // The console's filters are part of the key; `since` is not (it moves with the clock) — the + // window it came from is. + adminLogs: (filters: object) => ["admin-logs", filters] as const, + adminLogFacets: (filters: object) => ["admin-log-facets", filters] as const, adminStorage: () => ["admin-storage"] as const, adminDownloads: () => ["admin-downloads"] as const, adminQuota: (days: number) => ["admin-quota", days] as const, diff --git a/frontend/src/lib/releaseNotes.ts b/frontend/src/lib/releaseNotes.ts index 5306cb98..c6b60883 100644 --- a/frontend/src/lib/releaseNotes.ts +++ b/frontend/src/lib/releaseNotes.ts @@ -14,6 +14,26 @@ export interface ReleaseEntry { } export const RELEASE_NOTES: ReleaseEntry[] = [ + { + version: "0.90.0", + date: "2026-09-19", + summary: + "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.", + features: [ + "Admin → Server log: the stored log, newest first, with a search, level chips, and source, account, event and period filters. A line opens in place to its full record; its request id or job id narrows the list to everything that request or job wrote.", + "Filters live in the address bar, so a filtered view is a link, and Back brings the previous view back.", + "Live follows the newest lines every few seconds; Copy puts the loaded lines on the clipboard, oldest first. A failed read says so instead of quietly freezing the list.", + "Both log viewers (Server log and My log) can be walked with j/k and a line opened with Enter.", + ], + fixes: [ + "New videos no longer arrive late from channels whose YouTube feed answers 404 or 500 now and then: a feed is tried again before the channel counts as failed.", + "A % or _ typed into a search is searched for as itself, not as a wildcard.", + ], + chores: [ + "The console's own reads are logged at debug level, so watching the log does not fill it.", + "Two adversarial review rounds: 19 findings raised, 12 survived, all fixed, and every regression test was proven to fail with its own fix removed.", + ], + }, { version: "0.89.0", date: "2026-09-19", diff --git a/frontend/src/lib/urlState.ts b/frontend/src/lib/urlState.ts index 871899be..179b41dc 100644 --- a/frontend/src/lib/urlState.ts +++ b/frontend/src/lib/urlState.ts @@ -129,6 +129,7 @@ const PAGES = [ "config", "users", "audit", + "logs", "notifications", "messages", "downloads",