Mejores Prácticas de Logging Estructurado para Servidores

El logging estructurado transforma los mensajes de log de texto plano en objetos JSON con campos bien definidos, lo que facilita enormemente el procesamiento automatizado, las búsquedas y el análisis en sistemas de agregación de logs. Implementar logging estructurado correctamente desde el principio permite correlacionar eventos entre servicios, detectar anomalías automáticamente y reducir el tiempo de diagnóstico de incidentes en producción.

Requisitos Previos

  • Servidor Linux con cualquier distribución moderna
  • Conocimiento básico del lenguaje de programación de tu aplicación
  • Sistema de agregación de logs (opcional pero recomendado): Loki, Elasticsearch, Graylog

Formato JSON para Logs

El estándar de facto para logging estructurado es JSON. Cada evento de log debe ser un objeto JSON en una sola línea.

// Ejemplo de log estructurado completo
{
  "timestamp": "2024-01-15T14:30:45.123Z",
  "level": "info",
  "service": "api-backend",
  "version": "2.3.1",
  "environment": "produccion",
  "host": "web-01.miempresa.com",
  "request_id": "550e8400-e29b-41d4-a716-446655440000",
  "user_id": "usr_12345",
  "message": "Pedido procesado exitosamente",
  "pedido_id": "ord_67890",
  "importe_eur": 49.99,
  "duracion_ms": 145,
  "metodo_pago": "tarjeta",
  "ip_cliente": "192.168.1.100"
}
# Campos obligatorios en todo log estructurado:
# - timestamp: ISO 8601 en UTC
# - level: debug, info, warning, error, critical
# - service: nombre del servicio que genera el log
# - message: descripción legible del evento

# Campos recomendados:
# - request_id / trace_id: para correlación entre servicios
# - host: servidor que genera el log
# - version: versión del servicio
# - environment: produccion, staging, desarrollo

# Herramienta para validar el formato JSON de los logs
# Instalar jq para procesar JSON desde la línea de comandos
apt install -y jq

# Verificar que los logs son JSON válido
tail -f /var/log/mi_aplicacion/app.log | jq .

# Buscar errores en logs JSON
jq 'select(.level == "error")' /var/log/mi_aplicacion/app.log

Niveles de Log y Cuándo Usarlos

# Guía de uso de cada nivel de log:

# DEBUG: información detallada para diagnóstico en desarrollo
# Deshabilitar en producción por el volumen que genera
# Ejemplo: "Consulta SQL generada: SELECT * FROM usuarios WHERE id=123"

# INFO: eventos normales del ciclo de vida de la aplicación
# Ejemplo: "Servidor iniciado en puerto 8080"
# Ejemplo: "Usuario autenticado: user_id=456"
# Ejemplo: "Email de bienvenida enviado a user_id=456"

# WARNING: situación inesperada pero el sistema continúa funcionando
# Ejemplo: "Intento de login fallido: user=admin (intento 3/5)"
# Ejemplo: "Tiempo de respuesta elevado: 2.3s para /api/pedidos"
# Ejemplo: "Cola de mensajes por encima del 80% de capacidad"

# ERROR: fallo que impide completar una operación específica
# Ejemplo: "Error al procesar pago para pedido ord_789: tarjeta declinada"
# Ejemplo: "Error de conexión a la base de datos (retry 2/3)"
# Incluir siempre: stack trace, IDs relevantes, contexto del error

# CRITICAL: fallo grave que requiere intervención inmediata
# Ejemplo: "No se puede conectar a la base de datos tras 5 intentos"
# Ejemplo: "Disco lleno al 99%, no se pueden escribir logs"
# Estos eventos deben disparar alertas inmediatas

IDs de Correlación y Trazabilidad

# El request_id permite rastrear una petición a través de todos los servicios

# Configurar Nginx para generar y propagar el request_id
cat > /etc/nginx/conf.d/request-id.conf << 'EOF'
# Generar un UUID único por petición
map $request_id $trace_id {
  default $request_id;
}

# Agregar la cabecera a las respuestas (para el cliente)
add_header X-Request-ID $trace_id always;

# Propagar la cabecera a los backends
proxy_set_header X-Request-ID $trace_id;
EOF

# Formato de log JSON para Nginx
cat > /etc/nginx/conf.d/log-format.conf << 'EOF'
log_format json_combined escape=json
  '{'
    '"timestamp":"$time_iso8601",'
    '"level":"info",'
    '"service":"nginx",'
    '"request_id":"$request_id",'
    '"metodo":"$request_method",'
    '"ruta":"$uri",'
    '"estado":$status,'
    '"bytes_enviados":$body_bytes_sent,'
    '"duracion_ms":$request_time,'
    '"ip_cliente":"$remote_addr",'
    '"user_agent":"$http_user_agent",'
    '"referer":"$http_referer"'
  '}';

access_log /var/log/nginx/access.log json_combined;
error_log /var/log/nginx/error.log warn;
EOF

Enriquecimiento de Contexto

# El enriquecimiento agrega campos automáticamente a todos los logs
# sin necesidad de especificarlos en cada llamada al logger

# Ejemplo con Python (usando structlog)
pip install structlog

cat > /opt/mi_app/logging_config.py << 'PYTHON'
import structlog
import logging
import socket
import os
from datetime import datetime, timezone

def configurar_logging():
    """Configurar logging estructurado con campos de contexto automáticos."""
    
    # Procesadores que se aplican a cada log
    procesadores = [
        # Agregar campos de contexto automáticos
        structlog.contextvars.merge_contextvars,
        
        # Agregar el nombre del logger
        structlog.stdlib.add_logger_name,
        
        # Agregar el nivel de log
        structlog.stdlib.add_log_level,
        
        # Agregar timestamp en ISO 8601 UTC
        structlog.processors.TimeStamper(fmt="iso", utc=True),
        
        # Formatear el stack trace como string
        structlog.processors.format_exc_info,
        
        # Salida en JSON
        structlog.processors.JSONRenderer()
    ]
    
    structlog.configure(
        processors=procesadores,
        wrapper_class=structlog.stdlib.BoundLogger,
        context_class=dict,
        logger_factory=structlog.stdlib.LoggerFactory(),
        cache_logger_on_first_use=True,
    )
    
    # Configurar el logger raíz para que use structlog
    logging.basicConfig(
        format="%(message)s",
        level=logging.INFO,
    )

# Contexto global (se agrega a todos los logs del proceso)
structlog.contextvars.bind_contextvars(
    service="api-backend",
    version=os.getenv("APP_VERSION", "unknown"),
    environment=os.getenv("ENVIRONMENT", "produccion"),
    host=socket.gethostname(),
)
PYTHON

# Uso en la aplicación:
cat > /opt/mi_app/ejemplo_uso.py << 'PYTHON'
import structlog
from logging_config import configurar_logging

configurar_logging()
logger = structlog.get_logger()

def procesar_pedido(pedido_id: str, usuario_id: str):
    # Agregar contexto específico de la operación
    log = logger.bind(pedido_id=pedido_id, usuario_id=usuario_id)
    
    log.info("Inicio de procesamiento de pedido")
    
    try:
        # ... lógica del pedido ...
        importe = calcular_importe(pedido_id)
        
        log.info("Pedido procesado", importe_eur=importe, duracion_ms=145)
        
    except Exception as e:
        # El stack trace se incluye automáticamente
        log.error("Error al procesar pedido", 
                  error_type=type(e).__name__,
                  error_message=str(e),
                  exc_info=True)
        raise
PYTHON

Logging en Diferentes Lenguajes

# Node.js con pino (el más rápido para logging estructurado)
npm install pino pino-pretty

cat > logger.js << 'JAVASCRIPT'
const pino = require('pino');

const logger = pino({
  level: process.env.LOG_LEVEL || 'info',
  base: {
    service: 'api-backend',
    version: process.env.npm_package_version,
    environment: process.env.NODE_ENV || 'produccion',
    host: require('os').hostname(),
  },
  timestamp: pino.stdTimeFunctions.isoTime,
  formatters: {
    level: (label) => ({ level: label }),
  },
});

// Crear un logger hijo con contexto de la petición
function crearLoggerDePeticion(requestId, userId) {
  return logger.child({ request_id: requestId, user_id: userId });
}

module.exports = { logger, crearLoggerDePeticion };
JAVASCRIPT
# Go con zerolog o zap
go get github.com/rs/zerolog

cat > logging.go << 'GO'
package logging

import (
    "os"
    "time"
    
    "github.com/rs/zerolog"
    "github.com/rs/zerolog/log"
)

func Inicializar() {
    // Usar timestamp Unix en milisegundos para mayor precisión
    zerolog.TimeFieldFormat = time.RFC3339Nano
    
    // Logger de producción en JSON (en desarrollo usar ConsoleWriter)
    log.Logger = zerolog.New(os.Stdout).
        With().
        Timestamp().
        Str("service", "api-backend").
        Str("environment", os.Getenv("ENVIRONMENT")).
        Str("host", os.Getenv("HOSTNAME")).
        Logger()
}

// Uso:
// log.Info().
//     Str("request_id", requestID).
//     Str("user_id", userID).
//     Int64("duracion_ms", duracion).
//     Msg("Pedido procesado")
GO

Configuración del Sistema Operativo

# Configurar journald para almacenar logs estructurados eficientemente
cat > /etc/systemd/journald.conf << 'EOF'
[Journal]
# Tamaño máximo del journal en disco
SystemMaxUse=2G

# Retención máxima de logs
MaxRetentionSec=2week

# Comprimir los logs almacenados
Compress=yes

# Almacenamiento persistente (no solo en RAM)
Storage=persistent

# Tamaño máximo de cada archivo de journal
SystemMaxFileSize=100M
EOF

systemctl restart systemd-journald

# Exportar logs del journal en formato JSON (para enviar a sistemas de agregación)
journalctl -o json-pretty --since="1 hour ago" | head -50

# Stream de logs en JSON para procesamiento en tiempo real
journalctl -f -o json | jq '{
  timestamp: .REALTIME_TIMESTAMP,
  level: (._PRIORITY | tonumber | 
    if . <= 2 then "critical"
    elif . == 3 then "error"
    elif . == 4 then "warning"
    elif . == 5 then "notice"
    elif . == 6 then "info"
    else "debug" end),
  service: .SYSLOG_IDENTIFIER,
  message: .MESSAGE,
  pid: .SYSLOG_PID
}'

Integración con Sistemas de Agregación

# Configurar Vector (alternativa moderna a Filebeat) para enviar logs JSON a Loki
curl --proto '=https' --tlsv1.2 -sSf https://sh.vector.dev | bash

cat > /etc/vector/vector.toml << 'EOF'
[sources.mi_aplicacion]
type = "file"
include = ["/var/log/mi_aplicacion/*.log"]
data_dir = "/var/lib/vector"

# Parsear logs JSON
[transforms.parsear_json]
type = "remap"
inputs = ["mi_aplicacion"]
source = '''
. = parse_json!(.message)
# Asegurarse de que el timestamp está en formato correcto
.timestamp = parse_timestamp!(.timestamp, format: "%+")
'''

# Filtrar logs de DEBUG en producción
[transforms.filtrar_debug]
type = "filter"
inputs = ["parsear_json"]
condition = '.level != "debug"'

# Enviar a Loki
[sinks.loki]
type = "loki"
inputs = ["filtrar_debug"]
endpoint = "http://loki:3100"
labels.job = "mi_aplicacion"
labels.environment = "{{ .environment }}"
labels.service = "{{ .service }}"
labels.level = "{{ .level }}"
encoding.codec = "json"

# Enviar errores a Elasticsearch simultáneamente
[sinks.elasticsearch_errores]
type = "elasticsearch"
inputs = ["filtrar_debug"]
endpoints = ["http://elasticsearch:9200"]
index = "logs-errores-%Y.%m.%d"
condition = '.level == "error" or .level == "critical"'
EOF

systemctl enable vector && systemctl start vector

Solución de Problemas

Los logs JSON tienen saltos de línea internos:

# Los logs deben ser una línea por evento (JSON en una sola línea)
# Para limpiar logs con saltos de línea:
jq -c . /var/log/mi_aplicacion/app.log > /tmp/app-cleaned.log

# Configurar la aplicación para usar el modo compacto de JSON
# En Python con structlog:
# structlog.processors.JSONRenderer(sort_keys=True)  # Ya genera línea única

# En Node.js con pino:
# pino ya genera una línea por evento por defecto

Los logs tienen demasiados campos de alta cardinalidad:

# Revisar qué campos tienen muchos valores únicos (evitar como labels en Loki)
# Campos de ALTA cardinalidad (NO usar como labels):
# - user_id (millones de usuarios)
# - request_id (único por petición)
# - ip_cliente (muchas IPs distintas)

# Campos de BAJA cardinalidad (buenos como labels):
# - level (debug/info/warning/error/critical)
# - service (pocos servicios)
# - environment (produccion/staging/dev)
# - status_code (200/400/500 - pocos valores)

Conclusión

El logging estructurado con JSON es una inversión que se amortiza rápidamente cuando surge el primer incidente en producción: poder filtrar por usuario_id, correlacionar peticiones entre servicios mediante request_id o calcular métricas derivadas de los logs directamente desde el sistema de agregación transforma el proceso de diagnóstico de horas a minutos. Adoptar un formato consistente en todos los servicios desde el principio, con campos bien definidos y niveles de log correctamente utilizados, es una de las mejores prácticas de observabilidad que cualquier equipo puede implementar.