Logs, métricas y trazas: Los pilares de la observabilidad en Go

La observabilidad no es simplemente recolectar datos, es la capacidad de entender el estado interno de un sistema distribuido a partir de sus salidas externas. Para lograrlo, necesitamos tres señales fundamentales que, operando juntas, nos permiten responder preguntas que no sabíamos que íbamos a hacer.

Los logs son eventos discretos y estructurados; nos dicen qué pasó en un momento exacto (ej. “usuario X intentó pagar”). Las métricas son agregados numéricos que cambian con el tiempo; nos dicen la salud general (ej. “el 5% de los pagos fallan”). Las trazas son el hilo conductor que sigue una petición a través de múltiples procesos; nos dicen dónde se perdió el tiempo o dónde se rompió la cadena.

Si solo usas monitoreo, solo sabrás que algo anda mal porque un dashboard se puso en rojo (métricas). Si usas observabilidad, podrás entender por qué ocurrió ese error específico siguiendo el rastro exacto de la petición (trazas y logs correlacionados). Si fallas al implementar esto —por ejemplo, si tus logs no incluyen el ID de la traza—, el ruido de los logs en un entorno de alta concurrencia te impedirá encontrar la aguja en el pajar cuando el sistema colapse.

Para que la observabilidad sea efectiva en Go, la clave no es usar cada herramienta por separado, sino integrarlas mediante el context.Context. Esto permite que la información de la traza fluya a través de las llamadas a funciones y sea inyectada automáticamente en los logs estructurados mediante slog.

package main

import (
	"context"
	"fmt"
	"log/slog"
	"math/rand"
	"os"
	"time"
)

// Simulación de componentes de observabilidad (en producción usarías OpenTelemetry y Prometheus)

// Tracer simula la creación de spans de OpenTelemetry
type Tracer struct{}

func (t *Tracer) Start(ctx context.Context, name string) (context.Context, func()) {
	traceID := fmt.Sprintf("trc-%d", rand.Intn(100000))
	// Inyectamos el traceID en el contexto para que los logs lo puedan extraer
	ctx = context.WithValue(ctx, "trace_id", traceID)
	fmt.Printf("[TRACE] Inicio Span: %s | TraceID: %s\n", name, traceID)
	return ctx, func() {
		fmt.Printf("[TRACE] Fin Span: %s\n", name)
	}
}

// Metrics simula un contador de Prometheus
type Metrics struct {
	errorCounter int
}

func (m *Metrics) IncrError() {
	m.errorCounter++
	fmt.Printf("[METRIC] Incrementando contador de errores. Total: %d\n", m.errorCounter)
}

// ObservabilityStack agrupa nuestras herramientas
type ObservabilityStack struct {
	logger  *slog.Logger
	metrics *Metrics
	tracer  *Tracer
}

func main() {
	// 1. Configuración de logs estructurados con slog [disponible desde Go 1.21]
	// Usamos un handler que incluya el contexto para capturar el trace_id
	logger := slog.New(slog.NewJSONHandler(os.Stdout, nil))
	slog.SetDefault(logger)

	stack := &ObservabilityStack{
		logger:  logger,
		metrics: &Metrics{},
		tracer:  &Tracer{},
	}

	// Simulamos la llegada de peticiones
	for i := 0; i < 3; i++ {
		stack.HandleRequest(context.Background(), i)
		fmt.Println("--------------------------------------------------")
	}
}

func (os *ObservabilityStack) HandleRequest(ctx context.Context, reqID int) {
	// 2. Trazas: Iniciamos un span para la petición completa
	ctx, spanEnd := os.tracer.Start(ctx, "HandleRequest")
	defer spanEnd()

	// 3. Logs: Registramos el inicio con contexto
	// En un entorno real, usaríamos un middleware para extraer el trace_id del contexto
	traceID, _ := ctx.Value("trace_id").(string)
	l := os.logger.With(slog.String("trace_id", traceID), slog.Int("req_id", reqID))
	
	l.Info("Procesando nueva petición")

	if err := os.processPayment(ctx, l); err != nil {
		// 4. Métricas: Si algo falla, incrementamos el contador
		os.metrics.IncrError()
		l.Error("Petición fallida", "error", err)
		return
	}

	l.Info("Petición completada con éxito")
}

func (os *ObservabilityStack) processPayment(ctx context.Context, l *slog.Logger) error {
	// Simulamos trabajo y posible fallo
	traceID, _ := ctx.Value("trace_id").(string)
	l = l.With(slog.String("sub_trace_id", "sub-"+traceID)) // Simula un sub-span

	time.Sleep(50 * time.Millisecond)

	if rand.Float32() < 0.4 {
		return fmt.Errorf("insuficiente saldo en la cuenta")
	}

	l.Info("Pago procesado correctamente")
	return nil
}

Desglose de la implementación

En el ejemplo, la integración real ocurre en la gestión del context.Context.

1. Trazas y Propagación: La función tracer.Start simula la creación de un span de OpenTelemetry. Lo más importante aquí es cómo inyectamos el trace_id en el contexto (context.WithValue). En sistemas distribuidos, este ID viaja en las cabeceras HTTP hacia otros microservicios, permitiendo que la traza sea continua.
2. Logs Correlacionados: Fíjate en cómo HandleRequest extrae el trace_id del contexto para crear un slog.Logger con campos fijos mediante .With(...). Esto es vital: cada log generado en processPayment llevará automáticamente el trace_id. Si un cliente reporta un error, solo tienes que buscar ese ID en tu sistema de logs (como Loki o Elasticsearch) y verás el flujo completo, no solo líneas sueltas.
3. Métricas de Error: Cuando processPayment devuelve un error, la función HandleRequest llama a os.metrics.IncrError(). Esto representa la métrica de Prometheus que dispararía una alerta en un dashboard de Grafana. La métrica te avisa que “algo anda mal”, pero es el log correlacionado con la traza lo que te dirá “por qué falló el pago del usuario X”.

El error frecuente es tratar los logs como texto plano en lugar de datos estructurados. Si usas fmt.Printf o log.Print en lugar de slog con campos tipados, perderás la capacidad de filtrar métricas y trazas de forma programática, convirtiendo tu infraestructura de observabilidad en un simple almacén de texto inútil para el debugging de alta carga.

N° 212