Tracing a Single Address Through a Geocoding Pipeline

TL;DR: Attach a correlation identifier at ingestion, put it in a context variable so every log line carries it automatically, and have each stage log the decision it made rather than merely that it ran. Log all failures and sample successes, and keep a replay harness that reconstructs a result from the trace without calling anything. The metric side is covered in monitoring and alerting for geocoding pipelines.

What a Useful Trace Contains

The difference between a trace that answers a question and one that merely proves the code ran is whether each stage recorded its decision. “Cache miss” is an event; “cache miss on key geo:v3:n7:here:9f2c… because the key version changed this morning” is an explanation.

What each stage should record A five-row table. Parse logs the canonical form and the normalisation version. Cache logs the key and whether it hit. Route logs the chain and the position chosen. The provider call logs attempts, latency and the returned tier. Write logs the destination and whether the value replaced a better one. Stage Fields to log Question it answers parse canonical · norm_version did normalisation change the string? cache key · hit · age_days was this answer old, or new? route chain · position · skip_reason why did the fallback answer this? provider call attempts · latency_ms · tier was it slow, retried, or imprecise? write target · replaced_tier did we overwrite something better?

The last row is the one that catches the most insidious class of bug. A pipeline that silently downgrades good coordinates during a fallback period leaves no other evidence, and a single logged field — the tier that was replaced — makes it obvious the first time anyone looks.

Propagating the Identifier Without Threading It

Passing a trace identifier through every function signature is tedious and gets dropped at the first refactor. A context variable plus a logging filter attaches it automatically, and survives across await boundaries.

from __future__ import annotations

import logging
import uuid
from contextvars import ContextVar

_trace: ContextVar[str] = ContextVar("trace_id", default="-")


class TraceFilter(logging.Filter):
    """Inject the current trace id into every record."""

    def filter(self, record: logging.LogRecord) -> bool:
        record.trace_id = _trace.get()
        return True


def start_trace(existing: str | None = None) -> str:
    """Begin a trace, honouring an upstream identifier when one is supplied."""
    tid = existing or uuid.uuid4().hex[:16]
    _trace.set(tid)
    return tid

Accepting an upstream identifier matters when addresses arrive from another service. Reusing the caller’s identifier means a support ticket referencing their request can be joined straight to your pipeline’s logs, which removes an entire correlation step from every cross-team investigation.

Sampling That Keeps Costs Sane

Logging five structured lines for every record in a two-million-row batch produces ten million log lines a night, which is expensive and mostly worthless — the successful records are all alike. Asymmetric sampling keeps the useful traces and discards the rest.

Outcome Sample rate Reasoning
failure or exception 100% every one is a potential investigation
fallback answered 100% rare, and always interesting
low-precision result 10% enough to characterise the population
cache miss, resolved 1% common; the aggregate metric covers it
cache hit 0.1% the cheapest and least interesting path

Decide the sample at the start of the record’s processing, not per log line. A record that is sampled must produce all of its lines or the trace is incomplete, and a partial trace is often worse than none because it invites conclusions from missing evidence.

Sampling, Drawn

Sampling rate by outcome Four bars showing the retained share of traces by outcome. Failures and fallback answers are retained entirely. Low-precision results are retained at ten percent. Resolved cache misses at one percent. Cache hits at one tenth of one percent, which is enough to characterise the cheapest path. Share of traces retained, by outcome failure · fallback 100% low precision 10% resolved miss 1% cache hit 0.1%

Replaying a Trace Offline

The final step is being able to reconstruct what happened without touching a provider. If the trace records the canonical form, the key, the chain and the provider response tier, a small harness can re-run the decision logic against those recorded values and show where the outcome diverges from expectation.

from __future__ import annotations

import json
from dataclasses import dataclass


@dataclass(frozen=True)
class TraceRecord:
    trace_id: str
    canonical: str
    norm_version: int
    cache_key: str
    cache_hit: bool
    chain: list[str]
    chain_position: int
    tier: str


def load_trace(lines: list[str]) -> TraceRecord:
    """Rebuild a trace record from structured log lines for one trace id."""
    fields: dict = {}
    for line in lines:
        fields.update(json.loads(line))
    return TraceRecord(
        trace_id=fields["trace_id"],
        canonical=fields["canonical"],
        norm_version=fields["norm_version"],
        cache_key=fields["key"],
        cache_hit=fields["hit"],
        chain=fields["chain"],
        chain_position=fields["position"],
        tier=fields["tier"],
    )


def explain(rec: TraceRecord, current_norm: int) -> list[str]:
    """Human-readable findings for one traced record."""
    notes = []
    if rec.norm_version != current_norm:
        notes.append(
            f"normalised under v{rec.norm_version}, current is v{current_norm} — "
            "the key would differ today"
        )
    if not rec.cache_hit and rec.chain_position > 0:
        notes.append(
            f"answered by {rec.chain[rec.chain_position]} at position "
            f"{rec.chain_position} — the primary declined or was skipped"
        )
    if rec.tier in {"locality", "postcode"}:
        notes.append(f"weak result ({rec.tier}) — candidate for revalidation")
    return notes or ["nothing unusual in this trace"]

That function is deliberately small and dull. Its value is that it encodes the three questions everyone asks about a suspicious record, so the answer arrives in seconds rather than after an hour of reading raw logs.

Where the Trace Should Be Stored

Traces are logs, and the storage decision is the same one every log pipeline faces: searchable and expensive, or cheap and awkward. For this use case the deciding question is how quickly a trace needs to be found during an incident.

A searchable log store indexed on the trace identifier and a few structured fields is worth the cost if investigations are frequent. Being able to type an order number and see every stage of its geocoding in one query is the capability this whole design exists to provide, and it is undermined by storage that requires a scan.

Where volume makes that uneconomical, the compromise that works well is a two-tier retention: full traces in searchable storage for a short window — seven to fourteen days covers almost every investigation — and compressed archives for longer, retrievable by date and identifier when something older is genuinely needed.

Whichever you choose, keep the trace identifier on the output record itself, in the database row the pipeline writes. That single column means an investigation can start from the business record rather than from a timestamp, which is how the question always actually arrives: someone has a bad delivery, not a five-minute window.

Metrics and Traces Answer Different Questions

What each signal can and cannot answer Two panels. Metrics answer aggregate questions about what changed and when, and cannot explain an individual record. Traces answer why one record took the path it did, and cannot show whether the behaviour is widespread. Together they cover both questions an incident raises. metrics answers: what changed, when, how widely cheap at any volume, bounded cardinality cannot explain one record no identifiers, by design traces answers: why this record took this path sampled, retained for a bounded window cannot show how common it is a sample, not a census An incident needs both: the metric says something moved, the trace says what the pipeline decided for one record.

Edge Cases and Failure Modes

Trace identifiers in metric labels. Never. A trace identifier as a Prometheus label creates one series per record and will take the metrics backend down. Traces belong in logs and, if you use one, a tracing backend.

Context lost across executors. ContextVar propagates across await but not into a ProcessPoolExecutor. Pass the identifier explicitly as an argument at the process boundary and re-set it inside the worker, or every parallel stage logs a dash.

Personal data in traces. A full address is personal data, and a trace retained for ninety days is a ninety-day retention of that address. Log the canonical form and the key where possible, keep the raw string only for failures, and apply the same retention policy the source data has.

Sampling decided per line. Half a trace is worse than no trace. Decide once, carry the decision in the same context variable, and have the filter drop unsampled records consistently.

Untraceable batch aggregates. A record that fails inside a vectorised operation has no individual trace at all. Where a stage is vectorised, log the failing indices and their keys in one line rather than pretending the stage is per-record.

Integration Note

Tracing complements the metrics rather than duplicating them: metrics tell you that something moved, traces tell you why one record behaved the way it did. Together they cover the two questions an incident actually raises. The fields listed above are all values the pipeline already computes — the chain position, the cache key version and the precision tier — so the cost of tracing is almost entirely in the logging pipeline rather than in the geocoding one.

Keeping the identifier on the row is also what makes the trace useful to people outside the engineering team, who will always start from a customer complaint rather than from a log.