CreaRack-SL

Desconexiones recurrentes del Agente y WebSockets: causa raíz en redis-py 8.0.x

Resumen

El flapping recurrente de WebSockets (task #203) — especialmente graves en el Agente (3.539 reconexiones el 21-07-2026) — fue causado por una librería de cliente Redis, actualizada el 11 de julio de 2026 (v1.48.10, commit s217), que cambió de comportamiento con respecto a timeouts en operaciones bloqueantes.

Causa raíz: redis-py 8.0.x aplica el read_timeout del socket TCP a los comandos bloqueantes. El channel layer (channels_redis) espera mensajes con BZPOPMIN(timeout=5), perdiendo la carrera contra su propia respuesta vacía → receive() revienta con TimeoutError: Timeout reading from cache:6379 exactamente a los 5.0s. Daphne cierra el WebSocket con close_code 1011.

Impacto: todo consumer sin mensajes >5s se desconecta. El Agente (conexión de larga vida sin tráfico constante) moría cada ~6,6s.

Resolución: downgrade a redis==6.2.0 (estado bueno conocido, vigente meses sin incidentes). Test de regresión añadido.


Línea de tiempo

FechaEvento
11-07-2026 (v1.48.10, s217)Redis bump a 8.0.1; ningún test de receive() ocioso >5s en CI
21-07-2026Flapping masivo del Agente detectado en PROD; 3.539 reconexiones en 24h; task #203 abierta
22-07-2026 (v1.62.0)Instrumentación de close_code agregada → 1011 apunta a servidor
22-07-2026 (v1.62.0 tarde)Traceback de PROD: Timeout reading from cache:6379 en channels/utils.py await_many_dispatch
22-07-2026 (v1.62.1, 12:17 UTC)A/B reproducido (8.0.1 revienta / 6.2.0 aguanta indefinidamente); downgrade aplicado

Síntomas observados

  1. Cerramientos con close_code 1011 (servidor indica error interno) tras ~5-7s de inactividad
  2. Agente reconectando en bucle cada ~6,6s (sin actividad de usuario)
  3. Otros WebSockets sin datos en tiempo real también afectados (cualquiera que pasara >5s sin recibir)
  4. Traceback preciso en PROD: Timeout reading from cache:6379 en el path del channel layer
  5. Hipótesis descartadas por el diagnóstico:
    • VPN/keepalive de oficina (el cierre era de la aplicación SaaS)
    • Proxy Cloudflare (timeout ocurría antes del proxy)

Raíz técnica

Comportamiento de redis-py 6.2.0 vs 8.0.x

redis-py 6.2.0 (sano):

# En operaciones bloqueantes (BRPOP, BZPOPMIN, etc.):
# read_timeout NO se aplica — espera indefinidamente
sock.recv()  # bloqueante, sin timeout de socket

redis-py 8.0.x (buggy):

# El read_timeout configurado en el cliente (default 0 → sin timeout)
# SE APLICA TAMBIÉN a operaciones bloqueantes:
# Si el servidor tarda >5s en responder → TimeoutError
sock.recv()  # bloqueante CON read_timeout = socket_timeout

Cómo muere el consumer

  1. Consumer invoca layer.receive(channel) → channel layer envía BZPOPMIN con timeout=5
  2. Redis responde vacío (sin mensajes en la lista)
  3. En redis-py 8.0.x, el socket read-timeout (~0ms en conexión local, pero configurado en el cliente) entra en conflicto
  4. Exactamente a los 5.0s, receive() levanta TimeoutError
  5. Daphne captura la excepción no manejada y cierra el WebSocket con 1011

Resolución aplicada

Versión pinned: redis==6.2.0
Commit: c06a9d1 (22-07-2026)
Cambios:

  • requirements.txt: downgrade redis 8.0.1 → 6.2.0
  • Pin comentado con diagnóstico completo (motivo, bug, A/B, gate obligatorio)
  • Test de regresión: tests/api/test_channel_layer_stability.py

Test de regresión

def test_channel_layer_receive_survives_idle_gap():
    # Mantiene receive() ocioso >5s — con bug falla antes
    # Afirma por TIEMPO (no por excepción) para evitar enmascarse
    assert elapsed >= 6.4  # segundos

Gate obligatorio: cualquier intento futuro de re-subir redis-py a 8.x requiere pasar este test contra el candidato (task de seguimiento en Gestor).


Validación

  • ✅ A/B en PROD: 8.0.1 → 1011 cada 6.6s | 6.2.0 → sin cerramientos
  • ✅ A/B en local: reproducido con config REDIS_URL real
  • ✅ Valkey estaba sano (<1ms latencia, slowlog vacío) → era el cliente
  • ✅ Hipótesis VPN/CF/red descartadas por timing exacto a 5.0s

Impacto de negocio

  • Severidad: CRÍTICA (infraestructura de tiempo real inutilizable)
  • Duración: ~11 días (11-07 a 22-07-2026)
  • Usuarios afectados: todos con Agente o monitoreo en tiempo real
  • Métricas: 3.539 reconexiones del Agente en 24h (21-07)

Conceptos relacionados

  • [[entity—core—service—channel-layer]] — gestión de canales en tiempo real
  • [[entity—infra—service—redis-client]] — cliente Redis y configuración
  • [[decision—20260722—redis-6-2-0-cap-bloqueante]] — decisión arquitectónica del downgrade
  • [[concept—reliability—timeout-handling]] — manejo de timeouts en operaciones bloqueantes

Véase también

  • [[decision—20260722—redis-6-2-0-cap-bloqueante]]
  • [[entity—core—service—channel-layer]]
  • [[concept—reliability—timeout-handling]]
  • [[concept—infra—redis-config]]
  • [[entity—core—endpoint—websocket-agent]]