diff --git a/CHANGELOG.md b/CHANGELOG.md index ad1f016b..6b778a5b 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,6 +7,31 @@ 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.93.0 — 2026-09-20 + +A way to report a fault from inside the app: record what you did, mark the steps, attach screenshots — and the app writes the report for you, with the logs of exactly that session attached. + +### Features + +- Start a recording (the command palette, or Settings → Diagnostics) and a pill follows you: a timer, “Step” to mark what you just did, a screenshot button, and Stop. Everything you and the server do while it runs is collected under that one session, and nothing else is. +- Stop opens the composer: a drafted title and description, the steps you marked interleaved with the pages you visited, a table of your browser and the app's version, and the attachments — each one reviewable, each one removable. +- The log lines that would be sent can be read before they go, line by line, and any of them left out. +- Screenshots come from a paste, a drop, a file, or capturing the tab — up to eight, and any of them can be dropped again before sending. +- Send opens an issue on the project's tracker with the report and its logs attached, and the preview shows it exactly as the tracker will render it. Five reports an hour. +- Without a tracker configured — or whenever you would rather keep it — the same report downloads as a zip instead. +- An administrator sets the tracker up in Settings → System (address, repository, token) and can test the connection there. The server refuses to send to a public repository: a report carries its reporter's log. + +### Fixes + +- The Plex player keeps the keyboard inside itself: Tab no longer walks out of a playing film into the page behind it, not even while its own settings panel is open. +- A report cannot be sent twice at once, from any tab: while one send runs the others say so, and a send that fails half-way retries only what is missing — never a second issue. +- A recording ends by itself after an hour, and both Stop and that hour return your diagnostics level to whatever it was before you started. + +### Internal + +- A session's logs and screenshots are purged with the session after 7 days, like every other diagnostic line, and another account's session id is ignored rather than refused. +- Four adversarial review rounds at the epic's end: 80 findings fixed across them, every regression test proven to fail with its own fix removed, and the keyboard and focus work measured in a real browser rather than argued. + ## 0.92.0 — 2026-09-19 A debt burn: every item the roadmap had deferred is done or dropped — Plex playback per viewer, refusals said in your language, controls that keep the keyboard focus, and a screen reader that hears Hungarian. diff --git a/CLAUDE.md b/CLAUDE.md index cb86892c..84c8184f 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -56,9 +56,9 @@ how it gets built. Concretely: ## Architecture shape (don't fight it) `routes/*` (HTTP only: validation, auth-dependency, serialization) → domain packages `sync/`, `plex/`, -`downloads/`, `youtube/` (shared by routes + scheduler + worker) → flat core (`auth`, `quota`, +`downloads/`, `youtube/`, `issues/` (shared by routes + scheduler + worker) → flat core (`auth`, `quota`, `sysconfig`, `state`, `audit`, `notifications`, `userscope`, `realtime`, `ratelimit`, `progress`, -`security`, `logs`, `logsink`, `diagnostics`) → `models/db/config`. **Dependency direction is one-way: core never imports routes.** +`security`, `logs`, `logsink`, `diagnostics`, `debugsession`) → `models/db/config`. **Dependency direction is one-way: core never imports routes.** Frontend: `main.tsx` provider tree → `App.tsx` shell → `moduleRegistry` route-chunks → module components → the **platform layer `components/ui/`** (domain-free primitives: the popover engine and its menus, `Modal`/`Overlay`, `Button`/`form`, `DataTable`/`VirtualGrid`, `QueryState`, …). That diff --git a/VERSION b/VERSION index 36545ad3..9188543e 100644 --- a/VERSION +++ b/VERSION @@ -1 +1 @@ -0.92.0 +0.93.0 diff --git a/backend/alembic/versions/0089_debug_sessions.py b/backend/alembic/versions/0089_debug_sessions.py new file mode 100644 index 00000000..161d117f --- /dev/null +++ b/backend/alembic/versions/0089_debug_sessions.py @@ -0,0 +1,81 @@ +"""add debug_sessions + debug_screenshots, and index log_events.debug_session_id (E16) + +Revision ID: 0089_debug_sessions +Revises: 0088_channels_feed_fallback_at +Create Date: 2026-09-19 + +A debug session is one recording: Start → reproduce → Stop (app/debugsession.py). Every log line +of that user's requests while it runs carries its id in `log_events.debug_session_id` — the column +E22 created and left NULL — and the issue it ends in is built from exactly those rows, so the column +gets its index now. Partial: nearly every row has no session, and an index of NULLs would be most +of the table for nothing. + +At most one OPEN session per user, held by a partial unique index rather than by the start handler +alone: two tabs pressing Start at once would otherwise both pass a "none open" check. + +Screenshots are rows, not files: bounded (size and count per session, app/debugsession.py), gone +with their session by cascade, and a self-host has no file volume to configure for them. +""" + +import sqlalchemy as sa +from alembic import op + +revision: str = "0089_debug_sessions" +down_revision: str | None = "0088_channels_feed_fallback_at" +branch_labels: str | None = None +depends_on: str | None = None + + +def upgrade() -> None: + op.create_table( + "debug_sessions", + sa.Column("id", sa.String(16), primary_key=True), + sa.Column( + "user_id", + sa.Integer, + sa.ForeignKey("users.id", ondelete="CASCADE"), + nullable=False, + index=True, + ), + sa.Column("level", sa.String(8), nullable=False), + sa.Column("started_at", sa.DateTime(timezone=True), nullable=False), + sa.Column("until", sa.DateTime(timezone=True), nullable=False), + sa.Column("ended_at", sa.DateTime(timezone=True), nullable=True), + sa.Column("ended_reason", sa.String(16), nullable=True), + sa.Column("issue_url", sa.String(512), nullable=True), + ) + op.create_index( + "uq_debug_sessions_open_per_user", + "debug_sessions", + ["user_id"], + unique=True, + postgresql_where=sa.text("ended_at IS NULL"), + ) + op.create_table( + "debug_screenshots", + sa.Column("id", sa.Integer, primary_key=True), + sa.Column( + "session_id", + sa.String(16), + sa.ForeignKey("debug_sessions.id", ondelete="CASCADE"), + nullable=False, + index=True, + ), + sa.Column("created_at", sa.DateTime(timezone=True), nullable=False), + sa.Column("mime", sa.String(16), nullable=False), + sa.Column("size", sa.Integer, nullable=False), + sa.Column("data", sa.LargeBinary, nullable=False), + ) + op.create_index( + "ix_log_events_debug_session", + "log_events", + ["debug_session_id"], + postgresql_where=sa.text("debug_session_id IS NOT NULL"), + ) + + +def downgrade() -> None: + op.drop_index("ix_log_events_debug_session", table_name="log_events") + op.drop_table("debug_screenshots") + op.drop_index("uq_debug_sessions_open_per_user", table_name="debug_sessions") + op.drop_table("debug_sessions") diff --git a/backend/alembic/versions/0090_debug_session_draft.py b/backend/alembic/versions/0090_debug_session_draft.py new file mode 100644 index 00000000..6a021000 --- /dev/null +++ b/backend/alembic/versions/0090_debug_session_draft.py @@ -0,0 +1,27 @@ +"""add debug_sessions.draft — the issue being written from a session (E16 S3) + +Revision ID: 0090_debug_session_draft +Revises: 0089_debug_sessions +Create Date: 2026-09-19 + +The composer saves as it goes: the title, the rendered markdown body that an export or an issue +carries, the log rows the user took out, and the form's own fields so reopening it later (Settings → +Diagnosztika lists past sessions) shows what was written. NULL until the composer first saves. +""" + +import sqlalchemy as sa +from alembic import op +from sqlalchemy.dialects.postgresql import JSONB + +revision: str = "0090_debug_session_draft" +down_revision: str | None = "0089_debug_sessions" +branch_labels: str | None = None +depends_on: str | None = None + + +def upgrade() -> None: + op.add_column("debug_sessions", sa.Column("draft", JSONB, nullable=True)) + + +def downgrade() -> None: + op.drop_column("debug_sessions", "draft") diff --git a/backend/app/README.md b/backend/app/README.md index ec04ecc2..9fb2cac1 100644 --- a/backend/app/README.md +++ b/backend/app/README.md @@ -13,16 +13,17 @@ Three layers, by *who* runs the code — not by feature: response models, status-code mapping, serialization. It owns logic that runs *only* on a request. Business logic that a request happens to trigger does **not** live here if anything else runs it too. -2. **`plex/`, `downloads/`, `sync/` — domain logic shared by more than one caller.** Anything the +2. **`plex/`, `downloads/`, `sync/`, `issues/` — domain logic shared by more than one caller.** Anything the **scheduler or the worker** runs (not just a request) lives in one of these domain packages, so the route, the worker, and the scheduler share one definition. Examples from this codebase: `downloads/service.py` owns enqueue + the job state transitions (routes call it); `plex/sync.py` is - run by both the admin route and the scheduler; `downloads/pipeline.py` is the worker's child pipeline. + run by both the admin route and the scheduler; `downloads/pipeline.py` is the worker's child pipeline; + `issues/bundle.py` is the one definition of a bug report's files, for the zip export and the tracker. 3. **Flat `app/*.py` core modules — cross-cutting primitives.** `auth`, `sysconfig`, `quota`, `audit`, `notifications`, `userscope`, `realtime`, `ratelimit`, `progress`, `logs` (the one logging - configuration), `logsink` (its `log_events` table) and `diagnostics` (a user's consented log - level), … are single-file primitives many layers import. They depend on nothing above them (a core + configuration), `logsink` (its `log_events` table), `diagnostics` (a user's consented log + level) and `debugsession` (a recording that tags its user's lines, E16), … are single-file primitives many layers import. They depend on nothing above them (a core module must never import a `routes/…` module). **Extraction trigger: the SECOND consumer.** Keep new logic inline in its first caller. The moment a diff --git a/backend/app/audit.py b/backend/app/audit.py index 8a87f95c..6dfba3d1 100644 --- a/backend/app/audit.py +++ b/backend/app/audit.py @@ -58,6 +58,9 @@ class AuditAction: DOWNLOAD_CREDENTIAL_DELETE = "download_credential_delete" # The log itself was cleared (a single row survives the clear as tamper-evidence) AUDIT_CLEAR = "audit_clear" + # E16: a user sent a debug session's issue to the tracker — the one act that takes their log + # off this instance, so it is recorded (target = the session, summary = the issue's URL). + ISSUE_CREATE = "issue_create" def record( diff --git a/backend/app/auth.py b/backend/app/auth.py index 763954cf..cbee737c 100644 --- a/backend/app/auth.py +++ b/backend/app/auth.py @@ -4,7 +4,7 @@ from sqlalchemy import delete, func, select from sqlalchemy.orm import Session from starlette.requests import HTTPConnection -from app import diagnostics +from app import debugsession from app import email as email_mod from app import logs from app import mailtext @@ -367,7 +367,11 @@ def _session_user(request: Request, db: Session, user_id: int | None, is_default # session middleware and this task's context. `request.state` is shared across middleware layers # (it lives on the ASGI scope), so the access-log line can read it back. The user's consented # diagnostics level rides along: their requests are logged — and stored — in that detail (S5). - logs.set_user(user.id, diagnostics.effective_level(user), user.diagnostics_until) + # So does a debug session the request names (E16): only the caller's own open one counts, and a + # header naming anything else is ignored rather than refused — a stale tab must keep working. + session = debugsession.from_header(db, user, request.headers.get(debugsession.HEADER)) + level, until = debugsession.level_for(user, session) + logs.set_user(user.id, level, until, session.id if session else None) request.state.user_id = user.id return user diff --git a/backend/app/config.py b/backend/app/config.py index 8933fd62..8be0a0bd 100644 --- a/backend/app/config.py +++ b/backend/app/config.py @@ -351,6 +351,13 @@ class Settings(BaseSettings): tmdb_api_base: str = "https://api.themoviedb.org/3" # Metadata language for TMDB fetches (keyword/overview locale). Stored EN by default. tmdb_language: str = "en-US" + + # --- Bug reports (E16): where a debug session's issue goes. All three empty = no tracker; the + # composer still exports a zip. The repository must be PRIVATE — an issue carries the reporter's + # log — and app/issues/gitea.py refuses a public one. Runtime knobs (sysconfig, admin UI). --- + issues_gitea_url: str = "" + issues_gitea_repo: str = "" + issues_gitea_token: str = "" # How often the TMDB enrichment job fetches a batch of not-yet-enriched Plex titles, in minutes. tmdb_enrich_interval_min: int = 120 # Titles fetched per TMDB enrichment run (TMDB is fast + generously rate-limited). diff --git a/backend/app/debugsession.py b/backend/app/debugsession.py new file mode 100644 index 00000000..0f0aa167 --- /dev/null +++ b/backend/app/debugsession.py @@ -0,0 +1,485 @@ +"""Debug sessions (E16): Start → reproduce → Stop, and the evidence a bug report is built from. + +While a session is open its user's browser names it in `X-Debug-Session` on every request. The auth +dependency accepts the header only for the caller's OWN open session (anything else is ignored, never +an error — a stale tab must not break the app) and then logs that request at the session's level with +every line tagged by its id; the browser tags its own events the same way. The issue is later built +from exactly the rows carrying the tag, so what the review list shows is what gets sent. + +Starting a session IS the consent for its level, for its duration: the start dialog carries the +consent text. It needs no change to the user's own diagnostics level, and none is made — when the +session ends the level in force is simply the user's own again. + +A session is capped at `MAX_MINUTES`, set by the server at Start. An open one past its cap is over +whether or not anything has closed it yet: it reads as over at once, a new Start closes it, and the +hourly log job sweeps the rest. Sessions go with the logs they point at, after `log_retention_days`. + +Core layer: imports `models`, `diagnostics`. +""" + +import secrets +from datetime import datetime, timedelta, timezone +from enum import StrEnum +from typing import Literal, get_args +from uuid import uuid4 + +from sqlalchemy import and_, delete, func, not_, select, update +from sqlalchemy.orm import Session, defer + +from app import diagnostics +from app.models import DebugScreenshot, DebugSession, LogEvent, User + +HEADER = "x-debug-session" +MAX_MINUTES = diagnostics.SESSION_MINUTES +SCREENSHOT_MAX_BYTES = 10 * 1024 * 1024 +SCREENSHOTS_MAX = 8 +# What one user may keep in screenshots across ALL their sessions (until retention takes them): the +# per-session cap alone would let Start → 8 images → Stop repeat without end. +SCREENSHOT_USER_MAX_BYTES = 100 * 1024 * 1024 +# The screenshot types kept, and the extension each is exported and sent under — one table, so an +# accepted type always has a name. +IMAGE_TYPES = {"image/png": "png", "image/jpeg": "jpg", "image/webp": "webp"} +# What a screenshot is called in the zip and on the issue. `issues/bundle.py` builds the names from +# this and `IMAGE_TYPES`; this module and `issues/gitea.py` read them back to tell a screenshot's +# link from a log's. One definition, because three copies of a name is how the next rename breaks +# `images_pending` into silence. +SCREENSHOT_PREFIX = "screenshot-" +# Rows an issue can carry. A 60-minute session at Teljes is a few thousand rows; past this the +# bundle says how many it left out rather than growing without bound. +BUNDLE_MAX = 5_000 + +SessionLevel = Literal["DEBUG", "TRACE"] +SESSION_LEVELS: tuple[str, ...] = get_args(SessionLevel) +# Detail order of the diagnostics levels: a session raises the level in force, never lowers it. +_DETAIL = {"INFO": 0, "DEBUG": 1, "TRACE": 2} +_ID_LEN = 16 + + +class EndReason(StrEnum): + STOPPED = "stopped" + EXPIRED = "expired" + + +def is_live(session: DebugSession, now: datetime | None = None) -> bool: + """Open and within its cap — THE liveness rule: an open session past its cap is over.""" + return session.ended_at is None and session.until > (now or datetime.now(timezone.utc)) + + +def open_session(db: Session, user: User) -> DebugSession | None: + """The user's live session, or None. Read-only: one past its cap is over and reads as None; + `start` and the hourly sweep are what close it.""" + session = _unclosed(db, user) + if session is None or not is_live(session, datetime.now(timezone.utc)): + return None + return session + + +def _unclosed(db: Session, user: User) -> DebugSession | None: + return db.scalar( + select(DebugSession).where(DebugSession.user_id == user.id, DebugSession.ended_at.is_(None)) + ) + + +def start(db: Session, user: User, level: SessionLevel) -> DebugSession: + """Open a session, or return the live one — a second tab pressing Start joins the recording + rather than ending it. One past its cap is closed first: the one-open-per-user index would + refuse the new row beside it. Flushes; the caller commits. Two concurrent Starts can still both + get here: the index refuses the second, and the caller joins the one that won.""" + now = datetime.now(timezone.utc) + current = _unclosed(db, user) + if current is not None: + if is_live(current, now): + return current + end(current, EndReason.EXPIRED) + db.flush() + session = DebugSession( + id=secrets.token_hex(_ID_LEN // 2), + user_id=user.id, + level=level, + started_at=now, + until=now + timedelta(minutes=MAX_MINUTES), + ) + db.add(session) + db.flush() + return session + + +def stop(session: DebugSession) -> None: + """The user's Stop. Past its cap the session had already ended on its own, and a late Stop must + not rename that.""" + end(session, EndReason.STOPPED if is_live(session) else EndReason.EXPIRED) + + +def end(session: DebugSession, reason: EndReason) -> None: + """Close a session. An expired one is dated at its cap, not at whenever it was noticed.""" + if session.ended_at is not None: + return + session.ended_at = ( + session.until + if reason is EndReason.EXPIRED + else min(datetime.now(timezone.utc), session.until) + ) + session.ended_reason = reason + + +def from_header(db: Session, user: User, value: str | None) -> DebugSession | None: + """The session a request names, if it is the caller's own and still live; else None.""" + if not value or len(value) != _ID_LEN or not all(c in "0123456789abcdef" for c in value): + return None + session = db.get(DebugSession, value) + if ( + session is None + or session.user_id != user.id + or not is_live(session, datetime.now(timezone.utc)) + ): + return None + return session + + +def level_for(user: User, session: DebugSession | None) -> tuple[str, datetime | None]: + """The diagnostics level (and its expiry) a request is logged at: the user's own, raised to the + session's while one is named — whichever records more. + + A named session also caps the expiry at its own: this pair is what the process tracks under the + session (app/logs.py), and an expiry outliving the recording would hold the root logger down + after it ended.""" + own = diagnostics.effective_level(user) + until = user.diagnostics_until if own != diagnostics.BASE else None + if session is None: + return own, until + if _DETAIL[session.level] <= _DETAIL[own]: + return own, min(until, session.until) if until else session.until + return session.level, session.until + + +def lock(db: Session, session: DebugSession) -> None: + """Re-read the session under a row lock, held until the caller commits. Everything that changes + what an issue is made of — the draft, the screenshots, the send itself — takes it first: a send + in flight sees none of them change under it, and each of them sees a send that committed.""" + db.refresh(session, with_for_update=True) + + +def save_draft(session: DebugSession, draft: dict) -> None: + """Keep the composer's draft (the caller validated, locked and commits). Shape: `title`, `body` + (the rendered markdown an export or an issue carries), `excluded` (log row ids taken out of the + evidence) and `form` (the composer's own fields, to reopen it as it was). A delivery's progress + is not the composer's to replace, and is kept.""" + progress = (session.draft or {}).get("delivery") + session.draft = {**draft, "delivery": progress} if progress else draft + + +# --- a delivery's progress ----------------------------------------------------------------- +# Written by app/issues/gitea.py into the draft; read HERE, so the send's decision and what the +# composer shows are one reading of it. +def delivery(session: DebugSession) -> dict: + return dict((session.draft or {}).get("delivery") or {}) + + +def not_uploaded(session: DebugSession) -> list[str]: + """The files a send that stopped half-way has still to upload — by name, as the issue carries + them. What the composer names to the user.""" + return list(delivery(session).get("pending") or []) + + +def images_pending(session: DebugSession) -> bool: + """Whether the issue's body still has to be edited to show the screenshots it already carries + (every upload went, the edit that shows them did not).""" + state = delivery(session) + shown = state.get("images_shown") + return not shown and any(n.startswith(SCREENSHOT_PREFIX) for n in state.get("links") or {}) + + +def unfinished(session: DebugSession) -> bool: + """Whether a send owes the issue anything — the retry's question.""" + return bool(not_uploaded(session)) or images_pending(session) + + +# A send claims the session while it talks to the tracker, instead of holding the row's lock across +# those calls: a Stop, an autosave or a screenshot would queue behind a lock for the whole send. +# They see the claim and are refused at once instead. A claim not renewed for this long was left by +# a request that died mid-send (the process restarted), and the next send takes it over — which is +# why a live send RENEWS it every time it reports progress (`set_delivery`). A claim is a lease, and +# a send slower than the lease must not lose it while it is still running. +SEND_CLAIM_SECONDS = 600 + + +def _claim(session: DebugSession) -> dict: + claim = delivery(session).get("sending") + return claim if isinstance(claim, dict) else {} + + +def _stamp(token: str) -> dict: + return {"at": datetime.now(timezone.utc).isoformat(), "by": token} + + +def sending(session: DebugSession) -> bool: + """Whether a send is under way right now (a live claim).""" + at = _claim(session).get("at") + if not at: + return False + return (datetime.now(timezone.utc) - datetime.fromisoformat(at)).total_seconds() < ( + SEND_CLAIM_SECONDS + ) + + +def claim_send(session: DebugSession) -> str: + """Mark the session as being sent, and return the token that OWNS this claim. The caller holds + the lock and commits, which is what makes the claim visible to everyone else.""" + token = uuid4().hex + _write_delivery(session, {**delivery(session), "sending": _stamp(token)}) + return token + + +def release_send(session: DebugSession, token: str) -> None: + """Give back our OWN claim, and only ours: one that aged out and was taken over belongs to the + send holding it now, and handing that one back would let a third send in beside it.""" + if _claim(session).get("by") != token: + return + _write_delivery(session, {k: v for k, v in delivery(session).items() if k != "sending"}) + + +class SendClaimLost(Exception): + """This send's claim is no longer on the row: it aged out and another send took it over. The + send must stop — what it uploads from here it can no longer record, so a retry would send it + again — and it must not write, because the row now holds the other send's progress.""" + + +def claim_owner(db: Session, session: DebugSession) -> str | None: + """Who holds the row's claim RIGHT NOW, read from the ROW and not from the object. + + `expire_on_commit` is off (app/db.py), so a checkpoint does not re-read: a send that stalled + past its lease still carries its own dead token in memory long after another send took over. + A targeted scalar, not `lock`/`db.refresh` — a refresh here would discard the `issue_url` that + `gitea.deliver` assigns one line before its first progress report, and that link is the one + thing the send must not lose.""" + return db.scalar( + select(DebugSession.draft["delivery"]["sending"]["by"].as_string()).where( + DebugSession.id == session.id + ) + ) + + +def set_delivery(db: Session, session: DebugSession, state: dict, token: str) -> None: + """Write a delivery's progress (app/issues/gitea.py keeps it; this module reads it), and renew + the claim while doing it — a send still reporting progress is still alive, so one slower than + the lease cannot expire while it is still running. + + The claim is not the caller's to carry: `gitea.deliver` threads ONE snapshot of this dict + through a whole send, so a progress report that carried the claim wrote a stale one back at + every step. It is stamped from `token` here instead, and only after the ROW confirms the claim + is still ours. Without that check the write is a full-column overwrite with no WHERE: a send + that lost its lease came back and stomped the take-over send's committed links, then put its + own dead token back on an idle session (deep-review round 4). `release_send` has always made + the same check; this is the other half of it.""" + if claim_owner(db, session) != token: + raise SendClaimLost(session.id) + state = {k: v for k, v in state.items() if k != "sending"} + state["sending"] = _stamp(token) + _write_delivery(session, state) + + +def _write_delivery(session: DebugSession, state: dict) -> None: + # A new dict, so the JSONB column sees the change. + session.draft = {**(session.draft or {}), "delivery": state} + + +def serialize(session: DebugSession | None, screenshots: int = 0) -> dict | None: + if session is None: + return None + return { + "id": session.id, + "level": session.level, + "started_at": session.started_at.isoformat(), + "until": session.until.isoformat(), + "ended_at": session.ended_at.isoformat() if session.ended_at else None, + "ended_reason": session.ended_reason, + "issue_url": session.issue_url, + # A send that stopped half-way: the files it has still to upload, and whether the issue's + # body has still to be edited to show the screenshots it already carries. Both are true of a + # send that is RUNNING too — every step commits its progress — so `sending` goes with them: + # without it a reload or a second tab renders a live send as a failed one, and offers a + # retry that is certain to be refused. + "pending_files": not_uploaded(session), + "images_pending": images_pending(session), + "sending": sending(session), + "screenshots": screenshots, + "draft": session.draft, + } + + +def view(db: Session, session: DebugSession) -> dict: + """The session as the API serves it — one shape wherever it is served.""" + return serialize(session, screenshot_count(db, session)) or {} + + +def screenshot_count(db: Session, session: DebugSession) -> int: + return ( + db.scalar( + select(func.count()) + .select_from(DebugScreenshot) + .where(DebugScreenshot.session_id == session.id) + ) + or 0 + ) + + +# --- screenshots --------------------------------------------------------------------------- +# By content, not by the declared type: what is stored is served back to a browser as an image. +_SIGNATURES = ( + (b"\x89PNG\r\n\x1a\n", "image/png"), + (b"\xff\xd8\xff", "image/jpeg"), +) + + +def sniff(data: bytes) -> str | None: + """The image type `data` really is — one of IMAGE_TYPES — or None.""" + for magic, mime in _SIGNATURES: + if data.startswith(magic): + return mime + if len(data) >= 12 and data[:4] == b"RIFF" and data[8:12] == b"WEBP": + return "image/webp" + return None + + +def lock_user(db: Session, user_id: int) -> None: + """Hold this user's own lock for the rest of the transaction. A session's row lock bounds what + THAT session may keep; the byte cap below is the user's across all of them, and a lock on one + session cannot serialize a check that reads them all — two uploads to two sessions both read the + total before either commits, and both pass.""" + db.execute(select(func.pg_advisory_xact_lock(user_id))) + + +def stored_screenshot_bytes(db: Session, user_id: int) -> int: + return ( + db.scalar( + select(func.coalesce(func.sum(DebugScreenshot.size), 0)) + .join(DebugSession, DebugSession.id == DebugScreenshot.session_id) + .where(DebugSession.user_id == user_id) + ) + or 0 + ) + + +class ScreenshotRefused(Exception): + """A screenshot that cannot be kept; `code` is the refusal's machine word.""" + + def __init__(self, code: str) -> None: + super().__init__(code) + self.code = code + + +def add_screenshot(db: Session, session: DebugSession, data: bytes) -> DebugScreenshot: + """Keep one screenshot. Locks the user and the session, and flushes; the caller commits. + Refused while a send is under way or once the issue was sent (it can no longer carry it), past + the per-session count or the user's storage, or when it is not an image we can show.""" + if not data: + raise ScreenshotRefused("empty") + mime = sniff(data) + if mime is None: + raise ScreenshotRefused("not_an_image") + # Under both locks: two uploads at once cannot both pass the count (the session's), nor both + # pass the user's byte cap from two different sessions (the user's). Always in this order. + lock_user(db, session.user_id) + lock(db, session) + if sending(session): + raise ScreenshotRefused("sending") + if session.issue_url is not None: + raise ScreenshotRefused("already_sent") + if screenshot_count(db, session) >= SCREENSHOTS_MAX: + raise ScreenshotRefused("too_many") + if stored_screenshot_bytes(db, session.user_id) + len(data) > SCREENSHOT_USER_MAX_BYTES: + raise ScreenshotRefused("storage_full") + shot = DebugScreenshot( + session_id=session.id, + created_at=datetime.now(timezone.utc), + mime=mime, + size=len(data), + data=data, + ) + db.add(shot) + db.flush() + return shot + + +def remove_screenshot(db: Session, session: DebugSession, shot: DebugScreenshot) -> None: + """Delete one screenshot, under the lock. Refused while a send is under way or unfinished: a + delivery names the screenshots by their order, and removing one would renumber what it still + has to send. Once the issue has everything, this only drops OUR copy — the issue keeps its + own. The caller commits.""" + lock(db, session) + if sending(session): + raise ScreenshotRefused("sending") + if unfinished(session): + raise ScreenshotRefused("already_sent") + db.delete(shot) + db.flush() + + +def screenshots(db: Session, session: DebugSession) -> list[DebugScreenshot]: + """The session's screenshots, oldest first, WITHOUT their bytes loaded.""" + return list( + db.scalars( + select(DebugScreenshot) + .where(DebugScreenshot.session_id == session.id) + .options(defer(DebugScreenshot.data)) + .order_by(DebugScreenshot.id) + ) + ) + + +# --- the evidence -------------------------------------------------------------------------- +# The browser's own log upload (`POST` here, every few seconds while recording) is how the evidence +# arrives, not part of it: its server lines would fill the bundle with the recording's plumbing. The +# browser leaves its copies out for the same reason (frontend lib/diagnostics `isOwnRequest`). +INGEST_PATH = "/api/diagnostics/events" + + +def _evidence(session: DebugSession): + upload_line = and_( + LogEvent.event == "http.request", LogEvent.attrs["path"].astext == INGEST_PATH + ) + # `IS TRUE`, not the bare condition: for a row with no event or no attrs it is NULL, and + # `NOT NULL` would drop exactly the rows that are evidence. + return (LogEvent.debug_session_id == session.id, not_(upload_line.is_(True))) + + +def bundle( + db: Session, session: DebugSession, *, drop_excluded: bool = False +) -> tuple[list[LogEvent], int]: + """The session's log rows, browser and server interleaved in time, capped at BUNDLE_MAX — and + how many rows it has in all, so a cut bundle can say so. `drop_excluded` leaves out the rows + the user took out in the composer: what an export or an issue carries.""" + where = list(_evidence(session)) + excluded = (session.draft or {}).get("excluded") or [] if drop_excluded else [] + if excluded: + where.append(LogEvent.id.not_in(excluded)) + rows = list( + db.scalars( + select(LogEvent).where(*where).order_by(LogEvent.ts, LogEvent.id).limit(BUNDLE_MAX) + ) + ) + total = len(rows) + if total == BUNDLE_MAX: + total = db.scalar(select(func.count()).select_from(LogEvent).where(*where)) or total + return rows, total + + +# --- housekeeping (the hourly log job) ----------------------------------------------------- +def sweep(db: Session) -> int: + """Stage closing every open session past its cap; returns how many.""" + now = datetime.now(timezone.utc) + result = db.execute( + update(DebugSession) + .where(DebugSession.ended_at.is_(None), DebugSession.until <= now) + .values(ended_at=DebugSession.until, ended_reason=EndReason.EXPIRED.value) + .execution_options(synchronize_session=False) + ) + return result.rowcount or 0 + + +def gc(db: Session, retention_days: int) -> int: + """Stage deleting sessions (and by cascade their screenshots) started before the log retention + window — the rows they would bundle are gone by then too. Returns how many.""" + cutoff = datetime.now(timezone.utc) - timedelta(days=max(1, retention_days)) + result = db.execute(delete(DebugSession).where(DebugSession.started_at < cutoff)) + return result.rowcount or 0 diff --git a/backend/app/diagnostics.py b/backend/app/diagnostics.py index 89a78e9e..38e5adb4 100644 --- a/backend/app/diagnostics.py +++ b/backend/app/diagnostics.py @@ -27,6 +27,9 @@ DiagnosticsLevel = Literal["INFO", "DEBUG", "TRACE"] LEVELS: tuple[str, ...] = get_args(DiagnosticsLevel) BASE: DiagnosticsLevel = "INFO" ELEVATION_HOURS = 24 +# How long a debug session records at most (E16, app/debugsession.py). Here, beside the other +# consent window, because the start dialog's consent text states it and reads it from `state`. +SESSION_MINUTES = 60 def effective_level(user: User, now: datetime | None = None) -> DiagnosticsLevel: @@ -47,6 +50,7 @@ def state(db: Session, user: User) -> dict: "level": level, "until": user.diagnostics_until.isoformat() if level != BASE else None, "retention_days": sysconfig.get_int(db, "log_retention_days"), + "session_minutes": SESSION_MINUTES, } diff --git a/backend/app/issues/__init__.py b/backend/app/issues/__init__.py new file mode 100644 index 00000000..dd2ed760 --- /dev/null +++ b/backend/app/issues/__init__.py @@ -0,0 +1,3 @@ +"""Bug reports built from debug sessions (E16): the files an issue carries, and where they go — +downloaded as a zip, or (S4) sent to a Gitea issue tracker. The session itself — what is recorded +and tagged — is the core module `app/debugsession.py`.""" diff --git a/backend/app/issues/bundle.py b/backend/app/issues/bundle.py new file mode 100644 index 00000000..45c9def0 --- /dev/null +++ b/backend/app/issues/bundle.py @@ -0,0 +1,79 @@ +"""What an issue from a debug session carries, as files — one definition for the zip export and the +Gitea upload, so the two cannot drift apart. + + * `issue.md` — the title and the body the user wrote and reviewed in the composer (rendered there, + in their language; the server does not rewrite it); + * `client.log` / `server.log` — the session's evidence (`debugsession.bundle`) minus the rows the + user took out, one JSON object per line, browser rows and server rows apart. `.log`, not + `.jsonl`: Gitea refuses that extension (measured, plans/e16 S0); + * the screenshots, in the order they were taken. + +Every row is already redacted twice (at capture, and again when stored), and nothing here adds a +field the review list did not show. +""" + +import io +import json +import zipfile +from dataclasses import dataclass + +from sqlalchemy import select +from sqlalchemy.orm import Session + +from app import debugsession, logsink +from app.models import DebugScreenshot, DebugSession + + +@dataclass(frozen=True) +class IssueFile: + name: str + data: bytes + mime: str + + +def title_of(session: DebugSession) -> str: + # Not a sentence of ours: the composer always saves a title in the user's language, and a + # session exported before it ever saved is named by its date alone, in no language at all. + title = ((session.draft or {}).get("title") or "").strip() + return title or f"{session.started_at:%Y-%m-%d %H:%M} · {session.id}" + + +def body_of(session: DebugSession) -> str: + return ((session.draft or {}).get("body") or "").strip() + + +def _lines(rows) -> bytes: + return "".join( + json.dumps(logsink.serialize(r), ensure_ascii=False, default=str) + "\n" for r in rows + ).encode() + + +def files(db: Session, session: DebugSession) -> list[IssueFile]: + """The session's issue as files: the text, the two logs, the screenshots.""" + rows, _ = debugsession.bundle(db, session, drop_excluded=True) + text = f"# {title_of(session)}\n\n{body_of(session)}\n" + out = [ + IssueFile("issue.md", text.encode(), "text/markdown"), + IssueFile("client.log", _lines(r for r in rows if r.source == "web"), "text/plain"), + IssueFile("server.log", _lines(r for r in rows if r.source != "web"), "text/plain"), + ] + shots = db.scalars( + select(DebugScreenshot) + .where(DebugScreenshot.session_id == session.id) + .order_by(DebugScreenshot.id) + ) + for n, shot in enumerate(shots, start=1): + ext = debugsession.IMAGE_TYPES[shot.mime] + name = f"{debugsession.SCREENSHOT_PREFIX}{n}.{ext}" + out.append(IssueFile(name, shot.data, shot.mime)) + return out + + +def zipped(items: list[IssueFile]) -> bytes: + buf = io.BytesIO() + with zipfile.ZipFile(buf, "w", zipfile.ZIP_DEFLATED) as z: + for item in items: + # The images are compressed already: deflating them again costs time and wins nothing. + method = zipfile.ZIP_STORED if item.mime.startswith("image/") else zipfile.ZIP_DEFLATED + z.writestr(item.name, item.data, compress_type=method) + return buf.getvalue() diff --git a/backend/app/issues/gitea.py b/backend/app/issues/gitea.py new file mode 100644 index 00000000..aeb24492 --- /dev/null +++ b/backend/app/issues/gitea.py @@ -0,0 +1,275 @@ +"""The Gitea issue tracker a debug session's issue goes to (E16 S4) — measured against Gitea 1.27.1 +before a line of this was written (plans/e16-debug-issue.md, S0). + +Configured by an admin (sysconfig `issues_gitea_url` / `_repo` / `_token`, the token encrypted at +rest). The repository must be PRIVATE: an issue carries its reporter's log — page titles, filter +values, at Teljes what they typed into search — and a public repository would publish it. That is +checked on every send, not only in the admin's "test connection", because a repository can be made +public after the fact. + +What an issue is made of comes from `bundle.files` (the same files the zip export carries). Sending +is three kinds of call, measured: + * `POST /repos/{repo}/issues` — the title and the body the user wrote; + * `POST /repos/{repo}/issues/{n}/assets?name=…` — ONE file per request (field `attachment`); + * `PATCH /repos/{repo}/issues/{n}` — the body again, with the screenshots shown inline once their + links exist. +A private repository's attachment answers 404 to a browser not signed in to Gitea, which is why the +composer's own preview shows our copies, never these links. + +Delivery keeps its progress in the session's draft (`delivery`: the issue number, the files still to +upload, the links of those uploaded, whether the body shows the screenshots yet), so a failure +half-way keeps the issue that exists and a retry does only what is missing — never a second issue. +Every step is checkpointed (the caller's `db.commit`), so what did happen is kept whatever fails +next — and the first checkpoint comes before the first call, with the tracker's settings read ABOVE +it, so neither a row lock nor a read snapshot nor a pooled connection is held across the calls. The +caller claims the session for the send first (`debugsession.claim_send`) and passes the claim's +token in, which is what keeps a second send, an autosave or a screenshot out of the way; the claim +is renewed by every progress report, and a report whose claim is gone raises rather than writing +over the send that took it. `debugsession.not_uploaded` / `images_pending` read that progress. +""" + +from collections.abc import Callable, Iterator +from contextlib import contextmanager +from typing import Any, Literal + +import httpx +from sqlalchemy.orm import Session + +from app import debugsession, logs, sysconfig +from app.issues import bundle +from app.models import DebugSession + +log = logs.get_logger(__name__) + +TIMEOUT_SECONDS = 20.0 + +Reason = Literal[ + "not_configured", # url, repository or token missing + "unreachable", # no answer, or a 5xx + "bad_token", # 401/403: the token is wrong or lacks write:issue / read:repository + "repo_not_found", # 404 on the repository + "public_repo", # the repository is public — an issue would publish the reporter's log + "issues_disabled", # the repository has its issue tracker switched off + "rejected", # any other 4xx (a file type the instance does not allow, …), or an answer that is + # not the API's (a redirect — an http:// address behind https —, a page that is not JSON) +] + + +class GiteaError(Exception): + def __init__(self, reason: Reason) -> None: + super().__init__(reason) + self.reason: Reason = reason + + +def _settings(db: Session) -> tuple[str, str, str]: + return ( + sysconfig.get_str(db, "issues_gitea_url").strip().rstrip("/"), + sysconfig.get_str(db, "issues_gitea_repo").strip().strip("/"), + sysconfig.get_str(db, "issues_gitea_token").strip(), + ) + + +def target(db: Session) -> dict | None: + """Where a report goes, for the composer to say so — the repository — or None when no tracker is + configured (the report can then only be downloaded).""" + url, repo, token = _settings(db) + return {"repo": repo} if url and repo and token else None + + +@contextmanager +def _client(settings: tuple[str, str, str]) -> Iterator[tuple[httpx.Client, str]]: + # Takes the settings already read, not the session: reading them HERE opened a transaction one + # line after `deliver` had ended one, and held it across the calls below (deep-review round 4). + url, repo, token = settings + if not (url and repo and token): + raise GiteaError("not_configured") + with httpx.Client( + base_url=f"{url}/api/v1", + headers={"Authorization": f"token {token}", "Accept": "application/json"}, + timeout=TIMEOUT_SECONDS, + ) as client: + yield client, repo + + +def _call(client: httpx.Client, method: str, path: str, **kwargs) -> httpx.Response: + try: + r = client.request(method, path, **kwargs) + except httpx.HTTPError as exc: + log.warning( + "the issue tracker did not answer", + extra=logs.event("issues.gitea.unreachable", path=path, error=type(exc).__name__), + ) + raise GiteaError("unreachable") from None + if r.status_code < 300: + return r + # The status only: Gitea's message can quote back what was sent — the user's own title. + log.warning( + "the issue tracker refused a call", + extra=logs.event("issues.gitea.refused", path=path, status=r.status_code), + ) + if r.status_code in (401, 403): + raise GiteaError("bad_token") + if r.status_code == 404: + raise GiteaError("repo_not_found") + if r.status_code >= 500: + raise GiteaError("unreachable") + raise GiteaError("rejected") + + +def _json(r: httpx.Response, *keys: str) -> dict[str, Any]: + """The answer as the API's JSON, holding `keys` — anything else is refused, not a crash, so a + step after the issue was created cannot take down the request that holds its record. + + The CREATE call is the one place this cannot keep that record: its answer IS the record. An + answer it cannot read there leaves the session unsent, and a retry opens another issue — the + price of not being able to tell a refused create from an unreadable one.""" + try: + data = r.json() + # silent-ok: not JSON is one of the answers refused (and logged) just below. + except ValueError: + data = None + if not isinstance(data, dict) or any(k not in data for k in keys): + log.warning( + "the issue tracker answered something that is not its API", + extra=logs.event("issues.gitea.unexpected", status=r.status_code), + ) + raise GiteaError("rejected") + return data + + +def _private_repo(client: httpx.Client, repo: str) -> dict: + data = _json(_call(client, "GET", f"/repos/{repo}")) + if not data.get("private"): + raise GiteaError("public_repo") + if not data.get("has_issues"): + raise GiteaError("issues_disabled") + return data + + +def check(db: Session) -> dict: + """The admin's "test connection": the repository answers, is private and takes issues.""" + with _client(_settings(db)) as (client, repo): + data = _private_repo(client, repo) + return {"repo": data.get("full_name") or repo, "url": data.get("html_url")} + + +def preview(db: Session, text: str) -> str: + """The body as Gitea itself will render it (its markdown flavour, its sanitiser).""" + with _client(_settings(db)) as (client, repo): + r = _call(client, "POST", "/markdown", json={"Text": text, "Mode": "gfm", "Context": repo}) + return r.text + + +def deliver( + db: Session, + session: DebugSession, + *, + token: str, + checkpoint: Callable[[], None], + before_create: Callable[[], None] | None = None, + on_created: Callable[[], None] | None = None, +) -> str: + """Send the session's issue, or finish sending it; returns its URL. + + `token` is the caller's claim on this session (`debugsession.claim_send`). Every progress report + renews it and checks the row still holds it, so a send that outlived its lease stops here rather + than writing over the one that took over (`debugsession.SendClaimLost`). + + `checkpoint` persists what has happened so far and is called after every step (the caller's + commit — this module does not decide when a transaction ends). `before_create` runs right before + the tracker is asked to open a NEW issue, after the checks that can refuse it without asking, + and may raise to stop it; `on_created` runs right after one was opened, in time to be committed + by the SAME checkpoint that first writes `issue_url` — anything the caller must not be able to + lose separately from the link belongs there. + """ + state = debugsession.delivery(session) + files = bundle.files(db, session) + attachments = [f for f in files if f.name != "issue.md"] + settings = _settings(db) + # Reading the bundle and the tracker's settings opened a transaction; end it before the first + # call, so nothing holds a snapshot (and an idle connection) across minutes of tracker I/O. + # The settings are read HERE and handed to `_client`, not read inside it: reading them there + # was a SELECT one line after this commit, which reopened the transaction and held it — idle, + # with its snapshot pinned — across the repository check and the create (deep-review round 4 + # measured it in pg_stat_activity). A comment saying otherwise sat right here. + checkpoint() + with _client(settings) as (client, repo): + _private_repo(client, repo) + if "number" not in state: + if before_create is not None: + before_create() + created = _json( + _call( + client, + "POST", + f"/repos/{repo}/issues", + json={"title": bundle.title_of(session), "body": bundle.body_of(session)}, + ), + "number", + "html_url", + ) + # Built ON the state read at the start so nothing already in it is dropped. The claim + # is NOT among those things, whatever this comment used to say: `set_delivery` strips + # any `sending` passed to it and stamps the row's own from `token` (round 4 — removing + # the spread left the whole suite green, because the claim never travelled here). + state = { + **state, + "number": created["number"], + "pending": [f.name for f in attachments], + "links": {}, + } + session.issue_url = created["html_url"] + try: + debugsession.set_delivery(db, session, state, token) + except debugsession.SendClaimLost: + # The one step where losing the claim costs something irreversible: the issue is + # already open on the tracker and this is what would have recorded its link. We + # still must not write — another send owns the row and is opening its own issue — + # so say which issue was left behind, because nothing else will. + # noqa TRY400: the traceback is one SendClaimLost carrying the session id and + # nothing else; the issue number below is the whole news. + log.error( # noqa: TRY400 + "an issue was created by a send that had already lost its claim", + extra=logs.event( + "issues.gitea.orphaned", + number=created["number"], + session_id=session.id, + ), + ) + raise + if on_created is not None: + on_created() + checkpoint() + log.info( + "issue created", + extra=logs.event("issues.gitea.created", number=created["number"]), + ) + number = state["number"] + for item in attachments: + if item.name not in state["pending"]: + continue + asset = _json( + _call( + client, + "POST", + f"/repos/{repo}/issues/{number}/assets", + params={"name": item.name}, + files={"attachment": (item.name, item.data, item.mime)}, + ), + "browser_download_url", + ) + state = { + **state, + "pending": [n for n in state["pending"] if n != item.name], + "links": {**state["links"], item.name: asset["browser_download_url"]}, + } + debugsession.set_delivery(db, session, state, token) + checkpoint() + shots = [n for n in state["links"] if n.startswith(debugsession.SCREENSHOT_PREFIX)] + if shots and not state.get("images_shown"): + images = "\n".join(f"![{n}]({state['links'][n]})" for n in sorted(shots)) + body = f"{bundle.body_of(session)}\n\n---\n\n{images}" + _call(client, "PATCH", f"/repos/{repo}/issues/{number}", json={"body": body}) + debugsession.set_delivery(db, session, {**state, "images_shown": True}, token) + checkpoint() + return session.issue_url or "" diff --git a/backend/app/logs.py b/backend/app/logs.py index 565030c8..ce42b3dd 100644 --- a/backend/app/logs.py +++ b/backend/app/logs.py @@ -100,12 +100,14 @@ class _RequestScope: request; every copied context shares the same object, so what the dependency writes is seen by the handler and by the request line itself.""" - __slots__ = ("user_id", "level") + __slots__ = ("user_id", "level", "debug_session_id") def __init__(self) -> None: self.user_id: int | None = None # The user's consented diagnostics level as a logging number; None at the base level. self.level: int | None = None + # The user's own open debug session this request named (E16), else None. + self.debug_session_id: str | None = None _scope: contextvars.ContextVar[_RequestScope | None] = contextvars.ContextVar( @@ -113,11 +115,23 @@ _scope: contextvars.ContextVar[_RequestScope | None] = contextvars.ContextVar( ) -def set_user(user_id: int | None, level: str = "INFO", until: datetime | None = None) -> None: +def set_user( + user_id: int | None, + level: str = "INFO", + until: datetime | None = None, + debug_session: str | None = None, +) -> None: """Attribute the rest of this request's log lines to `user_id`, and log them at the user's consented diagnostics `level` until `until` (E22 S5; "INFO" = no elevation). Called from the auth dependency — the one place the session is actually resolved into an account — rather than - from the request middleware, which runs OUTSIDE the session middleware.""" + from the request middleware, which runs OUTSIDE the session middleware. + + `debug_session` tags every line with the user's open debug session (E16). The caller has + already checked it is theirs and open; a session's level arrives here as `level`/`until`. + + The root logger's floor is tracked per elevation: a request without the session's header (an + ``, a `