32  23. Necesitamos ver qué está pasando sin estar mirando

Sin logs, «algo falla a veces» es todo lo que sabrás jamás

Parte 5 — Robustez
NotaEn una frase

En producción no hay consola que mirar ni breakpoint que poner: cuando un usuario dice “a veces falla”, tu única ventana es lo que la app escribió. Logging real no es console.log suelto: son líneas estructuradas con request_id que te dejan reconstruir un request completo a las 3am sin despertar a nadie.

32.1 El problema

“El guardado falló ayer a las 15:14 con un usuario de Argentina.” Sin logs esa frase es el fin de la investigación. Con logs malos — print("aqui"), console.log(err) sin contexto — es peor: miles de líneas que no responden quién, qué endpoint, cuánto tardó, qué falló. El problema no es que falle; es que no puedas ver por qué.

Un log es el diario del programa: qué pasó, cuándo, con qué request. Estructurado = en JSON con campos (request_id, user_id), para filtrar por máquina y no con los ojos.

32.2 Cómo lo resuelve un equipo

Un equipo serio trata los logs como la fuente de datos de la verdad operativa: cada request genera un request_id al entrar, todas las líneas de ese request lo llevan, y cada línea es un objeto JSON que una máquina puede filtrar (request_id="r_9x", level="error", duration_ms>1000). Tres preguntas guían qué loguear: ¿quién (user_id, request_id), qué (endpoint, acción, resultado), cuánto (duración, tamaño). Y una regla que no se negocia: passwords, tokens y datos personales jamás tocan un log.

Un objeto es una colección de datos con nombre: {name: "Ana", age: 30} — cada dato es una propiedad (clave → valor). Python los llama dict, Go los arma con struct, TS con objetos/interface.

Un token es una credencial portable: una cadena que dice quién eres y hasta cuándo. El servidor la emite tras el login; el cliente la presenta en cada request en vez de la contraseña.

32.3 Conceptos nuevos

  • U Logging real: niveles, por qué print/console.log no es logging
  • TS pino/winston · Py logging · Go log/slog — estructurado gratis en stdlib
  • U Qué loguear y qué NUNCA loguear (passwords, tokens, datos personales)
  • U Logs estructurados (JSON): producción parsea logs, no los lee
  • U Request ID propagado por middleware en los tres

32.4 La explicación visual

Un request deja una huella rastreable — todas sus líneas comparten el mismo request_id:

{"ts":"...","level":"info","request_id":"r_9x2","msg":"request started","method":"POST","path":"/tasks","user_id":42}
{"ts":"...","level":"info","request_id":"r_9x2","msg":"task created","task_id":"t_77","duration_ms":14}
{"ts":"...","level":"error","request_id":"r_9x2","msg":"notify failed","service":"slack","duration_ms":3012}
{"ts":"...","level":"info","request_id":"r_9x2","msg":"request done","status":201,"duration_ms":3050}

Filtrar request_id=r_9x2 = reconstruir la película completa. Eso es lo que convierte “a veces falla” en “Slack tardó 3s y el timeout saltó”.

32.5 Implementación

Middleware que genera el request_id + log estructurado por request:

import pino from "pino";
const logger = pino();                            // JSON to stdout by default

app.use((req, res, next) => {
  req.id = crypto.randomUUID();
  const start = Date.now();
  res.on("finish", () =>
    logger.info({ request_id: req.id, method: req.method, path: req.path,
                  status: res.statusCode, duration_ms: Date.now() - start },
                "request done"));
  next();
});
// in the service: logger.error({ request_id: req.id, err }, "task failed")
import logging, json, uuid, time

class JsonFormatter(logging.Formatter):
    def format(self, record):
        return json.dumps({"ts": self.formatTime(record), "level": record.levelname,
                           "msg": record.getMessage(), **getattr(record, "ctx", {})})

@app.middleware("http")
async def log_requests(request, call_next):
    request.state.request_id = str(uuid.uuid4())
    start = time.time()
    response = await call_next(request)
    logger.info("request done", extra={"ctx": {
        "request_id": request.state.request_id, "method": request.method,
        "path": request.url.path, "status": response.status_code,
        "duration_ms": int((time.time() - start) * 1000)}})
    return response
func logging(next http.Handler) http.Handler {
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
        rid := uuid.NewString()
        ctx := context.WithValue(r.Context(), reqIDKey, rid)
        start := time.Now()
        rw := &statusWriter{ResponseWriter: w, status: 200}
        next.ServeHTTP(rw, r.WithContext(ctx))
        slog.Info("request done", "request_id", rid, "method", r.Method,
                  "path", r.URL.Path, "status", rw.status,
                  "duration_ms", time.Since(start).Milliseconds())
    })
}
// slog.New(slog.NewJSONHandler(os.Stdout, nil)) — structured out of the box
Agrega logging estructurado a mi API [Express/FastAPI/net-http].
Requisitos: middleware que genere request_id por request y lo propague
a todos los logs de ese request, formato JSON a stdout con
ts/level/method/path/status/duration_ms, niveles usados correctamente
(info para requests, error para fallos con el error serializado), y una
lista de campos que NUNCA se loguean (password, tokens, Authorization
header, body completo de /auth/*). Dame el middleware + ejemplo de uso
en un servicio.

32.6 ¿Por qué cada stack lo hace así?

Lo único que necesitas llevarte: el patrón es uno — id por request, contexto en cada línea, JSON que las máquinas filtran. pino, logging y slog son tres caras de la misma necesidad: producción parsea logs, no los lee.

Niveles = para quién es la línea: debug (tú, desarrollando), info (hechos normales que importan: request done, job encolado), warn (anómalo pero manejado: retry, degradación), error (algo se rompió y alguien debe mirarlo). Si todo es error, nada es alarma.

Nunca en un log: passwords, tokens/JWT, header Authorization, números de tarjeta, payloads completos de auth — un log filtrado es un incidente de seguridad, no solo feo. Se loguea user_id, no email; token present, no el token.

Más allá de logs (de crecer): métricas (números en el tiempo → alarmas), tracing (el viaje del request entre servicios) — decisión 23 del Ap. K. Los logs son la base: gratis, inmediatos, y suficientes durante mucho tiempo.

32.7 Errores comunes

Error Por qué pasa Fix
print/console.log en prod Es lo que funciona en dev Logger con niveles + formato — stdout es la interfaz, no el print
Loguear el body completo “Para debuguear” Secretos y PII en texto plano → loguea campos elegidos
Líneas sin contexto logger.error(err) suelto Siempre request_id + la acción — una línea debe contar su historia sola
Nivel error para todo “Para que se vea” Alarmas que lloran lobo: nadie mira errores que son normales
Puntos suspensivos en el medio logger.info("creando...") y nada más Log de resultado (created/failed) con duración — el intento sin cierre es ruido

32.8 Buenas prácticas

  • JSON a stdout: la app escribe líneas JSON; el colector (Docker, systemd, el agente de la nube) las recoge — la app no abre archivos.

La nube son computadoras de otro que rentas por hora: AWS, Azure, GCP te prestan máquinas, redes y servicios administrados. Pagas por no comprar hardware — y por no administrarlo tú.

  • Request_id en la respuesta (X-Request-Id header): cuando el usuario reporta “me falló”, te da el hilo exacto.
  • Loguea decisiones, no solo errores: “task created”, “payment processed”, “rate limit hit” — los hechos normales son lo que reconstruye la película.
  • Duración siempre: duration_ms en cada línea — los problemas de rendimiento se ven antes de que estallen.

32.9 Ejercicio

  1. De esta línea sobra algo: logger.info({"email": u.email, "password_hash": u.password_hash, "token": jwt}, "user registered"). ¿Qué va y qué queda?
  2. El usuario reporta “me dio error a las 15:14”. Con logs JSON + request_id, ¿cuál es tu primera query de búsqueda?
  3. ¿Por qué console.log(err) no basta aunque “imprime el error”?

Una query es la pregunta que le haces a la base de datos en SQL: SELECT * FROM tasks WHERE done = false. La BD traduce la pregunta a un plan de búsqueda — por eso los índices importan.

32.10 Mini reto

Dado un log “500 a las 3:14”, reconstruir qué pasó usando el request ID.

Ejercicio.

  1. Van fuera password_hash (nunca) y token (nunca — es una llave viva). email es dato personal: en muchos contextos se loguea user_id en su lugar. Queda: {user_id, request_id, msg}.
  2. request_id si el usuario lo tiene (del header X-Request-Id que vio en la respuesta); si no: level=error AND ts≈15:14 AND user_id=42 — y con el request_id de esa línea, filtras todas las líneas del request para ver la película completa.
  3. Porque no responde las preguntas que sí importan: ¿qué request era? ¿de qué usuario? ¿en qué endpoint? ¿después de qué? Un error sin contexto es un síntoma; un error con request_id es una historia.

Mini reto. level=error AND ts≈3:14 → encuentras la línea del 500 con su request_id → filtras todo ese id → ves: request started → query a BD → timeout de la API externa → error → status 500. La historia se reconstruye sin tocar el código ni reproducir el bug — eso es observabilidad.

32.11 Vocabulario técnico del capítulo

Una variable es una caja con nombre donde guardas un valor: let total = 42 guarda el 42 bajo el nombre total. Puedes leerla y cambiarla después (total = 50). const = caja que no se puede reemplazar.

Una función es una receta reutilizable: recibe ingredientes (parámetros), hace pasos y devuelve un plato (return). La escribes una vez y la llamas mil veces: add(2, 3) → 5.

Un array es una colección ordenada de elementos accedidos por posición: ["a","b","c"][0] es "a" (se cuenta desde 0). Python las llama listas, Go slices — misma idea, distinto acento.

Una clase es el molde de un objeto: define qué datos y qué métodos tiene. class Task es el molde; new Task() es una instancia concreta. Go no tiene clases — usa struct + métodos sueltos.

null (TS), None (Py), nil (Go) = “aquí no hay valor”. Es la respuesta a “¿qué devuelvo cuando no hay nada?” — y la fuente del bug más famoso de la historia (su inventor lo llamó “el error del billón de dólares”). Por eso el código revisa if x is not None.

return hace dos cosas a la vez: devuelve el resultado Y termina la función — lo que esté debajo nunca corre. return task = “aquí está el plato, salgo de la cocina”.

Asíncrono = empezar algo sin esperar sentado a que termine: pides la pizza (async) y sigues trabajando; cuando llega, te avisan. Lo opuesto a síncrono (esperar parado). Vital cuando la espera es larga: red, disco, bases de datos.

Un job es trabajo que se hace sin que el usuario espere: mandar el email, generar el PDF. Va a una cola y un worker lo procesa en segundo plano — la respuesta HTTP sale inmediata.

La terminal (consola, línea de comandos) es la interfaz de texto con el sistema operativo: escribes comandos, lees resultados. Es como hablarle a la computadora por cartas en vez de señalar con el mouse.

Una base de datos es el programa que guarda datos de forma permanente y los responde rápido. Relacional (Postgres): tablas con relaciones. No relacional: documentos, clave-valor, grafos — cada una para una forma de dato distinta.

La autenticación responde “¿quién eres?” — login, contraseña, token. Se confunde con autorización (“¿qué puedes hacer?”), que es la pregunta siguiente. Primero te identificas, luego te dejan o no pasar.

Un JWT (JSON Web Token) es un token firmado: el servidor lo genera con su secreto y puede verificarlo sin consultar la BD. Ojo: está firmado, no cifrado — cualquiera puede leer su contenido, pero no modificarlo.

Un middleware es un filtro en la cadena del request: pasa por él antes de llegar a tu handler. Auth es middleware — “verifica el token” vive una vez y protege todas las rutas, no se copia en cada una.

Docker empaqueta tu app con todo lo que necesita (runtime, librerías, config) en una imagen — el mismo paquete corre idéntico en tu laptop y en producción. Es la respuesta a “en mi máquina sí funcionaba”.

Una imagen es la plantilla inmutable de la que nacen contenedores: la foto del disco + cómo arrancar. Se construye en capas (Dockerfile), se versiona con tags, se publica en un registry.

32.12 Lo que deberías saber hacer ahora