This commit is contained in:
9qeklajc
2026-08-18 14:47:31 +02:00
parent 56fb540383
commit 172cb87a99
3 changed files with 76 additions and 125 deletions
+6 -17
View File
@@ -183,26 +183,15 @@ class RequestIdFilter(logging.Filter):
class ClientAppFilter(logging.Filter):
"""Filter to add the requesting client app to all log records.
The middleware resolves it from the OpenRouter-convention identity headers
(X-Title, then Referer, then User-Agent) into a context variable, so even
errors raised deep in the wallet/mint code carry it.
"""
"""Filter to add the requesting client app to all log records."""
def filter(self, record: logging.LogRecord) -> bool:
"""Add the client app to the log record unless set explicitly."""
if hasattr(record, "client_app"):
return True
try:
# Import here to avoid circular imports
from .middleware import UNKNOWN_CLIENT_APP, client_app_context
"""Add the client app to the log record if available."""
# Import here to avoid circular imports
from .middleware import UNKNOWN_CLIENT_APP, client_app_context
client_app = client_app_context.get(None)
record.client_app = client_app if client_app else UNKNOWN_CLIENT_APP
except ImportError:
# If middleware isn't available yet, just use default
record.client_app = "unknown"
client_app = client_app_context.get(None)
record.client_app = client_app if client_app else UNKNOWN_CLIENT_APP
return True
+14 -18
View File
@@ -14,26 +14,26 @@ logger = get_logger(__name__)
# Context variable to store request ID across async context
request_id_context: ContextVar[str | None] = ContextVar("request_id")
# Context variable holding the client app behind the current request, so log
# lines emitted while handling it (wallet/mint errors included) can say who
# triggered it.
# Context variable to store the client app across async context
client_app_context: ContextVar[str | None] = ContextVar("client_app")
UNKNOWN_CLIENT_APP = "unknown"
# OpenRouter-convention identity headers, in priority order: X-Title carries
# the app name, HTTP-Referer its URL; User-Agent covers SDKs and scripts that
# set neither.
_CLIENT_APP_HEADERS: tuple[str, ...] = ("x-title", "referer", "user-agent")
# Identity headers in priority order. X-Title and HTTP-Referer are the
# OpenRouter convention; User-Agent covers SDKs and scripts that set neither.
_CLIENT_APP_HEADERS: tuple[str, ...] = (
"x-title",
"http-referer",
"referer",
"user-agent",
)
# Headers are attacker-controlled free text: cap the length so one request
# can't bloat every log line, strip control characters so a crafted value
# can't forge log records.
# Header values are attacker-controlled: cap the length so one request can't
# bloat every log line.
_CLIENT_APP_MAX_LENGTH = 120
def client_app_from_headers(headers: Headers) -> str:
"""Resolve the requesting app from identity headers, or "unknown"."""
for header in _CLIENT_APP_HEADERS:
raw = headers.get(header)
if raw is None:
@@ -101,9 +101,9 @@ class LoggingMiddleware(BaseHTTPMiddleware):
# Set request ID in context for logging
token = request_id_context.set(request_id)
client_app = client_app_from_headers(request.headers)
request.state.client_app = client_app
client_app_token = client_app_context.set(client_app)
client_app_token = client_app_context.set(
client_app_from_headers(request.headers)
)
path = request.url.path
should_log = _should_log(request.method, path)
@@ -118,7 +118,6 @@ class LoggingMiddleware(BaseHTTPMiddleware):
"request_id": request_id,
"method": request.method,
"path": path,
"client_app": client_app,
"query_params": dict(request.query_params),
},
)
@@ -135,7 +134,6 @@ class LoggingMiddleware(BaseHTTPMiddleware):
"request_id": request_id,
"method": request.method,
"path": path,
"client_app": client_app,
"status_code": response.status_code,
"duration_ms": round(duration * 1000, 2),
},
@@ -154,7 +152,6 @@ class LoggingMiddleware(BaseHTTPMiddleware):
"request_id": request_id,
"method": request.method,
"path": path,
"client_app": client_app,
"duration_ms": round(duration * 1000, 2),
"error": str(e),
"error_type": type(e).__name__,
@@ -172,6 +169,5 @@ __all__ = [
"LoggingMiddleware",
"UNKNOWN_CLIENT_APP",
"client_app_context",
"client_app_from_headers",
"request_id_context",
]
+56 -90
View File
@@ -2,7 +2,8 @@
import logging
from fastapi import FastAPI, Request
import pytest
from fastapi import FastAPI
from fastapi.testclient import TestClient
from starlette.datastructures import Headers
@@ -27,49 +28,42 @@ def _record() -> logging.LogRecord:
)
# ---------------------------------------------------------------------------
# client_app_from_headers
# ---------------------------------------------------------------------------
def test_x_title_takes_priority() -> None:
"""X-Title wins over Referer and User-Agent."""
headers = Headers(
{
"x-title": "Goose",
"referer": "https://myapp.example.com",
"user-agent": "python-httpx/0.27",
}
)
assert client_app_from_headers(headers) == "Goose"
def test_referer_used_when_no_x_title() -> None:
headers = Headers(
{"referer": "https://myapp.example.com", "user-agent": "python-httpx/0.27"}
)
assert client_app_from_headers(headers) == "https://myapp.example.com"
def test_user_agent_is_last_fallback() -> None:
assert (
client_app_from_headers(Headers({"user-agent": "curl/8.4.0"})) == "curl/8.4.0"
)
def test_unknown_when_no_identity_headers() -> None:
assert client_app_from_headers(Headers({})) == UNKNOWN_CLIENT_APP
def test_blank_header_falls_through_to_next() -> None:
"""A whitespace-only X-Title must not shadow a usable User-Agent."""
headers = Headers({"x-title": " ", "user-agent": "curl/8.4.0"})
assert client_app_from_headers(headers) == "curl/8.4.0"
def test_all_blank_resolves_to_unknown() -> None:
headers = Headers({"x-title": " ", "user-agent": "\t"})
assert client_app_from_headers(headers) == UNKNOWN_CLIENT_APP
@pytest.mark.parametrize(
("headers", "expected"),
[
(
{
"x-title": "Goose",
"http-referer": "https://myapp.example.com",
"user-agent": "python-httpx/0.27",
},
"Goose",
),
(
{"http-referer": "https://myapp.example.com", "user-agent": "curl/8.4.0"},
"https://myapp.example.com",
),
(
{"referer": "https://myapp.example.com", "user-agent": "curl/8.4.0"},
"https://myapp.example.com",
),
({"user-agent": "curl/8.4.0"}, "curl/8.4.0"),
({}, UNKNOWN_CLIENT_APP),
({"x-title": " ", "user-agent": "curl/8.4.0"}, "curl/8.4.0"),
({"x-title": " ", "user-agent": "\t"}, UNKNOWN_CLIENT_APP),
],
ids=[
"x-title-wins",
"http-referer",
"referer",
"user-agent-fallback",
"no-identity-headers",
"blank-falls-through",
"all-blank",
],
)
def test_client_app_from_headers(headers: dict[str, str], expected: str) -> None:
assert client_app_from_headers(Headers(headers)) == expected
def test_value_is_truncated_to_120_chars() -> None:
@@ -82,11 +76,6 @@ def test_control_characters_are_stripped() -> None:
assert client_app_from_headers(headers) == "evil-app[0m fake INFO line"
# ---------------------------------------------------------------------------
# ClientAppFilter
# ---------------------------------------------------------------------------
def test_filter_reads_context_variable() -> None:
token = client_app_context.set("Goose")
try:
@@ -103,47 +92,24 @@ def test_filter_defaults_to_unknown_outside_request_context() -> None:
assert record.client_app == UNKNOWN_CLIENT_APP # type: ignore[attr-defined]
def test_filter_keeps_explicit_extra() -> None:
"""extra={"client_app": ...} on a log call wins over the context value."""
token = client_app_context.set("context-app")
def test_handler_logs_carry_client_app(caplog: pytest.LogCaptureFixture) -> None:
"""A log line emitted inside a handler still names the app that triggered it."""
app = FastAPI()
handler_logger = logging.getLogger("routstr.test.handler")
@app.get("/whoami")
async def whoami() -> dict[str, bool]:
handler_logger.warning("something went wrong")
return {"ok": True}
app.add_middleware(LoggingMiddleware)
caplog.handler.addFilter(ClientAppFilter())
handler_logger.addHandler(caplog.handler)
try:
record = _record()
record.client_app = "explicit-app" # type: ignore[attr-defined]
assert ClientAppFilter().filter(record) is True
assert record.client_app == "explicit-app" # type: ignore[attr-defined]
TestClient(app).get("/whoami", headers={"X-Title": "Goose"})
finally:
client_app_context.reset(token)
handler_logger.removeHandler(caplog.handler)
# ---------------------------------------------------------------------------
# LoggingMiddleware integration
# ---------------------------------------------------------------------------
def test_middleware_exposes_client_app_on_request_state() -> None:
app = FastAPI()
@app.get("/whoami")
async def whoami(request: Request) -> dict:
return {"client_app": request.state.client_app}
app.add_middleware(LoggingMiddleware)
client = TestClient(app)
response = client.get("/whoami", headers={"X-Title": "Goose"})
assert response.json() == {"client_app": "Goose"}
def test_middleware_reports_unknown_without_identity_headers() -> None:
app = FastAPI()
@app.get("/whoami")
async def whoami(request: Request) -> dict:
return {"client_app": request.state.client_app}
app.add_middleware(LoggingMiddleware)
# TestClient sets its own User-Agent; blank it out to simulate a bare client.
client = TestClient(app, headers={"user-agent": ""})
response = client.get("/whoami")
assert response.json() == {"client_app": UNKNOWN_CLIENT_APP}
record = next(r for r in caplog.records if r.name == "routstr.test.handler")
assert record.client_app == "Goose" # type: ignore[attr-defined]