Las gráficas del Observatory salían vacías a ratos: el suavizado se leía fuera del hilo del ORM (task #297)

Cuándo

07-09-2026, detectado por hallazgo colateral en el log de PROD durante otra sesión (task #297, segundo PR de s313). El síntoma llevaba tiempo activo pero pasaba desapercibido: sin error visible en pantalla, solo una gráfica en blanco de vez en cuando.

Reapareció el 25-09-2026 (ver sección dedicada abajo): el propio fix de este incidente introdujo una regresión distinta que rompió el mismo síntoma en CADA petición desde el día en que se desplegó (v1.129.0) — 18 días en producción sin detectarse, hasta la mega-auditoría ronda 5.

Síntomas visibles

En el log de producción aparecía, cada pocos minutos: [vm/all] target=1199 ping EXCEPTION: You cannot call this from an async context (visto a las 09:11 y 09:12 UTC). En pantalla, la ficha de un equipo en el Observatory mostraba la gráfica de ping (latencia o pérdida de paquetes) vacía una vez cada ~5 minutos por organización, sin ningún aviso — la petición HTTP devolvía 200 igualmente.

Causa raíz

MetricsReaderBase._get_smoothing_level lee la preferencia de suavizado del usuario con get_ui_pref, que consulta PostgreSQL cuando su caché L1 en Valkey (5 minutos de vida) no tiene el valor. Tres métodos de MetricsReader (get_ping_latency, get_ping_packet_loss, get_http_metrics, en monitoring/services/metrics_reader.py) son corrutinas que corren bajo run_async → asyncio.run, y llamaban a _get_smoothing_level en línea — código síncrono con acceso al ORM, que Django prohíbe ejecutar dentro de un event loop. La primera petición tras expirar la caché L1 moría con SynchronousOnlyOperation; el endpoint /api/monitoring/targets/{id}/vm/all envuelve estas llamadas en un gather(..., return_exceptions=True) que se tragaba la excepción, y la serie de esa métrica volvía vacía ({latency: [], packet_loss: []}) en vez de propagar el fallo.

Fix aplicado (07-09-2026)

Commit c7c20bdef87f8861373e5a5387e1660d2527c92b (PR #523, v1.129.0):

• Nuevo método MetricsReaderBase._aget_smoothing_level (monitoring/services/metrics_reader_base.py), que ejecuta la versión síncrona _get_smoothing_level en el hilo del ORM vía sync_to_async(..., thread_sensitive=True).
• Las tres corrutinas de metrics_reader.py pasan de cls._get_smoothing_level(tenant_id) a await cls._aget_smoothing_level(tenant_id).
• La versión síncrona original se conserva intacta — la siguen usando los tests de la task #286-#6 y las vistas síncronas del proyecto.
• 3 tests nuevos en tests/monitoring/test_smoothing_level_async.py (con transaction=True, serialized_rollback=True por cruzar de hilo): caché L1 vacía dentro de asyncio.run devuelve el valor de PostgreSQL en vez de reventar; get_ping_latency con L1 vacía usa la ventana de suavizado correcta; la versión síncrona sigue funcionando igual.

Reaparición 25-09-2026: el propio fix rompió el mismo síntoma por una causa distinta

El síntoma volvió — gráfica de ping vacía en /vm/all — pero esta vez en CADA petición, no solo tras expirar la caché L1, y desde el mismo despliegue del fix de arriba (v1.129.0). 18 días en producción sin que nadie lo detectara, hasta la mega-auditoría ronda 5 del 25-09-2026.

Causa raíz de la regresión: _aget_smoothing_level llamaba a sync_to_async(cls._get_smoothing_level, thread_sensitive=True) desde dentro de una vista síncrona de Django ejecutada bajo Daphne (ASGI) con al menos un middleware síncrono en la cadena. En ese contexto concreto, el hilo que ejecuta asyncio.run (vía run_async) es el MISMO hilo al que thread_sensitive=True intenta enviar el trabajo síncrono — y asgiref lo rechaza con RuntimeError: You cannot submit onto CurrentThreadExecutor from its own thread. El gather(..., return_exceptions=True) de /vm/all volvía a tragarse la excepción y la gráfica salía vacía, igual que el síntoma original, pero por un motivo nuevo: no es un problema de cruzar de hilo sin sync_to_async, es que ESE sync_to_async concreto apuntaba al hilo equivocado en este contexto real de despliegue (Daphne + middleware síncrono) — algo que los 3 tests del fix de septiembre, al invocar la corrutina directamente sin pasar por Daphne, no podían reproducir.

Fix real (commit 11d687c404a1755c9dc0c86a30a9bdb87914efd3, PR #608, v1.160.0): en vez de resolver smoothing_level dentro de la corrutina, las vistas síncronas (get_ping_metrics_sync, get_http_metrics_sync en monitoring/services/metrics_reader.py) lo resuelven ANTES, en su propio hilo síncrono (que ya tiene ORM y el GUC de RLS de la petición) llamando a _get_smoothing_level directo, y lo pasan como parámetro smoothing_level a get_ping_latency/get_ping_packet_loss/get_http_metrics/get_ping_metrics. _aget_smoothing_level (el sync_to_async problemático) queda solo como camino de repliegue para corrutinas que no pasan por una vista (tests, scripts) y, si aun así falla, devuelve "medium" con un aviso en el registro en vez de dejar la gráfica en blanco. También se corrigió _get_smoothing_level para tratar un valor guardado inválido (cadena vacía) como "medium", igual que ya hacía _get_smoothing_window.

Lecciones

Cualquier corrutina que llegue a tocar el ORM de Django — aunque sea indirectamente, a través de una función de utilidad que solo cachea en Valkey “la mayoría de las veces” — necesita el cruce explícito de hilo (sync_to_async). El fallo original no se veía en desarrollo ni en pruebas manuales porque la caché L1 casi siempre está caliente; solo aparecía en producción, en la ventana de segundos tras la expiración de cada clave, y encima quedaba absorbido en silencio por el gather(return_exceptions=True) del endpoint agregador.

Añadido tras la reaparición: sync_to_async(thread_sensitive=True) no es una solución universal para “corrutina que toca el ORM” — su corrección depende de EN QUÉ HILO se ejecuta la corrutina que lo llama, y ese hilo cambia según el servidor (ASGI puro vs. Daphne con middleware síncrono) y el camino de entrada (vista real vs. test que invoca la corrutina directamente). Un test que reproduce la corrutina de forma aislada, sin el servidor ASGI real ni su cadena de middleware, puede no reproducir el hilo/loop real de producción y dar un fix por bueno cuando no lo es.

Preventivos futuros

• Revisar si otras funciones de preferencia/configuración con patrón caché-Valkey-con-fallback-a-PostgreSQL se llaman en línea desde corrutinas del módulo monitoring sin pasar por sync_to_async.
• Seguía sin resolverse el 25-09: valorar que los gather(..., return_exceptions=True) de endpoints agregadores logueen la excepción capturada en vez de tragarla silenciosamente — las DOS apariciones de este incidente se ocultaron precisamente ahí; un log habría acortado 18 días de regresión silenciosa a horas.
• Un fix que envuelve una corrutina con sync_to_async(thread_sensitive=True) se valida bajo el servidor ASGI real (Daphne, con la cadena de middleware de la app), no solo con un test que llama a la corrutina de forma aislada.

Véase también

• [[crearack-tech—backend—network-observatory]]
• [[entity—monitoring—consumer—realtime-websocket]]
• [[incident—20260831—auditoria-suprema-2-tanda1-monitoring-racks]]
• [[feature—monitoring—auditoria-261-ciclo-4-cableado-observatory]]
• [[feature—monitoring—bandwidth-interface-selector]]
• [[decision—20260604—broken-access-control-vistas-observatory]]
• [[feature—monitoring—observatory-unified-sidebar]]