feat(observability): activate Logfire ops/error/LLM tracing (#119)

backend/.env.example

@@ -14,6 +14,15 @@ SUPABASE_SERVICE_KEY=your-service-role-key-here
 # app runtime, which goes through PostgREST.
 SUPABASE_DB_URL=postgresql://postgres:[password]@db.your-project-ref.supabase.co:5432/postgres
 
+# Logfire ops/error/LLM tracing (optional). Get a write token from
+# https://logfire.pydantic.dev → your project → Settings → Write tokens.
+# When unset, Logfire stays dormant: the app behaves exactly as today with no
+# egress. When set, FastAPI request traces and Pydantic AI agent spans (incl.
+# per-call LLM token usage) stream to Logfire. Prompt/completion/document text
+# is scrubbed to a length-capped preview + sha256 fingerprint before egress
+# (services/logfire_scrubber.py); request bodies/headers are never captured.
+# LOGFIRE_TOKEN=
+
 # Deployment environment. Defaults to "production" when unset (strict, fail-closed checks).
 # Set APP_ENV=local for local dev (relaxes SESSION_SECRET); set APP_ENV=staging on the staging
 # deploy (drives the noindex header). "staging" is NOT in IS_LOCAL, so it stays fail-closed.

backend/config.py

@@ -12,6 +12,12 @@
 SUPABASE_URL = os.getenv("SUPABASE_URL", "")
 SUPABASE_SERVICE_KEY = os.getenv("SUPABASE_SERVICE_KEY", "")
 
+# Logfire ops/error/LLM tracing. Optional: unset = dormant (main.py configures
+# send_to_logfire="if-token-present", so no spans egress without it). Logfire's
+# SDK reads this env var itself; surfaced here only so all env access stays
+# visible through config.py.
+LOGFIRE_TOKEN = os.getenv("LOGFIRE_TOKEN", "")
+
 PORT = int(os.getenv("PORT", "5000"))
 FRONTEND_URL = os.getenv("FRONTEND_URL", "http://localhost:3000")
 SESSION_SECRET = os.getenv("SESSION_SECRET", "")

backend/main.py

@@ -84,8 +84,45 @@ async def _lifespan(_app: FastAPI):
  # No shutdown hooks today.
 
 
+def _drop_request_arguments(_request, _attributes):
+ """request_attributes_mapper for instrument_fastapi: never log endpoint args.
+
+ FastAPI instrumentation otherwise records the parsed endpoint arguments —
+ the request body and query/path params — on the request span under
+ ``fastapi.arguments.values``. In Sapling those carry student content: chat
+ messages, note bodies, quiz answers, uploaded document text. That path is
+ NOT covered by the ``scrub_value`` callback (Logfire routes only a subset of
+ attributes through scrubbing, and a body field named e.g. ``body`` matches
+ no risky pattern), so the only safe move is to drop the arguments entirely.
+ Returning ``None`` tells Logfire to record no argument attributes at all.
+
+ We keep the method, route template, status, and latency — which is what the
+ request trace is actually for. (The full URL and rendered span message do
+ still carry the raw query string; Sapling query params are ids/enums plus a
+ couple of low-sensitivity search terms, never prompts/completions/document
+ text — see docs/observability-logging-tracking.md.)
+ """
+ return None
+
+
 app = FastAPI(title="Sapling API", version="1.0.0", lifespan=_lifespan)
 
+# Emit a span per HTTP request (method, route, status, latency) so request
+# traces and errors show up in Logfire alongside the Pydantic AI agent spans.
+# Like configure()/instrument_pydantic_ai() above, this is always on but inert
+# without LOGFIRE_TOKEN (send_to_logfire="if-token-present").
+#
+# Egress safety (layered): request bodies/params are dropped via
+# _drop_request_arguments; request/response headers are not captured
+# (capture_headers=False); and the separate arguments/endpoint spans are off
+# (extra_spans=False). No student content leaves the process on request spans.
+logfire.instrument_fastapi(
+ app,
+ capture_headers=False,
+ extra_spans=False,
+ request_attributes_mapper=_drop_request_arguments,
+)
+
 if recost_api_key and RecostMiddleware is not None:
  app.add_middleware(
  RecostMiddleware,

backend/services/flashcard_import_service.py

@@ -10,6 +10,7 @@
 import io
 import json
 import logging
+import math
 import os
 import re
 import sqlite3
@@ -91,7 +92,11 @@ def check_rate_limit(user_id: str) -> int | None:
  now = time.time()
  bucket = [t for t in _rate_state.get(user_id, []) if now - t < _RATE_WINDOW_SEC]
  if len(bucket) >= _RATE_LIMIT:
- retry = int(_RATE_WINDOW_SEC - (now - bucket[0])) + 1
+ # Seconds until the oldest call in the window ages out (freeing a slot),
+ # rounded up. ceil keeps a sub-second remainder from reporting 0, and —
+ # unlike the old `int(...) + 1` — never overshoots to 61 when the calls
+ # land in the same clock tick (elapsed == 0). Always in [1, _RATE_WINDOW_SEC].
+ retry = math.ceil(_RATE_WINDOW_SEC - (now - bucket[0]))
  _rate_state[user_id] = bucket
  return retry
  bucket.append(now)

backend/tests/test_logfire_scrubber.py

@@ -122,3 +122,125 @@ def test_scrub_value_redacts_when_inner_path_segment_is_risky():
  result = scrub_value(match)
  assert isinstance(result, str)
  assert "redacted" in result
+
+
+# ── instrument_fastapi wiring: no request bodies/headers may egress ──────────
+#
+# The scrubber only sees the attributes Logfire routes through it — and it does
+# NOT route the FastAPI endpoint-argument attribute (`fastapi.arguments.values`)
+# nor `http.url`/`logfire.msg`. That argument attribute otherwise carries the
+# request body and params: chat messages, note bodies, quiz answers, uploaded
+# document text. A body field named e.g. `body` matches no risky pattern, so
+# scrubbing can't be relied on here. main.py therefore drops the arguments at
+# the source via a `request_attributes_mapper` that returns None, keeps headers
+# off (`capture_headers=False`), and keeps the extra argument/endpoint spans off
+# (`extra_spans=False`). These guards fail loudly if any of that regresses.
+
+def _instrument_fastapi_kwargs():
+ """Parse main.py (no import/side effects) and return the keyword
+ arguments passed to logfire.instrument_fastapi(...), as an AST map."""
+ import ast
+ from pathlib import Path
+
+ main_src = Path(__file__).resolve().parents[1] / "main.py"
+ tree = ast.parse(main_src.read_text(encoding="utf-8"))
+ for node in ast.walk(tree):
+ if (
+ isinstance(node, ast.Call)
+ and isinstance(node.func, ast.Attribute)
+ and node.func.attr == "instrument_fastapi"
+ ):
+ return {kw.arg: kw.value for kw in node.keywords}
+ return None
+
+
+def test_instrument_fastapi_is_wired():
+ """FastAPI request traces (success criterion #1) require this call."""
+ assert _instrument_fastapi_kwargs() is not None, (
+ "logfire.instrument_fastapi(app) must be called in main.py so FastAPI "
+ "request traces reach Logfire."
+ )
+
+
+def test_instrument_fastapi_drops_arguments_and_headers():
+ """Egress guard: request bodies/params/headers must never leave the process.
+
+ - `request_attributes_mapper` must be provided (it drops `fastapi.arguments`).
+ - `capture_headers` / `extra_spans`, if present, must be explicitly False.
+ Flipping any of these would ship un-scrubbed student content.
+ """
+ import ast
+
+ kwargs = _instrument_fastapi_kwargs()
+ assert kwargs is not None
+ assert "request_attributes_mapper" in kwargs, (
+ "instrument_fastapi must pass request_attributes_mapper to drop request "
+ "bodies/params (fastapi.arguments.values), which the scrubber can't reach."
+ )
+ for flag in ("extra_spans", "capture_headers"):
+ val = kwargs.get(flag)
+ if val is not None:
+ assert isinstance(val, ast.Constant) and val.value is False, (
+ f"instrument_fastapi({flag}=...) must be False so request "
+ f"bodies/headers are not sent to Logfire."
+ )
+
+
+def test_request_body_does_not_appear_in_exported_spans():
+ """End-to-end: fire a real request with a body + query and assert the body
+ never lands in any exported span attribute.
+
+ This is the concrete proof of "no student content leaves un-fingerprinted"
+ for the request-trace egress path introduced by instrument_fastapi. It
+ mirrors main.py's wiring (mapper drops args) against an in-memory exporter.
+ """
+ import json
+
+ import logfire
+ from fastapi import FastAPI, Query
+ from fastapi.testclient import TestClient
+ from logfire.testing import SimpleSpanProcessor, TestExporter
+ from pydantic import BaseModel
+
+ from main import _drop_request_arguments # noqa: PLC2701 — the exact mapper we ship
+
+ exporter = TestExporter()
+ logfire.configure(
+ send_to_logfire=False,
+ additional_span_processors=[SimpleSpanProcessor(exporter)],
+ )
+
+ app = FastAPI()
+
+ class NoteIn(BaseModel):
+ title: str
+ body: str
+
+ @app.post("/notes/{note_id}")
+ def create_note(note_id: str, note: NoteIn, q: str = Query("")):
+ return {"ok": True}
+
+ logfire.instrument_fastapi(
+ app,
+ capture_headers=False,
+ extra_spans=False,
+ request_attributes_mapper=_drop_request_arguments,
+ )
+
+ secret = "MITOCHONDRIA_POWERHOUSE_ESSAY_BODY"
+ TestClient(app).post(
+ "/notes/note-123", json={"title": "Bio Notes", "body": secret + " " * 0}
+ )
+
+ spans = exporter.exported_spans_as_dict()
+ assert spans, "instrument_fastapi should emit a request span"
+ blob = json.dumps(spans)
+ assert secret not in blob, (
+ "request body leaked into a span attribute — the request_attributes_mapper "
+ "is not dropping fastapi.arguments.values"
+ )
+ # Sanity: the span still carries the useful ops fields.
+ attrs = spans[-1]["attributes"]
+ assert attrs.get("http.route") == "/notes/{note_id}"
+ assert attrs.get("http.method") == "POST"
+ assert "fastapi.arguments.values" not in attrs

docs/observability-logging-tracking.md

@@ -100,6 +100,65 @@ No raw content is ever stored — only fingerprints.
 - Admins can query usage, per-user activity, LLM cost rollups, and errors via
  `/api/admin/analytics`, and view them in an admin dashboard.
 
+## Logfire (activated in #119)
+
+Logfire is our external ops/error/LLM tracing tool. It is **complementary** to
+the owned Supabase `events`/`llm_usage` tables — it is not a replacement and
+does not write to them, so enabling it cannot double-count anything (the two
+capture paths share no code).
+
+### What Logfire captures
+
+- FastAPI **request traces**: method, route template (`/api/notes/{note_id}`),
+ status code, and latency — one span per request (`instrument_fastapi`).
+- Pydantic AI **agent spans**: the agent run, tool calls, and **live per-call
+ LLM token usage** (`instrument_pydantic_ai`).
+
+### How to enable
+
+1. Create a **write token** in the Logfire UI: https://logfire.pydantic.dev →
+ your project → Settings → Write tokens.
+2. Set `LOGFIRE_TOKEN=<token>` in the environment (see `backend/.env.example`).
+3. Restart the backend. Request and agent spans now stream to Logfire.
+
+With **no token**, Logfire is dormant: `logfire.configure(...)` uses
+`send_to_logfire="if-token-present"`, so nothing egresses and the app behaves
+exactly as before. `service_name="sapling-backend"` identifies the service in
+the Logfire UI. Both settings live in `backend/main.py`.
+
+### What is scrubbed / kept out of egress
+
+**No student content (prompts, completions, uploaded document text) leaves the
+process.** Three layers, all in `backend/main.py` + `services/logfire_scrubber.py`:
+
+- **Agent prompt/output** (`gen_ai.prompt`, `all_messages_events`,
+ `input/output.value`, …): the `scrub_value` callback truncates each string to
+ an 80-char preview and appends a `sha256` fingerprint, so a body is
+ debuggable/correlatable but never shipped in full. Logfire's built-in patterns
+ (`password`, `secret`, `api_key`, …) are still fully redacted.
+- **Request bodies + params** (`fastapi.arguments.values` — chat messages, note
+ bodies, quiz answers, uploaded text): dropped entirely via a
+ `request_attributes_mapper` that returns `None`. Logfire does **not** route
+ this attribute through the scrubber, so dropping it at the source is the only
+ safe option.
+- **Headers**: not captured (`capture_headers=False`).
+
+**Known, in-scope limitation — query strings.** The full request URL and the
+rendered span message (`http.url`, `logfire.msg`) still contain the raw query
+string, and Logfire deliberately keeps these standard attributes unscrubbed.
+Sapling query params are ids / enums / pagination plus a couple of
+low-sensitivity free-text terms (course search `q`, `check_username`) — **never
+prompts, completions, or document text**. Convention: do not put sensitive
+free-text in query params; send it in the request body (which is dropped).
+
+### Verifying the scrubbing
+
+`backend/tests/test_logfire_scrubber.py` covers it: unit tests for the
+prompt/output redaction, AST guards that fail if `instrument_fastapi` ever loses
+the argument-dropping mapper (or turns header/extra-span capture on), and an
+end-to-end test that fires a request with a body and asserts the body never
+appears in any exported span.
+
 ## Conventions honored
 
 - Supabase access only via `db/connection.py::table()`.