Stop logging /healthz + internal SSR hop, truncate logged IPs #35

Merged
admin_emi merged 1 commit from feat/healthz-ip-privacy-event-cume into dev 2026-07-24 19:28:48 +00:00
Owner

Logging waste + IP privacy (fixed)

/healthz was ~46.7% of prod's daily access log and the internal
frontend_ssr -> backend content-API hop (backend/api/content_routes.py,
called only by frontend/api_client.py, never by a browser) another
~32.2% -- both cost a threadpool dispatch + lock + file write per request
for traffic that isn't meaningful to retain.

  • core/metrics.py's classify_inbound gains "health" (for /healthz)
    and "internal" (for /api/v2/content/*) categories.
  • web/app.py's request-logging middleware excludes both, alongside the
    existing static/metrics/event exclusions, from audit.log_access --
    so they're never dispatched to the threadpool at all, not just cheaply
    logged once there.
  • The IP written to the access log is now truncated to /24 (IPv4) or /48
    (IPv6) before being persisted (_loggable_ip) -- coarse geo/abuse signal
    without a full, joinable address sitting in Loki for 30 days, matching
    the privacy page's claim that IPs aren't logged beyond normal request
    handling. _client_ip itself is untouched and still full precision --
    the event-beacon rate limiter (metrics._rate_ok) keys off that same
    untruncated value, so a NAT'd office still gets one shared quota, not one
    per truncated /24.
  • deploy/entrypoint.sh adds --no-access-log to the uvicorn invocation:
    it was duplicating every line audit.log_access already writes.

Tests: tests/core/test_metrics.py covers the two new categories;
tests/web/test_request_logging.py is new and covers the ASGI-level
behavior -- /healthz and an "internal"-classified route never reach
audit.log_access, the logged IP is the truncated one, the rate limiter
still receives the untruncated one, and a full HTTP round trip through
/api/v2/event is asserted to land in metrics.snapshot() (nothing
previously exercised that route through the real ASGI stack).

event_cume investigation

Went in assuming the stated hypothesis (sendBeacon dying silently to a
cross-origin frontend_ssr vs backend split) and could not confirm it
against how this is actually wired today:

  • content.py's ASSET_BASE (what {{ asset_base }}/digest.js etc.
    resolve against, and therefore what account.js's
    import.meta.url-derived APP_BASE/uv() end up targeting) only goes
    cross-origin when THERMOGRAPH_API_BASE_PUBLIC is set. It is unset in
    every compose/stack file in this repo (infra/docker-compose.yml,
    infra/docker-compose.dev.yml, infra/deploy/stack/thermograph-stack.yml) --
    same for THERMOGRAPH_CORS_ORIGINS (no CORSMiddleware is even added).
  • prod/beta's Caddy (infra/deploy/Caddyfile, and the Terraform template
    both are rendered from) path-splits /api/*, /digest,
    /discord/interactions to backend and everything else to frontend under
    one apparent origin -- a browser never sees two origins.
  • LAN dev publishes only backend's port; frontend has no published port at
    all and is reached solely through backend's own
    _proxy_to_frontend fallback (web/app.py), which is single-origin by
    construction -- its own docstring already says as much ("the primary
    same-origin mechanism is host Caddy in prod/beta ... this proxy is never
    actually exercised there").

So in every environment this repo actually deploys, the event beacon's
target is same-origin, and no CORS preflight is even in play. I also
walked the rest of the client chain looking for anything that would drop
the beacon regardless of origin: the EVENTS/NAV_SURFACES allowlists
match every data-event/track() call site exactly, digest.js's global
click listener is registered as a side effect of app.js's import { track } even on the homepage (which overrides base_scripts without
{{ super() }}, so it never gets its own literal <script> tag for
digest.js/account.js -- but the transitive import still runs their
top-level code), and I found no top-level throw or stopPropagation
anywhere in the click path. None of that turned up a defect either.

Verdict: inconclusive. I could not reproduce or find the actual break
in this pass -- ruled out cross-origin/CORS with reasonably strong
evidence, and reviewed (without finding an issue) the allowlists, the
click-listener wiring, and the URL-building helpers shared by
account.js/digest.js. What I could not do from here: capture a live
browser network trace on an actual LAN dev session (no headless browser
tooling available in this environment) to see whether the beacon request
is even attempted client-side, which would be the fastest way to
narrow this further.

Separately, while reading core/metrics.py's Postgres store I noticed
_boot_token() derives its "reset exactly once per deployment" guard from
the container's own PID 1 start time -- correct for multiple uvicorn
workers sharing one container, but prod's Swarm web service can run
multiple replica containers per deployment (WEB_MIN_REPLICAS/
WEB_MAX_REPLICAS, autoscaled), each with its own PID 1 and therefore its
own token. A second replica of the same deploy would see the stored
token mismatch its own and re-TRUNCATE event_cume (and the other
cumulative metrics tables) again. That's a real latent gap, but I'm not
shipping a fix for it here: it wouldn't explain dev/beta (single replica,
so unaffected), I have no live confirmation it's actually firing on prod,
and fixing it needs a stable per-deployment identifier plumbed through the
stack file (this repo's Postgres-backed metrics path is deliberately
excluded from the unit suite -- see tests/accounts/test_db_engines.py's
own docstring -- so it's also not unit-testable as-is). Flagging it here
for whoever picks this up next rather than guessing at a fix blind.

## Logging waste + IP privacy (fixed) `/healthz` was ~46.7% of prod's daily access log and the internal frontend_ssr -> backend content-API hop (`backend/api/content_routes.py`, called only by `frontend/api_client.py`, never by a browser) another ~32.2% -- both cost a threadpool dispatch + lock + file write per request for traffic that isn't meaningful to retain. - `core/metrics.py`'s `classify_inbound` gains `"health"` (for `/healthz`) and `"internal"` (for `/api/v2/content/*`) categories. - `web/app.py`'s request-logging middleware excludes both, alongside the existing `static`/`metrics`/`event` exclusions, from `audit.log_access` -- so they're never dispatched to the threadpool at all, not just cheaply logged once there. - The IP written to the access log is now truncated to /24 (IPv4) or /48 (IPv6) before being persisted (`_loggable_ip`) -- coarse geo/abuse signal without a full, joinable address sitting in Loki for 30 days, matching the privacy page's claim that IPs aren't logged beyond normal request handling. `_client_ip` itself is untouched and still full precision -- the event-beacon rate limiter (`metrics._rate_ok`) keys off that same untruncated value, so a NAT'd office still gets one shared quota, not one per truncated /24. - `deploy/entrypoint.sh` adds `--no-access-log` to the uvicorn invocation: it was duplicating every line `audit.log_access` already writes. Tests: `tests/core/test_metrics.py` covers the two new categories; `tests/web/test_request_logging.py` is new and covers the ASGI-level behavior -- `/healthz` and an `"internal"`-classified route never reach `audit.log_access`, the logged IP is the truncated one, the rate limiter still receives the untruncated one, and a full HTTP round trip through `/api/v2/event` is asserted to land in `metrics.snapshot()` (nothing previously exercised that route through the real ASGI stack). ## event_cume investigation Went in assuming the stated hypothesis (`sendBeacon` dying silently to a cross-origin `frontend_ssr` vs backend split) and could not confirm it against how this is actually wired today: - `content.py`'s `ASSET_BASE` (what `{{ asset_base }}/digest.js` etc. resolve against, and therefore what `account.js`'s `import.meta.url`-derived `APP_BASE`/`uv()` end up targeting) only goes cross-origin when `THERMOGRAPH_API_BASE_PUBLIC` is set. It is unset in every compose/stack file in this repo (`infra/docker-compose.yml`, `infra/docker-compose.dev.yml`, `infra/deploy/stack/thermograph-stack.yml`) -- same for `THERMOGRAPH_CORS_ORIGINS` (no `CORSMiddleware` is even added). - prod/beta's Caddy (`infra/deploy/Caddyfile`, and the Terraform template both are rendered from) path-splits `/api/*`, `/digest`, `/discord/interactions` to backend and everything else to frontend under **one apparent origin** -- a browser never sees two origins. - LAN dev publishes only backend's port; frontend has no published port at all and is reached solely through backend's own `_proxy_to_frontend` fallback (`web/app.py`), which is single-origin by construction -- its own docstring already says as much ("the primary same-origin mechanism is host Caddy in prod/beta ... this proxy is never actually exercised there"). So in every environment this repo actually deploys, the event beacon's target is same-origin, and no CORS preflight is even in play. I also walked the rest of the client chain looking for anything that would drop the beacon regardless of origin: the `EVENTS`/`NAV_SURFACES` allowlists match every `data-event`/`track()` call site exactly, `digest.js`'s global click listener is registered as a side effect of `app.js`'s `import { track }` even on the homepage (which overrides `base_scripts` without `{{ super() }}`, so it never gets its own literal `<script>` tag for `digest.js`/`account.js` -- but the transitive import still runs their top-level code), and I found no top-level throw or `stopPropagation` anywhere in the click path. None of that turned up a defect either. **Verdict: inconclusive.** I could not reproduce or find the actual break in this pass -- ruled out cross-origin/CORS with reasonably strong evidence, and reviewed (without finding an issue) the allowlists, the click-listener wiring, and the URL-building helpers shared by `account.js`/`digest.js`. What I could not do from here: capture a live browser network trace on an actual LAN dev session (no headless browser tooling available in this environment) to see whether the beacon request is even attempted client-side, which would be the fastest way to narrow this further. Separately, while reading `core/metrics.py`'s Postgres store I noticed `_boot_token()` derives its "reset exactly once per deployment" guard from the container's own PID 1 start time -- correct for multiple uvicorn *workers* sharing one container, but prod's Swarm `web` service can run multiple *replica containers* per deployment (`WEB_MIN_REPLICAS`/ `WEB_MAX_REPLICAS`, autoscaled), each with its own PID 1 and therefore its own token. A second replica of the *same* deploy would see the stored token mismatch its own and re-`TRUNCATE` `event_cume` (and the other cumulative metrics tables) again. That's a real latent gap, but I'm not shipping a fix for it here: it wouldn't explain dev/beta (single replica, so unaffected), I have no live confirmation it's actually firing on prod, and fixing it needs a stable per-deployment identifier plumbed through the stack file (this repo's Postgres-backed metrics path is deliberately excluded from the unit suite -- see `tests/accounts/test_db_engines.py`'s own docstring -- so it's also not unit-testable as-is). Flagging it here for whoever picks this up next rather than guessing at a fix blind.
admin_emi added 1 commit 2026-07-24 04:33:44 +00:00
Stop logging /healthz and the internal SSR->API hop, truncate logged IPs
All checks were successful
PR build (required check) / changes (pull_request) Successful in 7s
secrets-guard / encrypted (pull_request) Successful in 6s
PR build (required check) / build-frontend (pull_request) Has been skipped
shell-lint / shellcheck (pull_request) Successful in 7s
PR build (required check) / validate-observability (pull_request) Has been skipped
PR build (required check) / build-backend (pull_request) Successful in 58s
PR build (required check) / gate (pull_request) Successful in 2s
7bc0358278
/healthz accounted for ~47% of prod's daily access log and the internal
frontend_ssr->backend content-API hop for another ~32%, each costing a
threadpool dispatch + lock + file write on the request path for traffic
that isn't meaningful to retain. classify_inbound gains "health" and
"internal" categories for these, both excluded from audit.log_access
(alongside the existing static/metrics/event exclusions) so they're never
dispatched to the logging threadpool at all.

The access log's client IP is now truncated to /24 (IPv4) or /48 (IPv6)
before being persisted -- coarse geo/abuse signal without keeping a full,
joinable address in Loki for the 30-day retention window, matching the
privacy page's claim that IPs aren't logged beyond normal request
handling. The rate limiter keyed off the same IP (_rate_ok) is untouched
and still sees full precision.

uvicorn's own --no-access-log now suppresses its duplicate per-request
line, since the app's own middleware already writes one.
admin_emi merged commit 4ff113f2cf into dev 2026-07-24 19:28:48 +00:00
Sign in to join this conversation.
No reviewers
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference: Jinemi/thermograph#35
No description provided.