diff --git a/src/application/commands/create_kyc_command.py b/src/application/commands/create_kyc_command.py index 757e404..cdcf442 100644 --- a/src/application/commands/create_kyc_command.py +++ b/src/application/commands/create_kyc_command.py @@ -25,8 +25,16 @@ class PassKycCommand: async def __call__(self,user_id: str) -> BeorgKycCreateResponse: + self._logger.info(f'KYC session creation started for user {user_id}') + self._logger.info(f'KYC Beorg identification request started for user {user_id}') result = await self._beorg_service.create_identification(client_user_token=user_id) + self._logger.info( + f'KYC Beorg identification request finished for user {user_id} ' + f'status={result.status} user_token={result.user_token} client_user_token={result.client_user_token}' + ) expires_at = _utc_now() + timedelta(seconds=KYC_SESSION_TTL) + self._logger.info(f'KYC session expiration calculated for user {user_id} ttl={KYC_SESSION_TTL} expires_at={expires_at.isoformat()}') + self._logger.info(f'KYC session database save started for user {user_id}') async with self._unit_of_work as unit_of_work: await unit_of_work.kyc_repository.create_started_session( user_id=user_id, @@ -37,7 +45,8 @@ class PassKycCommand: expires_at=expires_at, error=result.error, ) - self._logger.info(f'KYC started for user {user_id}') + self._logger.info(f'KYC session database save finished for user {user_id}') + self._logger.info(f'KYC session creation finished for user {user_id}') return result diff --git a/src/infrastructure/security/jwt.py b/src/infrastructure/security/jwt.py index aee570e..c124737 100644 --- a/src/infrastructure/security/jwt.py +++ b/src/infrastructure/security/jwt.py @@ -13,6 +13,7 @@ class JwtService(IJwtService): self._key_store = key_store async def decode_access_token(self, token: str) -> AccessTokenPayload: + self._logger.info('JWT access token decode started') payload = await self._decode_and_verify(token) if payload.get('type') != 'access': @@ -20,7 +21,7 @@ class JwtService(IJwtService): raise InvalidTokenException('Invalid token type') try: - return AccessTokenPayload( + result = AccessTokenPayload( sub=str(payload['sub']), type='access', sid=str(payload['sid']), @@ -30,6 +31,8 @@ class JwtService(IJwtService): iss=payload.get('iss'), aud=payload.get('aud'), ) + self._logger.info(f'JWT access token decode completed user_id={result.sub} sid={result.sid}') + return result except KeyError as exception: self._logger.warning(f'Access token missing claim error={str(exception)}') raise InvalidTokenException(f'Missing token claim: {exception}') @@ -37,6 +40,7 @@ class JwtService(IJwtService): async def _decode_and_verify(self, token: str) -> dict: kid: str | None = None try: + self._logger.debug('JWT header parsing started') header = jwt.get_unverified_header(token) kid = header.get('kid') @@ -49,6 +53,7 @@ class JwtService(IJwtService): self._logger.warning(f'JWT invalid algorithm kid={kid} received_alg={received_alg} expected_alg={settings.JWT_ALGORITHM}') raise InvalidTokenException('Invalid token algorithm') + self._logger.debug(f'JWT public key lookup started kid={kid}') public_pem = await self._key_store.get_public_key_for_kid(str(kid)) if not public_pem: @@ -60,6 +65,7 @@ class JwtService(IJwtService): self._logger.warning(f'JWT unknown kid kid={kid}') raise InvalidTokenException('Unknown token kid') + self._logger.debug(f'JWT signature verification started kid={kid}') options = { 'verify_signature': True, 'verify_exp': True, @@ -91,6 +97,7 @@ class JwtService(IJwtService): self._logger.warning(f'JWT missing type claim kid={kid}') raise InvalidTokenException('Missing token claim: type') + self._logger.info(f'JWT signature verification completed kid={kid} user_id={payload.get("sub")} sid={payload.get("sid")}') return payload except ExpiredSignatureError as exception: diff --git a/src/presentation/decorators/auth.py b/src/presentation/decorators/auth.py index 6de43cb..05376c2 100644 --- a/src/presentation/decorators/auth.py +++ b/src/presentation/decorators/auth.py @@ -4,6 +4,7 @@ from src.application.contracts import IJwtService from src.application.domain.exceptions import InvalidTokenException,NotAuthenticatedException from src.application.domain.dto import AccessTokenPayload, AuthContext from src.presentation.dependencies import get_jwt_service +from src.presentation.dependencies.logger import get_logger def _extract_access_token(request: Request) -> str | None: @@ -25,12 +26,17 @@ async def require_access_token( request: Request, jwt_service: IJwtService = Depends(get_jwt_service), ) -> AuthContext: + logger = get_logger() + logger.info(f'JWT auth started path={request.url.path}') token = _extract_access_token(request) if not token: + logger.warning(f'JWT auth failed path={request.url.path} reason=missing_token') raise NotAuthenticatedException() payload: AccessTokenPayload = await jwt_service.decode_access_token(token) if payload.type != 'access': + logger.warning(f'JWT auth failed path={request.url.path} user_id={payload.sub} reason=invalid_token_type type={payload.type}') raise InvalidTokenException('Invalid token type') + logger.info(f'JWT auth completed path={request.url.path} user_id={payload.sub} sid={payload.sid}') return AuthContext(user_id=payload.sub, sid=payload.sid, token=payload) diff --git a/src/presentation/decorators/csrf.py b/src/presentation/decorators/csrf.py index e682223..935a553 100644 --- a/src/presentation/decorators/csrf.py +++ b/src/presentation/decorators/csrf.py @@ -5,6 +5,7 @@ from typing import Callable, Awaitable, Any, Optional, Annotated from fastapi import Request, Header from src.application.domain.exceptions import CsrfRequestRequiredException from src.infrastructure.security import CsrfService +from src.presentation.dependencies.logger import get_logger def csrf_protect( @@ -31,6 +32,7 @@ def csrf_protect( @wraps(func) async def wrapper(*args, **kwargs): + logger = get_logger() request: Request | None = kwargs.get('request') if request is None: for arg in args: @@ -39,8 +41,10 @@ def csrf_protect( break if request is None: + logger.warning('CSRF check failed reason=missing_request') raise CsrfRequestRequiredException() + logger.info(f'CSRF check started path={request.url.path}') csrf = CsrfService() cookie_token, _ = csrf.extract(request.cookies, request.headers) @@ -50,6 +54,7 @@ def csrf_protect( csrf.verify_pair(cookie_token, header_token, expected_subject) kwargs.pop('x_csrf_token', None) + logger.info(f'CSRF check completed path={request.url.path}') return await func(*args, **kwargs) wrapper.__signature__ = sig.replace(parameters=params)