Skip to content

Logs: route templates in the access log, class-only exception summaries, Celery logging (log privacy) - #66

Merged
Kohandezh merged 8 commits into
mainfrom
backend/log-privacy
Oct 19, 2026
Merged

Kohandezh merged 8 commits into
mainfrom
backend/log-privacy

Conversation

@Kohandezh

@Kohandezh Kohandezh commented Oct 18, 2026 •

Copy link
Copy Markdown
Owner

Log-privacy follow-up to HOM-113, freeze scope, requested by the Integrator. Stacked on #43 (base backend/hom-113-observability, e0b577e); retarget to main after #43 merges. No migration, no compose change.

What it does

  • uvicorn access log: AccessLogFilter (backend/observability/access_log.py) rewrites uvicorn's access record to show the matched route template instead of the raw path, and drops the query string. Paths matching no route show as unmatched. Share and invite tokens never reach the access log.
  • Exception summaries are class-only: class name plus bounded fields only (driver SQLSTATE and constraint/table/column, code=, errno=, the class of an explicit raise … from cause). A scrubbed message is added only for SAFE_MESSAGE_TYPES (ProviderError, the RLS posture error). An exception passed as a %s argument, and Celery's %(exc)s, are replaced by the summary. This covers raw psycopg errors, validation errors and wrappers.
  • Celery: a setup_logging receiver keeps our JSON handler in workers and beat. A failed task logs its summary and no traceback.
  • Scrubber bound: a credential that starts in the last KiB before the 16000-character bound is dropped, so a quoted value split by the bound can't survive. The hostile-input tests now use the full bound.
  • OTP_DELIVERY_FAILED logs the exception class, not its text.
  • Docs (observability.md, ADR 0036 item 6): SIGBUS on a full metrics tmpfs, which WriteGuard can't catch. Dead workers' counter files are kept on purpose: mark_process_dead only removes live-gauge files, and deleting counter files would reset the summed counters.

Tests (local PostgreSQL 16 on 54334 + Redis), not CI-validated

  • test_log_privacy.py (new, 29 tests):
    • a real uvicorn server with the access log on: requests carrying a token in the path, the query string, or an unmatched path; the captured uvicorn formatter output plus stdout and stderr contain no token;
    • a real Celery task run that raises an IntegrityError with an e-mail and a phone in its parameters and DETAIL: the logged line is the summary, with no SQL, DETAIL, PII or traceback;
    • ten exception-summary cases;
    • the quoted secret at the bound;
    • eight hostile inputs of 16000 characters or more, each scrubbed in under 1 s.
  • Mutation checks: with the Celery receiver disconnected, both Celery tests fail; with the access filter disabled, the access-log test fails.
  • Focused batch: every test file using caplog/capfd/capsys, plus auth, api, queue routing, observability and log privacy → 782 passed, 0 failed.
  • ruff clean on the changed files; gitleaks clean.

Security notes

  • Logs never carry exception text unless the type is allow-listed; raw paths and query strings never reach uvicorn's access log.
  • Residual: the nginx proxy access log still prints raw paths (documented). services/tombstone_journal.py:221 logs str(JournalUnavailable); that file is Lane C's, so it has been routed to the Integrator.

…es, Celery logging (log privacy)

Follow-up to HOM-113 requested by the Integrator (freeze scope):
- uvicorn.access writes the matched route template instead of the raw path
  and drops the query string; share and invitation tokens live in paths.
- exception_summary names the class and bounded fields only (driver SQLSTATE
  and constraint/table/column, code=, errno=, an explicit cause's class);
  messages only for SAFE_MESSAGE_TYPES. An exception passed as a message
  argument, and Celery's %(exc)s, are replaced by the summary.
- Celery workers and beat keep the JSON handler (setup_logging receiver), so
  a failed task logs its summary and no traceback.
- The scrubber's input bound drops a credential that starts in its last
  kilobyte (a quoted value split by the bound cannot survive); hostile-input
  tests use the full 16000 characters.
- OTP_DELIVERY_FAILED logs the exception class, not its text.
- Docs: SIGBUS on a full metrics tmpfs, why dead workers' counter files stay.
Tests capture real components: uvicorn's access and error loggers behind a
real server, Celery's task-failure record, the JSON handler on stdout.
…paths (PR #66 review)

- safe_message replaces every exception object in record.args (tuple and
  mapping forms) with its summary, with or without exc_info; Celery records
  without exc_info (Retry, throws=) get '[exception]' for their exc text.
- ServerLogFilter replaces the path of uvicorn's WebSocket handshake lines
  with '[path]' (the app serves no WebSocket route).
Tests: '%s, exc' and mapping arguments without exc_info, a Celery retry
record, both WebSocket handshake line shapes.
@Kohandezh
Kohandezh marked this pull request as ready for review October 18, 2026 22:00
Conflicts: observability.md keeps the SIGBUS and dead-worker notes with the
on-premise wiring from #43; the uvicorn test helper keeps its access_log
parameter in main's formatting. ruff format on celery_app and the new test.

Co-Authored-By: Mohammad Kohandezh <kohandezh@hotmail.com>
@Kohandezh
Kohandezh changed the base branch from backend/hom-113-observability to main October 18, 2026 23:50
…LED log fix

otp_request 3e58dd35bae417845a9941eb -> d656f4339ac14c193b185425: the delivery
failure is logged with the exception class instead of its text (which could
carry the phone number). Nothing else changes; otp_verify is untouched.
Owner approval 2026-10-18 (integrator session).

Co-Authored-By: Mohammad Kohandezh <kohandezh@hotmail.com>
…ard formatters (PR #66 CI hang)

A Celery worker routes warnings into logging (captureWarnings). With #66's
JSON handler kept in workers, JSONFormatter's datetime.utcnow() warned on
Python 3.12, the warning was logged and formatted again, and the recursion
killed the worker thread: test_queue_routing's in-process worker never
started and CI hit its 40-minute timeout.
- JSONFormatter uses datetime.now(UTC); a record logged while formatting gets
  a minimal line, and a formatting error never raises.
- ServerLogFilter and AccessLogFilter never raise into the server.
- The two Celery logging tests restore Celery's logging globals.
Regression tests: formatting under warnings-as-errors, a nested record, a
failing scrubber.

Co-Authored-By: Mohammad Kohandezh <kohandezh@hotmail.com>
Co-Authored-By: Mohammad Kohandezh <kohandezh@hotmail.com>
…tion (PR #66 CI)

An in-process Alembic run applied alembic.ini's logging (root WARNING plus a
console handler) to the whole process, so every later test lost INFO records:
CI's access-log test saw no uvicorn.access lines. env.py configures logging
only when nothing has (the alembic CLI). The access-log test sets and checks
its logger level and restores it. Regression test: running env.py in-process
leaves the root level and handlers unchanged.

Co-Authored-By: Mohammad Kohandezh <kohandezh@hotmail.com>
Co-Authored-By: Mohammad Kohandezh <kohandezh@hotmail.com>
@Kohandezh

Copy link
Copy Markdown
Owner Author

Integrator merge evidence (log privacy), head 1428702: reviews passed; CI hang root-caused (datetime.utcnow warning recursion in Celery workers) and fixed with guarded formatters; order-dependent access-log test root-caused (alembic.ini fileConfig raising root level) and fixed at the source with a regression test. Owner-approved otp_request re-baseline 2026-10-18. CI on 1428702 all green; owner guard re-run locally on main (after #55) + #66: fingerprint tests pass (only the host-load golden timing test failed). Merging.

@Kohandezh
Kohandezh merged commit 1ffa34f into main Oct 19, 2026
9 checks passed
Kohandezh added a commit that referenced this pull request Oct 19, 2026
Conflicts kept both sides: audit_service.py (main's per-delivery failure
count in the INSERT hook, then the HOM-115 ORM guard listeners), ADR 0036
(Decision 2's PR #55 review note, then Decision 3, then Decisions 4 and 5)
and audit.md (the PR #55 review section, then Protection).

Co-Authored-By: Mohammad Kohandezh <kohandezh@hotmail.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant