diff --git a/ai/tasks/done/TASK-231-fix-historical-recent-matches-single-server-timeouts.md b/ai/tasks/done/TASK-231-fix-historical-recent-matches-single-server-timeouts.md new file mode 100644 index 0000000..411a8a8 --- /dev/null +++ b/ai/tasks/done/TASK-231-fix-historical-recent-matches-single-server-timeouts.md @@ -0,0 +1,121 @@ +--- +id: TASK-231 +title: Fix historical recent matches single server timeouts +status: done +type: backend +team: Backend Senior +supporting_teams: [] +roadmap_item: foundation +priority: high +--- + +# TASK-231 - Fix historical recent matches single server timeouts + +## Goal + +Corregir los dos `CRITICAL` restantes de la auditoria publica global: + +- `GET /api/historical/recent-matches?server=comunidad-hispana-01&limit=20` +- `GET /api/historical/recent-matches?server=comunidad-hispana-02&limit=20` + +## Context + +Tras `TASK-230`, la auditoria completa mostro: + +- `launched`: 195 +- `OK`: 78 +- `WARNING`: 115 +- `CRITICAL`: 2 + +Los dos `CRITICAL` restantes eran: + +- `historical-recent-matches-comunidad-hispana-01`: timeout `30032.24 ms`. +- `historical-recent-matches-comunidad-hispana-02`: timeout `30027.15 ms`. + +Los snapshots equivalentes y el legacy agregado ya respondian rapido: + +- `snapshot-recent-matches-comunidad-hispana-01`: `77.50 ms`. +- `snapshot-recent-matches-comunidad-hispana-02`: `51.11 ms`. +- `historical-recent-matches-all-servers`: `50.66 ms`. +- `snapshot-recent-matches-all-servers`: `63.33 ms`. + +## Files Read First + +- `ai/architecture-index.md` +- `ai/repo-context.md` +- `ai/orchestrator/backend-senior.md` +- `scripts/audit_public_requests.py` +- `backend/app/routes.py` +- `backend/app/payloads.py` +- `backend/app/rcon_historical_read_model.py` +- `backend/app/rcon_admin_log_materialization.py` +- `backend/tests/test_historical_snapshot_refresh.py` + +## Call Chain Analysis + +Cadena de auditoria: + +1. `scripts/audit_public_requests.py` genera: + - `historical-recent-matches-comunidad-hispana-01` como `GET /api/historical/recent-matches?server=comunidad-hispana-01&limit=20`. + - `historical-recent-matches-comunidad-hispana-02` como `GET /api/historical/recent-matches?server=comunidad-hispana-02&limit=20`. +2. `backend/app/routes.py` mapea `/api/historical/recent-matches` a `build_recent_historical_matches_payload(limit=..., server_slug=...)`. +3. Tras `TASK-229`, solo `server=all-servers` usaba snapshot fast-path. +4. CH01 y CH02 seguian entrando en `get_rcon_historical_read_model().list_recent_activity(...)`. +5. El read model llama a `list_rcon_historical_recent_activity()`, que intenta primero `list_materialized_rcon_matches(target_key=..., only_ended=True, limit=...)`. +6. Si RCON no cubria o necesitaba completar items, el builder podia entrar tambien en `list_recent_historical_matches()` como fallback legacy CRCON/PostgreSQL display. +7. Los snapshots equivalentes ya respondian rapido porque leen snapshots precomputados y respetan el `limit`. + +## Root Cause + +El fast-path de `TASK-229` para recent-matches estaba limitado a `server=all-servers`. Los scopes por servidor seguian usando el camino runtime RCON/materialized y podian caer al fallback legacy de scoreboard, ambos fuera del contrato de lectura publica rapida. En produccion, CH01 y CH02 agotaban los 30 s en ese path. + +## Changes + +- `backend/app/payloads.py` + - `build_recent_historical_matches_payload()` usa snapshot fast-path para cualquier `server_slug` explicito, no solo `all-servers`. + - Se extrajo `_build_recent_historical_matches_legacy_snapshot_payload()` para conservar `context`, `limit`, `server_slug`, `items`, `historical_data_source`, `coverage_basis` y `legacy_endpoint_policy`. + - Si no hay snapshot, devuelve JSON controlado con `items: []` y metadata de snapshot missing, sin RCON live, sin scoreboard externo y sin fallback runtime pesado. +- `backend/tests/test_historical_snapshot_refresh.py` + - Cubre que `comunidad-hispana-01` no llama a `get_rcon_historical_read_model()` ni a `list_recent_historical_matches()`. + - Cubre que `comunidad-hispana-02` usa el mismo fast-path. + - Mantiene cobertura de `all-servers`. + - Mantiene cobertura del fast-path de `server-summary` de `TASK-230`. +- `docs/FULL_APPLICATION_REQUEST_AUDIT.md` + - Documenta el estado post-fix de `TASK-231`. +- `docs/PERFORMANCE_PUBLIC_QUERY_AUDIT.md` + - Actualiza la politica de `/api/historical/recent-matches?server=` como wrapper legacy sobre snapshot read-only. + +## Validation + +Validaciones ejecutadas: + +```powershell +python -m compileall backend/app +cd backend +python -m unittest tests.test_historical_snapshot_refresh +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_historical_snapshot_refresh`: OK, 19 tests. +- `cd backend; python -m unittest tests.test_current_match_payload tests.test_rcon_admin_log_storage tests.test_historical_snapshot_refresh`: OK, 26 tests. + +Auditoria de produccion pendiente tras redeploy: + +```powershell +python .\scripts\audit_public_requests.py --base-url https://comunidadhll.devzamode.es --timeout 30 --output tmp\full_audit_after_task231.json +``` + +## Outcome + +Los endpoints legacy recent-matches por servidor quedan alineados con los snapshots rapidos que ya consume `historico.html`. CH01, CH02 y `all-servers` evitan RCON live, scoreboard externo, inicializaciones de storage y fallbacks runtime pesados en lectura publica. + +No se cambiaron hosts, puertos, `27001`, variables de entorno ni configuracion de servidores. No se tocaron frontend, assets, SVGs, imagenes fisicas, `ai/system-metrics.md` ni `tmp/`. + +## Change Budget + +- Archivos de codigo modificados: 2. +- Documentacion actualizada: 3 archivos. +- Sin cambios en frontend ni configuracion. diff --git a/backend/app/payloads.py b/backend/app/payloads.py index 4c92689..5cbc338 100644 --- a/backend/app/payloads.py +++ b/backend/app/payloads.py @@ -1075,23 +1075,11 @@ def build_recent_historical_matches_payload( server_slug: str | None = None, ) -> dict[str, object]: """Return recent historical matches from persisted CRCON data.""" - if server_slug == ALL_SERVERS_SLUG: - snapshot_payload = build_recent_historical_matches_snapshot_payload( + if server_slug: + return _build_recent_historical_matches_legacy_snapshot_payload( limit=limit, server_slug=server_slug, ) - data = dict(snapshot_payload.get("data") or {}) - data.update( - { - "title": "Partidas recientes por servidor", - "context": "historical-recent-matches", - "source": "historical-precomputed-snapshots", - "historical_data_source": get_historical_data_source_kind(), - "coverage_basis": "precomputed-recent-matches-snapshot", - "legacy_endpoint_policy": "snapshot-read-only-fast-path", - } - ) - return {"status": snapshot_payload.get("status", "ok"), "data": data} if get_historical_data_source_kind() == "rcon": data_source = get_rcon_historical_read_model() @@ -1215,6 +1203,29 @@ def build_recent_historical_matches_payload( } +def _build_recent_historical_matches_legacy_snapshot_payload( + *, + limit: int, + server_slug: str, +) -> dict[str, object]: + snapshot_payload = build_recent_historical_matches_snapshot_payload( + limit=limit, + server_slug=server_slug, + ) + data = dict(snapshot_payload.get("data") or {}) + data.update( + { + "title": "Partidas recientes por servidor", + "context": "historical-recent-matches", + "source": "historical-precomputed-snapshots", + "historical_data_source": get_historical_data_source_kind(), + "coverage_basis": "precomputed-recent-matches-snapshot", + "legacy_endpoint_policy": "snapshot-read-only-fast-path", + } + ) + return {"status": snapshot_payload.get("status", "ok"), "data": data} + + def build_historical_match_detail_payload( *, server_slug: str, diff --git a/backend/tests/test_historical_snapshot_refresh.py b/backend/tests/test_historical_snapshot_refresh.py index 4dc8561..4f0a1c1 100644 --- a/backend/tests/test_historical_snapshot_refresh.py +++ b/backend/tests/test_historical_snapshot_refresh.py @@ -168,7 +168,7 @@ class HistoricalSnapshotRefreshTests(unittest.TestCase): self.assertEqual(len(payload["data"]["items"]), 1) self.assertFalse(payload["data"].get("fallback_used", False)) - def test_legacy_all_servers_recent_matches_uses_snapshot_fast_path(self) -> None: + def test_legacy_recent_matches_uses_snapshot_fast_path(self) -> None: snapshot = { "generated_at": "2026-06-10T04:00:00Z", "source_range_start": "2026-06-09T21:00:00Z", @@ -191,7 +191,7 @@ class HistoricalSnapshotRefreshTests(unittest.TestCase): patch("app.payloads.list_recent_historical_matches") as fallback_loader, ): payload = build_recent_historical_matches_payload( - server_slug="all-servers", + server_slug="comunidad-hispana-01", limit=20, ) @@ -199,8 +199,73 @@ class HistoricalSnapshotRefreshTests(unittest.TestCase): fallback_loader.assert_not_called() self.assertEqual(payload["data"]["context"], "historical-recent-matches") self.assertEqual(payload["data"]["legacy_endpoint_policy"], "snapshot-read-only-fast-path") + self.assertEqual(payload["data"]["server_slug"], "comunidad-hispana-01") self.assertEqual(payload["data"]["items"][0]["match_id"], "match-1") + def test_legacy_second_server_recent_matches_uses_snapshot_fast_path(self) -> None: + snapshot = { + "generated_at": "2026-06-10T04:00:00Z", + "source_range_start": "2026-06-09T21:00:00Z", + "source_range_end": "2026-06-09T22:00:00Z", + "is_stale": False, + "payload": { + "items": [ + { + "match_id": "match-2", + "closed_at": "2026-06-09T22:00:00Z", + } + ], + "limit": 100, + }, + } + with ( + patch("app.payloads._get_historical_snapshot_record", return_value=snapshot), + patch("app.payloads.get_historical_data_source_kind", return_value="rcon"), + patch("app.payloads.get_rcon_historical_read_model") as rcon_loader, + patch("app.payloads.list_recent_historical_matches") as fallback_loader, + ): + payload = build_recent_historical_matches_payload( + server_slug="comunidad-hispana-02", + limit=20, + ) + + rcon_loader.assert_not_called() + fallback_loader.assert_not_called() + self.assertEqual(payload["data"]["server_slug"], "comunidad-hispana-02") + self.assertEqual(payload["data"]["items"][0]["match_id"], "match-2") + + def test_legacy_all_servers_recent_matches_still_uses_snapshot_fast_path(self) -> None: + snapshot = { + "generated_at": "2026-06-10T04:00:00Z", + "source_range_start": "2026-06-09T21:00:00Z", + "source_range_end": "2026-06-09T22:00:00Z", + "is_stale": False, + "payload": { + "items": [ + { + "match_id": "match-all", + "closed_at": "2026-06-09T22:00:00Z", + } + ], + "limit": 100, + }, + } + with ( + patch("app.payloads._get_historical_snapshot_record", return_value=snapshot), + patch("app.payloads.get_historical_data_source_kind", return_value="rcon"), + patch("app.payloads.get_rcon_historical_read_model") as rcon_loader, + patch("app.payloads.list_recent_historical_matches") as fallback_loader, + ): + payload = build_recent_historical_matches_payload( + server_slug="all-servers", + limit=20, + ) + + rcon_loader.assert_not_called() + fallback_loader.assert_not_called() + self.assertEqual(payload["data"]["server_slug"], "all-servers") + self.assertEqual(payload["data"]["items"][0]["match_id"], "match-all") + def test_legacy_server_summary_uses_snapshot_fast_path(self) -> None: snapshot = { "generated_at": "2026-06-10T04:00:00Z", diff --git a/docs/FULL_APPLICATION_REQUEST_AUDIT.md b/docs/FULL_APPLICATION_REQUEST_AUDIT.md index 6762585..23ff1d4 100644 --- a/docs/FULL_APPLICATION_REQUEST_AUDIT.md +++ b/docs/FULL_APPLICATION_REQUEST_AUDIT.md @@ -279,6 +279,54 @@ Comando de validacion de produccion tras redeploy: python .\scripts\audit_public_requests.py --base-url https://comunidadhll.devzamode.es --timeout 30 --output tmp\full_audit_after_task230.json ``` +## Estado post-fix TASK-231 + +Fecha: 2026-06-10 +Alcance aplicado: dos `CRITICAL` restantes de recent-matches legacy por servidor tras `TASK-230`. + +URLs afectadas: + +- `GET /api/historical/recent-matches?server=comunidad-hispana-01&limit=20` +- `GET /api/historical/recent-matches?server=comunidad-hispana-02&limit=20` + +Evidencia de produccion previa al fix: + +- `historical-recent-matches-comunidad-hispana-01`: timeout `30032.24 ms`. +- `historical-recent-matches-comunidad-hispana-02`: timeout `30027.15 ms`. +- `snapshot-recent-matches-comunidad-hispana-01`: `77.50 ms`, OK. +- `snapshot-recent-matches-comunidad-hispana-02`: `51.11 ms`, OK. +- `historical-recent-matches-all-servers`: `50.66 ms`, OK. + +Causa confirmada: + +- `scripts/audit_public_requests.py` etiqueta esas rutas como `historical-recent-matches-comunidad-hispana-01` y `historical-recent-matches-comunidad-hispana-02`. +- `backend/app/routes.py` las mapea a `build_recent_historical_matches_payload(limit=20, server_slug=...)`. +- Tras `TASK-229`, solo `server=all-servers` tenia snapshot fast-path. +- CH01 y CH02 seguian entrando en `get_rcon_historical_read_model().list_recent_activity(...)`. +- El read model llama a `list_rcon_historical_recent_activity()`, que intenta materialized RCON/AdminLog (`list_materialized_rcon_matches`) antes del fallback por ventanas. +- Si RCON no cubria o no alcanzaba el `limit`, el builder podia intentar completar con `list_recent_historical_matches()` desde storage legacy CRCON/PostgreSQL display. + +Cambios aplicados: + +- `build_recent_historical_matches_payload()` usa snapshot fast-path para cualquier `server_slug` explicito. +- CH01, CH02 y `all-servers` quedan como wrappers legacy sobre `build_recent_historical_matches_snapshot_payload()`. +- El contrato conserva `context: historical-recent-matches`, `items`, `limit`, `server_slug`, `historical_data_source`, `coverage_basis` y `legacy_endpoint_policy: snapshot-read-only-fast-path`. +- Si falta snapshot, responde JSON controlado con `items: []`, sin RCON live, sin scoreboard externo, sin `initialize_*` y sin fallback runtime pesado. + +Estado esperado tras redeploy: + +| Endpoint | Estado TASK-231 en codigo | Severidad esperada tras deploy | +| --- | --- | --- | +| `/api/historical/recent-matches?server=comunidad-hispana-01&limit=20` | Wrapper legacy sobre snapshot read-only | OK o WARNING si snapshot missing, sin timeout | +| `/api/historical/recent-matches?server=comunidad-hispana-02&limit=20` | Wrapper legacy sobre snapshot read-only | OK o WARNING si snapshot missing, sin timeout | +| `/api/historical/recent-matches?server=all-servers&limit=20` | Wrapper legacy sobre snapshot read-only | OK o WARNING si snapshot missing, sin empeorar | + +Comando de validacion de produccion tras redeploy: + +```powershell +python .\scripts\audit_public_requests.py --base-url https://comunidadhll.devzamode.es --timeout 30 --output tmp\full_audit_after_task231.json +``` + ## Evidencia ejecutada Comandos ejecutados: @@ -406,7 +454,7 @@ La tabla usa rangos cuando una ruta se lanzo con varias combinaciones representa | M026 | backend-api | `backend/app/routes.py` | snapshot monthly MVP V2 | GET | `/api/historical/snapshots/monthly-mvp-v2` | `limit`, `server` | `/api/historical/snapshots/monthly-mvp-v2?server=all-servers&limit=10` | `build_monthly_mvp_v2_snapshot_payload` | displayed snapshots | snapshot | si en Postgres display | no pesado hoy | bajo | n/a | produccion | 200 | 40-41 ms | 1539 B | snapshot missing/fallback | WARNING | completar snapshots | | M027 | backend-api | `backend/app/routes.py` | snapshot player events | GET | `/api/historical/snapshots/player-events` | `limit`, `server`, `view` | `/api/historical/snapshots/player-events?server=all-servers&view=duels&limit=10` | `build_player_event_snapshot_payload` | displayed snapshots | snapshot | si en Postgres display | no pesado hoy | bajo | n/a | produccion | 200 | 40-57 ms | ~1176-1188 B | snapshot missing/fallback | WARNING | completar snapshots | | M028 | backend-api | `backend/app/routes.py` | snapshot weekly leaderboard | GET | `/api/historical/snapshots/weekly-leaderboard` | `limit`, `server`, `metric` | `/api/historical/snapshots/weekly-leaderboard?server=comunidad-hispana-01&metric=kills&limit=10` | `build_weekly_leaderboard_snapshot_payload` | displayed snapshots | snapshot | si en Postgres display | no pesado hoy | bajo | n/a | produccion | 200 | 44-70 ms | ~1610 B | snapshot missing/fallback | WARNING | completar snapshots | -| M029 | backend-api | `backend/app/routes.py` | historico recent matches legacy | GET | `/api/historical/recent-matches` | `limit`, `server` | `/api/historical/recent-matches?server=all-servers&limit=20` | `build_recent_historical_matches_payload` | snapshot recent matches | wrapper legacy sobre snapshot | no en `all-servers` | no | bajo | n/a | pendiente redeploy TASK-229 | pendiente | pendiente | pendiente | `legacy_endpoint_policy=snapshot-read-only-fast-path` | OK o WARNING sin timeout | mantener como compatibilidad legacy | +| M029 | backend-api | `backend/app/routes.py` | historico recent matches legacy | GET | `/api/historical/recent-matches` | `limit`, `server` | `/api/historical/recent-matches?server=comunidad-hispana-01&limit=20` | `build_recent_historical_matches_payload` | snapshot recent matches | wrapper legacy sobre snapshot para cualquier `server=` explicito | no | no | bajo | n/a | pendiente redeploy TASK-231 | pendiente | pendiente | pendiente | `legacy_endpoint_policy=snapshot-read-only-fast-path` | OK o WARNING sin timeout | mantener como compatibilidad legacy | | M030 | backend-api | `backend/app/routes.py` | historico recent snapshot | GET | `/api/historical/snapshots/recent-matches` | `limit`, `server` | `/api/historical/snapshots/recent-matches?server=all-servers&limit=20` | `build_recent_historical_matches_snapshot_payload` | displayed snapshots | snapshot | si en Postgres display | no | bajo | historico handles error | produccion | 200 | 48-82 ms | ~24185 B | OK | OK | mantener, quitar init display despues | | M031 | backend-api | `backend/app/routes.py` | historico match detail | GET | `/api/historical/matches/detail` | `server`, `match` | `/api/historical/matches/detail?server=comunidad-hispana-01&match=comunidad-hispana-01:1781023156:1781028555:purpleheartlanewarfare` | `build_historical_match_detail_payload` | RCON materialized detail; scoreboard fallback | materialized/read-model + fallback legacy | si: `get_materialized_rcon_match_detail` -> `initialize_rcon_materialized_storage` -> `initialize_postgres_rcon_storage`; fallback display init | si | medio | historico-partida muestra error, sin timeout | produccion | 200 | 120.47 ms | 125580 B | hoy OK, deuda de init persiste | OK | hardening posterior read-only estricto | | M032 | backend-api | `backend/app/routes.py` | historico server summary legacy | GET | `/api/historical/server-summary` | `server` | `/api/historical/server-summary?server=comunidad-hispana-01` | `build_historical_server_summary_payload` | snapshot server summary | wrapper legacy sobre snapshot para cualquier `server=` explicito | no | no | bajo | n/a | pendiente redeploy TASK-230 | pendiente | pendiente | pendiente | `legacy_endpoint_policy=snapshot-read-only-fast-path` | OK o WARNING sin timeout | mantener como compatibilidad legacy | diff --git a/docs/PERFORMANCE_PUBLIC_QUERY_AUDIT.md b/docs/PERFORMANCE_PUBLIC_QUERY_AUDIT.md index b759214..e3623eb 100644 --- a/docs/PERFORMANCE_PUBLIC_QUERY_AUDIT.md +++ b/docs/PERFORMANCE_PUBLIC_QUERY_AUDIT.md @@ -16,6 +16,8 @@ Actualizacion TASK-229, 2026-06-10: los endpoints legacy agregados `/api/histori Actualizacion TASK-230, 2026-06-10: el ultimo `CRITICAL` de la auditoria global fue `/api/historical/server-summary?server=comunidad-hispana-01`, con HTTP 200, `fallback=False` y ~10.1 s. La causa estaba en el path legacy por servidor, que seguia entrando en el read model RCON y enriquecia el resumen con actividad materializada reciente. `server-summary` legacy pasa a usar snapshot fast-path para cualquier `server=` explicito (`all-servers`, `comunidad-hispana-01`, `comunidad-hispana-02`), manteniendo contrato compatible con `items` y metadata de snapshot. +Actualizacion TASK-231, 2026-06-10: los dos `CRITICAL` restantes fueron `/api/historical/recent-matches?server=comunidad-hispana-01&limit=20` y `/api/historical/recent-matches?server=comunidad-hispana-02&limit=20`, ambos timeout ~30 s. El fast-path de `TASK-229` solo cubria `all-servers`; los scopes individuales seguian entrando en RCON/materialized recent activity y podian caer al fallback legacy. `recent-matches` legacy pasa a usar snapshot fast-path para cualquier `server=` explicito y respeta el `limit` recibido. + 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. @@ -51,7 +53,7 @@ Flujo observado: | `/api/stats/rankings/annual` | `frontend/assets/js/stats.js` | `build_annual_ranking_snapshot_payload()` | `rcon_annual_ranking_snapshots`, `rcon_annual_ranking_snapshot_items` | Snapshot anual | No recalcula ranking en lectura | P2 | | `/api/historical/snapshots/leaderboard` | `frontend/assets/js/historico.js` | `build_rcon_materialized_leaderboard_snapshot_payload()` en modo rcon | Snapshot historico publico equivalente | En modo rcon el nombre dice snapshot, pero sirve runtime fast path sobre materialized leaderboard | Si, por definicion del endpoint en modo rcon | P1 | | `/api/historical/snapshots/recent-matches` | `frontend/assets/js/historico.js` | `build_recent_historical_matches_snapshot_payload()` | Snapshot publico de recent matches | Snapshot precomputado read-only | No | P2 | -| `/api/historical/recent-matches?server=all-servers` | legacy historico audit | `build_recent_historical_matches_payload()` | Snapshot publico de recent matches | Wrapper legacy sobre snapshot precomputado | No | P2 | +| `/api/historical/recent-matches?server=` | legacy historico audit | `build_recent_historical_matches_payload()` | Snapshot publico de recent matches | Wrapper legacy sobre snapshot precomputado para cualquier `server=` explicito | No | P2 | | `/api/historical/server-summary?server=` | legacy historico audit | `build_historical_server_summary_payload()` | Snapshot publico de server summary | Wrapper legacy sobre snapshot precomputado para cualquier `server=` explicito | No | 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 |