Structured Logging for Geospatial Flows

In short: a log line should be a record with fields, not a sentence with numbers embedded in it. {"event": "tile_written", "tile.z": 12, "tile.x": 2100, "features": 4183, "crs": "EPSG:25832", "trace_id": "4bf9…"} can be filtered, aggregated and joined to a trace. "Wrote 4183 features for tile 12/2100/1300" can be grepped, which is not the same thing and stops working at the first change to the message.

Logs are the third observability signal and the one spatial pipelines most often get wrong, because the interesting facts are numerous — a tile index, two coordinate reference systems, a feature count, an extent, a source version — and prose absorbs them invisibly. The moment those facts are fields, questions like “which tiles wrote fewer features than yesterday” become queries rather than archaeology, and the log stops being a last resort.

The cost of getting this wrong is not that logs are unavailable; it is that they are available and useless, which is worse because it looks like coverage. A pipeline emitting a million prose lines a night has a log bill, a retention policy and a search box, and still cannot answer “which tiles wrote fewer features than last week” without someone writing a parser. The same volume in structured form answers it with a sum by (tile) over a field that was already there. The difference in effort at the call site is zero.

Prerequisites & Architecture Baseline#

• structlog ≥ 24, or the standard library's logging with a JSON formatter
• A log destination that indexes fields: Loki, Elasticsearch, or a vendor — plain files defeat the purpose
• The same attribute vocabulary the traces use, so tile.z means one thing everywhere
• Trace and span ids injected into every record, which is what makes logs and traces joinable
• A retention decision: logs are the most voluminous signal and the least valuable per byte
• A rule about what must never be logged — coordinates of protected sites, credentials, full geometries
• A module that owns the field names, so a typo is an import error rather than a silently new field
• Clock synchronisation across workers, since records are ordered by a timestamp each worker supplies itself

Core Principles#

1. Events have names, not sentences. event="tile_written" is a stable identifier that survives rewording; "Successfully wrote tile" is a string that somebody will improve next quarter, silently breaking every saved query built on it.

2. Facts are fields. Every number, identifier and classification in the message becomes a field. The message then contains no information at all, which is the goal — it exists for humans skimming, and the fields exist for everything else.

3. Share the trace’s vocabulary. If the span attribute is tile.z, the log field is tile.z. Two vocabularies mean two sets of saved queries and a permanent translation cost, and the translation is exactly what fails at 3 a.m.

4. Bind context once, at the top of the unit of work. A logger bound with the tile, the layer and the trace id carries them into every subsequent line without repetition. That is what makes concurrent work legible — without it, eight interleaved tiles produce a stream where consecutive lines are unrelated.

5. Log decisions and transitions, not progress. “Started”, “finished”, “skipped because the digest matched”, “repaired the geometry”, “fell back to cache” are all worth a line. “Processing tile 47 of 412” is worth none: it is a metric, it produces four hundred lines per scene, and nobody reads it.

6. Volume is a design constraint. A pipeline logging ten lines per tile at four hundred tiles per scene and three hundred scenes a night is 1.2 million lines. That is affordable if the lines are structured and sampled thoughtfully, and ruinous if every one of them is a paragraph of prose.

The concurrency point deserves emphasis because it is what makes spatial logs uniquely unreadable when they go wrong. A pipeline processing sixteen tiles at once produces a stream in which no two consecutive lines belong to the same tile, so the human habit of reading downward to follow a story simply fails. Bound context turns that from a problem into a filter: every line carries its tile, so “show me this tile’s story” is a query and the interleaving stops mattering. Without it, the only recourse is to reduce concurrency to one and re-run, which is both slow and often does not reproduce the problem.

Production Implementation#

structlog with a JSON renderer and a processor that injects the trace context gives every line the fields and the join key without any per-call-site effort.

from __future__ import annotations

import logging
from typing import Any, MutableMapping

import structlog
from opentelemetry import trace


def add_trace_context(_, __, event_dict: MutableMapping[str, Any]) -> MutableMapping[str, Any]:
    """Put the current trace and span ids on every record.

    This one processor is what makes logs and traces joinable. Without it the
    two systems describe the same run and cannot be connected.
    """
    span = trace.get_current_span()
    ctx = span.get_span_context()
    if ctx.is_valid:
        event_dict["trace_id"] = format(ctx.trace_id, "032x")
        event_dict["span_id"] = format(ctx.span_id, "016x")
    return event_dict


def redact_protected(_, __, event_dict: MutableMapping[str, Any]) -> MutableMapping[str, Any]:
    """Coarsen coordinates for layers where the exact location is sensitive."""
    if event_dict.get("layer") in PROTECTED_LAYERS and "geo.bbox" in event_dict:
        event_dict["geo.bbox"] = coarsen_to_grid(event_dict["geo.bbox"], km=10)
        event_dict["geo.redacted"] = True
    return event_dict


structlog.configure(
    processors=[
        structlog.contextvars.merge_contextvars,   # bound context, per task
        structlog.processors.add_log_level,
        structlog.processors.TimeStamper(fmt="iso", utc=True),
        add_trace_context,
        redact_protected,
        structlog.processors.StackInfoRenderer(),
        structlog.processors.format_exc_info,
        structlog.processors.JSONRenderer(),
    ],
    wrapper_class=structlog.make_filtering_bound_logger(logging.INFO),
    cache_logger_on_first_use=True,
)

log = structlog.get_logger()

Binding the context once, at the top of the unit of work, is what keeps the rest of the code free of repetition:

def render_tile(item, scratch) -> None:
    # Everything logged inside this task carries these fields automatically.
    structlog.contextvars.bind_contextvars(
        layer=item.layer, **{"tile.z": item.z, "tile.x": item.x, "tile.y": item.y},
    )
    try:
        if already_done(item.work_key):
            # A decision, with its reason as a field rather than in the sentence.
            log.info("tile_skipped", reason="digest_unchanged", digest=item.source_digest)
            return

        source = fetch_source(item.source_uri)
        log.info("source_fetched", scheme=scheme_of(item.source_uri),
                 bytes=source.stat().st_size)

        features, crs = warp_window(source, item, scratch)
        log.info("tile_written", features=features, crs=crs,
                 seconds=round(item.elapsed, 2))
    except Exception as exc:
        # exc_info gives the traceback as a field, not as twenty extra lines.
        log.error("tile_failed", failure_class=classify(exc), exc_info=exc)
        raise
    finally:
        structlog.contextvars.clear_contextvars()

Step-by-Step Walkthrough#

1. Configure once, at process start. The processor chain is the whole design; call sites should never format anything. A codebase where half the logs are structured and half are f-strings has the costs of both approaches.
2. Inject the trace context in a processor. Doing it per call site guarantees it will be forgotten somewhere, and the one line missing the trace id is the one you will want.
3. Bind the unit of work’s identity, then clear it. bind_contextvars at the top and clear_contextvars in a finally keeps context from leaking into the next tile on a reused worker, which produces logs that are wrong rather than merely missing.
4. Name the event and put everything else in fields. log.info("tile_skipped", reason="digest_unchanged") rather than log.info("Skipping tile because the digest was unchanged"). The reason is a value you can group by.
5. Log decisions, not progress. Every branch taken, every fallback used, every repair applied. Those are the lines that reconstruct a run; a progress counter is a metric wearing a log’s clothing.
6. Pass exceptions as exc_info. The traceback becomes a field on one record rather than twenty interleaved lines that are unattributable under concurrency.
7. Redact in a processor, not at the call site. A rule enforced centrally is a rule that holds; one applied by remembering is one that fails in the module written under time pressure.

Edge Cases & Failure Recovery#

Context leaking between units of work. A worker that binds a tile’s context and never clears it will attribute the next tile’s logs to the previous tile. The finally clause is not optional, and the failure is subtle enough — plausible fields, wrong values — that it can survive for months.

A field whose type changes. Logging features as an integer in one place and a string in another breaks aggregation in most backends, sometimes silently. Treat field types as part of the vocabulary, and prefer a small helper over ad-hoc dictionaries where a field is used in several modules.

Logging a full geometry. A single coastline in WKT can be several megabytes, and a log pipeline will either truncate it unhelpfully or fall over. Log the bounding box and the vertex count; if the geometry itself matters, it belongs in the dead-letter queue.

Volume that outgrows the budget. Structured logs are cheap per line and expensive per million. Sample the routine events — one in a hundred tile_written records is plenty for spot-checking — and never sample decisions, errors or transitions, which are the ones with information density.

Sensitive coordinates in a widely-readable index. Logs are usually visible to more people than the database is. Where a layer’s locations are protected, coarsening in a processor is the enforceable control; see masking sensitive coordinates in task logs.

Timestamps from the worker’s clock. Log records are ordered by their timestamp, so a worker whose clock drifts by seconds produces a stream where events appear out of order relative to other workers — and a reconstruction that reads “written” before “started” is confusing enough to send an investigation in the wrong direction. Use UTC everywhere, run NTP, and prefer the trace’s span ordering over log timestamps when the two disagree.

A logging call that is itself expensive. Computing a feature count purely to log it turns an observation into work. Log what the code already knows; if a value requires a query to produce, it is a metric or a trace attribute, not a log field.

A last operational note on that breakdown: the progress lines are usually not written deliberately. They accumulate from debugging sessions, from a library’s own INFO-level chatter, and from a loop that once needed watching. Auditing what a single scene actually emits — one run, one wc -l, one sum by (event) — is a fifteen-minute exercise that most pipelines have never done, and it reliably finds several thousand lines per scene that nobody chose.

Configuration Reference#

Retention is the setting most worth revisiting, because logs are the cheapest signal to produce and the most expensive to keep. A fortnight of full-fidelity logs covers essentially every investigation; anything older is almost always answered by metrics, traces or the pipeline’s own tables, all of which are far more compact. Where a longer record is genuinely needed — an audit of what was published and when — that belongs in a table designed for it rather than in a log index that happens to have a long retention.

Frequently Asked Questions#

Related#

• Logging feature counts and EPSG codes per task — the fields worth recording per stage
• Correlating logs and traces for one tile run — the join in practice
• OpenTelemetry tracing for spatial tasks — the vocabulary these fields share
• Masking sensitive coordinates in task logs — the redaction processor in detail
• Prometheus metrics for raster throughput — where the counting belongs instead

← Observability & Monitoring for Geospatial Pipelines