StackPractices
intermediate Por Mathias Paulenko

Structured Logging: logs JSON con campos consistentes

Cómo emitir logs JSON estructurados con campos consistentes para hacerlos consultables. Cubre structlog en Python, Winston, pino, Serilog, niveles de log y agregación.

Visión General

El structured logging emite las entradas de log como objetos JSON con campos fijos en lugar de texto libre. Cada entrada lleva un timestamp, un nivel, un nombre de evento corto y el contexto que importa: user ID, correlation ID, nombre del servicio, duración. El patrón reemplaza print(f"User {user_id} did {action}") por logger.info("user_action", user_id=user_id, action=action), que produce una línea como {"timestamp": "...", "level": "info", "event": "user_action", "user_id": 42, "action": "login"}.

La diferencia se nota a las 3 de la mañana. Con logs de texto tenés que hacer grep por substrings y rezar para que todos hayan escrito el mensaje igual. Los logs estructurados se indexan campo por campo en ELK, Datadog o Splunk, así que level:error AND service:order-service AND order_id:123 devuelve exactamente lo que necesitás. Yo depuré incidentes de pagos donde la única pista confiable era el correlation_id atravesando cinco servicios; sin campos estructurados esa consulta no existe.

Tiene un costo: el JSON se lee peor en una terminal de desarrollo, serializar campos agrega un overhead chico por llamada, y si los nombres de campo se desalinean entre servicios la agregación se vuelve adivinanza. Las secciones siguientes cubren cuándo vale la pena y cómo mantener el costo bajo.

Cuándo Usar

  • Cualquier aplicación en producción cuyos logs terminen en una herramienta de agregación.
  • Microservicios donde una sola request cruza varios procesos y necesitás correlacionar sus entradas (combinalo con un correlation ID).
  • Sistemas donde tenés que filtrar por atributo: tenant, plan, región, feature flag.
  • Entornos regulados que exigen campos auditables específicos en cada entrada.
  • Respuesta a incidentes donde buscar substrings en logs de texto es demasiado lento.

Cuándo NO usarlo

  • Herramientas CLI o scripts puntuales donde un humano lee la salida directamente.
  • Desarrollo local donde print() y la salida bonita de consola se escanean más rápido.
  • Aplicaciones con muy bajo volumen de logs donde el texto alcanza.
  • Targets embebidos donde serializar JSON y el overhead de campos salen caros.

Solución

La receta es la misma en todos los lenguajes: elegí una librería que emita JSON de forma nativa, adjuntá el contexto como campos en lugar de interpolar strings, y dale a cada entrada un nombre de evento estable.

Python con structlog

# Python — structlog para structured logging
import structlog
import logging

# Configurar 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()

# Uso: nombre de evento primero, contexto como 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 con logging estándar + JSON formatter

# Python — logging de stdlib con un formatter JSON
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,
        }

        # Copiar los campos extra adjuntados con 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)

# Uso
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})

Esto funciona sin dependencias, pero el filtrado de record.__dict__ es frágil y el mantenimiento queda de tu lado. Para código nuevo en Python uso structlog por defecto y solo recurro a este patrón cuando no puedo agregar dependencias.

JavaScript con Winston

// JavaScript — Winston para 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',
    }),
  ],
});

// Uso
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 con pino

// JavaScript — pino para structured logging de alto rendimiento
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',
  },
});

// Uso: primero el objeto de metadata, después el mensaje
logger.info({ orderId: 123, customerId: 456, total: 99.99 }, 'order_created');
logger.error({ orderId: 123, reason: 'insufficient_funds' }, 'payment_failed');

// Los child loggers arrastran contexto persistente
const requestLogger = logger.child({ requestId: 'abc-123', userId: 42 });
requestLogger.info('processing request');
requestLogger.info('request completed', { durationMs: 150 });

Pino es el logger mainstream más rápido de Node y su salida por defecto ya es JSON línea por línea, así que casi no necesita configuración para este patrón.

Java con SLF4J + Logstash encoder

// Java — Logback con el 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();
        }
    }
}

Dos detalles que valen la pena: MDC (Mapped Diagnostic Context) inyecta campos por request en cada entrada sin tener que pasarlos por todos lados, y limpiarlo en el finally evita que los valores se filtren a la request siguiente en un hilo de pool.

.NET con Serilog

// C# — Serilog para 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();

// Uso con propiedades nombradas en el message template
Log.Information("Order {OrderId} created for customer {CustomerId} with total {Total}",
    order.Id, order.CustomerId, order.Total);

// Pasá la excepción primero para que Serilog capture el stack trace
Log.Error(ex, "Payment failed for order {OrderId}", order.Id);

// Propiedades con scope via LogContext
using (LogContext.PushProperty("CorrelationId", correlationId))
{
    Log.Information("Processing order {OrderId}", order.Id);
    // Todas las entradas dentro de este scope incluyen CorrelationId
}

Los placeholders {OrderId} no son interpolación para humanos: Serilog los guarda como propiedades JSON de primera clase, así que la salida tiene un campo OrderId consultable.

Log levels y cuándo usarlos

# Python — guía de niveles de log
import structlog
logger = structlog.get_logger()

# DEBUG — diagnóstico detallado, normalmente apagado en producción
logger.debug("cache_hit", key="user:42", ttl=300)

# INFO — eventos operativos normales (request procesada, orden creada)
logger.info("order_created", order_id=123, total=99.99)

# WARNING — inesperado pero no fatal (rate limit cerca, retry necesario)
logger.warning("retry_attempt", attempt=2, max_attempts=3, delay_ms=500)

# ERROR — una falla que alguien debería investigar (pago fallido, error de DB)
logger.error("payment_failed", order_id=123, reason="insufficient_funds")

# CRITICAL — una falla de todo el sistema que requiere acción inmediata
logger.critical("database_unreachable", host="db.example.com", port=5432)

Logging contextual con campos bindeados

# Python — bindear contexto al logger una sola vez
import structlog
logger = structlog.get_logger()

# Bindear contexto por request para no repetirlo en cada llamada
request_logger = logger.bind(
    correlation_id="abc-123",
    user_id=42,
    endpoint="/api/orders",
)

# Todas las entradas siguientes incluyen los campos bindeados
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": "..."}

El contexto bindeado es donde este patrón se paga solo. Bindeá el correlation ID una vez en el middleware y cada línea de log posterior lo lleva, que es también lo que te permite unir los logs con una traza distribuida después.

Integración con ELK

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

filter {
  # Parsear el timestamp de la entrada en vez del de ingestión
  date {
    match => ["timestamp", "ISO8601"]
    target => "@timestamp"
  }

  # Marcar entradas sin campo service
  if ![service] {
    mutate { add_field => { "service" => "unknown" } }
  }
}

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

La línea codec => json hace el trabajo pesado: como cada línea ya es JSON válido, Logstash indexa los campos directo, sin patrones grok que mantener.

Integración con Datadog

# datadog.yaml — recolectar logs estructurados
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: '^\{'

Explicación

El structured logging son en realidad dos decisiones pegadas: emitir salida machine-readable (normalmente JSON línea por línea) y estandarizar el vocabulario de campos. La segunda es la que los equipos se saltan, y es la que determina si las consultas funcionan.

flowchart diagram: Aplicación<br/>entradas JSON

Una entrada recorre un pipeline corto. El logger serializa los campos a una línea JSON en stdout o en un archivo. Un shipper lee el archivo (o scrapea stdout en contenedores) y reenvía lotes al agregador, que indexa cada campo y te permite buscar, alertar y armar dashboards por atributo en vez de por substring.

Hay tres trade-offs. Primero, legibilidad: el JSON crudo es hostil en una terminal, así que la mayoría de los setups dejan un formatter bonito en stdout en desarrollo y pasan a JSON en producción. Segundo, costo: serializar campos en cada llamada es barato pero no gratis, y las escrituras síncronas pueden bloquear un hot path — por eso los servicios de alto throughput encolan los logs de forma asíncrona. Tercero, disciplina de esquema: user_id en un servicio y userId en otro producen dos columnas medio vacías que nadie consulta. Fijá una convención de nombres temprano — snake_case en todos lados es el default menos doloroso — y tratá los campos como una API pública.

Sobre los niveles: existen para subir o bajar el nivel de detalle por entorno sin tocar los call sites. Mantené el set chico (DEBUG, INFO, WARN, ERROR) y hacé del nivel una decisión de filtro, no un debate por llamada. Si estás emitiendo miles de entradas por segundo, el logging asíncrono y el sampling dejan de ser opcionales; ambos están en Variantes.

Por último, los logs estructurados se combinan con el resto de la observabilidad en lugar de reemplazarla. Los logs responden “qué pasó en esta request”, la agregación de métricas responde “con qué frecuencia”, y el tracing responde “a dónde se fue el tiempo”. El correlation ID es el campo que une los tres.

Variantes

Logging asíncrono para alto throughput

# Python — logging sin bloqueo con una queue
import logging
import logging.handlers
import queue

log_queue = queue.Queue(-1)  # tamaño ilimitado

# El handler solo encola; nunca toca disco desde el hilo de la request
queue_handler = logging.handlers.QueueHandler(log_queue)

# Un listener en otro hilo vacía la queue y escribe
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)

# Encola sin bloquear al llamador
logger.info("high_throughput_log", extra={"count": 1000000})

QueueListener saca la I/O del hilo de la request. El trade: si el proceso crashea, lo que quedó en la queue se pierde, así que las entradas de auditoría críticas las mantenés síncronas.

Sampling para logs de alto volumen

// JavaScript — samplear endpoints ruidosos, conservar los que importan
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) {
  // Saltar siempre los health checks; ahogan todo lo demás
  if (req.path === '/health') return;

  // Del resto, conservar 1 de cada 100 a nivel debug más cada error
  requestCount++;
  if (requestCount % 100 === 0) {
    logger.debug({ path: req.path, method: req.method }, 'request_received');
  }
}

El sampling es una perilla de volumen, no un filtro de corrección: conservá siempre los errores y los caminos poco frecuentes pero críticos (pagos, fallos de auth) sin samplear.

Redactar campos sensibles

# Python — redactar campos sensibles antes de serializar
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):
            # Atrapar números de tarjeta colados en cualquier campo string
            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(),
    ],
)

Poné la redacción en la cadena de processors, no en los call sites. Los desarrolladores se olvidan en los call sites; un processor atrapa cada campo, incluidos los que agrega el middleware.

Mejores Prácticas

Para una guía más profunda, mirá Structured Logging: JSON Logs, Correlation IDs, Aggregation.

  • Usá salida JSON en producción para que las herramientas de agregación indexen los campos directo.
  • Adjuntá el contexto como campos en lugar de interpolar: logger.info("order_created", order_id=123), no logger.info("Order 123 created").
  • Estandarizá los nombres de campo entre servicios; user_id en uno y userId en otro anula el punto del patrón.
  • Emití timestamps en ISO 8601 con timezone, por ejemplo 2026-01-15T10:00:00.123Z.
  • Mantené cuatro niveles (DEBUG, INFO, WARN, ERROR) y usalos de forma consistente.
  • Bindeá el contexto de la request (correlation ID, user ID, endpoint) para que cada entrada la lleve.
  • Redactá secretos, tokens y PII en un processor o en la capa de middleware.
  • Pasate a un queue handler cuando el volumen de logs empiece a costar latencia de requests.
  • Logueá en los límites: entrada/salida de servicios, llamadas externas, transiciones de estado.
  • Registrá siempre duration_ms en operaciones con tiempo: convierte los logs en un histograma de latencia de emergencia.

Errores Comunes

  • Interpolación de strings en vez de campos: logger.info(f"User {user_id} logged in") produce texto que no podés consultar por user_id. La forma estructurada es logger.info("user_login", user_id=user_id).
  • Nombres de campo que derivan entre servicios: user_id acá, userId allá. Los agregadores los indexan como campos distintos y las consultas cross-service pierden la mitad de los datos en silencio.
  • Secretos y PII en logs: una contraseña o un número de tarjeta en un log es un incidente de compliance. Redactá de forma centralizada y limpiá strings, no solo keys conocidas.
  • Seis niveles usados de forma inconsistente: cuando cada developer elige un nivel distinto para el mismo tipo de evento, nadie puede armar un filtro de severidad confiable. Cuatro alcanzan.
  • Timestamps faltantes: dejar que el shipper estampe las entradas mete el lag de ingestión en el orden. Emití timestamp dentro de la entrada.
  • Loguear dentro de hot loops: un info dentro de un loop ajustado puede generar gigabytes y ahogar la I/O. Sampleá, agregá o movelo a debug.
  • Loguear y bloquear: una escritura síncrona a un disco lento o a un target de red frena el hilo de la request justo cuando la carga es más alta. Para eso existen las queues asíncronas.

Resumen

  • Emití entradas de log como líneas JSON con campos estables: timestamp, nivel, evento, contexto.
  • Adjuntá el contexto como campos estructurados; nunca lo interpolés en el mensaje.
  • Bindeá el contexto por request (correlation ID, user ID) una vez en el límite.
  • Encolá o sampleá el logging cuando el volumen amenace la latencia de las requests.
  • Fijá una convención de nombres de campo entre servicios antes de publicar.

See Also

Preguntas frecuentes

¿Qué es el structured logging?

Emitir entradas de log como objetos JSON con campos consistentes en lugar de texto libre. Cada entrada tiene un timestamp, nivel, nombre de evento y campos contextuales que las herramientas de agregación indexan y consultan directamente.

¿Por qué logs JSON en vez de texto?

Los logs JSON son machine-parseable, así que agregadores como ELK, Datadog o Splunk pueden indexar cada campo. Eso habilita consultas como level:error AND service:order-service AND order_id:123, algo que la búsqueda por substrings sobre texto no logra de forma confiable.

¿Qué niveles de log debería usar?

DEBUG para diagnóstico de desarrollo, INFO para eventos operativos normales (request procesada, orden creada), WARN para eventos inesperados pero no fatales, ERROR para fallas que valga la pena investigar. Saltate CRITICAL salvo que realmente paginees con él.

¿Cómo mantengo datos sensibles fuera de los logs?

Redactá en un processor o middleware central, no en los call sites. Mantené una lista de keys sensibles (password, token, api_key), reemplazá sus valores con [REDACTED], y limpiá los valores string buscando patrones como números de tarjeta.

¿El structured logging afecta el rendimiento?

Serializar un puñado de campos a JSON cuesta microsegundos por llamada, así que la mayoría de las apps no lo notan. A miles de entradas por segundo pesan más las escrituras que la serialización: usá un queue handler asíncrono y sampleá los caminos ruidosos.

¿Cuándo vale la pena el logging asíncrono?

Cuando el volumen es lo bastante alto para que las escrituras síncronas se noten en la latencia de las requests (típicamente miles de entradas por segundo, o discos lentos). El costo es que un crash pierde lo que quedó encolado, así que las entradas críticas de auditoría se mantienen síncronas.