fix: add debug logging to authenticate_request exception handlers

- Add logger = logging.getLogger("stack_auth") at module level
- Emit logger.debug("authenticate_request failed", exc_info=True) in both sync and async handlers
- Add tests verifying debug log emission on verification failure
This commit is contained in:
Ejiro Asiuwhu 2026-03-25 08:02:10 +01:00
parent bfff27d4e7
commit 7ec2e27a8e
2 changed files with 65 additions and 0 deletions

View File

@ -9,9 +9,12 @@ from __future__ import annotations
import base64
import json
import logging
from dataclasses import dataclass
from typing import Any, Literal, Mapping
logger = logging.getLogger("stack_auth")
from stack_auth._jwt import (
AsyncJWKSFetcher,
SyncJWKSFetcher,
@ -159,6 +162,7 @@ def sync_authenticate_request(
token=token,
)
except Exception:
logger.debug("authenticate_request failed", exc_info=True)
return AuthState(status="unauthenticated")
@ -194,4 +198,5 @@ async def async_authenticate_request(
token=token,
)
except Exception:
logger.debug("authenticate_request failed", exc_info=True)
return AuthState(status="unauthenticated")

View File

@ -4,6 +4,7 @@ from __future__ import annotations
import base64
import json
import logging
import time
from typing import Any, Mapping
from unittest.mock import AsyncMock, MagicMock, patch
@ -229,3 +230,62 @@ class TestAsyncAuthenticateRequest:
assert result.status == "unauthenticated"
assert result.user_id is None
# ---------------------------------------------------------------------------
# Debug logging on authentication failure
# ---------------------------------------------------------------------------
class TestSyncAuthenticateRequestLogging:
"""Verify that sync_authenticate_request emits debug log on failure."""
def test_logs_debug_on_verification_failure(self, caplog: pytest.LogCaptureFixture) -> None:
fetcher = MagicMock(spec=SyncJWKSFetcher)
with (
patch("stack_auth._auth.sync_verify_token", side_effect=Exception("bad token")),
caplog.at_level(logging.DEBUG, logger="stack_auth"),
):
request = FakeRequest({"Authorization": "Bearer invalid-jwt"})
result = sync_authenticate_request(request, fetcher=fetcher)
assert result.status == "unauthenticated"
assert any("authenticate_request failed" in record.message for record in caplog.records)
def test_still_returns_unauthenticated_after_logging(self) -> None:
fetcher = MagicMock(spec=SyncJWKSFetcher)
with patch("stack_auth._auth.sync_verify_token", side_effect=ValueError("corrupt")):
request = FakeRequest({"Authorization": "Bearer corrupt-jwt"})
result = sync_authenticate_request(request, fetcher=fetcher)
assert result.status == "unauthenticated"
assert result.user_id is None
class TestAsyncAuthenticateRequestLogging:
"""Verify that async_authenticate_request emits debug log on failure."""
async def test_logs_debug_on_verification_failure(self, caplog: pytest.LogCaptureFixture) -> None:
fetcher = MagicMock(spec=AsyncJWKSFetcher)
with (
patch("stack_auth._auth.async_verify_token", new_callable=AsyncMock, side_effect=Exception("bad token")),
caplog.at_level(logging.DEBUG, logger="stack_auth"),
):
request = FakeRequest({"Authorization": "Bearer invalid-async-jwt"})
result = await async_authenticate_request(request, fetcher=fetcher)
assert result.status == "unauthenticated"
assert any("authenticate_request failed" in record.message for record in caplog.records)
async def test_still_returns_unauthenticated_after_logging(self) -> None:
fetcher = MagicMock(spec=AsyncJWKSFetcher)
with patch("stack_auth._auth.async_verify_token", new_callable=AsyncMock, side_effect=ValueError("corrupt")):
request = FakeRequest({"Authorization": "Bearer corrupt-async-jwt"})
result = await async_authenticate_request(request, fetcher=fetcher)
assert result.status == "unauthenticated"
assert result.user_id is None