From ba3700036014c59930e637e0ec613725698fdbdf Mon Sep 17 00:00:00 2001 From: devRaGonSa Date: Wed, 10 Jun 2026 19:58:18 +0200 Subject: [PATCH] Fix current match AdminLog read-only PostgreSQL path --- ...urrent-match-kills-and-players-timeouts.md | 162 ++++++++++++++++++ backend/app/rcon_admin_log_storage.py | 4 +- backend/tests/test_current_match_payload.py | 73 +++++++- docs/FULL_APPLICATION_REQUEST_AUDIT.md | 36 ++++ docs/PERFORMANCE_PUBLIC_QUERY_AUDIT.md | 10 +- 5 files changed, 278 insertions(+), 7 deletions(-) create mode 100644 ai/tasks/done/TASK-227-fix-current-match-kills-and-players-timeouts.md diff --git a/ai/tasks/done/TASK-227-fix-current-match-kills-and-players-timeouts.md b/ai/tasks/done/TASK-227-fix-current-match-kills-and-players-timeouts.md new file mode 100644 index 0000000..012d913 --- /dev/null +++ b/ai/tasks/done/TASK-227-fix-current-match-kills-and-players-timeouts.md @@ -0,0 +1,162 @@ +--- +id: TASK-227 +title: Fix current-match kills and players timeouts +status: done +type: backend +team: Backend Senior +supporting_teams: [] +roadmap_item: foundation +priority: high +--- + +# TASK-227 - Fix current-match kills and players timeouts + +## Goal + +Corregir especificamente los endpoints publicos secundarios de partida actual que seguian bloqueando tras `TASK-226`: + +- `/api/current-match/kills` +- `/api/current-match/players` + +El objetivo no es reconectar RCON ni cambiar configuracion, sino evitar que estos endpoints publicos entren en inicializacion o lecturas bloqueantes y asegurar degradacion JSON controlada cuando el read model no este disponible. + +## Context + +Validacion real tras `TASK-226` contra produccion: + +```powershell +python .\scripts\audit_public_requests.py --base-url https://comunidadhll.devzamode.es --timeout 30 --filter current-match --output tmp\task226_current_match_audit_after.json +``` + +Resultados relevantes: + +- `current-match-comunidad-hispana-01`: OK 200, 2314 ms. +- `current-match-kills-comunidad-hispana-01`: CRITICAL, timeout 30026 ms. +- `current-match-players-comunidad-hispana-01`: CRITICAL, timeout 30079 ms. +- `current-match-comunidad-hispana-02`: OK 200, 2265 ms. +- `current-match-kills-comunidad-hispana-02`: CRITICAL, timeout 30050 ms. +- `current-match-players-comunidad-hispana-02`: CRITICAL, 200 pero 26095 ms, `fallback=True`. + +Tambien se valido que `/api/servers` ya esta OK en unos 82 ms y que `TASK-225` sigue OK para player search/profile y historical match detail. Esta task no toca esas rutas. + +## Files Read First + +- `ai/architecture-index.md` +- `ai/repo-context.md` +- `ai/orchestrator/backend-senior.md` +- `backend/README.md` +- `backend/app/routes.py` +- `backend/app/payloads.py` +- `backend/app/rcon_admin_log_storage.py` +- `backend/app/postgres_rcon_storage.py` +- `backend/tests/test_current_match_payload.py` + +## Call Chain Analysis + +Rutas exactas en `backend/app/routes.py`: + +- `/api/current-match/kills` valida `server`, `limit`, `since_event_id` y llama `build_current_match_kill_feed_payload(server_slug=..., limit=..., since_event_id=...)`. +- `/api/current-match/players` valida `server` y llama `build_current_match_player_stats_payload(server_slug=...)`. +- `/api/current-match` general llama `build_current_match_payload(server_slug=...)`. + +Cadena del endpoint general: + +1. `resolve_get_payload("/api/current-match?...")` +2. `build_current_match_payload()` +3. `_query_current_match_rcon_sample()` intenta una muestra RCON de sesion. +4. Si falla, cae a `build_servers_payload()`. +5. Tras `TASK-226`, `build_servers_payload()` es cache/snapshot-only y no refresca RCON/A2S en el GET publico. + +Cadena de kills: + +1. `resolve_get_payload("/api/current-match/kills?...")` +2. `build_current_match_kill_feed_payload()` +3. `list_current_match_kill_feed(server_key=origin.slug, ensure_storage=False)` +4. En PostgreSQL, el codigo llamaba `connect_postgres_compat()` sin argumentos. +5. `connect_postgres_compat()` tiene `initialize=True` por defecto. +6. `initialize_postgres_rcon_storage()` ejecutaba bootstrap/DDL antes de abrir la lectura. + +Cadena de players: + +1. `resolve_get_payload("/api/current-match/players?...")` +2. `build_current_match_player_stats_payload()` +3. `list_current_match_player_stats(server_key=origin.slug, ensure_storage=False)` +4. En PostgreSQL, el codigo llamaba `connect_postgres_compat()` sin argumentos. +5. `connect_postgres_compat()` inicializaba storage por defecto igual que kills. + +## Root Cause + +`TASK-226` paso `ensure_storage=False` desde los payloads publicos, pero en la rama PostgreSQL de `backend/app/rcon_admin_log_storage.py` ese flag no se propagaba a `connect_postgres_compat()`. + +Resultado: en produccion con `HLL_BACKEND_DATABASE_URL`, kills/players seguian ejecutando `initialize_postgres_rcon_storage()` durante el GET publico. Esa inicializacion/DDL en el request path explica la diferencia frente a `/api/current-match` general: el endpoint general no pasa por AdminLog ni por `connect_postgres_compat()` para construir kills/players; usa muestra RCON de sesion y fallback a snapshot de servidores. + +No se encontro necesidad de cambiar hosts RCON, puertos, `27001`, `127.0.0.1`, variables de entorno ni configuracion de servidores. + +## Changes + +- `backend/app/rcon_admin_log_storage.py` + - `list_current_match_kill_feed()` ahora llama `connect_postgres_compat(initialize=ensure_storage)`. + - `list_current_match_player_stats()` ahora llama `connect_postgres_compat(initialize=ensure_storage)`. + - Con `ensure_storage=False`, las lecturas publicas de AdminLog no inicializan PostgreSQL. +- `backend/tests/test_current_match_payload.py` + - Anade tests de regresion para kills y players verificando que la ruta PostgreSQL read-only llama `connect_postgres_compat(initialize=False)`. +- `docs/FULL_APPLICATION_REQUEST_AUDIT.md` + - Documenta el estado post-fix de `TASK-227`. +- `docs/PERFORMANCE_PUBLIC_QUERY_AUDIT.md` + - Actualiza la nota de arquitectura de lectura publica para reflejar la correccion real de PostgreSQL read-only. + +## Validation + +Validaciones ejecutadas: + +```powershell +python -m compileall backend/app +cd backend +python -m unittest tests.test_current_match_payload +cd backend +python -m unittest tests.test_current_match_payload tests.test_rcon_admin_log_storage tests.test_historical_snapshot_refresh +``` + +Resultados: + +- `python -m compileall backend/app`: OK. +- `cd backend; python -m unittest tests.test_current_match_payload`: OK, 5 tests. +- `cd backend; python -m unittest tests.test_current_match_payload tests.test_rcon_admin_log_storage tests.test_historical_snapshot_refresh`: OK, 18 tests. + +Auditoria HTTP local: + +- No se ejecuto auditoria local porque `http://127.0.0.1:8000/health` no respondio desde el host. + +Comando exacto para validar produccion tras redeploy: + +```powershell +python .\scripts\audit_public_requests.py --base-url https://comunidadhll.devzamode.es --timeout 30 --filter current-match --output tmp\task227_current_match_audit_after.json +``` + +## Outcome + +La ruta publica secundaria de AdminLog queda realmente read-only en PostgreSQL cuando los payloads llaman con `ensure_storage=False`. Si el read model no existe o falla, los payloads ya capturan la excepcion y devuelven `status: ok`, `items: []`, `fallback_used: true` y `fallback_reason` controlado, sin 500 vacio. + +## Constraints Confirmed + +- No se cambio `27001`. +- No se cambiaron hosts ni puertos RCON. +- No se cambio `127.0.0.1`. +- No se cambiaron variables de entorno de servidores. +- No se cambio configuracion de servidores. +- No se toco `/api/servers`. +- No se tocaron player search/profile/historical detail. +- No se reactivo Elo/MMR. +- No se reintrodujo Comunidad Hispana #03. +- No se toco frontend. +- No se tocaron assets, SVGs ni imagenes fisicas. +- No se toco `frontend/assets/img/weapons/`. +- No se toco `frontend/assets/img/clans/`. +- No se toco `ai/system-metrics.md`. +- No se incluyo `tmp/`. + +## Risks + +- Si PostgreSQL esta caido o la apertura de conexion queda bloqueada por red/DNS, el endpoint aun depende del timeout de conexion de PostgreSQL. Esta task elimina el bootstrap/DDL publico identificado, no introduce cambios de configuracion ni pooling. +- `/api/current-match` general sigue con muestra RCON directa por diseno actual; no fue parte de esta task porque la auditoria post-226 lo midio OK en unos 2.3 s. +- La confirmacion final de latencia requiere redeploy y auditoria de produccion. diff --git a/backend/app/rcon_admin_log_storage.py b/backend/app/rcon_admin_log_storage.py index 21e022a..2f2a2c6 100644 --- a/backend/app/rcon_admin_log_storage.py +++ b/backend/app/rcon_admin_log_storage.py @@ -360,7 +360,7 @@ def list_current_match_kill_feed( if use_postgres_rcon_storage(explicit_sqlite_path=db_path): from .postgres_rcon_storage import connect_postgres_compat - connection_scope = connect_postgres_compat() + connection_scope = connect_postgres_compat(initialize=ensure_storage) else: connection_scope = closing(_connect_admin_log_sqlite_read(resolved_path)) @@ -485,7 +485,7 @@ def list_current_match_player_stats( if use_postgres_rcon_storage(explicit_sqlite_path=db_path): from .postgres_rcon_storage import connect_postgres_compat - connection_scope = connect_postgres_compat() + connection_scope = connect_postgres_compat(initialize=ensure_storage) else: connection_scope = closing(_connect_admin_log_sqlite_read(resolved_path)) diff --git a/backend/tests/test_current_match_payload.py b/backend/tests/test_current_match_payload.py index 1656071..d19c13d 100644 --- a/backend/tests/test_current_match_payload.py +++ b/backend/tests/test_current_match_payload.py @@ -1,9 +1,10 @@ from http import HTTPStatus from datetime import datetime, timezone import unittest -from unittest.mock import patch +from unittest.mock import MagicMock, patch from app import payloads +from app import rcon_admin_log_storage from app.payloads import build_current_match_payload from app.rcon_admin_log_storage import list_current_match_player_stats, persist_rcon_admin_log_entries from app.rcon_client import RconServerTarget @@ -561,6 +562,53 @@ class CurrentMatchPublicEndpointHardeningTests(unittest.TestCase): self.assertEqual(data["refresh_status"], "cache-only") self.assertEqual(data["source"], "persisted-stale-snapshot") + def test_kill_feed_postgres_read_only_does_not_initialize_storage(self) -> None: + connection = _FakeAdminLogConnection( + [ + None, + [], + ] + ) + connection_scope = _FakeConnectionScope(connection) + with ( + patch.object(rcon_admin_log_storage, "use_postgres_rcon_storage", return_value=True), + patch( + "app.postgres_rcon_storage.connect_postgres_compat", + return_value=connection_scope, + ) as connect_postgres, + ): + result = rcon_admin_log_storage.list_current_match_kill_feed( + server_key="comunidad-hispana-01", + ensure_storage=False, + ) + + connect_postgres.assert_called_once_with(initialize=False) + self.assertEqual(result["items"], []) + + def test_player_stats_postgres_read_only_does_not_initialize_storage(self) -> None: + connection = _FakeAdminLogConnection( + [ + None, + [], + ] + ) + connection_scope = _FakeConnectionScope(connection) + with ( + patch.object(rcon_admin_log_storage, "use_postgres_rcon_storage", return_value=True), + patch( + "app.postgres_rcon_storage.connect_postgres_compat", + return_value=connection_scope, + ) as connect_postgres, + ): + result = rcon_admin_log_storage.list_current_match_player_stats( + server_key="comunidad-hispana-01", + ensure_storage=False, + ) + + connect_postgres.assert_called_once_with(initialize=False) + self.assertEqual(result["items"], []) + self.assertEqual(result["source"], "rcon-admin-log-current-match-summary") + def _build_with_rcon_sample(sample: dict[str, object]) -> dict[str, object]: with ( @@ -590,3 +638,26 @@ def _build_with_snapshot_fallback( ): payload = build_current_match_payload(server_slug=server_slug) return payload["data"] + + +class _FakeConnectionScope: + def __init__(self, connection: object) -> None: + self.connection = connection + + def __enter__(self) -> object: + return self.connection + + def __exit__(self, exc_type: object, exc: object, traceback: object) -> None: + return None + + +class _FakeAdminLogConnection: + def __init__(self, query_results: list[object]) -> None: + self._query_results = list(query_results) + + def execute(self, *_args: object, **_kwargs: object) -> MagicMock: + result = self._query_results.pop(0) + cursor = MagicMock() + cursor.fetchone.return_value = result + cursor.fetchall.return_value = result + return cursor diff --git a/docs/FULL_APPLICATION_REQUEST_AUDIT.md b/docs/FULL_APPLICATION_REQUEST_AUDIT.md index 14f2ee9..4a08607 100644 --- a/docs/FULL_APPLICATION_REQUEST_AUDIT.md +++ b/docs/FULL_APPLICATION_REQUEST_AUDIT.md @@ -108,6 +108,42 @@ Notas: - La frescura de `/api/servers` depende ahora del proceso/runner que mantenga snapshots calientes fuera del request publico. - Auditoria parcial contra produccion ejecutada el 2026-06-10 antes de desplegar este codigo: `current-match` todavia mostro los timeouts/500 previos y `/api/servers` midio 4249.71 ms. Repetir tras deploy para confirmar los tiempos post-fix reales. +## Estado post-fix TASK-227 + +Fecha: 2026-06-10 +Alcance aplicado: correccion especifica de `/api/current-match/kills` y `/api/current-match/players` despues de que la auditoria real post-`TASK-226` siguiera mostrando timeouts de 26-30 s en esos endpoints. + +Causa confirmada: + +- Los payloads ya llamaban `list_current_match_kill_feed(..., ensure_storage=False)` y `list_current_match_player_stats(..., ensure_storage=False)`. +- En la rama SQLite eso abria el storage en modo lectura. +- En la rama PostgreSQL, `backend/app/rcon_admin_log_storage.py` llamaba `connect_postgres_compat()` sin pasar el flag. +- `connect_postgres_compat()` usa `initialize=True` por defecto, por lo que kills/players seguian ejecutando `initialize_postgres_rcon_storage()` en el GET publico. + +Cambios de codigo aplicados: + +- `/api/current-match/kills`: la lectura PostgreSQL de AdminLog ahora propaga `initialize=ensure_storage`; con `ensure_storage=False` no ejecuta bootstrap/DDL. +- `/api/current-match/players`: aplica el mismo fix para el resumen de jugadores. +- Tests de regresion verifican que ambos caminos PostgreSQL publicos llaman `connect_postgres_compat(initialize=False)`. + +Diferencia con `/api/current-match` general: + +- `/api/current-match` usa `_query_current_match_rcon_sample()` y fallback a snapshot de servidores; no pasa por el read model AdminLog de kills/players. +- Kills/players son vistas derivadas de AdminLog y el problema estaba en la inicializacion PostgreSQL de esa capa, no en host/puerto RCON. + +Estado esperado tras redeploy: + +| Endpoint | Estado TASK-227 en codigo | Severidad esperada tras deploy | +| --- | --- | --- | +| `/api/current-match/kills` | PostgreSQL read-only real; sin `initialize_postgres_rcon_storage()` en GET publico | OK o WARNING si falta read model | +| `/api/current-match/players` | PostgreSQL read-only real; sin `initialize_postgres_rcon_storage()` en GET publico | OK o WARNING si falta read model | + +Comando de validacion de produccion tras redeploy: + +```powershell +python .\scripts\audit_public_requests.py --base-url https://comunidadhll.devzamode.es --timeout 30 --filter current-match --output tmp\task227_current_match_audit_after.json +``` + ## Evidencia ejecutada Comandos ejecutados: diff --git a/docs/PERFORMANCE_PUBLIC_QUERY_AUDIT.md b/docs/PERFORMANCE_PUBLIC_QUERY_AUDIT.md index 77372ef..2eaf7e1 100644 --- a/docs/PERFORMANCE_PUBLIC_QUERY_AUDIT.md +++ b/docs/PERFORMANCE_PUBLIC_QUERY_AUDIT.md @@ -8,12 +8,14 @@ Actualizacion TASK-225, 2026-06-10: la deuda P1 de `stats search` y `stats playe Actualizacion TASK-226, 2026-06-10: `/api/current-match/kills` y `/api/current-match/players` pasan a usar AdminLog en lectura publica sin inicializar storage y con degradacion JSON controlada si el read model no esta disponible o falla. `/api/servers` pasa a ser snapshot/cache-only en el GET publico y ya no dispara refresh RCON/A2S live durante la lectura. La deuda restante de `current-match` queda en `/api/current-match`, que todavia puede intentar una muestra RCON directa antes de caer a snapshot. +Actualizacion TASK-227, 2026-06-10: la auditoria real post-`TASK-226` mostro que kills/players seguian bloqueando en produccion porque la rama PostgreSQL de AdminLog no propagaba `ensure_storage=False` a `connect_postgres_compat()`. El fix propaga `initialize=ensure_storage`, de modo que `/api/current-match/kills` y `/api/current-match/players` ya no ejecutan `initialize_postgres_rcon_storage()` en el GET publico cuando se sirven como lecturas read-only. + Conclusiones principales: - El backend de `ranking` ya no muestra el cuello de botella grave del ranking anual. La evidencia mas fuerte es el test `backend/tests/test_annual_ranking_payload.py`, que confirma que la lectura anual en PostgreSQL ya no inicializa storage en request publico. - El cuello de botella visible actual mas claro esta en frontend: `frontend/assets/js/ranking.js` y `frontend/assets/js/stats.js` bloquean la carga principal detras de `/health`, y `ranking.js` no tiene proteccion contra request race ni limpieza robusta del estado de carga. - `historico.js` es hoy la referencia mas sana del frontend publico: usa snapshots, cache TTL, deduplicacion de peticiones y `requestId` para ignorar respuestas obsoletas. -- `partida-actual.js` no bloquea por `/health`, pero hace polling agresivo y paralelo a tres endpoints (`/api/current-match`, `/api/current-match/kills`, `/api/current-match/players`) sin `AbortController`, con intervalos de 1.5 s y 3 s que pueden amplificar carga y re-render innecesario. Tras TASK-226, kills/players degradan desde backend en JSON controlado. +- `partida-actual.js` no bloquea por `/health`, pero hace polling agresivo y paralelo a tres endpoints (`/api/current-match`, `/api/current-match/kills`, `/api/current-match/players`) sin `AbortController`, con intervalos de 1.5 s y 3 s que pueden amplificar carga y re-render innecesario. Tras TASK-227, kills/players usan AdminLog PostgreSQL en modo read-only real y degradan desde backend en JSON controlado. - En backend siguen existiendo fallbacks runtime publicos sobre tablas materializadas grandes para `ranking`, `stats search` y `stats player profile`. Son mejores que consultar RCON directo, pero siguen rompiendo la meta de servir lecturas publicas desde read models dedicados. - Las queries runtime de leaderboard y player stats usan patrones como `COALESCE(CAST(matches.ended_at AS TEXT), CAST(matches.started_at AS TEXT))` y agregaciones sobre `rcon_match_player_stats`, lo que aumenta riesgo de scans y de uso parcial de indices. - `current-match` sigue consultando RCON directo en request publico cuando hay target confiable. Eso contradice la regla objetivo de esta auditoria y debe tratarse como deuda arquitectonica explicita aunque hoy sea un requisito funcional de la pagina live. @@ -31,7 +33,7 @@ Flujo observado: - `ranking` y `stats` mezclan frontend secuencial con backend que aun puede caer a runtime sobre tablas materializadas si falta snapshot o read model. - `historico` ya prioriza snapshots y fallback controlado. -- `current-match` expone una excepcion relevante: `/api/current-match` consulta RCON directo en la ruta publica cuando encuentra target valido. Kills/players ya leen AdminLog sin inicializar storage en request publico. +- `current-match` expone una excepcion relevante: `/api/current-match` consulta RCON directo en la ruta publica cuando encuentra target valido. Kills/players leen AdminLog sin inicializar storage en request publico, incluyendo la rama PostgreSQL corregida en `TASK-227`. ## Inventario de Endpoints Publicos @@ -45,8 +47,8 @@ Flujo observado: | `/api/historical/snapshots/recent-matches` | `frontend/assets/js/historico.js` | `build_recent_historical_matches_snapshot_payload()` | Snapshot publico de recent matches | Segun source kind puede usar RCON read model o fallback publico | Si | P2 | | `/api/historical/matches/detail` | `frontend/assets/js/historico-partida.js` | `build_historical_match_detail_payload()` | Read model detalle de partida | Intenta `get_rcon_historical_match_detail()`, luego fallback a storage historico publico | Si | P2 | | `/api/current-match` | `frontend/assets/js/partida-actual.js` | `build_current_match_payload()` | Read model live propio | Primero intenta `_query_current_match_rcon_sample()` directo; luego fallback a `/api/servers` snapshot | Si, y toca RCON directo | P0 | -| `/api/current-match/kills` | `frontend/assets/js/partida-actual.js` | `build_current_match_kill_feed_payload()` | Read model live propio de kill feed | AdminLog materializado en modo read-only publico | Degradacion JSON controlada si falla read model | P2 | -| `/api/current-match/players` | `frontend/assets/js/partida-actual.js` | `build_current_match_player_stats_payload()` | Read model live propio de player stats | AdminLog materializado en modo read-only publico | Degradacion JSON controlada si falla read model | P2 | +| `/api/current-match/kills` | `frontend/assets/js/partida-actual.js` | `build_current_match_kill_feed_payload()` | Read model live propio de kill feed | AdminLog materializado en modo read-only publico; PostgreSQL usa `connect_postgres_compat(initialize=False)` | Degradacion JSON controlada si falla read model | P2 | +| `/api/current-match/players` | `frontend/assets/js/partida-actual.js` | `build_current_match_player_stats_payload()` | Read model live propio de player stats | AdminLog materializado en modo read-only publico; PostgreSQL usa `connect_postgres_compat(initialize=False)` | Degradacion JSON controlada si falla read model | P2 | | `/api/servers` | `frontend/assets/js/main.js`, fallback de current-match | `build_servers_payload()` | Snapshot live de servidores | Snapshot/cache persistido | Sin refresh live en GET publico | P2 | | `/health` | `frontend/assets/js/main.js`, `ranking.js`, `stats.js` | `build_health_payload()` | N/A | Check tecnico | No aplica | P1 por bloqueo UI, no por backend |