261 lines
14 KiB
Python
261 lines
14 KiB
Python
"""HTTP, browser and runtime audit hooks without a dependency on the match database."""
|
||
from __future__ import annotations
|
||
|
||
import functools
|
||
import inspect
|
||
import json
|
||
import re
|
||
import secrets
|
||
import time
|
||
from typing import Any, Literal
|
||
|
||
from fastapi import APIRouter, Depends, Request
|
||
from pydantic import BaseModel, ConfigDict, Field
|
||
|
||
from .program_log import get_log_context, log_event, reset_log_context, set_log_context
|
||
|
||
_ASSETS = ("/ui-builder-assets/", "/hockey-assets/")
|
||
_SENSITIVE_PATH = re.compile(r"(/(?:admin|vmix)/session/)[^/]+", re.I)
|
||
_TOKEN_SEGMENT = re.compile(r"(?<=/)[A-Za-z0-9_-]{32,}(?=/|$)")
|
||
_GAME_PATH = re.compile(r"/games/([^/]+)")
|
||
_DEVICE_PATH = re.compile(r"/(?:agents|devices)/([^/]+)")
|
||
_NO_BODY = re.compile(r"(?:^/login$|/auth/|/credentials|/connection/test|/import|/database/)")
|
||
|
||
|
||
def safe_path(path: str) -> str:
|
||
return _TOKEN_SEGMENT.sub("[private]", _SENSITIVE_PATH.sub(r"\1[private]", path.split("?", 1)[0]))[:500]
|
||
|
||
|
||
def apply_web_cache_policy(request, response):
|
||
path = request.url.path
|
||
if path.startswith(_ASSETS) and request.query_params.get("v"):
|
||
response.headers["Cache-Control"] = "private, max-age=31536000, immutable"
|
||
for header in ("Pragma", "Expires"):
|
||
if header in response.headers:
|
||
del response.headers[header]
|
||
elif (path in {"/", "/editor", "/logs"} or path.startswith(_ASSETS)
|
||
or path.startswith(("/api/", "/khl-site"))):
|
||
response.headers["Cache-Control"] = "private, no-store, no-cache, must-revalidate, max-age=0"
|
||
response.headers["Pragma"] = "no-cache"
|
||
response.headers["Expires"] = "0"
|
||
return response
|
||
|
||
|
||
class WebAuditMiddleware:
|
||
"""Tee bounded request data; never consume a request or buffer its response."""
|
||
|
||
def __init__(self, app, *, slow_ms: float = 1500):
|
||
self.app = app
|
||
self.slow_ms = slow_ms
|
||
|
||
async def __call__(self, scope, receive, send):
|
||
if scope["type"] not in {"http", "websocket"}:
|
||
return await self.app(scope, receive, send)
|
||
path = safe_path(scope.get("path", ""))
|
||
headers = {k.decode("latin1").lower(): v.decode("latin1") for k, v in scope.get("headers", [])}
|
||
request_id = secrets.token_hex(12)
|
||
state = scope.setdefault("state", {})
|
||
state["program_request_id"] = request_id
|
||
game_match = _GAME_PATH.search(path)
|
||
device_match = _DEVICE_PATH.search(path)
|
||
game_id = headers.get("x-hockey-game", "")[:100] or (game_match.group(1) if game_match else "")
|
||
device_id = headers.get("x-hockey-device", "")[:160] or (device_match.group(1) if device_match else "")
|
||
token = set_log_context(request_id=request_id, game_id=game_id, device_id=device_id)
|
||
started = time.perf_counter()
|
||
status_code = 500
|
||
response_bytes = 0
|
||
error = None
|
||
body = bytearray()
|
||
body_truncated = False
|
||
method = scope.get("method", "WS")
|
||
capture_body = method not in {"GET", "HEAD", "OPTIONS"} and not _NO_BODY.search(path)
|
||
|
||
async def receive_audit():
|
||
nonlocal body_truncated
|
||
message = await receive()
|
||
if capture_body and message["type"] == "http.request":
|
||
chunk = message.get("body", b"")
|
||
remaining = 32768 - len(body)
|
||
if remaining > 0:
|
||
body.extend(chunk[:remaining])
|
||
if len(chunk) > remaining:
|
||
body_truncated = True
|
||
return message
|
||
|
||
async def send_audit(message):
|
||
nonlocal status_code, response_bytes
|
||
if message["type"] == "http.response.start":
|
||
status_code = message["status"]
|
||
outgoing = list(message.get("headers", []))
|
||
outgoing.append((b"x-request-id", request_id.encode("ascii")))
|
||
elapsed = (time.perf_counter() - started) * 1000
|
||
outgoing.append((b"server-timing", f"app;dur={elapsed:.2f}".encode("ascii")))
|
||
message = {**message, "headers": outgoing}
|
||
elif message["type"] == "http.response.body":
|
||
response_bytes += len(message.get("body", b""))
|
||
elif message["type"] == "websocket.accept":
|
||
status_code = 101
|
||
log_event("INFO", "connections", "websocket.connected", "Открыто WebSocket-соединение",
|
||
request_id=request_id, details={"path": path, "client": (scope.get("client") or [""])[0]})
|
||
elif message["type"] == "websocket.close":
|
||
status_code = message.get("code", 1000)
|
||
await send(message)
|
||
|
||
try:
|
||
await self.app(scope, receive_audit, send_audit)
|
||
except BaseException as exc:
|
||
error = {"type": type(exc).__name__, "message": str(exc)}
|
||
raise
|
||
finally:
|
||
duration = round((time.perf_counter() - started) * 1000, 2)
|
||
user = state.get("wfl_user")
|
||
details: dict[str, Any] = {
|
||
"method": method, "path": path, "status": status_code,
|
||
"duration_ms": duration, "response_bytes": response_bytes,
|
||
"client": (scope.get("client") or [""])[0],
|
||
"user_agent": headers.get("user-agent", "")[:400],
|
||
}
|
||
# Values of URL query parameters may contain bearer credentials.
|
||
# Capture their names, and capture safe structured action bodies instead.
|
||
if scope.get("query_string"):
|
||
details["query_keys"] = [part.split("=", 1)[0][:80] for part in
|
||
scope["query_string"].decode("utf-8", "replace").split("&")[:40]]
|
||
if body and not body_truncated and "application/json" in headers.get("content-type", ""):
|
||
try:
|
||
details["action"] = json.loads(body)
|
||
except (ValueError, UnicodeError):
|
||
details["action"] = "[invalid JSON]"
|
||
if body_truncated:
|
||
details["action"] = "[payload exceeds 32 KiB]"
|
||
action = details.get("action")
|
||
if isinstance(action, dict):
|
||
context = action.get("context") if isinstance(action.get("context"), dict) else {}
|
||
device_id = device_id or str(action.get("device_id") or context.get("device_id") or "")[:160]
|
||
game_id = game_id or str(action.get("game_id") or context.get("game_id") or "")[:100]
|
||
if error:
|
||
details["error"] = error
|
||
level = ("ERROR" if error else "INFO") if method == "WS" else (
|
||
"ERROR" if error or status_code >= 500 else "WARNING" if status_code >= 400 or duration >= self.slow_ms else "INFO")
|
||
if path.startswith(_ASSETS) and level == "INFO":
|
||
level = "DEBUG"
|
||
category = "connections" if method == "WS" else "operator" if method not in {"GET", "HEAD", "OPTIONS"} else "http"
|
||
log_event(level, category, "websocket.closed" if method == "WS" else "http.request",
|
||
f"{method} {path} · {status_code} · {duration:g} мс",
|
||
actor_id=getattr(user, "id", ""), actor_login=getattr(user, "login", ""),
|
||
game_id=game_id, device_id=device_id, request_id=request_id, details=details)
|
||
reset_log_context(token)
|
||
|
||
|
||
class BrowserEvent(BaseModel):
|
||
model_config = ConfigDict(extra="forbid")
|
||
event: Literal["ready", "error", "unhandledrejection", "performance"]
|
||
build: str = Field(default="", max_length=80)
|
||
message: str = Field(default="", max_length=2000)
|
||
path: str = Field(default="/", max_length=500)
|
||
metrics: dict[str, float] = Field(default_factory=dict, max_length=40)
|
||
|
||
|
||
def create_browser_event_router(auth_dependency) -> APIRouter:
|
||
router = APIRouter(prefix="/api/hockey", tags=["Browser diagnostics"])
|
||
|
||
@router.post("/client-events")
|
||
async def browser_event(payload: BrowserEvent, request: Request, user=Depends(auth_dependency)):
|
||
metrics = {str(k)[:80]: round(v, 2) for k, v in payload.metrics.items() if 0 <= v <= 86_400_000}
|
||
log_event("ERROR" if payload.event in {"error", "unhandledrejection"} else "INFO", "browser",
|
||
f"browser.{payload.event}", payload.message or "Браузер: интерфейс готов",
|
||
actor_id=user.id, actor_login=user.login, request_id=getattr(request.state, "program_request_id", ""),
|
||
details={"build": payload.build, "path": safe_path(payload.path), "metrics": metrics})
|
||
return {"ok": True}
|
||
|
||
return router
|
||
|
||
|
||
def install_runtime_audit(service, hub) -> None:
|
||
"""Attach audit at stable runtime boundaries, preserving public method signatures."""
|
||
if getattr(hub, "_program_audit_installed", False):
|
||
return
|
||
hub._program_audit_installed = True
|
||
device_context: dict[str, dict[str, str]] = {}
|
||
|
||
original_send = hub.send
|
||
|
||
@functools.wraps(original_send)
|
||
async def send(device_id, payload, **kwargs):
|
||
delivered = await original_send(device_id, payload, **kwargs)
|
||
kind = str(payload.get("type", ""))
|
||
if kind in {"vmix.command", "vmix.batch", "match.assign", "mapping.assigned", "mapping.missing", "pairing.confirmed", "pairing.revoked", "vmix.probe"}:
|
||
context = device_context.setdefault(device_id, {})
|
||
if kind == "match.assign":
|
||
context["game_id"] = str(payload.get("game_id", ""))
|
||
if kind == "pairing.confirmed":
|
||
context.update(actor_id=str((payload.get("account") or {}).get("id", "")),
|
||
actor_login=str((payload.get("account") or {}).get("login", "")))
|
||
details = dict(payload)
|
||
details["device_owner"] = dict(context)
|
||
if kind == "mapping.assigned":
|
||
details = {key: payload.get(key) for key in ("type", "id", "name", "version")}
|
||
details["fields_count"] = len(payload.get("fields") or [])
|
||
initiator = get_log_context()
|
||
attribution = {**context, **{key: value for key, value in initiator.items()
|
||
if key in {"actor_id", "actor_login"} and value}}
|
||
log_event("INFO" if delivered else "WARNING", "vmix" if kind.startswith("vmix.") else "agent",
|
||
f"{kind}.sent" if delivered else f"{kind}.failed",
|
||
"Команда отправлена Agent" if delivered else "Не удалось отправить команду Agent",
|
||
device_id=device_id, **attribution, details=details)
|
||
return delivered
|
||
hub.send = send
|
||
|
||
original_ack = hub.receive_command_ack
|
||
|
||
@functools.wraps(original_ack)
|
||
async def receive_ack(device_id, message):
|
||
acknowledged = message.get("ok") is True
|
||
log_event("INFO" if acknowledged else "WARNING", "vmix", "command.ack",
|
||
"Получен успешный ответ Agent" if acknowledged else "Получен неуспешный или некорректный ответ Agent",
|
||
device_id=device_id, **device_context.get(device_id, {}), details=message)
|
||
return await original_ack(device_id, message)
|
||
hub.receive_command_ack = receive_ack
|
||
|
||
original_register = hub.register
|
||
|
||
@functools.wraps(original_register)
|
||
async def register(websocket, hello):
|
||
result = await original_register(websocket, hello)
|
||
device_id = str(result.get("device_id", ""))
|
||
device_context[device_id] = {"actor_login": str(result.get("owner", "")),
|
||
"game_id": str(result.get("current_match_id", ""))}
|
||
log_event("INFO", "agent", "agent.connected", "Agent подключился", device_id=device_id,
|
||
**device_context[device_id], details={key: result.get(key) for key in
|
||
("name", "hostname", "agent_version", "vmix_connected", "online", "mapping")})
|
||
return result
|
||
hub.register = register
|
||
|
||
names = ("sync_tournaments", "sync_games", "sync_match_details", "sync_standings",
|
||
"sync_tournament_statistics", "sync_player_directory", "sync_referee_directory",
|
||
"sync_coach_directory", "sync_country_directory", "_sync_live_game_once")
|
||
for name in names:
|
||
original = getattr(service, name, None)
|
||
if original is None or not inspect.iscoroutinefunction(original):
|
||
continue
|
||
|
||
def instrument(function, operation):
|
||
@functools.wraps(function)
|
||
async def wrapped(*args, **kwargs):
|
||
started = time.perf_counter()
|
||
context = {"operation": operation, "arguments": kwargs}
|
||
try:
|
||
result = await function(*args, **kwargs)
|
||
except Exception as error:
|
||
log_event("ERROR", "sources", "source.failed", f"Ошибка обновления: {operation}",
|
||
game_id=str(kwargs.get("game_external_id", "")),
|
||
details={**context, "duration_ms": round((time.perf_counter() - started) * 1000, 2),
|
||
"error": str(error), "type": type(error).__name__})
|
||
raise
|
||
summary = {k: v for k, v in result.items() if isinstance(v, (str, int, float, bool))} if isinstance(result, dict) else {}
|
||
log_event("INFO", "sources", "source.updated", f"Данные обновлены: {operation}",
|
||
game_id=str(kwargs.get("game_external_id", "")),
|
||
details={**context, "duration_ms": round((time.perf_counter() - started) * 1000, 2), "result": summary})
|
||
return result
|
||
return wrapped
|
||
setattr(service, name, instrument(original, name))
|