structlog Is Not logging: The %s Trap

Log lines came out with %s placeholders left unformatted, and in some cases the logging call raised a TypeError instead of logging anything. The cause was muscle memory: writing structlog calls in the logging style.

// 01 — THE SETUP

The project standardized on structlog for structured, JSON-able logs across every module. But in places, the code had been written with the standard-library logging signature.

// 02 — THE SYMPTOM

log.info("processed %s chunks", count)

Output showed a literal processed %s chunks with no substitution, or threw a TypeError when the processor chain tried to handle the printf markers. The logs were either wrong or fatal.

// 03 — THE CULPRIT

The two APIs look the same and aren’t. Standard logging does lazy printf-style interpolation: log.info("processed %s", count) substitutes %s later. structlog expects structured keyword arguments like log.info("event_name", count=count) and treats the first argument as an event key, not a format string. Hand structlog a %s string and there’s nothing to interpolate it; the marker survives to the output, or trips the processor chain.

// 04 — THE FIX

Convert every call to the structured form across all modules:

# before (logging style)
log.info("processed %s chunks for %s", count, source)
# after (structlog style)
log.info("chunks_processed", count=count, source=source)

This is also strictly better: count and source are now queryable fields in the JSON output, not baked into a string.

TAKEAWAYS

• structlog and logging share a method name and nothing else. logging interpolates %s; structlog wants event_key, field=value. Mixing them silently corrupts output or raises.
• Structured logging’s payoff is fields you can filter and query. count=count beats a number embedded in prose.
• When you adopt structlog, audit every log call. The old-style ones don’t error at import; they fail at runtime, one line at a time.

NEXT

• Concept: embeddings explained: from text to cosine similarity.