fix(diagnostics): deep-review round 2 — a send that claims, not one that blocks

The send no longer holds the session's row lock while it talks to the tracker:
it claims the session, gives the lock back, and checkpoints each step. A Stop
is never held behind a send, while a draft, a screenshot or a second send are
refused at once instead of queueing. The claim ages out, so a request that
died mid-send does not strand the session.

What the composer says is what happened: an attachment that went is no longer
named as one that did not (the missing body edit is its own line), and the
issue's screenshot count comes from the server when the list cannot be read,
so a failed read no longer blocks saving the draft. The zip is fetched as a
request, so its pace is a message and not a saved error page. Screenshots of a
finished report can be removed again; only one still being sent is held.

A recording's log elevation can no longer outlive it. The step prompt keeps
the keyboard (the page's keys stay quiet) and traps Tab itself. An image
pasted into a dialog opened over the composer stays that dialog's.
This commit is contained in:
2026-09-20 00:51:12 +02:00
parent 134ec9a68e
commit 3f983e6d76
17 changed files with 347 additions and 126 deletions
+71 -16
View File
@@ -132,11 +132,17 @@ def from_header(db: Session, user: User, value: str | None) -> DebugSession | No
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."""
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 or _DETAIL[session.level] <= _DETAIL[own]:
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
@@ -163,14 +169,56 @@ def delivery(session: DebugSession) -> dict:
return dict((session.draft or {}).get("delivery") or {})
def unfinished(session: DebugSession) -> list[str]:
"""What a send that stopped half-way still owes its issue: the files not yet uploaded, and the
screenshots uploaded but not yet shown in its body (the edit that shows them failed)."""
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)
missing = list(state.get("pending") or [])
if not state.get("images_shown"):
missing += [n for n in state.get("links") or {} if n.startswith("screenshot-")]
return missing
shown = state.get("images_shown")
return not shown and any(n.startswith("screenshot-") 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 older than this was left by a request
# that died mid-send (the process restarted), and the next send takes it over.
SEND_CLAIM_SECONDS = 600
def sending(session: DebugSession) -> bool:
"""Whether a send is under way right now (a live claim)."""
since = delivery(session).get("sending")
if not since:
return False
started = datetime.fromisoformat(since)
return (datetime.now(timezone.utc) - started).total_seconds() < SEND_CLAIM_SECONDS
def claim_send(session: DebugSession) -> None:
"""Mark the session as being sent. The caller holds the lock and commits, which is what makes
the claim visible to everyone else."""
set_delivery(session, {**delivery(session), "sending": datetime.now(timezone.utc).isoformat()})
def release_send(session: DebugSession) -> None:
state = {k: v for k, v in delivery(session).items() if k != "sending"}
set_delivery(session, state)
def set_delivery(session: DebugSession, state: dict) -> None:
"""Write a delivery's progress (app/issues/gitea.py keeps it; this module reads it)."""
# 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:
@@ -184,8 +232,10 @@ def serialize(session: DebugSession | None, screenshots: int = 0) -> dict | None
"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: what it still owes.
"pending_files": unfinished(session),
# 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.
"pending_files": not_uploaded(session),
"images_pending": images_pending(session),
"screenshots": screenshots,
"draft": session.draft,
}
@@ -253,9 +303,10 @@ def add_screenshot(db: Session, session: DebugSession, data: bytes) -> DebugScre
mime = sniff(data)
if mime is None:
raise ScreenshotRefused("not_an_image")
# Under the lock: a send in flight is waited for (and then refuses this), and two uploads at
# once cannot both pass the count.
# Under the lock: two uploads at once cannot both pass the count.
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:
@@ -275,10 +326,14 @@ def add_screenshot(db: Session, session: DebugSession, data: bytes) -> DebugScre
def remove_screenshot(db: Session, session: DebugSession, shot: DebugScreenshot) -> None:
"""Delete one screenshot, under the lock. Refused once the issue was sent: it carries this one
already, and a delivery names the screenshots by their order. The caller commits."""
"""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 session.issue_url is not None:
if sending(session):
raise ScreenshotRefused("sending")
if unfinished(session):
raise ScreenshotRefused("already_sent")
db.delete(shot)
db.flush()
+27 -19
View File
@@ -19,8 +19,10 @@ 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 flushes; the caller holds the session's lock throughout (`debugsession.lock`) and commits,
also when a step fails, so what did happen is kept. `debugsession.unfinished` reads that progress.
Every step is checkpointed (the caller's `db.commit`), so what did happen is kept whatever fails
next — and no transaction is held open across these calls. The caller claims the session for the
send first (`debugsession.claim_send`), which is what keeps a second send, an autosave or a
screenshot out of the way. `debugsession.not_uploaded` / `images_pending` read that progress.
"""
from collections.abc import Callable, Iterator
@@ -110,8 +112,12 @@ def _call(client: httpx.Client, method: str, path: str, **kwargs) -> httpx.Respo
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: a
crash after the issue was created would lose the record that it was."""
"""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.
@@ -149,17 +155,19 @@ def preview(db: Session, text: str) -> str:
return r.text
def _save(session: DebugSession, state: dict) -> None:
# A new dict, so the JSONB column sees the change.
session.draft = {**(session.draft or {}), "delivery": state}
def deliver(
db: Session, session: DebugSession, *, before_create: Callable[[], None] | None = None
db: Session,
session: DebugSession,
*,
checkpoint: Callable[[], None],
before_create: Callable[[], None] | None = None,
) -> str:
"""Send the session's issue, or finish sending it; returns its URL. Flushes after every step.
`before_create` runs right before a NEW issue is opened — after every check that could refuse
it — and may raise to stop it (the caller's pace on new issues)."""
(
"""Send the session's issue, or finish sending it; returns its URL. `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.""",
)
state = debugsession.delivery(session)
files = bundle.files(db, session)
attachments = [f for f in files if f.name != "issue.md"]
@@ -184,8 +192,8 @@ def deliver(
"links": {},
}
session.issue_url = created["html_url"]
_save(session, state)
db.flush()
debugsession.set_delivery(session, state)
checkpoint()
log.info(
"issue created",
extra=logs.event("issues.gitea.created", number=created["number"]),
@@ -209,13 +217,13 @@ def deliver(
"pending": [n for n in state["pending"] if n != item.name],
"links": {**state["links"], item.name: asset["browser_download_url"]},
}
_save(session, state)
db.flush()
debugsession.set_delivery(session, state)
checkpoint()
shots = [n for n in state["links"] if n.startswith("screenshot-")]
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})
_save(session, {**state, "images_shown": True})
db.flush()
debugsession.set_delivery(session, {**state, "images_shown": True})
checkpoint()
return session.issue_url or ""
+37 -19
View File
@@ -147,9 +147,11 @@ def save_draft(
session = owned_or_404(db, DebugSession, sid, user, what="debug_session")
if len(json.dumps(body.form, ensure_ascii=False).encode()) > FORM_MAX_BYTES:
raise HTTPException(status_code=413, detail={"code": "too_large"})
# Under the lock: a save that arrives while the issue is being sent waits for the send, and then
# sees it — the draft of a sent issue cannot change after it.
# Under the lock, and refused while a send is under way: the issue is being built from the draft
# as it was saved, and this would change it under the send.
debugsession.lock(db, session)
if debugsession.sending(session):
raise refused(409, "issue_sending")
if session.issue_url is not None:
# Sent: the issue is on the tracker now, and a draft edited after it would say otherwise.
raise refused(409, "issue_already_sent")
@@ -181,9 +183,10 @@ def export_session(
# --- the issue tracker (S4) -----------------------------------------------------------------
# Issues a user may OPEN per hour — finishing a half-sent one, or an attempt refused before the issue
# was opened, is not counted. The composer sends one at a time; this is room for a bad afternoon, not
# a pace anything legitimate keeps up.
# Issues a user may open per hour — counted once the tracker is ASKED to open one (an answer that
# goes missing may still have created it, so an attempt cannot be given back); finishing a half-sent
# one, or an attempt refused before the tracker was asked, is not counted. The composer sends one at
# a time; this is room for a bad afternoon, not a pace anything legitimate keeps up.
_new_issues = RateLimiter(max_events=5, window_seconds=3600)
@@ -198,10 +201,12 @@ def send_issue(
"""Send the session's issue to the tracker — from the SAVED draft, as the export is built — or
finish a send that stopped half-way (the issue exists; only what is missing is sent)."""
session = owned_or_404(db, DebugSession, sid, user, what="debug_session")
# Held to the end: a second send (another tab, a retry after a timeout) waits for this one and
# then finds the issue it opened, instead of opening another; an autosave or a screenshot waits
# too, and then finds the issue sent.
# The session is CLAIMED for the send rather than locked through it: the tracker is slow (a
# dozen calls, 20 s each), and a row lock held across them would queue this user's Stop, their
# autosave and their screenshots behind it. They see the claim instead and are refused at once.
debugsession.lock(db, session)
if debugsession.sending(session):
raise refused(409, "issue_sending")
new = session.issue_url is None
if not new and not debugsession.unfinished(session):
return {"ok": True, "session": _view(db, session)}
@@ -211,30 +216,41 @@ def send_issue(
raise refused(422, "issue_title_required")
if _new_issues.exhausted(key):
raise _issues_rate_limited()
debugsession.claim_send(session)
db.commit() # the claim is what everything else sees; the lock ends here
def count_new_issue() -> None:
if not _new_issues.allow(key):
raise _issues_rate_limited()
try:
gitea.deliver(db, session, before_create=count_new_issue)
gitea.deliver(db, session, checkpoint=db.commit, before_create=count_new_issue)
except gitea.GiteaError as exc:
# Keep what did happen: an issue created before an upload failed stays linked, and the
# retry does only what is still missing.
_record_created(db, user, session, new)
db.commit()
raise issue_refused(exc) from None
except HTTPException:
raise # the pace, refused before anything was opened
except Exception:
# Anything else after the issue was opened must not lose the record that it was: a retry
# would open a second one.
raise # the pace, refused before the tracker was asked
finally:
_end_send(db, user, session, new)
return {"ok": True, "session": _view(db, session)}
def _end_send(db: Session, user: User, session: DebugSession, new: bool) -> None:
"""Give the claim back, and record an issue this send opened — whatever else happened. A
failure here must not replace the failure that brought us: a dead transaction (the database
went away mid-send) is rolled back, and the claim then simply ages out."""
try:
debugsession.lock(db, session)
debugsession.release_send(session)
_record_created(db, user, session, new)
db.commit()
raise
_record_created(db, user, session, new)
db.commit()
return {"ok": True, "session": _view(db, session)}
except Exception: # noqa: BLE001 — whatever went wrong here, the send's own failure is the news
db.rollback()
log.warning(
"a send could not give its claim back",
extra=logs.event("issues.claim.stuck", session_id=session.id),
)
def _record_created(db: Session, user: User, session: DebugSession, new: bool) -> None:
@@ -315,6 +331,8 @@ def _screenshot_refused(code: str) -> HTTPException:
return refused(409, "screenshot_already_sent")
if code == "too_many":
return refused(422, "screenshot_too_many", limit=debugsession.SCREENSHOTS_MAX)
if code == "sending":
return refused(409, "issue_sending")
if code == "storage_full":
mb = debugsession.SCREENSHOT_USER_MAX_BYTES // (1024 * 1024)
return refused(422, "screenshot_storage_full", limit=mb)