Una API de pagamentos se cae a las 3 de la mañana. Abres el log y lees "Error processing request". La línea no trae request ID, trae el timestamp en un formato distinto al de los demás eventos y omite el monto que se estaba procesando. No devuelve nada con lo que investigar.

El logging estructurado trata cada evento como un objeto con campos con nombre, en lugar de un string armado a mano. La ganancia aparece al filtrar: "todos los errores de pago del usuario usr_xyz789" se vuelve una consulta indexada.

Una línea JSON por evento

Cada evento ocupa una línea y repite los mismos campos. La herramienta de observabilidad indexa cada campo y acepta filtros cruzados.

{
  "level": "error",
  "timestamp": "2025-12-18T14:30:00.123Z",
  "message": "Failed to process payment",
  "service": "payment-api",
  "request_id": "req_abc123",
  "user_id": "usr_xyz789",
  "error": {
    "name": "PaymentGatewayError",
    "message": "Card declined",
    "stack": "PaymentGateway.ts:45:12"
  },
  "context": {
    "amount": 15000,
    "currency": "BRL",
    "payment_method": "credit_card"
  }
}

El mismo incidente en texto corrido guardaría "Error al procesar pago". El objeto de arriba responde a tres preguntas distintas: errores de pago de ese usuario, rechazos de tarjeta en los últimos cinco minutos, tasa de fallo del gateway X.

Los campos de los que depende el debug

  • level: error, warn, info o debug, con el mismo vocabulario en toda la aplicación. console.log no tiene nivel y no entra en ningún filtro.
  • timestamp: RFC 3339 en UTC. El RFC 3339 fija el formato que las herramientas de log reconocen sin parser propio.
  • service: el microservicio que emitió el evento. En arquitectura distribuida, el mensaje solo no identifica el origen.
  • request_id: el identificador del request, propagado por todo el camino.
  • user_id: el usuario afectado, cuando la operación tiene uno.
  • error: nombre, mensaje y stack trace en un objeto, cada uno en su campo.
  • context: los datos de la operación que explican el error, como monto, moneda y método de pago.

Implementación con pino

Pino emite JSON y serializa campos extra sin costo de concatenación de strings. La documentación de pino describe child() como la forma de fijar contexto por request.

import pino from 'pino'

const logger = pino({
  level: process.env.LOG_LEVEL || 'info',
  formatters: {
    level: (label) => ({ level: label }),
  },
  timestamp: pino.stdTimeFunctions.isoTime,
})

app.use((req, res, next) => {
  req.log = logger.child({
    request_id: crypto.randomUUID(),
    method: req.method,
    url: req.url,
  })

  const start = Date.now()
  res.on('finish', () => {
    req.log.info({
      status_code: res.statusCode,
      duration_ms: Date.now() - start,
    }, 'Request completed')
  })

  next()
})

Toda línea emitida durante el request carga request_id, método y URL. Cuando una alerta nombra un request_id, la búsqueda devuelve la secuencia completa de eventos de esa llamada.

Request ID y trace context

El request_id nace en el borde: el gateway o la API de entrada lee X-Request-Id del header o genera uno nuevo, y lo pasa en cada llamada interna. El W3C Trace Context estandariza esa entrega con los headers traceparent y tracestate, y la misma idea aparece en el modelo de logs de OpenTelemetry.

const requestId = req.headers['x-request-id'] || crypto.randomUUID()

await fetch('http://user-service/api/users', {
  headers: { 'X-Request-Id': requestId },
})

Con Datadog, Elasticsearch o Loki, el filtro por request_id reconstruye la línea de tiempo del request, servicio por servicio.

Qué entra en el log y qué se queda fuera

Entra: error, warning, evento de negocio con peso (pago aprobado, cuenta creada, email enviado) y la duración de queries y respuestas.

Se queda fuera: contraseña, token, número de tarjeta, variable de entorno y el paso a paso de una operación que salió bien. Dato sensible en un log se convierte en un incidente de seguridad más grande que el bug original, porque el log vive mucho tiempo y está copiado en más de un lugar.

// mal
logger.info({ password: user.password, token: jwt })

// bien
logger.info({ user_id: user.id, action: 'login', ip: req.ip })

Niveles en la práctica

Error: una falla que necesita a alguien ahora, con alerta configurada. Warn: comportamiento inesperado que merece investigación sin frenar el sistema. Info: un evento normal del dominio. Debug: detalle de desarrollo, apagado en producción y encendido por variable de entorno durante una investigación.

El log responde qué, la métrica responde cuánto

Un log de error explica el caso. La tasa de errores por endpoint mide la dimensión del problema. El capítulo 6 del Google SRE Book trata latencia, tráfico, errores y saturación como las señales que monitorean un servicio; el capítulo 10 describe la investigación que arranca en los agregados y baja hasta el caso individual. Los dos se apoyan en el mismo request_id.

Referencias