From 66dbd0af81510a1134a17033a87968c88b5773b9 Mon Sep 17 00:00:00 2001 From: npeter83 Date: Sat, 19 Sep 2026 01:33:32 +0200 Subject: [PATCH 1/9] fix(search): typed text is a literal in every LIKE pattern The feed's channel-name match and the live search's term fold built their LIKE pattern from the typed text as it was, so `_` and `%` acted as wildcards: `build_log` also matched `buildXlog`. The term fold also tested a substring, so a term already present inside a longer word (`cat` in `category`) was never folded into search_terms. It now compares whole terms, escaped. `like_escape` moves from the Plex query module to `app.utils`, beside `to_tsquery_str`, and every pattern built from typed text goes through it. --- backend/app/feedquery.py | 7 ++- backend/app/plex/query.py | 4 -- backend/app/routes/plex/collections.py | 3 +- backend/app/routes/search.py | 31 ++++++---- backend/app/utils.py | 8 +++ backend/tests/test_like_literals.py | 81 ++++++++++++++++++++++++++ 6 files changed, 116 insertions(+), 18 deletions(-) create mode 100644 backend/tests/test_like_literals.py 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/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/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/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", + } From 5e208353e31388aced7ffd0a2b036aa61d122edb Mon Sep 17 00:00:00 2001 From: npeter83 Date: Sat, 19 Sep 2026 01:40:46 +0200 Subject: [PATCH 2/9] feat(diagnostics): admin query API over the stored log GET /api/admin/logs pages `log_events` newest first on a (ts, id) keyset: a browser row's ts is clamped into its consent window, so ts alone is not unique. Filters AND together: level, source, account (or `none`), event code (or `none`), request id, job id, a free-text search over the message, code, request id, stack and attributes (typed text is a literal), and a time window. Each page names the accounts it mentions. GET /api/admin/logs/facets counts what the filter chips offer over the window alone, so a chip row does not shrink as filters are picked. Admin-only and read-only; reading is not audited (the console's live tail polls). There is deliberately no "ids after N" tail: several processes write this table and a batch takes its ids at insert, not at commit, so a tail keyed on ids could pass a row that commits late. --- backend/app/main.py | 2 + backend/app/routes/admin_logs.py | 199 +++++++++++++++++++++++++++++++ backend/tests/test_admin_logs.py | 154 ++++++++++++++++++++++++ 3 files changed, 355 insertions(+) create mode 100644 backend/app/routes/admin_logs.py create mode 100644 backend/tests/test_admin_logs.py 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/routes/admin_logs.py b/backend/app/routes/admin_logs.py new file mode 100644 index 00000000..4f351b4b --- /dev/null +++ b/backend/app/routes/admin_logs.py @@ -0,0 +1,199 @@ +"""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 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"] +# `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} + + +@router.get("") +def list_logs( + 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, + 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) + if levels: + query = query.where(LogEvent.level.in_(levels)) + if sources: + query = query.where(LogEvent.source.in_(sources)) + if user is not None: + query = query.where( + LogEvent.user_id.is_(None) if user == NONE else LogEvent.user_id == int(user) + ) + if event is not None: + query = query.where(LogEvent.event.is_(None) if event == NONE else LogEvent.event == event) + if request_id is not None: + query = query.where(LogEvent.request_id == request_id) + if job_id is not None: + query = query.where(LogEvent.job_id == job_id) + if since is not None: + query = query.where(LogEvent.ts >= _utc(since)) + if until is not None: + query = query.where(LogEvent.ts < _utc(until)) + if q and q.strip(): + like = f"%{like_escape(q.strip())}%" + query = query.where( + or_( + LogEvent.msg.ilike(like), + LogEvent.event.ilike(like), + LogEvent.request_id.ilike(like), + LogEvent.exc.ilike(like), + cast(LogEvent.attrs, Text).ilike(like), + ) + ) + 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( + since: datetime | None = None, + _: User = Depends(admin_user), + db: Session = Depends(get_db), +) -> dict: + """What the filter chips offer, with counts: every level, source and account present in the + window, and its most frequent events. Over the window alone, not the other filters — a chip + row that shrank as you clicked would hide the way back.""" + window = [LogEvent.ts >= _utc(since)] if since is not None else [] + + def counts(col, cap: int | None = None) -> list[dict]: + n = func.count().label("n") + stmt = select(col, n).where(*window).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) + return { + "levels": counts(LogEvent.level), + "sources": counts(LogEvent.source), + "events": counts(LogEvent.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(select(func.count()).select_from(LogEvent).where(*window)) or 0, + } diff --git a/backend/tests/test_admin_logs.py b/backend/tests/test_admin_logs.py new file mode 100644 index 00000000..3bf24702 --- /dev/null +++ b/backend/tests/test_admin_logs.py @@ -0,0 +1,154 @@ +"""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"} From b5996a0e56460820ca93c932b542089dda5112db Mon Sep 17 00:00:00 2001 From: npeter83 Date: Sat, 19 Sep 2026 01:54:48 +0200 Subject: [PATCH 3/9] feat(diagnostics): the admin log console MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Admin → Diagnostics reads the server's stored log: one list, newest first, where a line opens in place to its full record (time, source and logger, account, request and job ids, version, message, attributes, stack). A request or job id narrows the list to that request or job with every other filter off, shown as a removable chip. Filters: level group, source, account, event, period and a free-text search; all of them live in the URL (`l*` keys, which setPage clears like the Plex and Channels keys), so a filtered view is a link and Back restores it. "Live" re-reads the newest page every few seconds while the tab is visible; paging into older rows turns it off. Copy puts the loaded lines on the clipboard as JSON lines. The facet counts now honour every filter but their own, as the feed's do: a request pivot narrows them, and a picked level does not zero its siblings. A value in use stays offered even when the counts drop it. "Saját napló" and the console draw a line with one shared component, `LogLine`, whose phone layout gives the message its own full-width line (sharing the code's line left it a few characters). The level groups moved to lib/log.ts for both. The console's own reads are logged at DEBUG on success, like the healthcheck: at INFO its live tail filled the log with itself. --- backend/app/logs.py | 8 +- backend/app/routes/admin_logs.py | 121 +++-- backend/tests/test_admin_logs.py | 20 + backend/tests/test_logs.py | 18 +- .../src/components/AdminLogs.dom.test.tsx | 152 +++++++ frontend/src/components/AdminLogs.tsx | 425 ++++++++++++++++++ frontend/src/components/LogLine.tsx | 68 +++ frontend/src/components/MyLogViewer.tsx | 103 ++--- .../NavigationProvider.dom.test.tsx | 11 + .../src/components/NavigationProvider.tsx | 2 + frontend/src/components/moduleRegistry.tsx | 2 + frontend/src/i18n/locales/en/adminLogs.json | 40 ++ frontend/src/i18n/locales/en/header.json | 1 + frontend/src/i18n/locales/hu/adminLogs.json | 40 ++ frontend/src/i18n/locales/hu/header.json | 1 + frontend/src/lib/api/admin.ts | 84 +++- frontend/src/lib/log.ts | 11 + frontend/src/lib/logsUrlState.test.ts | 42 ++ frontend/src/lib/logsUrlState.ts | 80 ++++ frontend/src/lib/modules.ts | 9 + frontend/src/lib/pageMeta.test.ts | 1 + frontend/src/lib/queryKeys.ts | 4 + frontend/src/lib/urlState.ts | 1 + 23 files changed, 1127 insertions(+), 117 deletions(-) create mode 100644 frontend/src/components/AdminLogs.dom.test.tsx create mode 100644 frontend/src/components/AdminLogs.tsx create mode 100644 frontend/src/components/LogLine.tsx create mode 100644 frontend/src/i18n/locales/en/adminLogs.json create mode 100644 frontend/src/i18n/locales/hu/adminLogs.json create mode 100644 frontend/src/lib/logsUrlState.test.ts create mode 100644 frontend/src/lib/logsUrlState.ts 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/routes/admin_logs.py b/backend/app/routes/admin_logs.py index 4f351b4b..01d19ef0 100644 --- a/backend/app/routes/admin_logs.py +++ b/backend/app/routes/admin_logs.py @@ -18,6 +18,7 @@ commits, so a slower batch can land below an id the tail already passed — and import base64 import binascii import json +from dataclasses import dataclass from datetime import datetime, timezone from typing import Literal @@ -91,8 +92,62 @@ def _accounts(db: Session, user_ids: set[int]) -> dict[str, str]: return {str(uid): email for uid, email in rows} -@router.get("") -def list_logs( +@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: str | 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})$"), @@ -104,6 +159,13 @@ def list_logs( 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), @@ -111,36 +173,7 @@ def list_logs( ) -> 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) - if levels: - query = query.where(LogEvent.level.in_(levels)) - if sources: - query = query.where(LogEvent.source.in_(sources)) - if user is not None: - query = query.where( - LogEvent.user_id.is_(None) if user == NONE else LogEvent.user_id == int(user) - ) - if event is not None: - query = query.where(LogEvent.event.is_(None) if event == NONE else LogEvent.event == event) - if request_id is not None: - query = query.where(LogEvent.request_id == request_id) - if job_id is not None: - query = query.where(LogEvent.job_id == job_id) - if since is not None: - query = query.where(LogEvent.ts >= _utc(since)) - if until is not None: - query = query.where(LogEvent.ts < _utc(until)) - if q and q.strip(): - like = f"%{like_escape(q.strip())}%" - query = query.where( - or_( - LogEvent.msg.ilike(like), - LogEvent.event.ilike(like), - LogEvent.request_id.ilike(like), - LogEvent.exc.ilike(like), - cast(LogEvent.attrs, Text).ilike(like), - ) - ) + 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 @@ -169,18 +202,17 @@ def list_logs( @router.get("/facets") def log_facets( - since: datetime | None = None, + filters: LogFilters = Depends(log_filters), _: User = Depends(admin_user), db: Session = Depends(get_db), ) -> dict: - """What the filter chips offer, with counts: every level, source and account present in the - window, and its most frequent events. Over the window alone, not the other filters — a chip - row that shrank as you clicked would hide the way back.""" - window = [LogEvent.ts >= _utc(since)] if since is not None else [] + """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, cap: int | None = None) -> list[dict]: + def counts(col, skip: str, cap: int | None = None) -> list[dict]: n = func.count().label("n") - stmt = select(col, n).where(*window).group_by(col).order_by(n.desc(), col) + 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 [ @@ -188,12 +220,13 @@ def log_facets( for value, count in db.execute(stmt).all() ] - users = counts(LogEvent.user_id) + users = counts(LogEvent.user_id, "user") + total = select(func.count()).select_from(LogEvent).where(*filters.conditions("levels")) return { - "levels": counts(LogEvent.level), - "sources": counts(LogEvent.source), - "events": counts(LogEvent.event, FACET_EVENTS_MAX), + "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(select(func.count()).select_from(LogEvent).where(*window)) or 0, + "total": db.scalar(total) or 0, } diff --git a/backend/tests/test_admin_logs.py b/backend/tests/test_admin_logs.py index 3bf24702..7d634616 100644 --- a/backend/tests/test_admin_logs.py +++ b/backend/tests/test_admin_logs.py @@ -152,3 +152,23 @@ def test_facets_count_the_window_and_name_the_rows_without_a_value(db, admin): ] 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}] 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/frontend/src/components/AdminLogs.dom.test.tsx b/frontend/src/components/AdminLogs.dom.test.tsx new file mode 100644 index 00000000..773ec9e7 --- /dev/null +++ b/frontend/src/components/AdminLogs.dom.test.tsx @@ -0,0 +1,152 @@ +// @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; a failed read is an error, not an empty log. +import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; +import { 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), + }, + }; +}); + +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( + + + , + ); +} + +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(() => { + 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 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..9289de67 --- /dev/null +++ b/frontend/src/components/AdminLogs.tsx @@ -0,0 +1,425 @@ +import { useMemo, 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 { 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 { 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 → Diagnosztika: 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. + +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, setLive] = useState(false); + 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) => last.next_cursor ?? undefined, + placeholderData: keepPreviousData, + refetchInterval: live ? LIVE_MS : false, + }); + const facets = useQuery({ + queryKey: qk.adminLogFacets({ ...query, window: state.window }), + queryFn: () => api.adminLogFacets({ ...query, since: sinceOf(state.window) }), + placeholderData: keepPreviousData, + refetchInterval: live ? LIVE_MS * 4 : false, + }); + + 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 (!live) { + // Watching the top: drop the older pages, or every tick would re-read all of them. + qc.setQueryData(key, (d) => + d ? { pages: d.pages.slice(0, 1), pageParams: d.pageParams.slice(0, 1) } : d, + ); + } + setLive(!live); + }; + + 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 })} + /> + )} +
+ )} + +
+ {logs.isError && !logs.data ? ( + void logs.refetch()}> + {t("common.loadError")} + + ) : logs.isLoading ? ( + + ) : rows.length === 0 ? ( +

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

+ ) : ( + rows.map((row) => ( + setOpen(open === row.id ? null : row.id)} + > + pivot({ requestId, jobId: null })} + onJob={(jobId) => pivot({ requestId: null, jobId })} + /> + + )) + )} +
+ +
+ {t("adminLogs.count", { count: rows.length })} + {logs.hasNextPage && ( + + )} +
+
+
+
+ ); +} + +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")}
+
{new Date(row.ts).toLocaleString()}
+
{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..7dc63fed --- /dev/null +++ b/frontend/src/components/LogLine.tsx @@ -0,0 +1,68 @@ +import type { ReactNode } from "react"; + +import type { Level } from "../lib/log"; + +// 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. + +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, + 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 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..16ec4912 100644 --- a/frontend/src/components/MyLogViewer.tsx +++ b/frontend/src/components/MyLogViewer.tsx @@ -3,33 +3,23 @@ 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 { 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 +63,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 +83,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 +92,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 +150,32 @@ 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) => ( + 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..0a99b6c0 --- /dev/null +++ b/frontend/src/i18n/locales/en/adminLogs.json @@ -0,0 +1,40 @@ +{ + "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.", + "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..c29248ed 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": "Diagnostics", "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..e5418b73 --- /dev/null +++ b/frontend/src/i18n/locales/hu/adminLogs.json @@ -0,0 +1,40 @@ +{ + "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.", + "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..2c744d33 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": "Diagnosztika", "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/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/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", From 8cfab498cf89641855969e2d5d467ff46c4aae24 Mon Sep 17 00:00:00 2001 From: npeter83 Date: Sat, 19 Sep 2026 01:58:40 +0200 Subject: [PATCH 4/9] fix(sync): try a channel's feed again before counting it as failed YouTube's feed endpoint answers the same channel with 404, 500 and 200 in turn: on prod 182, then 296 of 396 channels failed a poll, and a probe of 24 channels saw 15 fail a first request while 16 had succeeded by the fifth. A channel that failed once waited for the next poll, 20 minutes later, so new uploads showed up late. A feed is now tried up to three times (after 1 s and 2 s) on a transport error, a 404, a 429 or a 5xx; a refusal such as 403 is not retried. The last failure is what gets counted. A feed that is really gone costs two more requests per poll. --- backend/app/youtube/rss.py | 43 +++++++++++++++++++++------- backend/tests/test_sync_guards.py | 47 +++++++++++++++++++++++++++++++ 2 files changed, 80 insertions(+), 10 deletions(-) diff --git a/backend/app/youtube/rss.py b/backend/app/youtube/rss.py index e4624e76..b83d4b17 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,15 @@ 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. +RETRY_DELAYS = (1.0, 2.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 +34,34 @@ 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=20.0, 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 + 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_sync_guards.py b/backend/tests/test_sync_guards.py index ef688baf..f58cda15 100644 --- a/backend/tests/test_sync_guards.py +++ b/backend/tests/test_sync_guards.py @@ -246,6 +246,53 @@ 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_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) From 142593083f1d0ad0443ccadeedbad7daab2fd36f Mon Sep 17 00:00:00 2001 From: npeter83 Date: Sat, 19 Sep 2026 02:02:45 +0200 Subject: [PATCH 5/9] feat(diagnostics): walk the log lines from the keyboard; name the console "Server log" MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Both log viewers put their lines in a NavGrid: j/k (and the arrows) step from line to line, and Enter opens one exactly as a click does (the line's button is its `data-nav-open`). A focused line is named by its code and message. The console's nav entry is "Szervernapló" / "Server log", its page title: "Diagnosztika" was already the Settings tab that holds the user's own log, and two places with one name read as one place. --- .../src/components/AdminLogs.dom.test.tsx | 11 ++++ frontend/src/components/AdminLogs.tsx | 44 ++++++++------- frontend/src/components/LogLine.tsx | 11 +++- frontend/src/components/MyLogViewer.tsx | 56 ++++++++++--------- frontend/src/i18n/locales/en/header.json | 2 +- frontend/src/i18n/locales/hu/header.json | 2 +- 6 files changed, 77 insertions(+), 49 deletions(-) diff --git a/frontend/src/components/AdminLogs.dom.test.tsx b/frontend/src/components/AdminLogs.dom.test.tsx index 773ec9e7..f4646334 100644 --- a/frontend/src/components/AdminLogs.dom.test.tsx +++ b/frontend/src/components/AdminLogs.dom.test.tsx @@ -142,6 +142,17 @@ describe("AdminLogs", () => { ).toBe("true"); }); + 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(); diff --git a/frontend/src/components/AdminLogs.tsx b/frontend/src/components/AdminLogs.tsx index 9289de67..1d8b9992 100644 --- a/frontend/src/components/AdminLogs.tsx +++ b/frontend/src/components/AdminLogs.tsx @@ -24,13 +24,14 @@ 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 → Diagnosztika: the server's stored log (`log_events`, E22.6). One list, newest first; a line +// 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 @@ -287,25 +288,28 @@ export default function AdminLogs() { {t("adminLogs.empty")}

) : ( - rows.map((row) => ( - setOpen(open === row.id ? null : row.id)} - > - pivot({ requestId, jobId: null })} - onJob={(jobId) => pivot({ requestId: null, jobId })} - /> - - )) + + {rows.map((row, index) => ( + setOpen(open === row.id ? null : row.id)} + > + pivot({ requestId, jobId: null })} + onJob={(jobId) => pivot({ requestId: null, jobId })} + /> + + ))} + )} diff --git a/frontend/src/components/LogLine.tsx b/frontend/src/components/LogLine.tsx index 7dc63fed..bb9ea5cc 100644 --- a/frontend/src/components/LogLine.tsx +++ b/frontend/src/components/LogLine.tsx @@ -1,10 +1,12 @@ 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" }, @@ -30,6 +32,7 @@ export default function LogLine({ open, onToggle, title, + navIndex, children, }: { ts: string; @@ -40,14 +43,20 @@ export default function LogLine({ 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 ( -
+
diff --git a/frontend/src/i18n/locales/en/header.json b/frontend/src/i18n/locales/en/header.json index c29248ed..19968222 100644 --- a/frontend/src/i18n/locales/en/header.json +++ b/frontend/src/i18n/locales/en/header.json @@ -35,7 +35,7 @@ "addAccount": "Add another account", "switchTo": "Switch to {{name}}", "audit": "Audit log", - "logs": "Diagnostics", + "logs": "Server log", "googleAddress": "Google account: {{email}}" }, "sync": { diff --git a/frontend/src/i18n/locales/hu/header.json b/frontend/src/i18n/locales/hu/header.json index 2c744d33..7aa1d217 100644 --- a/frontend/src/i18n/locales/hu/header.json +++ b/frontend/src/i18n/locales/hu/header.json @@ -35,7 +35,7 @@ "addAccount": "Másik fiók hozzáadása", "switchTo": "Váltás erre: {{name}}", "audit": "Auditnapló", - "logs": "Diagnosztika", + "logs": "Szervernapló", "googleAddress": "Google-fiók: {{email}}" }, "sync": { From 1c49870a7a3a3841d1ba5cd9713262e58415b42c Mon Sep 17 00:00:00 2001 From: npeter83 Date: Sat, 19 Sep 2026 03:42:26 +0200 Subject: [PATCH 6/9] fix(sync): don't try a timed-out feed again A request that hung for the full timeout says the way out is hanging, not that the endpoint is flaky; three of them per channel stretched a poll over a dead egress to about three times its interval. --- backend/app/youtube/rss.py | 9 +++++++-- backend/tests/test_sync_guards.py | 8 ++++++++ 2 files changed, 15 insertions(+), 2 deletions(-) diff --git a/backend/app/youtube/rss.py b/backend/app/youtube/rss.py index b83d4b17..510bc13d 100644 --- a/backend/app/youtube/rss.py +++ b/backend/app/youtube/rss.py @@ -12,8 +12,11 @@ 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. +# 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}) @@ -41,11 +44,13 @@ def _get_feed(channel_id: str) -> bytes: if attempt: time.sleep(RETRY_DELAYS[attempt - 1]) try: - resp = httpx.get(url, timeout=20.0, headers={"User-Agent": "Siftlode/1.0"}) + 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 diff --git a/backend/tests/test_sync_guards.py b/backend/tests/test_sync_guards.py index f58cda15..b36ce352 100644 --- a/backend/tests/test_sync_guards.py +++ b/backend/tests/test_sync_guards.py @@ -282,6 +282,14 @@ class TestRssErrorVsEmpty: 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: From 8f6f89832f8fdc64129e8e32ff0293340ec6d5f7 Mon Sep 17 00:00:00 2001 From: npeter83 Date: Sat, 19 Sep 2026 03:42:26 +0200 Subject: [PATCH 7/9] fix(diagnostics): honest live console after review - Live stops polling on a failed read and marks the list as possibly stale (with Retry), instead of re-raising the error dialog every tick. - While live, a refetch reads the newest page only, whatever the cache holds (a late "Load older", a revisited filter set). - Copy is disabled and the list dimmed while a filter change loads. - Dates follow the UI language; the pivot chip uses the shared .chip. - Tests: query-string wire test, Copy, every facet's skip key. --- backend/app/routes/admin_logs.py | 6 +- backend/tests/test_admin_logs.py | 17 ++++ .../src/components/AdminLogs.dom.test.tsx | 80 ++++++++++++++++++- frontend/src/components/AdminLogs.tsx | 61 +++++++++++--- frontend/src/i18n/locales/en/adminLogs.json | 1 + frontend/src/i18n/locales/hu/adminLogs.json | 1 + frontend/src/lib/api/adminLogs.dom.test.ts | 64 +++++++++++++++ 7 files changed, 213 insertions(+), 17 deletions(-) create mode 100644 frontend/src/lib/api/adminLogs.dom.test.ts diff --git a/backend/app/routes/admin_logs.py b/backend/app/routes/admin_logs.py index 01d19ef0..43ae3c65 100644 --- a/backend/app/routes/admin_logs.py +++ b/backend/app/routes/admin_logs.py @@ -39,6 +39,8 @@ PAGE_MAX = 200 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" @@ -106,7 +108,7 @@ class LogFilters: since: datetime | None until: datetime | None - def conditions(self, skip: str | None = None) -> list: + 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).""" @@ -210,7 +212,7 @@ def log_facets( 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: str, cap: int | None = None) -> list[dict]: + 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: diff --git a/backend/tests/test_admin_logs.py b/backend/tests/test_admin_logs.py index 7d634616..87660e41 100644 --- a/backend/tests/test_admin_logs.py +++ b/backend/tests/test_admin_logs.py @@ -172,3 +172,20 @@ def test_a_facet_counts_under_every_other_filter_but_not_its_own(db, admin): 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/frontend/src/components/AdminLogs.dom.test.tsx b/frontend/src/components/AdminLogs.dom.test.tsx index f4646334..e06e6575 100644 --- a/frontend/src/components/AdminLogs.dom.test.tsx +++ b/frontend/src/components/AdminLogs.dom.test.tsx @@ -2,9 +2,10 @@ // // 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; a failed read is an error, not an empty log. +// 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 { cleanup, fireEvent, render, screen, waitFor, within } from "@testing-library/react"; +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"; @@ -35,6 +36,14 @@ vi.mock("../lib/api", async (importOriginal) => { }; }); +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 { @@ -75,6 +84,9 @@ function renderConsole() { ); } +// 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") @@ -85,6 +97,7 @@ beforeEach(() => { facetsMock.mockResolvedValue(FACETS); }); afterEach(() => { + vi.useRealTimers(); cleanup(); logsMock.mockReset(); facetsMock.mockReset(); @@ -142,6 +155,69 @@ describe("AdminLogs", () => { ).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); + }); + + 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(); diff --git a/frontend/src/components/AdminLogs.tsx b/frontend/src/components/AdminLogs.tsx index 1d8b9992..9608491e 100644 --- a/frontend/src/components/AdminLogs.tsx +++ b/frontend/src/components/AdminLogs.tsx @@ -1,4 +1,4 @@ -import { useMemo, useState } from "react"; +import { useMemo, useRef, useState } from "react"; import { useTranslation } from "react-i18next"; import { keepPreviousData, @@ -10,6 +10,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 { LEVEL_GROUPS, type LevelGroup } from "../lib/log"; import { DEFAULT_LOGS_STATE, @@ -35,7 +36,8 @@ import { LoadingState, StateMessage } from "./ui/QueryState"; // 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. +// 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"]; @@ -68,7 +70,15 @@ export default function AdminLogs() { const [state, setState] = useState(() => logsParamsToState(new URLSearchParams(window.location.search)), ); - const [live, setLive] = useState(false); + 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)); @@ -85,16 +95,25 @@ export default function AdminLogs() { queryFn: ({ pageParam }) => api.adminLogs({ ...query, since: sinceOf(state.window) }, pageParam), initialPageParam: null as string | null, - getNextPageParam: (last) => last.next_cursor ?? undefined, + getNextPageParam: (last) => (liveRef.current ? undefined : (last.next_cursor ?? undefined)), placeholderData: keepPreviousData, - refetchInterval: live ? LIVE_MS : false, + 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: live ? LIVE_MS * 4 : false, + refetchInterval: (q) => (live && q.state.status !== "error" ? LIVE_MS * 4 : false), }); + // What "Load older" continues from — read off the data, since `hasNextPage` is off while live. + const olderCursor = logs.data?.pages[logs.data.pages.length - 1]?.next_cursor ?? null; + // A read failed while rows (or counts) were already on screen: they are kept, and said to be old. + const stale = (logs.isError && !!logs.data) || facets.isError; + const retryStale = () => { + 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( @@ -111,7 +130,7 @@ export default function AdminLogs() { const toggleLive = () => { if (!live) { - // Watching the top: drop the older pages, or every tick would re-read all of them. + // 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, ); @@ -249,7 +268,8 @@ export default function AdminLogs() { variant="outline" size="xs" icon={} - disabled={rows.length === 0} + // While a filter change loads, the rows on screen are the previous filter's. + disabled={rows.length === 0 || logs.isPlaceholderData} onClick={() => void copy()} > {t("adminLogs.copy")} @@ -276,7 +296,22 @@ export default function AdminLogs() {
)} -
+ {stale && ( + + {t("adminLogs.stale")} + + )} + +
{logs.isError && !logs.data ? ( void logs.refetch()}> {t("common.loadError")} @@ -297,7 +332,7 @@ export default function AdminLogs() { level={row.level} event={row.event ?? "—"} msg={row.msg} - title={new Date(row.ts).toLocaleString()} + title={formatDateTime(row.ts)} open={open === row.id} onToggle={() => setOpen(open === row.id ? null : row.id)} > @@ -315,7 +350,7 @@ export default function AdminLogs() {
{t("adminLogs.count", { count: rows.length })} - {logs.hasNextPage && ( + {olderCursor !== null && (
)} - {stale && ( + {failure && ( - {t("adminLogs.stale")} + {t(`adminLogs.${failure}`)} )} diff --git a/frontend/src/i18n/locales/en/adminLogs.json b/frontend/src/i18n/locales/en/adminLogs.json index fb734b2b..f121848a 100644 --- a/frontend/src/i18n/locales/en/adminLogs.json +++ b/frontend/src/i18n/locales/en/adminLogs.json @@ -27,6 +27,8 @@ "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", diff --git a/frontend/src/i18n/locales/hu/adminLogs.json b/frontend/src/i18n/locales/hu/adminLogs.json index f5d31811..e8ef112e 100644 --- a/frontend/src/i18n/locales/hu/adminLogs.json +++ b/frontend/src/i18n/locales/hu/adminLogs.json @@ -27,6 +27,8 @@ "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", From 4e3e68d6e624264a6494b6bb8c148ab97b573427 Mon Sep 17 00:00:00 2001 From: npeter83 Date: Sat, 19 Sep 2026 03:57:29 +0200 Subject: [PATCH 9/9] chore(release): 0.90.0 --- CHANGELOG.md | 21 +++++++++++++++++++++ VERSION | 2 +- frontend/src/lib/releaseNotes.ts | 20 ++++++++++++++++++++ 3 files changed, 42 insertions(+), 1 deletion(-) 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/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",