Depuración de sistemas distribuidos: correlación y causalidad
Depura sistemas distribuidos con IDs de correlación, propagación de contexto de trazas, agregación de logs y orden causal hasta la causa raíz.
Depurar un monolito es difícil. Depurar un sistema distribuido es exponencialmente más difícil porque el fallo puede originarse en el servicio A, manifestarse en el servicio B y solo volverse visible en el servicio C. Sin una forma de rastrear la causalidad más allá de los límites del servicio, te quedas reducido a buscar timestamps con grep y esperar que los relojes estén sincronizados.
Los IDs de correlación, el tracing distribuido y la agregación de logs estructurados transforman esta conjetura en una investigación sistemática. Te dan la capacidad de seguir una sola solicitud a través de decenas de servicios e identificar exactamente dónde las cosas salieron mal.
Propagación del ID de correlación
Cada solicitud que entra a tu sistema recibe un ID de correlación único. Este ID se propaga a través de cada llamada de servicio, cada publicación en cola de mensajes y cada entrada de log, creando un hilo que puedes jalar para desentrañar todo el ciclo de vida de la solicitud.
// ❌ Logs without correlation — impossible to connect
// [auth-service] User login successful
// [order-service] Order created for user 42
// [payment-service] Payment failed
// Which login led to which order? Which order's payment failed?// ✅ Correlation ID middleware that propagates across services
import { randomUUID } from "crypto";
import { Request, Response, NextFunction } from "express";
const CORRELATION_HEADER = "x-correlation-id";
const CAUSATION_HEADER = "x-causation-id";
interface RequestContext {
correlationId: string;
causationId: string;
parentSpanId?: string;
serviceName: string;
}
function correlationMiddleware(
serviceName: string
) {
return (
req: Request,
res: Response,
next: NextFunction
) => {
// Inherit correlation ID from upstream or create new one
const correlationId =
req.headers[CORRELATION_HEADER] as string ??
randomUUID();
// Causation ID tracks the immediate parent
const causationId =
req.headers[CAUSATION_HEADER] as string ??
correlationId;
const context: RequestContext = {
correlationId,
causationId,
parentSpanId: req.headers["x-parent-span"] as string,
serviceName,
};
// Attach to request for downstream use
(req as any).context = context;
// Include in response headers for debugging
res.setHeader(CORRELATION_HEADER, correlationId);
next();
};
}
// HTTP client that propagates context
class CorrelatedHttpClient {
constructor(private context: RequestContext) {}
async get(url: string): Promise<Response> {
const spanId = randomUUID();
return fetch(url, {
headers: {
[CORRELATION_HEADER]: this.context.correlationId,
[CAUSATION_HEADER]: spanId,
"x-parent-span": this.context.parentSpanId ?? "",
},
});
}
async post(
url: string,
body: unknown
): Promise<Response> {
const spanId = randomUUID();
return fetch(url, {
method: "POST",
headers: {
"Content-Type": "application/json",
[CORRELATION_HEADER]: this.context.correlationId,
[CAUSATION_HEADER]: spanId,
"x-parent-span": this.context.parentSpanId ?? "",
},
body: JSON.stringify(body),
});
}
}La distinción entre IDs de correlación y de causalidad importa. El ID de correlación se mantiene igual a través de toda la cadena de solicitudes. El ID de causalidad cambia en cada salto, creando una cadena: la solicitud A causó la llamada B, que causó la llamada C. Esto te permite reconstruir el grafo de llamadas exacto.
Registro estructurado para agregación
Los logs no estructurados son ruido a escala. Los logs estructurados con campos consistentes permiten consultar a través de millones de entradas de decenas de servicios.
interface StructuredLog {
timestamp: string;
level: "debug" | "info" | "warn" | "error";
service: string;
correlationId: string;
causationId: string;
spanId: string;
message: string;
duration?: number;
error?: {
name: string;
message: string;
stack?: string;
};
metadata: Record<string, unknown>;
}
class CorrelatedLogger {
constructor(
private serviceName: string,
private context: RequestContext
) {}
info(message: string, metadata: Record<string, unknown> = {}): void {
this.emit("info", message, metadata);
}
error(
message: string,
error: Error,
metadata: Record<string, unknown> = {}
): void {
this.emit("error", message, {
...metadata,
error: {
name: error.name,
message: error.message,
stack: error.stack,
},
});
}
private emit(
level: StructuredLog["level"],
message: string,
metadata: Record<string, unknown>
): void {
const log: StructuredLog = {
timestamp: new Date().toISOString(),
level,
service: this.serviceName,
correlationId: this.context.correlationId,
causationId: this.context.causationId,
spanId: this.context.parentSpanId ?? "",
message,
metadata,
};
// Single-line JSON for log aggregation systems
console.log(JSON.stringify(log));
}
}
// Usage in a request handler
function handleOrder(req: Request, res: Response) {
const logger = new CorrelatedLogger(
"order-service",
(req as any).context
);
logger.info("Processing order", {
orderId: req.body.orderId,
itemCount: req.body.items.length,
});
// Later, if something fails:
// logger.error("Payment processing failed", paymentError, {
// orderId: req.body.orderId,
// paymentProvider: "stripe",
// });
}Con esta estructura, puedes consultar tu sistema de agregación de logs con correlationId = "abc-123" y ver cada entrada de log de cada servicio para esa solicitud específica, ordenada por timestamp.
Ensamblaje de trazas distribuidas
Los spans individuales de cada servicio deben ensamblarse en una traza completa que muestre la línea de tiempo completa de la solicitud.
interface Span {
traceId: string;
spanId: string;
parentSpanId: string | null;
serviceName: string;
operationName: string;
startTime: number;
duration: number;
status: "ok" | "error";
tags: Record<string, string>;
logs: SpanLog[];
}
interface SpanLog {
timestamp: number;
message: string;
fields: Record<string, unknown>;
}
class TraceAssembler {
private spans: Map<string, Span[]> = new Map();
addSpan(span: Span): void {
const existing = this.spans.get(span.traceId) ?? [];
existing.push(span);
this.spans.set(span.traceId, existing);
}
assembleTrace(traceId: string): {
rootSpan: Span | null;
tree: SpanNode[];
totalDuration: number;
criticalPath: Span[];
errors: Span[];
} | null {
const spans = this.spans.get(traceId);
if (!spans || spans.length === 0) return null;
const rootSpan =
spans.find((s) => s.parentSpanId === null) ?? null;
const tree = this.buildTree(spans);
const criticalPath = this.findCriticalPath(spans);
const errors = spans.filter((s) => s.status === "error");
const totalDuration = rootSpan?.duration ?? Math.max(
...spans.map((s) => s.startTime + s.duration)
) - Math.min(...spans.map((s) => s.startTime));
return { rootSpan, tree, totalDuration, criticalPath, errors };
}
private buildTree(spans: Span[]): SpanNode[] {
const nodeMap = new Map<string, SpanNode>();
const roots: SpanNode[] = [];
for (const span of spans) {
nodeMap.set(span.spanId, { span, children: [] });
}
for (const span of spans) {
const node = nodeMap.get(span.spanId)!;
if (span.parentSpanId) {
const parent = nodeMap.get(span.parentSpanId);
if (parent) {
parent.children.push(node);
} else {
roots.push(node);
}
} else {
roots.push(node);
}
}
return roots;
}
private findCriticalPath(spans: Span[]): Span[] {
// The critical path is the longest chain of sequential spans
return spans
.filter((s) => s.status === "error" || s.duration > 500)
.sort((a, b) => b.duration - a.duration);
}
}
interface SpanNode {
span: Span;
children: SpanNode[];
}Desviación de relojes y ordenamiento causal
Los sistemas distribuidos no pueden confiar en los timestamps de reloj de pared para el ordenamiento porque los relojes se desvían. Los timestamps de Lamport o los relojes vectoriales establecen un ordenamiento causal sin relojes sincronizados.
class LamportClock {
private counter: number = 0;
tick(): number {
return ++this.counter;
}
receive(remoteTimestamp: number): number {
this.counter = Math.max(this.counter, remoteTimestamp) + 1;
return this.counter;
}
current(): number {
return this.counter;
}
}
// Use in service-to-service communication
class CausalMessageClient {
private clock: LamportClock;
constructor(private serviceName: string) {
this.clock = new LamportClock();
}
send(
destination: string,
payload: unknown
): { payload: unknown; timestamp: number; sender: string } {
const timestamp = this.clock.tick();
return {
payload,
timestamp,
sender: this.serviceName,
};
}
receive(message: {
payload: unknown;
timestamp: number;
sender: string;
}): { payload: unknown; localTimestamp: number } {
const localTimestamp = this.clock.receive(
message.timestamp
);
return {
payload: message.payload,
localTimestamp,
};
}
}Si el evento A tiene timestamp de Lamport 5 y el evento B tiene timestamp 8, sabes que B no causó A. Este ordenamiento parcial es suficiente para establecer relaciones "happens-before" que el tiempo de reloj de pared no puede garantizar.
Conclusiones clave
La depuración distribuida requiere instrumentación intencional — sin IDs de correlación y logs estructurados, rastrear una solicitud a través de servicios es casi imposible. Propaga tanto IDs de correlación (constantes a lo largo de toda la solicitud) como IDs de causalidad (cambian en cada salto) para reconstruir el grafo de llamadas exacto que llevó a un fallo. Usa logging JSON estructurado con campos consistentes en todos los servicios para que las consultas de agregación de logs puedan abarcar todo el sistema. Ensambla trazas distribuidas a partir de spans individuales para visualizar la línea de tiempo completa de la solicitud, identificar la ruta crítica y detectar dónde se acumula la latencia. No confíes en los timestamps de reloj de pared para ordenar eventos en sistemas distribuidos — usa relojes de Lamport o relojes vectoriales para establecer relaciones causales que sobrevivan a la desviación de relojes. La inversión en infraestructura de observabilidad se paga sola la primera vez que diagnosticas un fallo cross-service en minutos en lugar de horas, rastreando la cadena exacta de eventos desde el trigger hasta el síntoma.
