feat: implement FastHTML app shell with auth/CSRF middleware (Step 7.1)

Add web layer foundation:
- FastHTML app factory with Beforeware pattern
- Auth middleware validating trusted proxy IPs and X-Oidc-Username header
- CSRF dual-token validation (cookie + header + Origin/Referer)
- Request ID generation (ULID) and NDJSON request logging
- Role-based permission helpers (can_edit_event, can_delete_event)

🤖 Generated with [Claude Code](https://claude.com/claude-code)

Co-Authored-By: Claude Opus 4.5 <noreply@anthropic.com>
This commit is contained in:
2025-12-29 19:52:15 +00:00
parent eb9dc8eadd
commit 84225d865f
10 changed files with 1579 additions and 9 deletions

141
tests/test_web_app.py Normal file
View File

@@ -0,0 +1,141 @@
# ABOUTME: Integration tests for FastHTML application creation.
# ABOUTME: Tests app factory, middleware wiring, and route configuration.
import os
import pytest
def make_test_settings(
csrf_secret: str = "test-secret",
trusted_proxy_ips: str = "127.0.0.1",
auth_header_name: str = "X-Oidc-Username",
):
"""Create Settings for testing by setting env vars temporarily."""
from animaltrack.config import Settings
old_env = os.environ.copy()
try:
os.environ["CSRF_SECRET"] = csrf_secret
os.environ["TRUSTED_PROXY_IPS"] = trusted_proxy_ips
os.environ["AUTH_HEADER_NAME"] = auth_header_name
return Settings()
finally:
os.environ.clear()
os.environ.update(old_env)
class TestCreateApp:
"""Tests for the create_app factory function."""
def test_creates_app_with_provided_settings(self, seeded_db):
"""create_app(settings=...) uses provided settings."""
from animaltrack.web.app import create_app
settings = make_test_settings()
app, rt = create_app(settings=settings, db=seeded_db)
assert app is not None
assert rt is not None
assert app.state.settings is settings
assert app.state.db is seeded_db
def test_app_has_db_on_state(self, seeded_db):
"""Database accessible via app.state.db."""
from animaltrack.web.app import create_app
settings = make_test_settings()
app, rt = create_app(settings=settings, db=seeded_db)
assert hasattr(app.state, "db")
assert app.state.db is seeded_db
def test_app_has_settings_on_state(self, seeded_db):
"""Settings accessible via app.state.settings."""
from animaltrack.web.app import create_app
settings = make_test_settings()
app, rt = create_app(settings=settings, db=seeded_db)
assert hasattr(app.state, "settings")
assert app.state.settings.csrf_secret == "test-secret"
class TestAppWithTestClient:
"""Integration tests using Starlette TestClient."""
@pytest.fixture
def client(self, seeded_db):
"""Create a test client for the app."""
from starlette.testclient import TestClient
from animaltrack.web.app import create_app
# TestClient uses 'testclient' as the host, so we need to trust it
settings = make_test_settings(trusted_proxy_ips="testclient")
app, rt = create_app(settings=settings, db=seeded_db)
return TestClient(app, raise_server_exceptions=False)
def test_healthz_returns_200(self, client):
"""GET /healthz returns 200 OK."""
resp = client.get("/healthz")
assert resp.status_code == 200
def test_unauthenticated_route_returns_401(self, client):
"""Protected route without auth returns 401."""
# Any route that requires auth
resp = client.get("/")
assert resp.status_code == 401
def test_authenticated_request_succeeds(self, client):
"""Request with valid auth header succeeds."""
resp = client.get(
"/",
headers={"X-Oidc-Username": "ppetru"},
)
# Should get a valid response (200 or 404 if route not implemented yet)
# The key is it shouldn't be 401
assert resp.status_code != 401
def test_untrusted_proxy_returns_403(self, seeded_db):
"""Request from untrusted IP returns 403."""
from starlette.testclient import TestClient
from animaltrack.web.app import create_app
# Configure with a different trusted IP (not 'testclient')
settings = make_test_settings(trusted_proxy_ips="10.0.0.1")
app, rt = create_app(settings=settings, db=seeded_db)
client = TestClient(app, raise_server_exceptions=False)
resp = client.get("/", headers={"X-Oidc-Username": "ppetru"})
# Should fail because TestClient uses host 'testclient', not in trusted list
assert resp.status_code == 403
assert b"not from trusted proxy" in resp.content
def test_csrf_required_on_post(self, client):
"""POST without CSRF token returns 403."""
# POST to / route - should fail CSRF check before reaching handler
resp = client.post(
"/",
headers={"X-Oidc-Username": "ppetru"},
)
assert resp.status_code == 403
assert b"CSRF" in resp.content
def test_csrf_with_valid_tokens_succeeds(self, client):
"""POST with matching CSRF tokens proceeds."""
csrf_token = "test-csrf-token-123"
resp = client.post(
"/",
headers={
"X-Oidc-Username": "ppetru",
"X-CSRF-Token": csrf_token,
"Origin": "http://testserver",
},
cookies={"csrf_token": csrf_token},
)
# Should get through CSRF check (200 or 405 if method not allowed)
# The key is it shouldn't be 403 CSRF error
assert resp.status_code != 403 or b"CSRF" not in resp.content

393
tests/test_web_auth.py Normal file
View File

@@ -0,0 +1,393 @@
# ABOUTME: Tests for web authentication and authorization helpers.
# ABOUTME: Covers role checks, permission logic, and user extraction.
import os
import pytest
from animaltrack.models.reference import User, UserRole
def make_test_settings(
csrf_secret: str = "test-secret",
trusted_proxy_ips: str = "",
auth_header_name: str = "X-Oidc-Username",
):
"""Create Settings for testing by setting env vars temporarily."""
from animaltrack.config import Settings
# Settings loads from env, so we set env vars temporarily
old_env = os.environ.copy()
try:
os.environ["CSRF_SECRET"] = csrf_secret
os.environ["TRUSTED_PROXY_IPS"] = trusted_proxy_ips
os.environ["AUTH_HEADER_NAME"] = auth_header_name
return Settings()
finally:
os.environ.clear()
os.environ.update(old_env)
# Fixtures for test users
@pytest.fixture
def admin_user():
"""Create an admin user for testing."""
return User(
username="admin",
role=UserRole.ADMIN,
active=True,
created_at_utc=1000000,
updated_at_utc=1000000,
)
@pytest.fixture
def recorder_user():
"""Create a recorder user for testing."""
return User(
username="recorder",
role=UserRole.RECORDER,
active=True,
created_at_utc=1000000,
updated_at_utc=1000000,
)
@pytest.fixture
def inactive_user():
"""Create an inactive user for testing."""
return User(
username="inactive",
role=UserRole.RECORDER,
active=False,
created_at_utc=1000000,
updated_at_utc=1000000,
)
class TestIsAdmin:
"""Tests for is_admin helper function."""
def test_returns_true_for_admin(self, admin_user):
"""is_admin returns True for admin role."""
from animaltrack.web.auth import is_admin
assert is_admin(admin_user) is True
def test_returns_false_for_recorder(self, recorder_user):
"""is_admin returns False for recorder role."""
from animaltrack.web.auth import is_admin
assert is_admin(recorder_user) is False
class TestIsRecorder:
"""Tests for is_recorder helper function."""
def test_returns_true_for_recorder(self, recorder_user):
"""is_recorder returns True for recorder role."""
from animaltrack.web.auth import is_recorder
assert is_recorder(recorder_user) is True
def test_returns_false_for_admin(self, admin_user):
"""is_recorder returns False for admin role."""
from animaltrack.web.auth import is_recorder
assert is_recorder(admin_user) is False
class TestCanEditEvent:
"""Tests for can_edit_event permission check."""
def test_admin_can_edit_any_event(self, admin_user):
"""Admin can edit events created by any user."""
from animaltrack.web.auth import can_edit_event
assert can_edit_event(admin_user, "other_user") is True
assert can_edit_event(admin_user, "admin") is True
def test_recorder_can_edit_own_events(self, recorder_user):
"""Recorder can edit their own events."""
from animaltrack.web.auth import can_edit_event
assert can_edit_event(recorder_user, "recorder") is True
def test_recorder_cannot_edit_other_events(self, recorder_user):
"""Recorder cannot edit events created by others."""
from animaltrack.web.auth import can_edit_event
assert can_edit_event(recorder_user, "other_user") is False
class TestCanDeleteEvent:
"""Tests for can_delete_event permission check."""
def test_admin_can_delete_any_event_without_dependents(self, admin_user):
"""Admin can delete any event without dependents."""
from animaltrack.web.auth import can_delete_event
assert can_delete_event(admin_user, "other_user", has_dependents=False) is True
assert can_delete_event(admin_user, "admin", has_dependents=False) is True
def test_admin_can_delete_any_event_with_dependents(self, admin_user):
"""Admin can cascade delete events with dependents."""
from animaltrack.web.auth import can_delete_event
assert can_delete_event(admin_user, "other_user", has_dependents=True) is True
assert can_delete_event(admin_user, "admin", has_dependents=True) is True
def test_recorder_can_delete_own_event_without_dependents(self, recorder_user):
"""Recorder can delete their own events without dependents."""
from animaltrack.web.auth import can_delete_event
assert can_delete_event(recorder_user, "recorder", has_dependents=False) is True
def test_recorder_cannot_delete_own_event_with_dependents(self, recorder_user):
"""Recorder cannot delete their own events if they have dependents."""
from animaltrack.web.auth import can_delete_event
assert can_delete_event(recorder_user, "recorder", has_dependents=True) is False
def test_recorder_cannot_delete_other_events(self, recorder_user):
"""Recorder cannot delete events created by others."""
from animaltrack.web.auth import can_delete_event
assert can_delete_event(recorder_user, "other_user", has_dependents=False) is False
assert can_delete_event(recorder_user, "other_user", has_dependents=True) is False
# HTTP-level auth middleware tests
class TestGetClientIp:
"""Tests for client IP extraction."""
def test_extracts_from_x_forwarded_for(self):
"""Extracts client IP from X-Forwarded-For header."""
from unittest.mock import MagicMock
from animaltrack.web.middleware import get_client_ip
req = MagicMock()
req.headers = {"x-forwarded-for": "203.0.113.50"}
req.client = MagicMock(host="10.0.0.1")
assert get_client_ip(req) == "203.0.113.50"
def test_extracts_first_ip_from_chain(self):
"""Extracts first IP when multiple proxies in chain."""
from unittest.mock import MagicMock
from animaltrack.web.middleware import get_client_ip
req = MagicMock()
req.headers = {"x-forwarded-for": "203.0.113.50, 10.0.0.2, 10.0.0.1"}
req.client = MagicMock(host="10.0.0.1")
assert get_client_ip(req) == "203.0.113.50"
def test_falls_back_to_client_host(self):
"""Falls back to direct client IP when no X-Forwarded-For."""
from unittest.mock import MagicMock
from animaltrack.web.middleware import get_client_ip
req = MagicMock()
req.headers = {}
req.client = MagicMock(host="192.168.1.100")
assert get_client_ip(req) == "192.168.1.100"
def test_returns_unknown_when_no_client(self):
"""Returns 'unknown' when no client info available."""
from unittest.mock import MagicMock
from animaltrack.web.middleware import get_client_ip
req = MagicMock()
req.headers = {}
req.client = None
assert get_client_ip(req) == "unknown"
class TestIsTrustedProxy:
"""Tests for trusted proxy validation."""
def test_accepts_trusted_ip(self):
"""Request from trusted IP proceeds."""
from unittest.mock import MagicMock
from animaltrack.web.middleware import is_trusted_proxy
req = MagicMock()
req.client = MagicMock(host="127.0.0.1")
settings = make_test_settings(trusted_proxy_ips="127.0.0.1,10.0.0.1")
assert is_trusted_proxy(req, settings) is True
def test_rejects_untrusted_ip(self):
"""Returns False for untrusted IP."""
from unittest.mock import MagicMock
from animaltrack.web.middleware import is_trusted_proxy
req = MagicMock()
req.client = MagicMock(host="192.168.1.1")
settings = make_test_settings(trusted_proxy_ips="127.0.0.1,10.0.0.1")
assert is_trusted_proxy(req, settings) is False
def test_empty_trusted_list_rejects_all(self):
"""When no trusted IPs configured, all requests rejected."""
from unittest.mock import MagicMock
from animaltrack.web.middleware import is_trusted_proxy
req = MagicMock()
req.client = MagicMock(host="127.0.0.1")
settings = make_test_settings(trusted_proxy_ips="")
assert is_trusted_proxy(req, settings) is False
def test_rejects_when_no_client(self):
"""Returns False when no client info available."""
from unittest.mock import MagicMock
from animaltrack.web.middleware import is_trusted_proxy
req = MagicMock()
req.client = None
settings = make_test_settings(trusted_proxy_ips="127.0.0.1")
assert is_trusted_proxy(req, settings) is False
class TestAuthBefore:
"""Tests for auth_before middleware function."""
def test_rejects_untrusted_proxy(self, seeded_db):
"""Returns 403 when request from untrusted IP."""
from unittest.mock import MagicMock
from animaltrack.web.middleware import auth_before
req = MagicMock()
req.client = MagicMock(host="192.168.1.1")
req.headers = {"x-oidc-username": "ppetru"}
settings = make_test_settings(trusted_proxy_ips="127.0.0.1")
resp = auth_before(req, settings, seeded_db)
assert resp is not None
assert resp.status_code == 403
assert b"not from trusted proxy" in resp.body
def test_rejects_missing_auth_header(self, seeded_db):
"""Returns 401 when auth header is missing."""
from unittest.mock import MagicMock
from animaltrack.web.middleware import auth_before
req = MagicMock()
req.client = MagicMock(host="127.0.0.1")
req.headers = {} # No auth header
settings = make_test_settings(trusted_proxy_ips="127.0.0.1")
resp = auth_before(req, settings, seeded_db)
assert resp is not None
assert resp.status_code == 401
assert b"Missing auth header" in resp.body
def test_rejects_unknown_user(self, seeded_db):
"""Returns 401 when user not in database."""
from unittest.mock import MagicMock
from animaltrack.web.middleware import auth_before
req = MagicMock()
req.client = MagicMock(host="127.0.0.1")
req.headers = {"x-oidc-username": "nonexistent_user"}
settings = make_test_settings(trusted_proxy_ips="127.0.0.1")
resp = auth_before(req, settings, seeded_db)
assert resp is not None
assert resp.status_code == 401
assert b"Unknown user" in resp.body
def test_rejects_inactive_user(self, seeded_db):
"""Returns 401 when user is inactive."""
from unittest.mock import MagicMock
from animaltrack.models.reference import User, UserRole
from animaltrack.repositories.users import UserRepository
from animaltrack.web.middleware import auth_before
# Create an inactive user
user_repo = UserRepository(seeded_db)
inactive = User(
username="inactive_test",
role=UserRole.RECORDER,
active=False,
created_at_utc=1000000,
updated_at_utc=1000000,
)
user_repo.upsert(inactive)
req = MagicMock()
req.client = MagicMock(host="127.0.0.1")
req.headers = {"x-oidc-username": "inactive_test"}
settings = make_test_settings(trusted_proxy_ips="127.0.0.1")
resp = auth_before(req, settings, seeded_db)
assert resp is not None
assert resp.status_code == 401
assert b"Inactive user" in resp.body
def test_sets_user_in_scope(self, seeded_db):
"""User object is set in req.scope['auth'] on success."""
from unittest.mock import MagicMock
from animaltrack.web.middleware import auth_before
req = MagicMock()
req.client = MagicMock(host="127.0.0.1")
req.headers = {"x-oidc-username": "ppetru"} # From seeds
req.scope = {}
settings = make_test_settings(trusted_proxy_ips="127.0.0.1")
resp = auth_before(req, settings, seeded_db)
assert resp is None # Continue processing
assert "auth" in req.scope
assert req.scope["auth"].username == "ppetru"
assert req.scope["auth"].role == UserRole.ADMIN
def test_respects_custom_auth_header_name(self, seeded_db):
"""Uses AUTH_HEADER_NAME setting for header lookup."""
from unittest.mock import MagicMock
from animaltrack.web.middleware import auth_before
req = MagicMock()
req.client = MagicMock(host="127.0.0.1")
req.headers = {"x-custom-user": "ppetru"}
req.scope = {}
settings = make_test_settings(
trusted_proxy_ips="127.0.0.1",
auth_header_name="X-Custom-User",
)
resp = auth_before(req, settings, seeded_db)
assert resp is None # Continue processing
assert "auth" in req.scope
assert req.scope["auth"].username == "ppetru"

172
tests/test_web_csrf.py Normal file
View File

@@ -0,0 +1,172 @@
# ABOUTME: Tests for CSRF validation logic.
# ABOUTME: Covers token matching, origin/referer validation, and safe methods.
class TestValidateCSRFToken:
"""Tests for CSRF token validation logic."""
def test_accepts_matching_tokens(self):
"""Valid when cookie and header tokens match."""
from animaltrack.web.middleware import validate_csrf_token
assert validate_csrf_token("abc123", "abc123") is True
def test_rejects_mismatched_tokens(self):
"""Invalid when cookie and header tokens differ."""
from animaltrack.web.middleware import validate_csrf_token
assert validate_csrf_token("abc123", "xyz789") is False
def test_rejects_empty_cookie_token(self):
"""Invalid when cookie token is empty."""
from animaltrack.web.middleware import validate_csrf_token
assert validate_csrf_token("", "abc123") is False
def test_rejects_empty_header_token(self):
"""Invalid when header token is empty."""
from animaltrack.web.middleware import validate_csrf_token
assert validate_csrf_token("abc123", "") is False
def test_rejects_none_tokens(self):
"""Invalid when either token is None."""
from animaltrack.web.middleware import validate_csrf_token
assert validate_csrf_token(None, "abc123") is False
assert validate_csrf_token("abc123", None) is False
assert validate_csrf_token(None, None) is False
class TestIsSafeMethod:
"""Tests for HTTP safe method detection."""
def test_get_is_safe(self):
"""GET is a safe method."""
from animaltrack.web.middleware import is_safe_method
assert is_safe_method("GET") is True
def test_head_is_safe(self):
"""HEAD is a safe method."""
from animaltrack.web.middleware import is_safe_method
assert is_safe_method("HEAD") is True
def test_options_is_safe(self):
"""OPTIONS is a safe method."""
from animaltrack.web.middleware import is_safe_method
assert is_safe_method("OPTIONS") is True
def test_post_is_not_safe(self):
"""POST is not a safe method."""
from animaltrack.web.middleware import is_safe_method
assert is_safe_method("POST") is False
def test_put_is_not_safe(self):
"""PUT is not a safe method."""
from animaltrack.web.middleware import is_safe_method
assert is_safe_method("PUT") is False
def test_delete_is_not_safe(self):
"""DELETE is not a safe method."""
from animaltrack.web.middleware import is_safe_method
assert is_safe_method("DELETE") is False
def test_patch_is_not_safe(self):
"""PATCH is not a safe method."""
from animaltrack.web.middleware import is_safe_method
assert is_safe_method("PATCH") is False
def test_case_insensitive(self):
"""Method check is case-insensitive."""
from animaltrack.web.middleware import is_safe_method
assert is_safe_method("get") is True
assert is_safe_method("Get") is True
assert is_safe_method("post") is False
class TestValidateOrigin:
"""Tests for Origin/Referer header validation."""
def test_accepts_matching_origin(self):
"""Valid when Origin matches expected host."""
from animaltrack.web.middleware import validate_origin
assert validate_origin("https://example.com", "example.com") is True
def test_accepts_matching_origin_with_port(self):
"""Valid when Origin matches expected host with port."""
from animaltrack.web.middleware import validate_origin
assert validate_origin("https://example.com:3366", "example.com:3366") is True
def test_rejects_different_origin(self):
"""Invalid when Origin doesn't match expected host."""
from animaltrack.web.middleware import validate_origin
assert validate_origin("https://evil.com", "example.com") is False
def test_rejects_subdomain_mismatch(self):
"""Invalid when Origin is a subdomain of expected host."""
from animaltrack.web.middleware import validate_origin
assert validate_origin("https://sub.example.com", "example.com") is False
def test_accepts_none_origin(self):
"""None origin returns False (will check Referer instead)."""
from animaltrack.web.middleware import validate_origin
assert validate_origin(None, "example.com") is False
def test_accepts_empty_origin(self):
"""Empty origin returns False."""
from animaltrack.web.middleware import validate_origin
assert validate_origin("", "example.com") is False
class TestValidateReferer:
"""Tests for Referer header validation."""
def test_accepts_matching_referer(self):
"""Valid when Referer host matches expected host."""
from animaltrack.web.middleware import validate_referer
assert validate_referer("https://example.com/page", "example.com") is True
def test_accepts_matching_referer_with_port(self):
"""Valid when Referer matches expected host with port."""
from animaltrack.web.middleware import validate_referer
assert validate_referer("https://example.com:3366/page", "example.com:3366") is True
def test_rejects_different_referer(self):
"""Invalid when Referer host doesn't match expected host."""
from animaltrack.web.middleware import validate_referer
assert validate_referer("https://evil.com/page", "example.com") is False
def test_rejects_none_referer(self):
"""Invalid when Referer is None."""
from animaltrack.web.middleware import validate_referer
assert validate_referer(None, "example.com") is False
def test_rejects_empty_referer(self):
"""Invalid when Referer is empty."""
from animaltrack.web.middleware import validate_referer
assert validate_referer("", "example.com") is False
def test_rejects_malformed_referer(self):
"""Invalid when Referer is malformed."""
from animaltrack.web.middleware import validate_referer
assert validate_referer("not-a-url", "example.com") is False

View File

@@ -0,0 +1,302 @@
# ABOUTME: Tests for request ID generation and logging middleware.
# ABOUTME: Covers ULID generation, scope storage, and NDJSON log format.
import json
import os
import time
from unittest.mock import MagicMock
def make_test_settings(
csrf_secret: str = "test-secret",
trusted_proxy_ips: str = "",
auth_header_name: str = "X-Oidc-Username",
):
"""Create Settings for testing by setting env vars temporarily."""
from animaltrack.config import Settings
old_env = os.environ.copy()
try:
os.environ["CSRF_SECRET"] = csrf_secret
os.environ["TRUSTED_PROXY_IPS"] = trusted_proxy_ips
os.environ["AUTH_HEADER_NAME"] = auth_header_name
return Settings()
finally:
os.environ.clear()
os.environ.update(old_env)
class TestRequestIdBefore:
"""Tests for request ID generation middleware."""
def test_generates_request_id(self):
"""Generates a request_id in the scope."""
from animaltrack.web.middleware import request_id_before
req = MagicMock()
req.scope = {}
request_id_before(req)
assert "request_id" in req.scope
assert req.scope["request_id"] is not None
def test_request_id_is_ulid(self):
"""Request ID is a valid 26-char ULID."""
from animaltrack.web.middleware import request_id_before
req = MagicMock()
req.scope = {}
request_id_before(req)
request_id = req.scope["request_id"]
assert len(request_id) == 26
# ULIDs are base32, should only contain valid chars
valid_chars = "0123456789ABCDEFGHJKMNPQRSTVWXYZ"
assert all(c in valid_chars for c in request_id.upper())
def test_generates_unique_ids(self):
"""Each request gets a unique request_id."""
from animaltrack.web.middleware import request_id_before
ids = set()
for _ in range(100):
req = MagicMock()
req.scope = {}
request_id_before(req)
ids.add(req.scope["request_id"])
assert len(ids) == 100 # All unique
def test_sets_start_time(self):
"""Sets request_start_time in scope for duration calculation."""
from animaltrack.web.middleware import request_id_before
req = MagicMock()
req.scope = {}
before = time.time()
request_id_before(req)
after = time.time()
assert "request_start_time" in req.scope
assert before <= req.scope["request_start_time"] <= after
class TestLoggingAfter:
"""Tests for request logging middleware."""
def test_logs_in_ndjson_format(self, capsys):
"""Log line is valid JSON."""
from animaltrack.web.middleware import logging_after
req = MagicMock()
req.scope = {"request_id": "TEST123", "request_start_time": time.time()}
req.url = MagicMock(path="/test")
req.method = "GET"
req.headers = {}
req.client = MagicMock(host="127.0.0.1")
resp = MagicMock()
resp.status_code = 200
settings = make_test_settings()
logging_after(req, resp, settings)
captured = capsys.readouterr()
log_line = captured.out.strip()
# Should be valid JSON
parsed = json.loads(log_line)
assert isinstance(parsed, dict)
def test_log_includes_required_fields(self, capsys):
"""Log includes: ts, level, route, actor, ip, method, status, duration_ms."""
from animaltrack.models.reference import User, UserRole
from animaltrack.web.middleware import logging_after
user = User(
username="testuser",
role=UserRole.RECORDER,
active=True,
created_at_utc=1000000,
updated_at_utc=1000000,
)
req = MagicMock()
req.scope = {
"request_id": "TEST123",
"request_start_time": time.time() - 0.1, # 100ms ago
"auth": user,
}
req.url = MagicMock(path="/test/route")
req.method = "POST"
req.headers = {}
req.client = MagicMock(host="127.0.0.1")
resp = MagicMock()
resp.status_code = 201
settings = make_test_settings()
logging_after(req, resp, settings)
captured = capsys.readouterr()
parsed = json.loads(captured.out.strip())
assert "ts" in parsed
assert parsed["level"] == "info"
assert parsed["route"] == "/test/route"
assert parsed["actor"] == "testuser"
assert parsed["method"] == "POST"
assert parsed["status"] == 201
assert "duration_ms" in parsed
assert parsed["duration_ms"] >= 0
def test_log_includes_request_id(self, capsys):
"""Log includes request_id field."""
from animaltrack.web.middleware import logging_after
req = MagicMock()
req.scope = {"request_id": "01ARZ3NDEKTSV4RRFFQ69G5FAV", "request_start_time": time.time()}
req.url = MagicMock(path="/test")
req.method = "GET"
req.headers = {}
req.client = MagicMock(host="127.0.0.1")
resp = MagicMock()
resp.status_code = 200
settings = make_test_settings()
logging_after(req, resp, settings)
captured = capsys.readouterr()
parsed = json.loads(captured.out.strip())
assert parsed["request_id"] == "01ARZ3NDEKTSV4RRFFQ69G5FAV"
def test_log_includes_event_id_when_provided(self, capsys):
"""Log includes event_id field when provided."""
from animaltrack.web.middleware import logging_after
req = MagicMock()
req.scope = {"request_id": "TEST123", "request_start_time": time.time()}
req.url = MagicMock(path="/actions/product-collected")
req.method = "POST"
req.headers = {}
req.client = MagicMock(host="127.0.0.1")
resp = MagicMock()
resp.status_code = 200
settings = make_test_settings()
logging_after(req, resp, settings, event_id="01ARZ3NDEKTSV4RRFFQ69G5EVT")
captured = capsys.readouterr()
parsed = json.loads(captured.out.strip())
assert parsed["event_id"] == "01ARZ3NDEKTSV4RRFFQ69G5EVT"
def test_duration_ms_accurate(self, capsys):
"""duration_ms reflects actual request time."""
from animaltrack.web.middleware import logging_after
req = MagicMock()
# Started 150ms ago
req.scope = {"request_id": "TEST123", "request_start_time": time.time() - 0.150}
req.url = MagicMock(path="/test")
req.method = "GET"
req.headers = {}
req.client = MagicMock(host="127.0.0.1")
resp = MagicMock()
resp.status_code = 200
settings = make_test_settings()
logging_after(req, resp, settings)
captured = capsys.readouterr()
parsed = json.loads(captured.out.strip())
# Should be approximately 150ms (with some tolerance)
assert 100 <= parsed["duration_ms"] <= 250
def test_logs_x_forwarded_for_ip(self, capsys):
"""Log ip field uses X-Forwarded-For when present."""
from animaltrack.web.middleware import logging_after
req = MagicMock()
req.scope = {"request_id": "TEST123", "request_start_time": time.time()}
req.url = MagicMock(path="/test")
req.method = "GET"
req.headers = {"x-forwarded-for": "203.0.113.50, 10.0.0.1"}
req.client = MagicMock(host="10.0.0.1") # Proxy IP
resp = MagicMock()
resp.status_code = 200
settings = make_test_settings()
logging_after(req, resp, settings)
captured = capsys.readouterr()
parsed = json.loads(captured.out.strip())
# Should use the client IP from X-Forwarded-For, not the proxy IP
assert parsed["ip"] == "203.0.113.50"
def test_actor_is_none_when_unauthenticated(self, capsys):
"""Log actor is None when no user in scope."""
from animaltrack.web.middleware import logging_after
req = MagicMock()
req.scope = {"request_id": "TEST123", "request_start_time": time.time()}
req.url = MagicMock(path="/healthz")
req.method = "GET"
req.headers = {}
req.client = MagicMock(host="127.0.0.1")
resp = MagicMock()
resp.status_code = 200
settings = make_test_settings()
logging_after(req, resp, settings)
captured = capsys.readouterr()
parsed = json.loads(captured.out.strip())
assert parsed["actor"] is None
def test_timestamp_is_milliseconds(self, capsys):
"""Log ts field is milliseconds since epoch."""
from animaltrack.web.middleware import logging_after
req = MagicMock()
req.scope = {"request_id": "TEST123", "request_start_time": time.time()}
req.url = MagicMock(path="/test")
req.method = "GET"
req.headers = {}
req.client = MagicMock(host="127.0.0.1")
resp = MagicMock()
resp.status_code = 200
settings = make_test_settings()
before_ms = int(time.time() * 1000)
logging_after(req, resp, settings)
after_ms = int(time.time() * 1000)
captured = capsys.readouterr()
parsed = json.loads(captured.out.strip())
# ts should be between before and after (in milliseconds)
assert before_ms <= parsed["ts"] <= after_ms
# Should be a reasonable timestamp (year 2020+)
assert parsed["ts"] > 1577836800000 # 2020-01-01