Module 10 · Observability and debugging

Lesson 45 — Structured logging

Correlation identifiers to follow a request across the whole system.

Published
In this lesson
  1. Exercise 1 — The JSON formatter
  2. Exercise 2 — The trace_id end-to-end
  3. Exercise 3 — The event catalog
  4. Exercise 4 — The diagnostic query
  5. Exercise 5 — The audit log vs the log
  6. Submit

TicketFlow's trail, queryable. No solutions.md before submitting.

Exercise 1 — The JSON formatter

  1. Configure §3's LOGGING (pythonjsonlogger or your own) and verify: a service log line is valid JSON with ts/level/logger/event/trace_id/version. Paste the line.
  2. extra as a habit: rewrite 5 log calls using f-strings to logger.info(event, extra={...}). The test: grep -rn 'logger.*f"' services/ returns empty.
  3. The TZ: simulate a UTC server with TIME_ZONE=Europe/Madrid: what timestamp does the log record and which one does the collector's console show? Decide and document: does the log carry UTC ALWAYS (and the event's time for the user? — 31: business time is domain, not log).

Exercise 2 — The trace_id end-to-end

  1. Implement the middleware + ContextFilter (§2) and the test: two concurrent requests (ThreadPoolExecutor, 34) carry DIFFERENT trace_ids in their logs (no mixing under threads).
  2. Propagation to the queue: add trace_id to enviar_email_confirmacion.delay's kwargs and the trace_id_var.set at the task's start. Test: endpoint → eager task → the task's log carries the SAME tid.
  3. Propagation to the outbox and the response: the outbox event (25) carries trace_id in its payload; the HTTP response (and 26's problem+json) exposes it as X-Request-ID/trace_id. The thread's E2E test: POST reservation → the response's tid appears in the endpoint's log, in the outbox and in the fake email.

Exercise 3 — The event catalog

  1. Write the complete catalog: table event | level | logger | extra keys | who emits it. Cover the course's ~12 events (25's domain, 32's saga, 29/31's jobs, 30's DLQ, 18-20's auth).
  2. The right level: reclassify the ones you have wrong (the request's 404 as ERROR? the gateway retry as ERROR? — §4 decides). The spam test: run the integration suite and count the WARNING/ERROR: is the ratio readable or does noise eat the signal?
  3. What does NOT go: search your code for logger.*request.data|payload|body and django.db.backends at DEBUG: each finding with its PII risk (23) and its fix (the field that DOES go: the user's id, not the body).

Exercise 4 — The diagnostic query

  1. With the JSON log in a file (or the local stack): simulate 47's incident — "customer RF-8A21 says they paid and it doesn't confirm": write the query (jq/grep) reconstructing the story with ONE trace_id. How many commands did it cost you?
  2. The per-user history: "what did u-841 do on 2027-09-28 between 14:00 and 15:00?" — the query and its GDPR implication (23): who can run that query and with what authorization? Document the log access policy.
  3. The retention: decide (or document the provider's default) §5's 30 days + 1 year cold with the estimated cost (the volume: 36's logs × 50k reservations/month ≈ how many GB?).

Exercise 5 — The audit log vs the log

  1. Implement the distinction: the audit log (23/56) as an append-only TABLE (who, what, when, IP, result) for: login, role change, GDPR export download, price change. The diagnostic log does NOT record these (or it does: decide and justify the double life).
  2. The audit test: a role change generates an audit row AND a WARNING log; the export generates an audit row + an INFO log. Which auditor query (56) does each satisfy?
  3. The log dashboard: write the "top 5 errors of the last hour grouped by event" query (jq or the stack's language). The query 46 will turn into an alert.

Submit

Paste the JSON line, the catalog's table, the simulated incident's query and the audit vs log policy. Next: Lesson 46 — Metrics, traces and alerts.