mirror of
https://github.com/Routstr/routstr-core.git
synced 2026-10-05 20:28:23 +00:00
9qeklajc
c2b807bb20
The dated JSON log files were a credential store. Structured `extra` fields bypass the message-level regex scrubbing entirely — the JSON formatter reads them straight off the record dict — and the only pass they received was organization-ID redaction. So a full Cashu refund token, and the `hashed_key` that `sk-<hashed_key>` auth accepts as a live reusable API key, were written verbatim, as were all request query values. Anyone able to read a log file could spend from it. Fixed at both ends so neither alone is load-bearing. The call sites stop handing over the values: balance logs a token length and an eight-char key prefix, and the request middleware logs query parameter names without their values. The SecurityFilter then refuses to emit them anyway, walking every extra recursively and stripping both secret-shaped keys and secret-shaped values (Cashu tokens, bearer values, `sk-` keys, nsec keys, full SHA-256 hashes, secret-ish query parameters) wherever they are nested. The walk is depth-limited and cycle-safe so a malformed payload degrades to `[REDACTED]` instead of failing the log call, and numeric values are never touched, which keeps the usage-analytics fields the dashboard parses intact. Retention is also wired up: `backupCount` never expired anything here because the base filename moves with the date, so the inherited rollover found no siblings and every day of logs was kept forever. Rollover now prunes explicitly.
136 lines
4.3 KiB
Python
136 lines
4.3 KiB
Python
import time
|
|
import uuid
|
|
from contextvars import ContextVar
|
|
from typing import Callable
|
|
|
|
from fastapi import Request, Response
|
|
from starlette.middleware.base import BaseHTTPMiddleware
|
|
|
|
from .logging import get_logger
|
|
|
|
logger = get_logger(__name__)
|
|
|
|
# Context variable to store request ID across async context
|
|
request_id_context: ContextVar[str | None] = ContextVar("request_id")
|
|
|
|
|
|
# Methods that are never logged: HEAD requests are health probes from
|
|
# monitoring/load balancers, OPTIONS are CORS preflights — both are framework
|
|
# chatter, not user-meaningful events.
|
|
_SKIP_LOG_METHODS: frozenset[str] = frozenset({"HEAD", "OPTIONS"})
|
|
|
|
# Path prefixes to skip. Includes Next.js static chunks and the admin
|
|
# dashboard's internal polling API (/admin/api/*) which the UI hits on a timer
|
|
# to refresh balances, logs, providers, etc. — high volume, low diagnostic
|
|
# value. Mutating admin actions are recorded separately in the audit log.
|
|
_SKIP_LOG_PREFIXES: tuple[str, ...] = (
|
|
"/_next/",
|
|
"/admin/api/",
|
|
)
|
|
|
|
# Exact paths to skip. RSC payload prefetches (`*/index.txt`) fire automatically
|
|
# as the user hovers near `<Link>`s, and `/v1/wallet/info` is polled by the UI.
|
|
_SKIP_LOG_EXACT: frozenset[str] = frozenset(
|
|
{
|
|
"/favicon.ico",
|
|
"/icon.ico",
|
|
"/v1/wallet/info",
|
|
"/index.txt",
|
|
"/login/index.txt",
|
|
"/model/index.txt",
|
|
"/providers/index.txt",
|
|
"/settings/index.txt",
|
|
"/transactions/index.txt",
|
|
"/balances/index.txt",
|
|
"/logs/index.txt",
|
|
"/usage/index.txt",
|
|
"/unauthorized/index.txt",
|
|
}
|
|
)
|
|
|
|
|
|
def _should_log(method: str, path: str) -> bool:
|
|
if method in _SKIP_LOG_METHODS:
|
|
return False
|
|
if path in _SKIP_LOG_EXACT:
|
|
return False
|
|
return not any(path.startswith(prefix) for prefix in _SKIP_LOG_PREFIXES)
|
|
|
|
|
|
class LoggingMiddleware(BaseHTTPMiddleware):
|
|
"""Middleware to log proxy interactions and page navigation.
|
|
|
|
Skips logging for static assets and Next.js chunks to avoid noise.
|
|
"""
|
|
|
|
async def dispatch(self, request: Request, call_next: Callable) -> Response:
|
|
# Generate request ID
|
|
request_id = str(uuid.uuid4())
|
|
request.state.request_id = request_id
|
|
|
|
# Set request ID in context for logging
|
|
token = request_id_context.set(request_id)
|
|
|
|
path = request.url.path
|
|
should_log = _should_log(request.method, path)
|
|
|
|
# Start timing
|
|
start_time = time.time()
|
|
|
|
if should_log:
|
|
logger.info(
|
|
"Incoming request",
|
|
extra={
|
|
"request_id": request_id,
|
|
"method": request.method,
|
|
"path": path,
|
|
# Names only: query values carry API keys and refund
|
|
# tokens on the wallet routes.
|
|
"query_param_names": sorted(request.query_params.keys()),
|
|
},
|
|
)
|
|
|
|
# Process request
|
|
try:
|
|
response = await call_next(request)
|
|
|
|
if should_log:
|
|
duration = time.time() - start_time
|
|
logger.info(
|
|
"Request completed",
|
|
extra={
|
|
"request_id": request_id,
|
|
"method": request.method,
|
|
"path": path,
|
|
"status_code": response.status_code,
|
|
"duration_ms": round(duration * 1000, 2),
|
|
},
|
|
)
|
|
if hasattr(response, "headers"):
|
|
response.headers["x-routstr-request-id"] = request_id
|
|
|
|
return response
|
|
|
|
except Exception as e:
|
|
# Always log failures, even for skipped paths, so we don't lose errors.
|
|
duration = time.time() - start_time
|
|
logger.error(
|
|
"Request failed",
|
|
extra={
|
|
"request_id": request_id,
|
|
"method": request.method,
|
|
"path": path,
|
|
"duration_ms": round(duration * 1000, 2),
|
|
"error": str(e),
|
|
"error_type": type(e).__name__,
|
|
},
|
|
exc_info=True,
|
|
)
|
|
raise
|
|
finally:
|
|
# Reset context
|
|
request_id_context.reset(token)
|
|
|
|
|
|
__all__ = ["LoggingMiddleware", "request_id_context"]
|