"""E16 S1 — debug sessions: Start → reproduce → Stop, the tag on every line, the screenshots.
Four parts:
* the session's life: one open per user, a second Start joins it, a Stop ends it, the cap ends it
on its own, the demo account cannot record, nobody reaches another user's session (DB lane);
* the tag: a request naming the caller's own open session is logged at its level with every line
tagged, while a header naming anything else is ignored (a real sign-in through `_session_user`);
* the browser's batches: a session counts as consent to its level, and only its own events keep
its tag (DB lane);
* screenshots: judged by their bytes, capped in size and count, served back only to their owner.
"""
import contextvars
import json
import logging
from datetime import datetime, timedelta, timezone
import httpx
import pytest
from fastapi import BackgroundTasks
from sqlalchemy import func, select
from app import debugsession, logs
from app.models import AuditLog, DebugScreenshot, DebugSession, LogEvent, User
from app.routes import diagnostics as diagnostics_routes
_PW = "correct horse battery"
_PNG = b"\x89PNG\r\n\x1a\n" + b"\x00" * 32
_JPEG = b"\xff\xd8\xff\xe0" + b"\x00" * 32
_WEBP = b"RIFF\x00\x00\x00\x00WEBPVP8 " + b"\x00" * 16
def _signed_in(client, make_user, email="rec@example.com", **kw) -> User:
"""A real sign-in, so the auth dependency itself reads `X-Debug-Session` (`as_user` bypasses
it)."""
user = make_user(email=email, password=_PW, **kw)
r = client.post("/auth/password-login", json={"email": email, "password": _PW})
assert r.status_code == 200, r.text
return user
def _start(client, level="DEBUG") -> dict:
r = client.post("/api/debug-sessions", json={"level": level})
assert r.status_code == 200, r.text
return r.json()["session"]
# --- the session's life ---------------------------------------------------------------------
def test_start_opens_a_capped_session_that_me_reports(db, client, make_user):
_signed_in(client, make_user)
session = _start(client, "TRACE")
assert session["level"] == "TRACE" and session["ended_at"] is None
started = datetime.fromisoformat(session["started_at"])
until = datetime.fromisoformat(session["until"])
assert until - started == timedelta(minutes=debugsession.MAX_MINUTES)
assert client.get("/api/me").json()["debug_session"]["id"] == session["id"]
def test_a_second_start_joins_the_running_session(db, make_user, as_user):
client = as_user(make_user())
first = _start(client, "DEBUG")
assert _start(client, "TRACE")["id"] == first["id"]
assert db.scalar(select(DebugSession).where(DebugSession.id == first["id"])).level == "DEBUG"
def test_only_the_two_raised_levels_can_be_recorded(db, make_user, as_user):
client = as_user(make_user())
for bogus in ("INFO", "WARNING", "trace"):
assert client.post("/api/debug-sessions", json={"level": bogus}).status_code == 422
def test_the_demo_account_cannot_record(db, make_user, as_user):
r = as_user(make_user(is_demo=True)).post("/api/debug-sessions", json={"level": "DEBUG"})
assert r.status_code == 403 and r.json()["detail"]["code"] == "demo"
def test_stop_ends_it_and_me_stops_reporting_it(db, client, make_user):
_signed_in(client, make_user)
sid = _start(client)["id"]
r = client.post(f"/api/debug-sessions/{sid}/stop")
assert r.status_code == 200 and r.json()["session"]["ended_reason"] == "stopped"
assert client.get("/api/me").json()["debug_session"] is None
# A second Stop changes nothing.
again = client.post(f"/api/debug-sessions/{sid}/stop").json()["session"]
assert again["ended_at"] == r.json()["session"]["ended_at"]
def _expire(db, sid: str) -> None:
session = db.get(DebugSession, sid)
session.started_at -= timedelta(hours=2)
session.until = datetime.now(timezone.utc) - timedelta(minutes=1)
db.commit()
def test_a_session_past_its_cap_is_over_before_anything_closes_it(db, client, make_user):
_signed_in(client, make_user)
sid = _start(client)["id"]
_expire(db, sid)
assert client.get("/api/me").json()["debug_session"] is None
# A late Stop records that it ended on its own, at its cap.
stopped = client.post(f"/api/debug-sessions/{sid}/stop").json()["session"]
assert stopped["ended_reason"] == "expired"
assert stopped["ended_at"] == stopped["until"]
def test_a_start_after_an_expired_session_closes_it_and_opens_a_new_one(db, make_user, as_user):
client = as_user(make_user())
old = _start(client)["id"]
_expire(db, old)
new = _start(client)["id"]
assert new != old
db.expire_all()
assert db.get(DebugSession, old).ended_reason == "expired"
def test_nobody_reaches_another_users_session(db, make_user, as_user):
owner, stranger = as_user(make_user()), as_user(make_user())
sid = _start(owner)["id"]
shot = owner.post(
f"/api/debug-sessions/{sid}/screenshots",
content=_PNG,
headers={"content-type": "image/png"},
).json()["screenshot"]["id"]
for method, path in (
("get", f"/api/debug-sessions/{sid}"),
("post", f"/api/debug-sessions/{sid}/stop"),
("get", f"/api/debug-sessions/{sid}/events"),
("get", f"/api/debug-sessions/{sid}/screenshots"),
("get", f"/api/debug-sessions/{sid}/screenshots/{shot}"),
("delete", f"/api/debug-sessions/{sid}/screenshots/{shot}"),
("get", f"/api/debug-sessions/{sid}/export"),
):
r = getattr(stranger, method)(path)
assert r.status_code == 404, (method, path, r.status_code)
assert r.json()["detail"] == {"code": "not_found", "reason": "debug_session"}
r = stranger.put(f"/api/debug-sessions/{sid}/draft", json={"title": "x", "body": "y"})
assert r.status_code == 404
r = stranger.post(
f"/api/debug-sessions/{sid}/screenshots",
content=_PNG,
headers={"content-type": "image/png"},
)
assert r.status_code == 404
assert stranger.get("/api/debug-sessions").json()["items"] == []
db.expire_all()
assert db.get(DebugSession, sid).ended_at is None
def test_the_list_is_the_users_own_newest_first(db, make_user, as_user):
client = as_user(make_user())
first = _start(client)["id"]
client.post(f"/api/debug-sessions/{first}/stop")
second = _start(client)["id"]
assert [s["id"] for s in client.get("/api/debug-sessions").json()["items"]] == [second, first]
def test_the_hourly_job_closes_expired_sessions_and_drops_old_ones(db, make_user):
user = make_user()
now = datetime.now(timezone.utc)
lapsed = DebugSession(
id="b" * 16,
user_id=user.id,
level="DEBUG",
started_at=now - timedelta(hours=2),
until=now - timedelta(hours=1),
)
db.add(lapsed)
ancient = DebugSession(
id="c" * 16,
user_id=user.id,
level="DEBUG",
started_at=now - timedelta(days=30),
until=now - timedelta(days=30) + timedelta(hours=1),
ended_at=now - timedelta(days=30),
ended_reason="stopped",
)
db.add(ancient)
db.flush() # no ORM relationship orders the inserts: the session row first
db.add(
DebugScreenshot(session_id=ancient.id, created_at=now, mime="image/png", size=4, data=b"x")
)
db.commit()
assert debugsession.sweep(db) == 1
assert debugsession.gc(db, 7) == 1
db.commit()
db.expire_all()
assert db.get(DebugSession, lapsed.id).ended_reason == "expired"
assert db.get(DebugSession, lapsed.id).ended_at == lapsed.until
assert db.get(DebugSession, ancient.id) is None
assert db.scalars(select(DebugScreenshot)).all() == []
def test_an_erased_account_takes_its_sessions_with_it(db, make_user, as_user):
from app.auth import purge_user
user = make_user()
client = as_user(user)
sid = _start(client)["id"]
client.post(
f"/api/debug-sessions/{sid}/screenshots",
content=_PNG,
headers={"content-type": "image/png"},
)
purge_user(db, user, BackgroundTasks())
assert db.get(DebugSession, sid) is None
assert db.scalars(select(DebugScreenshot)).all() == []
# --- the tag --------------------------------------------------------------------------------
class _Capture(logging.Handler):
def __init__(self):
super().__init__(level=logging.NOTSET)
self.records: list[logging.LogRecord] = []
self.addFilter(logs.ContextFilter())
self.addFilter(logs.LevelGate())
def emit(self, record):
self.records.append(record)
@pytest.fixture
def gated():
"""The process at INFO with a gated handler on the root, as test_diagnostics' fixture."""
root = logging.getLogger()
saved = (logs._base_level, dict(logs._elevations), logs._root_applied, root.level)
handler = _Capture()
root.addHandler(handler)
logs._elevations.clear()
logs.set_level("INFO")
try:
yield handler
finally:
root.removeHandler(handler)
logs._base_level, logs._root_applied = saved[0], saved[2]
logs._elevations.clear()
logs._elevations.update(saved[1])
root.setLevel(saved[3])
def _request_lines(handler: _Capture) -> list[logging.LogRecord]:
return [r for r in handler.records if getattr(r, "event", None) == "http.request"]
def test_a_request_naming_the_own_open_session_is_tagged_and_raised(gated, db, client, make_user):
_signed_in(client, make_user)
sid = _start(client, "DEBUG")["id"]
gated.records.clear()
client.get("/api/debug-sessions", headers={"x-debug-session": sid})
(line,) = _request_lines(gated)
assert getattr(line, "debug_session_id", None) == sid
# Raised to the session's level: the line is kept for storage though the user's own is Alap.
assert getattr(line, "elevated", False) is True
def test_a_header_naming_anything_else_is_ignored_not_refused(gated, db, client, make_user):
other = make_user(email="other@example.com")
foreign = debugsession.start(db, other, "TRACE").id
db.commit()
_signed_in(client, make_user)
own = _start(client)["id"]
client.post(f"/api/debug-sessions/{own}/stop")
for value in (foreign, own, "not-a-session", "f" * 16, "A" * 16):
gated.records.clear()
# Not `/api/me`: a polled route logs at DEBUG, and an un-raised request would drop the very
# line this checks.
r = client.get("/api/debug-sessions", headers={"x-debug-session": value})
assert r.status_code == 200, value
(line,) = _request_lines(gated)
assert getattr(line, "debug_session_id", None) is None, value
assert getattr(line, "elevated", False) is False, value
def test_a_header_naming_the_own_session_past_its_cap_is_ignored(gated, db, client, make_user):
_signed_in(client, make_user)
sid = _start(client)["id"]
_expire(db, sid) # past its cap, not yet swept: still open in the table
gated.records.clear()
client.get("/api/debug-sessions", headers={"x-debug-session": sid})
(line,) = _request_lines(gated)
assert getattr(line, "debug_session_id", None) is None
assert getattr(line, "elevated", False) is False
def test_a_request_without_the_header_keeps_the_sessions_floor(gated):
"""The browser's own requests (an
, a