Structured Logging for Geospatial CLIs

A geospatial batch job that logs prose is a job you cannot ask questions of. Emitting one JSON object per event, carrying the CRS pair, the feature or window identifier, and the duration, turns why was last night slow from an afternoon of grepping into a single query. This guide covers the record shape, the handler configuration, and the two places geospatial logging differs from ordinary application logging. It is part of the CLI Architecture & Design Patterns guide.

Prerequisites

• Python 3.10 or later — the examples use structlog-style processors implemented on the standard library’s logging module, so no third-party logger is strictly required.
• pip install rasterio pyogrio for the geospatial context the records carry; pip install structlog if you prefer its processor pipeline to a hand-rolled formatter.
• A CLI whose console output already distinguishes human-facing rendering from machine-facing records, as described in Rich Console Output & Progress Bars.
• Familiarity with where log configuration sits relative to other settings — see Configuration File Management for the layering this plugs into.

Problem framing

The log line a geospatial tool naturally produces looks like this:

2026-08-06 09:14:22 WARNING  failed to reproject tiles/34/12/9.tif: CRSError

It is readable, and it is nearly useless at scale. It cannot answer how many failures shared a CRS pair, whether the slow tiles clustered in one region, or how long the median transform took, because none of that is in the line — and the parts that are in it are welded into a sentence. Ten thousand of these is a text file, not a dataset.

The same event as a structured record answers all three:

{"ts":"2026-08-06T09:14:22Z","level":"warning","event":"reproject_failed",
 "src":"tiles/34/12/9.tif","src_crs":"EPSG:27700","dst_crs":"EPSG:3857",
 "error_class":"CRSError","duration_ms":812,"batch_id":"b-4471","worker":3}

Nothing was added that the program did not already know. The difference is entirely in whether the values stayed as fields or were flattened into a sentence.

Two streams, not one

The mistake that causes the most trouble is treating console output and the log as the same thing. They have different audiences, different lifetimes and — critically — different destinations.

One event can legitimately produce output on two of those streams — a failure is both a line a person should see and a record a query should find. What must not happen is a single stream serving two purposes, because the formatting that makes one useful makes the other unusable.

Step-by-step implementation

1. A formatter that emits one object per line

The standard library gets you most of the way. A formatter subclass that serialises the record plus any extra fields is about twenty lines and has no dependencies.

# gistools/logging_setup.py
import json
import logging
import sys
from datetime import datetime, timezone

# Attributes the logging module puts on every record; anything else came from extra=.
_RESERVED = {
    "args", "asctime", "created", "exc_info", "exc_text", "filename", "funcName",
    "levelname", "levelno", "lineno", "module", "msecs", "message", "msg", "name",
    "pathname", "process", "processName", "relativeCreated", "stack_info",
    "thread", "threadName", "taskName",
}


class SpatialJsonFormatter(logging.Formatter):
    def format(self, record: logging.LogRecord) -> str:
        payload = {
            "ts": datetime.fromtimestamp(record.created, timezone.utc)
                          .isoformat(timespec="milliseconds")
                          .replace("+00:00", "Z"),
            "level": record.levelname.lower(),
            "event": record.getMessage(),
            "logger": record.name,
        }
        for key, value in record.__dict__.items():
            if key not in _RESERVED and not key.startswith("_"):
                payload[key] = value
        if record.exc_info:
            payload["error_class"] = record.exc_info[0].__name__
            payload["error"] = str(record.exc_info[1])
        return json.dumps(payload, default=_coerce, separators=(",", ":"))


def _coerce(obj):
    """Make the geospatial types that reach a log record serialisable."""
    import numpy as np

    if isinstance(obj, (np.integer,)):
        return int(obj)
    if isinstance(obj, (np.floating,)):
        return float(obj)
    if hasattr(obj, "to_string"):       # pyproj CRS
        return obj.to_string()
    if hasattr(obj, "__geo_interface__"):
        return obj.__geo_interface__
    return str(obj)

The default=_coerce hook is the part specific to this domain. Geospatial code puts numpy scalars and pyproj objects into log context without thinking about it, and without the hook the first such record raises a TypeError from inside the logging machinery — where it is caught, swallowed, and printed to stderr as a logging error rather than raised.

2. Bind the context once, not at every call site

Repeating batch_id=..., worker=... on every log call is how fields get forgotten. A LoggerAdapter binds them once and merges them into every record.

class BoundLogger(logging.LoggerAdapter):
    def process(self, msg, kwargs):
        extra = {**self.extra, **kwargs.pop("extra", {})}
        kwargs["extra"] = extra
        return msg, kwargs

    def bind(self, **fields) -> "BoundLogger":
        return BoundLogger(self.logger, {**self.extra, **fields})


def get_logger(name: str, **fields) -> BoundLogger:
    return BoundLogger(logging.getLogger(name), fields)

Usage then reads as a narrowing of scope, with each layer adding what it knows:

log = get_logger("gistools").bind(batch_id=batch_id)

for window in windows:
    wlog = log.bind(window=(window.col_off, window.row_off,
                            window.width, window.height))
    started = time.perf_counter()
    try:
        reproject_window(src, dst, window)
    except Exception:
        wlog.exception("reproject_failed",
                       extra={"duration_ms": _ms_since(started)})
    else:
        wlog.info("reproject_ok", extra={"duration_ms": _ms_since(started)})

Note that wlog.exception captures the traceback and the formatter turns it into error_class and error fields. The traceback text itself does not belong in the record — it is enormous, it varies between runs, and it makes every log query slower.

3. Choose the fields deliberately

A record should carry what a future query will filter or group by, and nothing else. For a spatial batch, five field families cover almost every question anyone asks.

The location family is the one that has no equivalent in ordinary application logging, and it is the one that pays off most. A bounding box on every record means a failure set can be loaded straight back into a GIS and looked at, which frequently makes the cause obvious in a way no aggregate does.

4. Wire it up at the entry point

def configure_logging(json_path: Path | None, level: str = "INFO") -> None:
    root = logging.getLogger()
    root.setLevel(level)
    root.handlers.clear()

    # Human stream: plain text on stderr, never JSON.
    human = logging.StreamHandler(sys.stderr)
    human.setFormatter(logging.Formatter("%(levelname)-7s %(message)s"))
    human.setLevel(max(logging.getLevelName(level), logging.INFO))
    root.addHandler(human)

    # Machine stream: JSON to a file, at full detail.
    if json_path is not None:
        machine = logging.FileHandler(json_path, encoding="utf-8")
        machine.setFormatter(SpatialJsonFormatter())
        machine.setLevel(logging.DEBUG)
        root.addHandler(machine)

The asymmetry in levels is deliberate. A person watching a terminal wants INFO and above; a stored record wants everything, because the debug records are what make an incident reconstructable and nobody will rerun a four-hour batch with a higher verbosity.

Capturing GDAL’s own errors

GDAL reports problems through its own C-level error handler, and by default most of them never reach Python at all — they go to stderr as text, outside your logging entirely. Anything a query needs to find has to be routed in.

from osgeo import gdal

_GDAL_LEVELS = {
    gdal.CE_Debug: logging.DEBUG,
    gdal.CE_Warning: logging.WARNING,
    gdal.CE_Failure: logging.ERROR,
    gdal.CE_Fatal: logging.CRITICAL,
}


def install_gdal_log_bridge(log) -> None:
    def handler(err_class, err_num, message):
        log.log(_GDAL_LEVELS.get(err_class, logging.INFO), "gdal_message",
                extra={"gdal_code": err_num, "gdal_message": message.strip()})

    gdal.PushErrorHandler(handler)
    gdal.UseExceptions()

Two things happen here that are worth being explicit about. PushErrorHandler routes the message into your records, so a warning about an overview mismatch becomes queryable. UseExceptions makes failures raise in Python instead of returning error codes, which is what lets the surrounding try/except see them at all. Without the second call, a failed gdal.Open returns None and the traceback you eventually get is an AttributeError twenty lines later.

Correlating across workers

A multiprocess batch produces records from several processes, and they interleave. Three fields make the stream reassemblable: a batch identifier generated once in the parent and passed to every worker, a worker identifier, and a monotonically increasing sequence number per worker.

The batch identifier must be generated before the pool starts and passed as an argument. Generating it inside the worker gives every process a different value and defeats the purpose; reading it from a module-level global works under fork and silently breaks under spawn, which is the start method Optimizing GDAL Batch Operations with multiprocessing.Pool recommends.

Writing is the other half. Several processes appending to one file works on Linux for records under the pipe buffer size — which a JSON log line comfortably is — but it is not guaranteed, and it fails on other platforms. The robust arrangement is one file per worker, named by the worker identifier, concatenated afterwards. Log analysis tools ingest a directory as happily as a file, and the ambiguity disappears.

Volume is the constraint that shapes everything else. Choosing the granularity of a record before writing the first one avoids the rewrite that otherwise follows the first million-feature batch.

Emitting per-chunk records at INFO and per-feature records at DEBUG gives both, with the second switched on only for the batch you are investigating.

Error handling and gotchas

A field name that collides with a reserved attribute is silently dropped. Passing extra={"module": "raster"} conflicts with the record’s own module and raises at format time. Prefix domain fields consistently — gis_module, or a nested ctx object — and the class of problem disappears.

Logging inside a tight loop dominates the loop. A record per feature over a million features is several seconds of JSON serialisation. Log per chunk, and let the chunk record carry counts and a duration summary.

Do not log geometry. A polygon with ten thousand vertices produces a log line larger than the feature. Log its bounding box and vertex count; if the geometry itself is needed for triage, that is what a dead-letter store is for.

Redact before serialising, not after. A signed URL carrying a token will end up in a record if the code logs a source path without thinking. A processor that strips query strings from anything resembling a URL is a five-line function and removes the whole category.

Verification

Three checks confirm the setup is doing what it claims:

# 1. Every line is valid JSON — one malformed record poisons an ingest pipeline.
python -c "import json,sys; [json.loads(l) for l in open('run.jsonl')]" && echo OK

# 2. The fields you rely on are present on every record of that event type.
jq -c 'select(.event=="reproject_ok") | [.batch_id, .duration_ms, .dst_crs]' run.jsonl | head

# 3. No secrets leaked into the stream.
grep -Ei 'AKIA|secret|signature=|token=' run.jsonl && echo "LEAK" || echo "clean"

The third one belongs in CI, not just in your terminal. It runs against a test batch’s log output in under a second and catches the one class of logging bug that cannot be fixed after the fact.

Performance notes

JSON serialisation costs roughly ten to thirty microseconds per record with the standard library, which is negligible per chunk and significant per feature — the argument for chunk-level records again. If profiling shows serialisation on the hot path, orjson is roughly five times faster and is a drop-in replacement for the json.dumps call in the formatter.

Handler I/O matters more than serialisation. A FileHandler flushes on every record by default; on a network filesystem that is a round trip per log line. Wrapping it in a MemoryHandler with a capacity of a few hundred records batches the writes and cuts the cost to something unmeasurable, at the price of losing the last few records if the process is killed rather than exiting. For a batch job that already checkpoints, that trade is usually right.

Retention, sampling and the cost of keeping records

A structured stream is only worth producing if it will still be there when someone asks a question, and that means deciding retention before volume forces the decision for you.

The useful framing is to work backwards from the questions. Why did last night’s batch take longer than usual needs a few weeks. Has the failure rate on this CRS pair been creeping up needs a quarter. What did we run in the incident last spring needs a year, and probably only the summary records rather than every unit. Three tiers of retention over one stream — a week of everything, a quarter of rollups, a year of run-level summaries — costs almost nothing and answers all three.

Sampling is the other lever, and it needs care in a spatial context. Uniform sampling of successful units is safe: a tenth of them still characterises the distribution. Sampling failures is never safe, because they are rare by construction and each one is evidence. The rule that works is to keep every failure, every rollup, and a sample of successes, which keeps the volume proportional to how much is going wrong rather than to how much work was done.

Making the records queryable without a platform

It is tempting to conclude that structured logs require a log platform. They do not. A directory of newline-delimited JSON files is queryable with tools already on the machine, and for a batch pipeline that is frequently enough.

jq handles filtering and aggregation directly:

# Failure counts by CRS pair, across a run
jq -r 'select(.event=="reproject_failed") | "\(.src_crs) -> \(.dst_crs)"' run.jsonl \
  | sort | uniq -c | sort -rn

# The slowest twenty units, with their source
jq -r 'select(.duration_ms) | [.duration_ms, .src] | @tsv' run.jsonl \
  | sort -rn | head -20

# Total wall clock accounted for, by event type
jq -r 'select(.duration_ms) | [.event, .duration_ms] | @tsv' run.jsonl \
  | awk -F'\t' '{sum[$1]+=$2} END {for (k in sum) print sum[k]/1000"s", k}' | sort -rn

For anything larger, DuckDB reads newline-delimited JSON directly and gives you SQL over it without an ingest step, which covers the middle ground between jq and a hosted platform comfortably.

The reason this matters is that it removes the excuse. A team that would have to stand up a log platform before structured logging pays off will keep printing sentences; a team that can answer its first question with a one-line jq invocation will keep the records.

What not to put in a record

Three categories cause trouble, and all three are easy to add without thinking.

Anything unbounded — a geometry, a full traceback, a list of every feature id in a chunk — turns a record into a document. The bounding box, the exception class, and a count are what a query needs; the rest belongs in a dead-letter store if it is needed at all.

Anything secret, obviously, but the non-obvious cases are the ones that leak: a signed URL contains a credential in its query string, and a connection string contains a password. Redacting at the formatter rather than at each call site is what makes this reliable, because a new call site inherits the protection.

Anything derived that a query could compute. Recording both duration_ms and duration_s doubles the field count and creates a chance for them to disagree after a refactor. Record the raw value in one unit, consistently, and let the query do arithmetic.

FAQ

Related

• Logging Spatial Transformation Results to Structured JSON — the same idea applied inside the transform loop.
• Rich Console Output & Progress Bars — the human half of the two streams above.
• Error Handling in Spatial Pipelines — what to do with the failures these records surface.