¿Qué pasó, cuánto y dónde? Logs, métricas y trazas sin confundirlos

Explicación

Los tres son señales del mismo sistema, pero cada uno responde una pregunta distinta. Por eso no compiten entre sí: se complementan.

Tres preguntas distintas

Dos matices que marcan la diferencia en una entrevista. Un log útil hoy es estructurado, con campos clave-valor que se pueden filtrar, no una línea de texto libre. Y una métrica no guarda cada request: resume por intervalo (cuenta, suma, distribución). Por eso es barata y rápida de consultar sin importar el tráfico, y por eso es la que sirve para alertar.

Juntos en un incidente

El orden típico de una investigación es métrica, traza y log:

1. La métrica alerta. La latencia p95 de POST /orders sube de 300 ms a 4 s y se dispara la alerta. Sé que algo anda mal, pero no dónde.
2. La traza ubica. Abro una traza lenta y veo que el span inventory.reserve se lleva 3,8 s de los 4. Ya sé dónde está el problema.
3. El log explica. Filtro los logs del servicio de inventario por ese traceId y aparece un timeout contra la base de datos. Ya sé por qué.

Lo que une los tres pasos es el trace id (o correlation id): viaja entre servicios en los headers de cada llamada y se escribe en cada log. Sin él son tres herramientas sueltas y el troubleshooting se vuelve adivinar por la hora.

OpenTelemetry como pegamento

OpenTelemetry es el estándar abierto que instrumenta los tres pilares con la misma API, propaga el contexto entre servicios y exporta a cualquier backend, sea open source o comercial. En .NET, sus conceptos se mapean a APIs del propio runtime: Activity para los spans, Meter para las métricas e ILogger para los logs.

Código

El mismo handler de checkout genera las tres señales: abre un span, escribe un log estructurado con el traceId y registra la duración en un histograma. Dejo fuera la configuración del SDK y del exportador.

import { metrics, trace, SpanStatusCode } from '@opentelemetry/api';
import express from 'express';
import pino from 'pino';
import { reserveStock } from './inventory';

const app = express();
const logger = pino();
const tracer = trace.getTracer('orders');
const duration = metrics.getMeter('orders').createHistogram('checkout.duration', { unit: 'ms' });

app.post('/orders', async (req, res) => {
  await tracer.startActiveSpan('checkout', async (span) => {
    const start = performance.now();
    const traceId = span.spanContext().traceId;
    let status = 200;
    try {
      await reserveStock(req.body); // abre su propio span hijo
      logger.info({ traceId, items: req.body.items.length }, 'order created');
      res.status(status).json({ ok: true });
    } catch (err) {
      status = 500;
      span.setStatus({ code: SpanStatusCode.ERROR });
      logger.error({ traceId, err }, 'checkout failed');
      res.status(status).end();
    } finally {
      // etiquetas de baja cardinalidad: nunca orderId ni userId
      duration.record(performance.now() - start, { route: '/orders', status });
      span.end();
    }
  });
});

using System.Diagnostics;
using System.Diagnostics.Metrics;

var app = WebApplication.CreateBuilder(args).Build();
var source = new ActivitySource("Orders");
var duration = new Meter("Orders").CreateHistogram<double>("checkout.duration", unit: "ms");

app.MapPost("/orders", async (Order order, ILogger<Program> logger) =>
{
    using var activity = source.StartActivity("checkout"); // en .NET, un span es una Activity
    var start = Stopwatch.GetTimestamp();
    var traceId = activity?.TraceId.ToString();
    var status = 200;
    try
    {
        await Inventory.ReserveAsync(order); // abre su propio span hijo
        logger.LogInformation("Order created ({Items} items) {TraceId}", order.Items.Count, traceId);
        return Results.Ok();
    }
    catch (Exception ex)
    {
        status = 500;
        activity?.SetStatus(ActivityStatusCode.Error);
        logger.LogError(ex, "Checkout failed {TraceId}", traceId);
        return Results.StatusCode(status);
    }
    finally
    {
        // etiquetas de baja cardinalidad: nunca orderId ni userId
        var tags = new TagList { { "route", "/orders" }, { "status", status } };
        duration.Record(Stopwatch.GetElapsedTime(start).TotalMilliseconds, tags);
    }
});

app.Run();

Trade-offs

• Cada señal tiene su costo. Los logs pesan por volumen, así que importan los niveles y la retención. Las métricas son baratas mientras la cardinalidad esté controlada. Las trazas son caras por request y por eso se muestrean, a cambio de perder el detalle de parte del tráfico.
• El error típico: confundir los roles. Usar logs como métricas (contar errores buscando un texto) es caro y lento para alertar. Al revés, meter userId u orderId como etiqueta de una métrica crea una serie por cada valor y explota la cardinalidad. Esos datos van en el log y en la traza.
• Sin correlación no hay troubleshooting. Si el traceId no queda en cada log, tienes tres herramientas que no se hablan entre sí.
• Alertar sobre síntomas, no sobre texto. Las alertas van sobre métricas de latencia y tasa de errores, que es lo que siente el usuario. Los logs y las trazas sirven para investigar después.