En 06-01 dejamos a TechCorp con logs consultables por requestId y un p95 de POST /v1/pedidos de 250 ms. Lo que esas señales no dicen es dónde se van esos 250 ms: ¿en la llamada a Catálogo, en la de Clientes, en PostgreSQL, en el propio Express? Y cuando la petición termina con un 202, la saga sigue por RabbitMQ en otros tres servicios: los logs de cada uno existen, pero nadie los une en un solo recorrido. Las trazas distribuidas son la señal que dibuja ese camino. Esta lección instrumenta los servicios de TechCorp con OpenTelemetry, propaga el contexto por HTTP y por RabbitMQ, monta el Collector y Jaeger en Kubernetes y enseña a leer una traza real de ped-88213.

1. El problema: una petición, cuatro servicios y una saga
2. Trazas, spans y contexto: traceparent y su relación con X-Request-Id
3. OpenTelemetry: API, SDK, instrumentaciones, Collector y exportadores
4. Instrumentar Node.js: src/telemetria.js en la plantilla y en el Dockerfile
5. Spans manuales en el caso de uso crearPedido
6. Propagar el contexto por RabbitMQ: outbox, consumidores y links
7. El Collector y Jaeger en Kubernetes
8. Leer una traza: ped-88213 y el cuello de botella
9. Correlación trazas ↔ logs y trazas ↔ métricas
10. Muestreo y coste

Sigamos el pedido de Ana Ruiz desde el navegador:

Con lo que tenemos, cada tramo deja un log de acceso con su responseTime y una observación en el histograma de 06-01. Pero para responder "¿por qué esta petición tardó 1,8 s?" habría que abrir Loki, buscar el requestId, anotar a mano los tiempos de cuatro servicios y restarlos. Y la parte asíncrona ni siquiera comparte requestId de forma natural: el consumidor de Inventario recibe un mensaje, no una petición.

Una traza hace ese trabajo automáticamente: registra cada operación como un span con inicio, duración, atributos y padre, y las une con un identificador común. Verlas en Jaeger es ver la sequenceDiagram anterior con tiempos reales.

El formato estándar es W3C Trace Context: una cabecera traceparent con cuatro campos separados por guiones:

Y una opcional tracestate para datos de proveedores. Todo lo que hable HTTP en TechCorp (gateway, servicios, fetch) debe reenviar traceparent igual que reenviaba X-Request-Id.

¿Sustituye traceparent a X-Request-Id? No: conviven con papeles distintos.

Decisión: se mantienen los dos. El requestId es lo que un operador de soporte pide al cliente y busca en Loki; el trace_id es lo que el desarrollador abre en Jaeger. Ambos aparecen en cada línea de log, así que pasar de uno a otro es una consulta.

OpenTelemetry (OTel) es el estándar de la CNCF que unifica cómo se generan y transportan trazas, métricas y logs, independiente del proveedor que las almacene. Sus piezas:

• API: lo que usa el código de la aplicación (trace.getTracer, startActiveSpan, propagation.inject). Es estable y no depende de la implementación: si no hay SDK cargado, no hace nada.
• SDK: la implementación que crea los spans de verdad, aplica el muestreo, los agrupa en lotes y los entrega al exportador.
• Instrumentaciones automáticas: monkey-patching de librerías conocidas para crear spans sin tocar nuestro código: http (entrante y saliente, incluido fetch global de Node 20 desde @opentelemetry/instrumentation-undici), express (un span por middleware/ruta), pg, mongodb, amqplib.
• Exportadores: envían por OTLP (el protocolo nativo de OTel, gRPC en 4317 o HTTP en 4318) al Collector, o directamente a un backend.
• Collector: un proceso intermedio que recibe, procesa (lotes, muestreo de cola, enriquecimiento con metadatos de Kubernetes) y reexporta a uno o varios destinos. Desacopla la aplicación del backend: cambiar Jaeger por Tempo es cambiar la configuración del Collector, no redesplegar siete servicios.

Las instrumentaciones automáticas parchean los módulos cuando se cargan, así que el SDK debe inicializarse antes que Express, pg o amqplib. La forma limpia es un fichero aparte cargado con --require, sin tocar servidor.js:

Explicación:

• resource describe quién emite: service.name es lo que Jaeger muestra como servicio; service.version permite comparar el canary (05-04) con la versión estable. OTLPTraceExporter() sin argumentos toma el destino de OTEL_EXPORTER_OTLP_ENDPOINT, que va al ConfigMap del servicio (05-02).
• getNodeAutoInstrumentations activa todo el catálogo; desactivamos fs y excluimos las sondas y /metrics de los spans entrantes por la misma razón que en los logs de 06-01. enhancedDatabaseReporting: false: el span de pg incluye la sentencia SQL pero no los parámetros: los datos de Ana Ruiz no deben viajar a Jaeger (misma regla que la redacción de logs).
• El handler de SIGTERM es importante: los spans se exportan en lotes cada pocos segundos; sin shutdown() el último lote de un pod que muere en un rolling se pierde. Convive con el apagado ordenado del servidor de 04-02.

Variables de entorno estándar de OTel que añadimos a la plantilla de configuración (04-03) y al ConfigMap:

El arranque cambia en el package.json y en el Dockerfile de 05-01:

--require carga el módulo antes de la primera línea de servidor.js; a partir de ahí, cada petición Express, cada fetch saliente y cada consulta pg produce spans sin más código. Con esto, un POST /v1/pedidos ya genera en Jaeger la traza gateway → pedidos → catálogo/clientes → pg. Lo que falta es lo que la instrumentación automática no sabe: dónde empieza y acaba nuestra lógica de negocio.

Un span propio marca la operación de negocio y le añade atributos que luego se pueden buscar en Jaeger. Modificamos el caso de uso de 04-04:

• trace.getTracer('servicio-pedidos'): obtiene un tracer de la API. Solo importamos @opentelemetry/api: el caso de uso no conoce el SDK, y en las pruebas de 04-05 sin SDK cargado los spans son "no-op".
• startActiveSpan('crearPedido', fn): crea el span como hijo del activo (el span POST /v1/pedidos de Express) y lo deja activo durante fn, de modo que los fetch a Catálogo y Clientes y el INSERT de pg cuelgan de él automáticamente. Ese es el truco de "contexto activo": la instrumentación automática busca el span activo en el AsyncLocalStorage de Node y se engancha.
• Los atributos siguen la convención dominio.campo (pedido.id, cliente.id); son valores de alta cardinalidad, que en trazas sí son bienvenidos (a diferencia de las etiquetas de métricas de 06-01): Jaeger permite buscar pedido.id=ped-88213.
• addEvent añade una marca temporal dentro del span; recordException + setStatus(ERROR) hacen que la traza aparezca en rojo y con el stack (sin esto, un ErrorNegocio que termina en 503 se vería como un span verde que acaba antes de tiempo); y span.end() va siempre en finally: un span sin cerrar no se exporta nunca.

Los mismos tres gestos (startActiveSpan, atributos, recordException) se aplican en crearCasoUsoReservarStock de Inventario y en cobrar de Pagos.

La instrumentación de amqplib inyecta traceparent en las cabeceras cuando se publica dentro de un span activo y lo extrae al consumir. En TechCorp hay una trampa: el evento pedido.creado no lo publica el caso de uso, sino el relay del outbox (04-04), en otro momento y sin ningún span activo relacionado con la petición. Si no hacemos nada, la saga arranca una traza nueva sin relación con el POST.

Solución: guardar el contexto en la fila del outbox al escribirla y restaurarlo al publicar.

propagation.inject toma el contexto activo (estamos dentro de crearPedido, apartado 5) y escribe las cabeceras W3C en un objeto cualquiera; ese objeto se guarda en la columna cabeceras (JSONB) junto al requestId que ya guardábamos en 03-02.

En el relay (mensajeria/relayOutbox.js), al publicar cada fila:

Aquí hay una decisión de diseño. Podríamos hacer que el span de publicación fuera hijo del POST /v1/pedidos original, pero ese span terminó hace segundos: la traza mostraría un hijo que empieza después de que su padre acabe, y las trazas de sagas de 15 minutos serían inmanejables. OTel tiene el concepto de link para esto: el span de publicación pertenece a su propia traza (la del relay/la saga) pero enlaza con el span original. Jaeger muestra los enlaces y permite saltar de una traza a otra. La regla en TechCorp:

• Dentro de una petición síncrona (HTTP): relación padre-hijo.
• Entre la petición y el procesamiento asíncrono (outbox, consumidores): link al span de origen y una traza por evento.
• Dentro de un consumidor, todo lo que provoque (consultas, publicación del siguiente evento) es hijo del span de consumo, así que cada paso de la saga es una traza pequeña enlazada a la anterior: POST ⇢ publicar pedido.creado ⇢ consumir pedido.creado (Inventario) ⇢ publicar stock.reservado ⇢ …

En el consumidor de la saga (mensajeria/consumidorSaga.js) la instrumentación de amqplib ya crea un span pedidos.saga process con SpanKind.CONSUMER a partir del traceparent de las cabeceras. Solo añadimos atributos y, si el mensaje viene de un reintento o de la DLQ (06-03), conservamos las cabeceras para no romper la cadena. Cuando un servicio publica sin pasar por outbox (Inventario publica stock.reservado dentro del span de consumo), la inyección automática basta.

El equipo de Plataforma despliega el Collector en el namespace observabilidad como Deployment (dos réplicas detrás de un Service otel-collector con los puertos 4317/4318) y su configuración en un ConfigMap:

• receivers.otlp: acepta lo que envían los servicios (gRPC 4317, HTTP 4318).
• processors: memory_limiter protege al Collector; k8sattributes etiqueta cada span con el pod y el Deployment de origen (mismos nombres que en Loki: se cruzan bien); tail_sampling decide qué trazas conservar después de verlas completas; batch agrupa antes de exportar.
• exporters.otlp/jaeger: Jaeger v2 acepta OTLP directamente. Cambiarlo por Grafana Tempo es cambiar el endpoint; Tempo se integra mejor con Grafana/Loki, Jaeger tiene la interfaz más conocida. TechCorp empieza con Jaeger (jaeger-query publicado internamente en jaeger.techcorp.internal).
• El connector spanmetrics genera métricas RED (traces_span_metrics_calls_total, traces_span_metrics_duration_milliseconds) a partir de los spans; las expone en 8889 para que Prometheus (06-01) las raspe. Es una segunda fuente de RED por servicio y operación, útil sobre todo para las llamadas salientes.

En el ConfigMap de cada servicio (05-02) añadimos OTEL_EXPORTER_OTLP_ENDPOINT y OTEL_SERVICE_NAME; en compose.yaml de local (05-01) un contenedor jaegertracing/all-in-one con OTLP activado y la interfaz en http://localhost:16686 sirve para desarrollar sin Collector.

Marta busca en Jaeger servicio=servicio-pedidos, pedido.id=ped-88213 y abre la traza. Jaeger la muestra como diagrama de Gantt; en forma de tabla (tiempos ficticios pero realistas):

Cómo se lee:

1. El gateway añade 3 ms de sobrecarga: despreciable.
2. Catálogo (40 ms) y Clientes (25 ms) se ejecutan en paralelo (Promise.all del apartado 5): empiezan ambos en el ms 9. Si fueran secuenciales, la traza mostraría el segundo empezando al terminar el primero: la primera optimización que una traza suele revelar.
3. Las consultas a base de datos son rápidas: MongoDB 9 ms, PostgreSQL 6 y 12 ms.
4. Sumando: 40 (lo más lento del paralelo) + 12 de pg = 52 ms de trabajo real, pero crearPedido dura 176 ms. Hay 120 ms sin span entre el COMMIT (ms 64) y el final del span (ms 184). Es un hueco: tiempo que pasó dentro de nuestro código sin ninguna operación instrumentada. Al mirar el caso de uso, Luis encuentra que tras persistir se llama a una función calcularRecomendaciones heredada del monolito que hace un cálculo síncrono pesado. Bloquea el event loop (06-04) y no aporta nada al pedido. Se elimina y el p95 de POST /v1/pedidos cae de 250 a 90 ms.

Reglas prácticas de lectura: buscar el span más largo entre hermanos; buscar huecos sin hijos (código propio no instrumentado o event loop bloqueado); comprobar si los hijos son secuenciales cuando podrían ser paralelos; y, en la parte asíncrona, seguir los links de una traza a la siguiente para medir la saga completa (publicar pedido.creado a las 10:21:04.6, consumir pedido.confirmado a las 10:21:07.9: 3,3 s, coherente con el histograma saga_duracion_segundos de 06-01).

Trazas ↔ logs. La instrumentación @opentelemetry/instrumentation-pino (activada en el apartado 4) añade automáticamente trace_id, span_id y trace_flags a cada línea de log emitida dentro de un span activo. La línea de 06-01 pasa a ser:

Si no se quiere depender de esa instrumentación, un mixin en crearLogger hace lo mismo a mano:

Con eso, en Grafana se configura en el datasource de Loki un derived field: expresión "trace_id":"(\w+)" → enlace a Jaeger/Tempo por trace_id. Y en sentido inverso, desde un span en Jaeger, un enlace a Loki con {namespace="techcorp"} | json | trace_id="…". El operador ya no elige entre logs y trazas: salta.

Trazas ↔ métricas. Los exemplars permiten que un bucket del histograma http_request_duration_seconds lleve adjunto el trace_id de una petición representativa; Grafana los pinta como puntos sobre la gráfica del p95 y un clic abre la traza. Requiere prom-client con soporte de exemplars y --enable-feature=exemplar-storage en Prometheus. Lo dejamos como mención: TechCorp lo activará cuando la pila esté estable; el salto métrica → logs → traza del punto anterior cubre el mismo caso con un paso más.

Cada POST /v1/pedidos genera unos 12 spans; con la saga, unos 30. A 3.000 pedidos/día es poco, pero el catálogo sirve cientos de miles de GET /v1/productos y en Black Friday ×20. Guardar el 100 % es caro (almacenamiento y CPU en el Collector) y casi siempre innecesario: las trazas "normales" se parecen todas. Por eso se muestrea:

TechCorp combina las dos:

• En los servicios, OTEL_TRACES_SAMPLER=parentbased_traceidratio con OTEL_TRACES_SAMPLER_ARG=0.1 en producción (10 % de las trazas raíz; parentbased significa que si el padre fue muestreado, el hijo también: una traza nunca sale a medias) y 1.0 en dev/staging.
• En el Collector, la política tail_sampling del apartado 7: todas las trazas con error o de más de 1 s, y el 10 % del resto. Como el head ya redujo al 10 %, el tail actúa sobre ese subconjunto; para que los errores no se pierdan en el head se puede subir el ratio de los servicios críticos (Pedidos, Pagos: 0,5) y dejar el 0,1 para Catálogo.
• Retención en Jaeger: 7 días. Los requestId de los logs siguen 30 días, así que un incidente antiguo se investiga con logs aunque su traza haya expirado.

Última nota, para cerrar el hilo con 05-05: un service mesh como Istio genera spans en cada sidecar (entrada y salida de cada pod) y los envía al mismo Collector, pero no puede propagar el contexto dentro de la aplicación: entre la petición entrante y la saliente hay código nuestro, y solo nuestro proceso sabe que la segunda es consecuencia de la primera. Si algún día TechCorp adopta el mesh, la aplicación seguirá necesitando exactamente esta lección: reenviar traceparent, y con RabbitMQ, inyectarlo y extraerlo a mano.

• Cargar el SDK después de Express o pg. Nada se instrumenta y no hay error. Siempre --require ./src/telemetria.js (o NODE_OPTIONS=--require), nunca un require dentro de servidor.js tras otros imports.
• Olvidar span.end() en un camino de error. El span no se exporta y la traza queda "abierta" en Jaeger. Usar siempre try/finally o la variante con callback que cierra sola.
• Perder el contexto en setTimeout, colas internas o EventEmitter. El AsyncLocalStorage sigue a await y promises, pero un setTimeout o un emitter.on pueden ejecutarse fuera del contexto. context.with(ctx, fn) lo restaura.
• Hacer padre-hijo lo que debe ser link. Trazas de 15 minutos con miles de spans y padres que terminan antes que sus hijos. Asíncrono = links.
• Meter datos personales en atributos (cliente.email, cuerpos de peticiones). Aplican las mismas reglas que a los logs (06-01, 07-03).
• Muestreo 100 % en producción "para no perder nada". Se pierde el Collector. Head 10 % + tail para errores.
• Consejo: en local, jaegertracing/all-in-one en compose.yaml y OTEL_TRACES_SAMPLER_ARG=1.0; ver la traza de un curl a POST /v1/pedidos es la mejor manera de entender la estructura de una petición.

Un mensaje de pedidos.saga fue a pedidos.saga.dlq y se reprocesa manualmente (06-03). ¿Qué hay que conservar para que el nuevo procesamiento aparezca enlazado a la traza original? ¿Debería ser hijo o link? Escribe el fragmento que crea el span de reproceso.

En una traza de POST /v1/pedidos ves: crearPedido 410 ms; fetch catálogo empieza en el ms 5 y dura 45 ms; fetch clientes empieza en el ms 52 y dura 30 ms; pg 15 ms a partir del ms 84; nada más hasta el ms 410. Enumera los dos problemas y qué harías con cada uno.

Ejercicio 1

Hay que conservar las cabeceras del mensaje original (traceparent, requestId, eventoId) cuando el script mueve el mensaje de la DLQ a la cola principal. El reproceso ocurre mucho después y por iniciativa humana: debe ser link, no hijo. Fragmento del script reprocesarDlq.js:

El consumidor recibirá el traceparent del span de reproceso y, a través del link, se podrá llegar a la traza del fallo original.

Ejercicio 2

1. Llamadas secuenciales que podrían ser paralelas. Clientes empieza en el ms 52, justo cuando termina Catálogo. Con Promise.all la fase de validación duraría 45 ms en lugar de 75. Cambio en el caso de uso.
2. Hueco de ~310 ms sin spans tras el COMMIT (ms 99 → ms 410). Es código propio no instrumentado o event loop bloqueado. Se localiza envolviendo las funciones sospechosas del caso de uso en spans manuales (o con nodejs_eventloop_lag_seconds de 06-01 en ese pod) y se elimina, se hace asíncrono, o se mueve fuera de la petición (a un evento). El resultado esperado: crearPedido en torno a 60-70 ms.

Con esta lección, TechCorp ve por fin el camino de cada petición. Cada servicio arranca con node --require ./src/telemetria.js, que carga el SDK de OpenTelemetry con instrumentaciones automáticas de http, express, pg, mongodb, amqplib y pino, se identifica con OTEL_SERVICE_NAME y service.version, y exporta por OTLP al Collector; los casos de uso añaden spans manuales (crearPedido, reservarStock, cobrar) con atributos pedido.id/cliente.id y excepciones registradas; el contexto W3C traceparent viaja por HTTP junto al X-Request-Id, se guarda en la fila del outbox y se reinyecta en el relay, y las etapas asíncronas de la saga se unen con links; el Collector aplica k8sattributes, tail_sampling y batch y reexporta a Jaeger y a Prometheus; y trace_id en cada línea de log cierra el triángulo con Loki. Al leer la traza de ped-88213 hemos encontrado un hueco de 120 ms que ninguna métrica delataba. Ya podemos ver los fallos y las lentitudes; la siguiente lección se ocupa de sobrevivirlos: los patrones de gestión de errores y recuperación (timeouts, reintentos, circuit breaker, bulkhead, colas de reintento y DLQ, el vigilante de la saga) que los módulos 2, 3 y 5 fueron remitiendo a 06-03.