Structured Logging: Emit JSON Logs with Consistent Fields

Overview

Structured logging emits log entries as JSON objects with fixed fields instead of free-form text. Every entry carries a timestamp, a level, a short event name, and whatever context matters: user ID, correlation ID, service name, duration. The pattern replaces print(f"User {user_id} did {action}") with logger.info("user_action", user_id=user_id, action=action), which produces a line like {"timestamp": "...", "level": "info", "event": "user_action", "user_id": 42, "action": "login"}.

The payoff shows up at 3 a.m. Text logs force you to grep for substrings and hope everyone spelled the message the same way. Structured logs are indexed field by field in ELK, Datadog, or Splunk, so level:error AND service:order-service AND order_id:123 returns exactly what you need. I’ve debugged payment incidents where the only reliable lead was correlation_id glued across five services; without structured fields that query wouldn’t exist.

There’s a cost: JSON output is harder to read on a dev laptop, serializing fields adds a small per-call overhead, and if field names drift between services the aggregation side turns into guesswork. The sections below cover when that trade is worth it and how to keep it cheap.

When to Use

• Any production application whose logs end up in an aggregation tool.
• Microservices where a single request crosses several processes and you need to correlate its entries (pair this with a correlation ID).
• Systems where you must filter by attribute: tenant, plan, region, feature flag.
• Regulated environments that require specific auditable fields in every entry.
• Incident response where substring search on text logs is too slow to be useful.

When NOT to Use

• CLI tools and one-off scripts where a human reads the output directly.
• Local development where print() and pretty console output are faster to scan.
• Applications with very low log volume where text logs are already enough.
• Embedded targets where JSON serialization and field overhead are too expensive.

Solution

The recipe is the same in every language: pick a library that emits JSON natively, attach context as fields instead of interpolating strings, and give every entry a stable event name.

Python with structlog

# Python — structlog for structured logging
import structlog
import logging

# Configure structlog
structlog.configure(
    processors=[
        structlog.stdlib.filter_by_level,
        structlog.stdlib.add_logger_name,
        structlog.stdlib.add_log_level,
        structlog.stdlib.PositionalArgumentsFormatter(),
        structlog.processors.TimeStamper(fmt="iso"),
        structlog.processors.StackInfoRenderer(),
        structlog.processors.format_exc_info,
        structlog.processors.JSONRenderer(),
    ],
    wrapper_class=structlog.stdlib.BoundLogger,
    logger_factory=structlog.stdlib.LoggerFactory(),
    cache_logger_on_first_use=True,
)

logger = structlog.get_logger()

# Usage: event name first, context as keyword arguments
logger.info("user_login", user_id=42, ip_address="192.168.1.1", method="oauth")
logger.error("payment_failed", order_id=123, reason="insufficient_funds", amount=99.99)
logger.warning("rate_limit_approaching", endpoint="/api/orders", current_rate=95, limit=100)

# Output:
# {"event": "user_login", "user_id": 42, "ip_address": "192.168.1.1",
#  "method": "oauth", "level": "info", "timestamp": "2026-01-15T10:00:00Z"}

Python with standard logging + JSON formatter

# Python — stdlib logging with a JSON formatter
import logging
import json
from datetime import datetime, timezone

class JsonFormatter(logging.Formatter):
    def format(self, record):
        log_entry = {
            "timestamp": datetime.now(timezone.utc).isoformat(),
            "level": record.levelname.lower(),
            "message": record.getMessage(),
            "logger": record.name,
        }

        # Copy extra fields attached via logger.info(..., extra={...})
        for key, value in record.__dict__.items():
            if key not in ("name", "msg", "args", "levelname", "levelno",
                          "pathname", "filename", "module", "exc_info",
                          "exc_text", "stack_info", "lineno", "funcName",
                          "created", "msecs", "relativeCreated", "thread",
                          "threadName", "processName", "process", "message"):
                log_entry[key] = value

        if record.exc_info:
            log_entry["exception"] = self.formatException(record.exc_info)

        return json.dumps(log_entry, default=str)

# Setup
handler = logging.StreamHandler()
handler.setFormatter(JsonFormatter())
logger = logging.getLogger("myapp")
logger.addHandler(handler)
logger.setLevel(logging.INFO)

# Usage
logger.info("Order created", extra={"order_id": 123, "customer_id": 456, "total": 99.99})
logger.error("Database connection failed", extra={"host": "db.example.com", "port": 5432})

This works with zero dependencies, but record.__dict__ filtering is fragile and you own the maintenance. For new Python code I default to structlog and only reach for this pattern when dependencies are off the table.

JavaScript with Winston

// JavaScript — Winston structured logging
const winston = require('winston');

const logger = winston.createLogger({
  level: process.env.LOG_LEVEL || 'info',
  format: winston.format.combine(
    winston.format.timestamp(),
    winston.format.errors({ stack: true }),
    winston.format.json()
  ),
  defaultMeta: {
    service: 'order-service',
    version: '1.0.0',
    environment: process.env.NODE_ENV || 'development',
  },
  transports: [
    new winston.transports.Console(),
    new winston.transports.File({
      filename: 'logs/error.log',
      level: 'error',
    }),
    new winston.transports.File({
      filename: 'logs/combined.log',
    }),
  ],
});

// Usage
logger.info('order_created', {
  orderId: 123,
  customerId: 456,
  total: 99.99,
  items: 3,
});

logger.error('payment_failed', {
  orderId: 123,
  reason: 'insufficient_funds',
  amount: 99.99,
  paymentMethod: 'credit_card',
});

logger.warn('rate_limit_warning', {
  endpoint: '/api/orders',
  currentRate: 95,
  limit: 100,
  windowMs: 60000,
});

JavaScript with pino

// JavaScript — pino for high-throughput structured logging
const pino = require('pino');

const logger = pino({
  level: process.env.LOG_LEVEL || 'info',
  timestamp: pino.stdTimeFunctions.isoTime,
  formatters: {
    level: (label) => ({ level: label }),
  },
  base: {
    service: 'order-service',
    version: '1.0.0',
  },
});

// Usage: metadata object first, message second
logger.info({ orderId: 123, customerId: 456, total: 99.99 }, 'order_created');
logger.error({ orderId: 123, reason: 'insufficient_funds' }, 'payment_failed');

// Child loggers carry persistent context
const requestLogger = logger.child({ requestId: 'abc-123', userId: 42 });
requestLogger.info('processing request');
requestLogger.info('request completed', { durationMs: 150 });

Pino is the fastest mainstream Node logger and its default output is already newline-delimited JSON, so it needs almost no configuration for this pattern.

Java with SLF4J + Logstash encoder

// Java — Logback with the Logstash JSON encoder
// pom.xml: net.logstash.logback:logstash-logback-encoder

// logback.xml
/*
<configuration>
  <appender name="JSON" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="net.logstash.logback.encoder.LogstashEncoder">
      <customFields>{"service":"order-service","version":"1.0.0"}</customFields>
    </encoder>
  </appender>
  <root level="INFO">
    <appender-ref ref="JSON" />
  </root>
</configuration>
*/

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;

public class OrderService {
    private static final Logger logger = LoggerFactory.getLogger(OrderService.class);

    public void createOrder(OrderRequest request) {
        MDC.put("orderId", String.valueOf(request.getOrderId()));
        MDC.put("customerId", String.valueOf(request.getCustomerId()));

        logger.info("order_created total={} items={}",
            request.getTotal(), request.getItems().size());

        try {
            processPayment(request);
            logger.info("payment_successful amount={}", request.getTotal());
        } catch (PaymentException e) {
            logger.error("payment_failed reason={} amount={}",
                e.getReason(), request.getTotal(), e);
        } finally {
            MDC.clear();
        }
    }
}

Two details worth noting: MDC (Mapped Diagnostic Context) injects per-request fields into every entry without passing them around, and clearing it in finally prevents values from leaking into the next request on a pooled thread.

.NET with Serilog

// C# — Serilog structured logging
using Serilog;
using Serilog.Formatting.Json;

Log.Logger = new LoggerConfiguration()
    .Enrich.WithProperty("Service", "order-service")
    .Enrich.WithProperty("Version", "1.0.0")
    .Enrich.FromLogContext()
    .WriteTo.Console(new JsonFormatter())
    .WriteTo.File(new JsonFormatter(), "logs/app.log")
    .CreateLogger();

// Usage with named message-template properties
Log.Information("Order {OrderId} created for customer {CustomerId} with total {Total}",
    order.Id, order.CustomerId, order.Total);

// Pass the exception first so Serilog captures the stack trace
Log.Error(ex, "Payment failed for order {OrderId}", order.Id);

// Scoped properties via LogContext
using (LogContext.PushProperty("CorrelationId", correlationId))
{
    Log.Information("Processing order {OrderId}", order.Id);
    // Every entry inside this scope includes CorrelationId
}

The {OrderId} placeholders aren’t interpolation for humans: Serilog stores them as first-class JSON properties, so the output has an OrderId field you can query.

Log levels and when to use them

# Python — log level guidelines
import structlog
logger = structlog.get_logger()

# DEBUG — detailed diagnostics, usually off in production
logger.debug("cache_hit", key="user:42", ttl=300)

# INFO — normal operational events (request processed, order created)
logger.info("order_created", order_id=123, total=99.99)

# WARNING — unexpected but not fatal (rate limit near, retry needed)
logger.warning("retry_attempt", attempt=2, max_attempts=3, delay_ms=500)

# ERROR — a failure someone should investigate (payment failed, DB error)
logger.error("payment_failed", order_id=123, reason="insufficient_funds")

# CRITICAL — a system-wide failure needing immediate action
logger.critical("database_unreachable", host="db.example.com", port=5432)

Contextual logging with bound fields

# Python — bind context to a logger once
import structlog
logger = structlog.get_logger()

# Bind per-request context so you don't repeat it in every call
request_logger = logger.bind(
    correlation_id="abc-123",
    user_id=42,
    endpoint="/api/orders",
)

# Every subsequent entry includes the bound fields
request_logger.info("request_started")
request_logger.info("db_query_executed", query="SELECT * FROM orders", duration_ms=15)
request_logger.info("request_completed", status_code=200, duration_ms=150)

# Output:
# {"correlation_id": "abc-123", "user_id": 42, "endpoint": "/api/orders",
#  "event": "request_started", "level": "info", "timestamp": "..."}

Bound context is where this pattern pays for itself. Bind the correlation ID once at the middleware layer and every downstream log line carries it, which is also what lets you stitch logs together with a distributed trace later.

ELK integration

# logstash.conf — Logstash pipeline syntax (not YAML)
input {
  file {
    path => "/var/log/myapp/*.log"
    codec => json
    start_position => "beginning"
  }
}

filter {
  # Parse the entry's own timestamp instead of ingest time
  date {
    match => ["timestamp", "ISO8601"]
    target => "@timestamp"
  }

  # Tag entries that lack a service field
  if ![service] {
    mutate { add_field => { "service" => "unknown" } }
  }
}

output {
  elasticsearch {
    hosts => ["http://elasticsearch:9200"]
    index => "myapp-logs-%{+YYYY.MM.dd}"
  }
}

The codec => json line does the heavy lifting: because each line is already valid JSON, Logstash indexes fields directly with no grok patterns to maintain.

Datadog integration

# datadog.yaml — collect structured logs
logs:
  - type: file
    path: "/var/log/myapp/*.log"
    service: "order-service"
    source: "python"
    sourcecategory: "sourcecode"
    log_processing_rules:
      - type: multi_line
        name: "json_logs"
        pattern: '^\{'

Explanation

Structured logging is really two decisions glued together: emit machine-readable output (usually newline-delimited JSON) and standardize the field vocabulary. The second part is the one teams skip, and it’s the part that determines whether queries work.

An entry travels a short pipeline. The logger serializes fields to a JSON line on stdout or to a file. A shipper tails the file (or scrapes stdout in containers) and forwards batches to the aggregator, which indexes each field and lets you search, alert, and dashboard by attribute instead of by substring.

Three trade-offs come with it. First, readability: raw JSON is hostile in a terminal, so most setups keep a pretty formatter on stdout in development and switch to JSON in production. Second, cost: serializing fields on every call is cheap but not free, and synchronous writes can block a hot path, which is why high-throughput services queue logs asynchronously. Third, schema discipline: user_id in one service and userId in another produces two half-empty columns nobody queries. Fix a naming convention early — snake_case everywhere is the least painful default — and treat fields like a public API.

On levels: they exist so you can raise or lower verbosity per environment without touching call sites. Keep the set small (DEBUG, INFO, WARN, ERROR) and make level a filter decision, not a per-call debate. If you’re emitting thousands of entries per second, async logging and sampling stop being optional; both are shown under Variants.

Finally, structured logs compose with the rest of observability rather than replacing it. Logs answer “what happened on this request,” metrics aggregation answers “how often,” and tracing answers “where the time went.” The correlation ID is the field that ties all three together.

Variants

Async logging for high throughput

# Python — non-blocking logging with a queue
import logging
import logging.handlers
import queue

log_queue = queue.Queue(-1)  # unlimited size

# The handler just enqueues; it never touches disk from the request thread
queue_handler = logging.handlers.QueueHandler(log_queue)

# A listener on a separate thread drains the queue and writes
file_handler = logging.FileHandler("app.log")
file_handler.setFormatter(JsonFormatter())

listener = logging.handlers.QueueListener(log_queue, file_handler)
listener.start()

logger = logging.getLogger("myapp")
logger.addHandler(queue_handler)
logger.setLevel(logging.INFO)

# Enqueues without blocking the caller
logger.info("high_throughput_log", extra={"count": 1000000})

QueueListener moves the I/O off the request thread. The trade: if the process crashes, whatever was still in the queue is lost, so keep critical audit entries synchronous.

Sampling for high-volume logs

// JavaScript — sample noisy endpoints, keep signal endpoints
const pino = require('pino');

const logger = pino({
  level: 'debug',
  timestamp: pino.stdTimeFunctions.isoTime,
  base: { service: 'api' },
}, pino.destination({ sync: false }));

let requestCount = 0;
function logRequest(req) {
  // Always skip health checks; they drown everything else out
  if (req.path === '/health') return;

  // Of the rest, keep 1 in 100 at debug level plus every error
  requestCount++;
  if (requestCount % 100 === 0) {
    logger.debug({ path: req.path, method: req.method }, 'request_received');
  }
}

Sampling is a volume knob, not a filter for correctness: always keep errors, and keep rare-but-critical paths (payments, auth failures) unsampled.

Redacting sensitive fields

# Python — redact sensitive fields before serialization
import structlog
import re

def redact_sensitive(processor, logger, event_dict):
    sensitive_keys = {"password", "token", "api_key", "credit_card", "ssn"}
    for key in list(event_dict.keys()):
        if key.lower() in sensitive_keys:
            event_dict[key] = "[REDACTED]"
        elif isinstance(event_dict[key], str):
            # Catch card numbers that leaked into any string field
            event_dict[key] = re.sub(
                r'\b\d{4}[-\s]?\d{4}[-\s]?\d{4}[-\s]?\d{4}\b',
                '[REDACTED]',
                event_dict[key],
            )
    return event_dict

structlog.configure(
    processors=[
        structlog.stdlib.add_log_level,
        structlog.processors.TimeStamper(fmt="iso"),
        redact_sensitive,
        structlog.processors.JSONRenderer(),
    ],
)

Put redaction in the processor chain, not at call sites. Developers will forget at call sites; a processor catches every field, including ones added by middleware.

Best Practices

For a deeper guide, see Structured Logging: JSON Logs, Correlation IDs, Aggregation.

• Use JSON output in production so aggregation tools can index fields directly.
• Attach context as fields instead of interpolating: logger.info("order_created", order_id=123), not logger.info("Order 123 created").
• Standardize field names across services; user_id in one and userId in another defeats the point.
• Emit timestamps in ISO 8601 with timezone, e.g. 2026-01-15T10:00:00.123Z.
• Keep four levels (DEBUG, INFO, WARN, ERROR) and use them consistently.
• Bind request context (correlation ID, user ID, endpoint) so every entry for a request carries it.
• Redact secrets, tokens, and PII in a processor or middleware layer.
• Switch to a queue handler when log volume starts costing request latency.
• Log at boundaries: entry/exit of services, external calls, state transitions.
• Always record duration_ms for timed operations — it turns logs into a poor-man’s latency histogram.

Common Mistakes

• String interpolation instead of fields: logger.info(f"User {user_id} logged in") produces text you can’t query by user_id. The structured form is logger.info("user_login", user_id=user_id).
• Field names that drift between services: user_id here, userId there. Aggregators index them as different fields and cross-service queries silently miss half the data.
• Secrets and PII in logs: a password or card number in a log is a compliance incident. Redact centrally and scrub strings, not just known keys.
• Six levels used inconsistently: when every developer picks a different level for the same kind of event, nobody can set a reliable severity filter. Four is enough.
• Missing timestamps: letting the shipper stamp entries inserts ingestion lag into ordering. Emit timestamp in the entry itself.
• Logging inside hot loops: an info call inside a tight loop can generate gigabytes and throttle I/O. Sample, aggregate, or move it to debug.
• Logging and blocking: a synchronous write to a slow disk or network target stalls the request thread exactly when load is highest. That’s the failure mode async queues exist for.

Summary

• Emit log entries as JSON lines with stable fields: timestamp, level, event, context.
• Attach context as structured fields; never interpolate it into the message.
• Bind per-request context (correlation ID, user ID) once at the boundary.
• Queue or sample logging when volume threatens request latency.
• Fix a field-naming convention across services before you ship.

See Also

• structlog documentation — the Python reference for this pattern
• pino documentation — fastest mainstream Node.js logger, JSON by default
• Logstash Logback encoder — JSON output for SLF4J/Logback
• OpenTelemetry Logs — the emerging standard that correlates logs with traces