""" API middleware for logging, profiling, and error handling. """ import functools import logging import time from typing import Callable from fastapi import HTTPException, Request from fastapi.responses import JSONResponse logger = logging.getLogger(__name__) try: from .profiler import Profiler, profile_context HAS_PROFILER = True except ImportError: HAS_PROFILER = False def api_endpoint_logging( endpoint_name: str, log_request: bool = True, log_response: bool = True, include_profiling: bool = True, ): """ Decorator for API endpoints that adds: - Request/response logging - Error handling with structured error responses - Profiling integration - Timing information Args: endpoint_name: Name of the endpoint for logging log_request: Whether to log request details log_response: Whether to log response details include_profiling: Whether to include profiling """ def decorator(func: Callable) -> Callable: @functools.wraps(func) async def wrapper(*args, **kwargs): request = kwargs.get("request") or ( args[0] if args and isinstance(args[0], Request) else None ) # Extract request details request_id = None if request: request_id = ( request.headers.get("X-Request-ID") or f"req_{int(time.time() * 1000)}" ) client_ip = request.client.host if request.client else "unknown" method = request.method path = request.url.path query_params = dict(request.query_params) else: client_ip = "unknown" method = "UNKNOWN" path = endpoint_name query_params = {} start_time = time.time() # Log request if log_request: logger.info( f"[{endpoint_name}] Request started", extra={ "request_id": request_id, "method": method, "path": path, "client_ip": client_ip, "query_params": query_params, "endpoint": endpoint_name, }, ) # Track request with profiler if available profiler_context = None if include_profiling and HAS_PROFILER: profiler = Profiler.get_instance() if profiler.enabled: profiler_context = profile_context( stage="api_endpoint", operation=endpoint_name ) profiler_context.__enter__() try: # Execute the endpoint function if profiler_context: with profile_context(stage="api_endpoint", operation=endpoint_name): result = await func(*args, **kwargs) else: result = await func(*args, **kwargs) duration = time.time() - start_time # Log successful response if log_response: status_code = 200 if hasattr(result, "status_code"): status_code = result.status_code elif isinstance(result, dict) and "status_code" in result: status_code = result["status_code"] logger.info( f"[{endpoint_name}] Request completed successfully", extra={ "request_id": request_id, "duration_ms": duration * 1000, "status_code": status_code, "endpoint": endpoint_name, }, ) return result except HTTPException as e: duration = time.time() - start_time logger.warning( f"[{endpoint_name}] HTTP error", extra={ "request_id": request_id, "duration_ms": duration * 1000, "status_code": e.status_code, "detail": str(e.detail), "endpoint": endpoint_name, }, exc_info=True, ) raise except ValueError as e: duration = time.time() - start_time logger.error( f"[{endpoint_name}] Validation error", extra={ "request_id": request_id, "duration_ms": duration * 1000, "error": str(e), "endpoint": endpoint_name, }, exc_info=True, ) return JSONResponse( status_code=400, content={ "error": "ValidationError", "message": str(e), "request_id": request_id, "endpoint": endpoint_name, }, ) except FileNotFoundError as e: duration = time.time() - start_time logger.error( f"[{endpoint_name}] File not found", extra={ "request_id": request_id, "duration_ms": duration * 1000, "error": str(e), "endpoint": endpoint_name, }, exc_info=True, ) return JSONResponse( status_code=404, content={ "error": "FileNotFoundError", "message": str(e), "request_id": request_id, "endpoint": endpoint_name, }, ) except PermissionError as e: duration = time.time() - start_time logger.error( f"[{endpoint_name}] Permission error", extra={ "request_id": request_id, "duration_ms": duration * 1000, "error": str(e), "endpoint": endpoint_name, }, exc_info=True, ) return JSONResponse( status_code=403, content={ "error": "PermissionError", "message": str(e), "request_id": request_id, "endpoint": endpoint_name, }, ) except Exception as e: duration = time.time() - start_time # Log full exception with traceback logger.error( f"[{endpoint_name}] Unexpected error", extra={ "request_id": request_id, "duration_ms": duration * 1000, "error_type": type(e).__name__, "error": str(e), "endpoint": endpoint_name, }, exc_info=True, ) # Return structured error response return JSONResponse( status_code=500, content={ "error": "InternalServerError", "message": "An unexpected error occurred", "error_type": type(e).__name__, "request_id": request_id, "endpoint": endpoint_name, }, ) finally: if profiler_context: try: profiler_context.__exit__(None, None, None) except Exception: pass return wrapper return decorator def log_execution_time(func_name: str): """Decorator to log execution time of a function.""" def decorator(func: Callable) -> Callable: @functools.wraps(func) def wrapper(*args, **kwargs): start_time = time.time() try: result = func(*args, **kwargs) duration = time.time() - start_time logger.debug(f"{func_name} executed in {duration:.3f}s") return result except Exception as e: duration = time.time() - start_time logger.error(f"{func_name} failed after {duration:.3f}s: {e}", exc_info=True) raise return wrapper return decorator