Módulo 13: Observabilidad en Producción: Logging Estructurado & Métricas

logger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
	Level: slog.LevelInfo,
}))
slog.SetDefault(logger) // ahora slog.Info(...) usa este logger

slog.Info("tarea creada", "tarea_id", 42, "usuario_id", 7)
// {"time":"2026-10-21T10:00:00Z","level":"INFO","msg":"tarea creada","tarea_id":42,"usuario_id":7}

var nivel slog.LevelVar
nivel.Set(slog.LevelDebug)   // se puede cambiar en caliente

slog.Error("falló la consulta",
	slog.String("operacion", "listar_tareas"),
	slog.Int64("usuario_id", 7),
	slog.Duration("duracion", 83*time.Millisecond),
	slog.Any("error", err),
)

slog.Info("petición",
	slog.Group("http",
		slog.String("metodo", "GET"),
		slog.String("ruta", "/tareas"),
		slog.Int("estado", 200),
	),
)
// {"msg":"petición","http":{"metodo":"GET","ruta":"/tareas","estado":200}}

log := slog.Default().With("componente", "servicio_tareas")
log.Info("iniciado")   // todos sus registros llevan componente=servicio_tareas

type claveLogger struct{}

func ConLogger(ctx context.Context, l *slog.Logger) context.Context {
	return context.WithValue(ctx, claveLogger{}, l)
}

// Log devuelve el logger de la petición, o el global si no hay.
func Log(ctx context.Context) *slog.Logger {
	if l, ok := ctx.Value(claveLogger{}).(*slog.Logger); ok {
		return l
	}
	return slog.Default()
}

func IDPeticion(next http.Handler) http.Handler {
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		id := r.Header.Get("X-Request-ID")
		if id == "" {
			id = uuid.NewString()
		}
		w.Header().Set("X-Request-ID", id)
		l := slog.Default().With("request_id", id)
		next.ServeHTTP(w, r.WithContext(ConLogger(r.Context(), l)))
	})
}

func Registro(next http.Handler) http.Handler {
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		inicio := time.Now()
		rec := &respuestaRegistrada{ResponseWriter: w, estado: http.StatusOK}
		next.ServeHTTP(rec, r)

		Log(r.Context()).LogAttrs(r.Context(), slog.LevelInfo, "petición",
			slog.String("metodo", r.Method),
			slog.String("ruta", r.URL.Path),
			slog.Int("estado", rec.estado),
			slog.Duration("duracion", time.Since(inicio)),
			slog.String("ip", r.RemoteAddr),
		)
	})
}

type Usuario struct{ ID int64; Email, Password string }

func (u Usuario) LogValue() slog.Value {
	return slog.GroupValue(slog.Int64("id", u.ID)) // solo el ID
}

go get github.com/prometheus/client_golang/prometheus
go get github.com/prometheus/client_golang/prometheus/promhttp

package observabilidad

import (
	"net/http"
	"strconv"
	"time"

	"github.com/prometheus/client_golang/prometheus"
	"github.com/prometheus/client_golang/prometheus/promauto"
)

var (
	peticiones = promauto.NewCounterVec(prometheus.CounterOpts{
		Name: "http_requests_total",
		Help: "Total de peticiones HTTP.",
	}, []string{"metodo", "ruta", "estado"})

	latencia = promauto.NewHistogramVec(prometheus.HistogramOpts{
		Name:    "http_request_duration_seconds",
		Help:    "Duración de las peticiones HTTP.",
		Buckets: prometheus.DefBuckets, // 5 ms … 10 s; ajústalos a tu SLO
	}, []string{"metodo", "ruta"})

	enVuelo = promauto.NewGauge(prometheus.GaugeOpts{
		Name: "http_requests_in_flight",
		Help: "Peticiones en curso.",
	})
)

func Metricas(next http.Handler) http.Handler {
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		enVuelo.Inc()
		defer enVuelo.Dec()

		inicio := time.Now()
		rec := &respuestaRegistrada{ResponseWriter: w, estado: http.StatusOK}
		next.ServeHTTP(rec, r)

		// r.Pattern (Go 1.23+) = patrón del enrutador, p. ej. "GET /tareas/{id}"
		ruta := r.Pattern
		if ruta == "" {
			ruta = "desconocida"
		}
		latencia.WithLabelValues(r.Method, ruta).Observe(time.Since(inicio).Seconds())
		peticiones.WithLabelValues(r.Method, ruta, strconv.Itoa(rec.estado)).Inc()
	})
}

import "github.com/prometheus/client_golang/prometheus/promhttp"

// En un puerto interno (o protegido), no en el público:
interno := http.NewServeMux()
interno.Handle("GET /metrics", promhttp.Handler())
go http.ListenAndServe("127.0.0.1:9100", interno)

tareasCreadas = promauto.NewCounter(prometheus.CounterOpts{Name: "tareas_creadas_total", Help: "Tareas creadas."})
colaProfundidad = promauto.NewGaugeFunc(prometheus.GaugeOpts{Name: "cola_pendientes"}, func() float64 { return float64(contarPendientes()) })

# Tasa de peticiones por segundo
sum(rate(http_requests_total[5m]))

# Porcentaje de errores 5xx
sum(rate(http_requests_total{estado=~"5.."}[5m])) / sum(rate(http_requests_total[5m]))

# Latencia p95
histogram_quantile(0.95, sum by (le) (rate(http_request_duration_seconds_bucket[5m])))

scrape_configs:
  - job_name: tareas
    scrape_interval: 15s
    static_configs:
      - targets: ["host.docker.internal:9100"]

GET /tareas (trace 4bf92f…)
├─ handler.listar              90 ms
│  ├─ db.ListarTareas          70 ms   ← el cuello de botella se ve de un vistazo
│  └─ template.render          15 ms

go get go.opentelemetry.io/otel \
       go.opentelemetry.io/otel/sdk \
       go.opentelemetry.io/otel/exporters/stdout/stdouttrace \
       go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp

func IniciarTrazas(ctx context.Context, servicio string) (func(context.Context) error, error) {
	exp, err := stdouttrace.New(stdouttrace.WithPrettyPrint()) // en producción: OTLP (otlptracegrpc)
	if err != nil {
		return nil, err
	}
	res, err := resource.Merge(resource.Default(),
		resource.NewSchemaless(semconv.ServiceName(servicio)))
	if err != nil {
		return nil, err
	}
	tp := sdktrace.NewTracerProvider(
		sdktrace.WithBatcher(exp),
		sdktrace.WithResource(res),
		sdktrace.WithSampler(sdktrace.ParentBased(sdktrace.TraceIDRatioBased(0.1))), // muestrea el 10 %
	)
	otel.SetTracerProvider(tp)
	otel.SetTextMapPropagator(propagation.NewCompositeTextMapPropagator(
		propagation.TraceContext{}, propagation.Baggage{}))
	return tp.Shutdown, nil // llamar al apagar para vaciar los spans pendientes
}

// Todo el servidor: crea un span por petición y propaga el contexto entrante
handler := otelhttp.NewHandler(mux, "tareas")

// Spans propios
var tracer = otel.Tracer("tareas/servicio")

func (s *Servicio) Listar(ctx context.Context) ([]Tarea, error) {
	ctx, span := tracer.Start(ctx, "servicio.Listar")
	defer span.End()

	ts, err := s.repo.Listar(ctx)
	if err != nil {
		span.RecordError(err)
		span.SetStatus(codes.Error, "falló el listado")
		return nil, err
	}
	span.SetAttributes(attribute.Int("tareas.cantidad", len(ts)))
	return ts, nil
}

sc := trace.SpanContextFromContext(ctx)
if sc.IsValid() {
	l = l.With("trace_id", sc.TraceID().String(), "span_id", sc.SpanID().String())
}

// Liveness: el proceso responde.
mux.HandleFunc("GET /healthz", func(w http.ResponseWriter, _ *http.Request) {
	w.WriteHeader(http.StatusOK)
})

// Readiness: está lista para recibir tráfico (dependencias OK).
mux.HandleFunc("GET /readyz", func(w http.ResponseWriter, r *http.Request) {
	ctx, cancel := context.WithTimeout(r.Context(), 2*time.Second)
	defer cancel()
	if err := pool.Ping(ctx); err != nil {
		http.Error(w, "base de datos no disponible", http.StatusServiceUnavailable)
		return
	}
	w.WriteHeader(http.StatusOK)
})

go build -ldflags "-X main.version=$(git describe --tags --always)" ./cmd/tareas