Observability en DRF: structured logging, metrics y OpenTelemetry

Los tres pilares de observability

• Logs: lo que paso (mensajes con contexto). Buenos para debugging, pero costosos si abusan.
• Metrics: agregados numericos (peticiones/s, latencia p99, errores 5xx). Cardinalidad baja, baratos, ideales para alertas.
• Traces: el viaje de una peticion atravesando varios servicios. Permiten ver donde se pierde el tiempo realmente.

Cada uno responde a preguntas distintas.

Sin los tres, debugging en produccion se vuelve adivinanza. Logs te dicen que paso, metrics te dicen cuantas veces, traces te dicen donde.

Structured logging con structlog

Los print() y los logs con f"User {user_id} did X" son ilegibles en produccion. Lo correcto es JSON estructurado con campos.

pip install structlog django-structlog

# settings.py
import structlog

INSTALLED_APPS += ["django_structlog"]

MIDDLEWARE += [
    "django_structlog.middlewares.RequestMiddleware",
]

LOGGING = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "json": {
            "()": "structlog.stdlib.ProcessorFormatter",
            "processor": structlog.processors.JSONRenderer(),
        },
    },
    "handlers": {
        "console": {"class": "logging.StreamHandler", "formatter": "json"},
    },
    "root": {"level": "INFO", "handlers": ["console"]},
}

structlog.configure(
    processors=[
        structlog.contextvars.merge_contextvars,
        structlog.processors.TimeStamper(fmt="iso"),
        structlog.processors.add_log_level,
        structlog.stdlib.PositionalArgumentsFormatter(),
        structlog.processors.StackInfoRenderer(),
        structlog.processors.format_exc_info,
        structlog.stdlib.ProcessorFormatter.wrap_for_formatter,
    ],
    logger_factory=structlog.stdlib.LoggerFactory(),
)

Uso:

import structlog
log = structlog.get_logger(__name__)

class PedidoViewSet(ModelViewSet):
    def perform_create(self, serializer):
        pedido = serializer.save()
        log.info("pedido_creado", pedido_id=pedido.id, total=str(pedido.total))

Salida:

{"event": "pedido_creado", "pedido_id": 42, "total": "59.90", "timestamp": "2026-04-18T10:00:00Z", "level": "info", "request_id": "abc-123"}

Los campos son queryables en herramientas como Loki, Datadog Logs, Splunk o Elasticsearch. Buscar "todas las peticiones del usuario X que fallaron" se vuelve trivial.

Metricas Prometheus con django-prometheus

pip install django-prometheus

# settings.py
INSTALLED_APPS += ["django_prometheus"]

MIDDLEWARE = [
    "django_prometheus.middleware.PrometheusBeforeMiddleware",
    *MIDDLEWARE,
    "django_prometheus.middleware.PrometheusAfterMiddleware",
]

# urls.py
urlpatterns = [
    path("", include("django_prometheus.urls")),  # /metrics
    ...
]

GET /metrics ya devuelve metricas estandar:

django_http_responses_total_by_status{status="200"} 12345
django_http_requests_latency_seconds_by_view_method_bucket{le="0.1"} 9000
django_db_query_duration_seconds_count 8765

Configura Prometheus para hacer scrape cada 15s y conecta Grafana para dashboards.

Metricas custom

from prometheus_client import Counter, Histogram

pedidos_creados = Counter(
    "pedidos_creados_total",
    "Numero de pedidos creados",
    ["estado"],
)
pago_duration = Histogram(
    "pago_duration_seconds",
    "Duracion del proceso de pago",
)

def crear_pedido(usuario, items):
    with pago_duration.time():
        pedido = procesar_pago(usuario, items)
    pedidos_creados.labels(estado=pedido.estado).inc()
    return pedido

Cuidado con la cardinalidad de los labels: nunca uses user_id o pedido_id como label (cada valor crea una serie temporal nueva). Maximo 10-20 valores distintos por label.

OpenTelemetry: trazas distribuidas

Una peticion que entra a tu API puede llamar a Postgres, a Redis y a un microservicio externo. Sin trazas, ves tres lineas de log inconexas. Con OpenTelemetry, ves un arbol completo con la duracion de cada span.

pip install \
  opentelemetry-distro \
  opentelemetry-exporter-otlp \
  opentelemetry-instrumentation-django \
  opentelemetry-instrumentation-psycopg2 \
  opentelemetry-instrumentation-requests \
  opentelemetry-instrumentation-celery \
  opentelemetry-instrumentation-redis

# core/otel.py
from opentelemetry import trace
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import BatchSpanProcessor
from opentelemetry.sdk.resources import Resource
from opentelemetry.exporter.otlp.proto.grpc.trace_exporter import OTLPSpanExporter
from opentelemetry.instrumentation.django import DjangoInstrumentor
from opentelemetry.instrumentation.psycopg2 import Psycopg2Instrumentor
from opentelemetry.instrumentation.requests import RequestsInstrumentor
from opentelemetry.instrumentation.celery import CeleryInstrumentor

def configurar_otel(service_name="drf-api"):
    resource = Resource.create({"service.name": service_name})
    provider = TracerProvider(resource=resource)
    provider.add_span_processor(BatchSpanProcessor(OTLPSpanExporter(
        endpoint="http://otel-collector:4317",
        insecure=True,
    )))
    trace.set_tracer_provider(provider)
    DjangoInstrumentor().instrument(is_sql_commentor_enabled=True)
    Psycopg2Instrumentor().instrument()
    RequestsInstrumentor().instrument()
    CeleryInstrumentor().instrument()

# manage.py o wsgi.py o asgi.py al arrancar
from core.otel import configurar_otel
configurar_otel()

Auto-instrumentacion crea spans automaticamente para vistas Django, queries SQL y llamadas requests. Manual solo para tu logica de dominio si necesitas spans adicionales.

Spans manuales

from opentelemetry import trace
tracer = trace.get_tracer(__name__)

def procesar_pago(pedido):
    with tracer.start_as_current_span("procesar_pago", attributes={"pedido.id": pedido.id}):
        with tracer.start_as_current_span("stripe.charge"):
            stripe_charge(...)
        with tracer.start_as_current_span("enviar_email"):
            send_email(...)

Propagacion W3C traceparent

OpenTelemetry usa el header traceparent (W3C Trace Context) para propagar el trace entre servicios:

GET /api/recos HTTP/1.1
traceparent: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01

Si tu API llama via requests (instrumentado) a otro servicio, automaticamente le manda traceparent. El otro servicio (si tambien usa OTel) crea spans hijos del mismo trace, lo que te da una traza distribuida.

Trace_id en los logs

Para correlacionar logs y trazas, anade el trace_id a cada log:

import structlog
from opentelemetry import trace

def add_trace_id(logger, method_name, event_dict):
    span = trace.get_current_span()
    if span and span.get_span_context().is_valid:
        ctx = span.get_span_context()
        event_dict["trace_id"] = format(ctx.trace_id, "032x")
        event_dict["span_id"]  = format(ctx.span_id, "016x")
    return event_dict

structlog.configure(processors=[
    add_trace_id,
    structlog.processors.JSONRenderer(),
])

Ahora cada log incluye trace_id y desde Datadog/Grafana puedes saltar log -> traza con un click.

Diagrama del stack

flowchart TB
    subgraph App[DRF API]
        V[ViewSet]
        L[structlog]
        T[OpenTelemetry SDK]
        M[django-prometheus]
    end
    subgraph Backends
        Loki[(Loki)]
        Prom[(Prometheus)]
        Tempo[(Tempo / Jaeger)]
    end
    subgraph UI
        Graf[Grafana]
    end
    L --> Loki
    M --> Prom
    T --> OC[OTel collector]
    OC --> Tempo
    Loki --> Graf
    Prom --> Graf
    Tempo --> Graf

Patrones a evitar

• Loggear info sensible (passwords, tokens, PII). Filtralos con un processor redactor antes de exportar.
• Cardinalidad infinita en metricas: nunca user_id como label.
• Spans gigantes: traces que duran 10 minutos llenan la BBDD del backend. Si un job dura asi, divide en spans mas pequenos.
• Sample rate al 100% en alto volumen: 1 millon de spans/s puede saturar tu collector. Usa TraceIdRatioBased(0.1) para muestrear 10%.
• No alertar sobre metricas: tener Grafana sin alertas en Prometheus es solo decoracion.

Que medir como minimo

Cuatro golden signals (Google SRE):

• Latencia (p50, p95, p99 por endpoint).
• Trafico (req/s).
• Errores (4xx y 5xx por endpoint).
• Saturacion (CPU, memoria, conexiones BBDD activas, queue depth Celery).

Configura alertas en p95 > 500ms, error rate > 1% y queue depth > 1000.