Update logging middleware for FastAPI - Enhanced logging with request tracking, performance monitoring, and security logging

src/server/fastapi_app.py

@@ -37,6 +37,7 @@ from pydantic_settings import BaseSettings
 # Import our custom middleware
 from web.middleware.fastapi_auth_middleware import AuthMiddleware
 from web.middleware.fastapi_validation_middleware import ValidationMiddleware
+from web.middleware.fastapi_logging_middleware import EnhancedLoggingMiddleware
 
 # Configure logging
 logging.basicConfig(
@@ -251,38 +252,10 @@ app.add_middleware(
 )
 
 # Add custom middleware
+app.add_middleware(EnhancedLoggingMiddleware)
 app.add_middleware(AuthMiddleware)
 app.add_middleware(ValidationMiddleware)
 
-# Request logging middleware
-@app.middleware("http")
-async def log_requests(request: Request, call_next):
-    """Log all incoming HTTP requests for debugging."""
-    start_time = datetime.utcnow()
-    
-    # Log basic request info
-    client_ip = getattr(request.client, 'host', 'unknown') if request.client else 'unknown'
-    logger.info(f"Request: {request.method} {request.url} from {client_ip}")
-    
-    try:
-        response = await call_next(request)
-        
-        # Log response info
-        process_time = (datetime.utcnow() - start_time).total_seconds()
-        logger.info(f"Response: {response.status_code} ({process_time:.3f}s)")
-        
-        return response
-    except Exception as exc:
-        logger.error(f"Request failed: {exc}", exc_info=True)
-        return JSONResponse(
-            status_code=500,
-            content={
-                "success": False,
-                "error": "Internal Server Error",
-                "code": "REQUEST_FAILED"
-            }
-        )
-
 # Add global exception handler
 app.add_exception_handler(Exception, global_exception_handler)
 

src/server/web/middleware/fastapi_logging_middleware.py

@@ -0,0 +1,262 @@
+"""
+FastAPI enhanced logging middleware that integrates with the existing logging infrastructure.
+
+This module provides comprehensive logging for FastAPI applications including:
+- Request/response logging
+- Error logging with detailed context
+- Performance monitoring
+- Integration with existing logging systems
+"""
+
+import json
+import logging
+import time
+import traceback
+from typing import Callable, Dict, Any, Optional
+from fastapi import Request, Response, HTTPException, status
+from fastapi.responses import JSONResponse
+from datetime import datetime, timezone
+
+
+class EnhancedLoggingMiddleware:
+    """
+    Enhanced FastAPI logging middleware.
+    
+    This middleware provides comprehensive logging capabilities:
+    - Request/response logging with timing
+    - Detailed error logging with context
+    - Performance monitoring
+    - Integration with existing loggers
+    """
+    
+    def __init__(self, app, log_level: str = "INFO", log_body: bool = False, max_body_size: int = 1024):
+        self.app = app
+        self.log_level = getattr(logging, log_level.upper())
+        self.log_body = log_body
+        self.max_body_size = max_body_size
+        
+        # Setup loggers
+        self.setup_loggers()
+    
+    def setup_loggers(self):
+        """Setup specialized loggers for different types of events."""
+        # Main request logger
+        self.request_logger = logging.getLogger("aniworld.requests")
+        self.request_logger.setLevel(self.log_level)
+        
+        # Performance logger
+        self.performance_logger = logging.getLogger("aniworld.performance")
+        self.performance_logger.setLevel(logging.INFO)
+        
+        # Error logger (integrates with existing error logging)
+        self.error_logger = logging.getLogger("aniworld.errors")
+        self.error_logger.setLevel(logging.ERROR)
+        
+        # Security logger for auth-related events
+        self.security_logger = logging.getLogger("aniworld.security")
+        self.security_logger.setLevel(logging.WARNING)
+        
+        # Setup file handlers if not already configured
+        if not any(isinstance(h, logging.FileHandler) for h in self.request_logger.handlers):
+            # Request handler
+            request_handler = logging.FileHandler("./logs/aniworld.log")
+            request_handler.setFormatter(logging.Formatter(
+                "%(asctime)s - %(name)s - %(levelname)s - %(message)s"
+            ))
+            self.request_logger.addHandler(request_handler)
+            
+            # Error handler
+            error_handler = logging.FileHandler("./logs/errors.log")
+            error_handler.setFormatter(logging.Formatter(
+                "%(asctime)s - %(name)s - %(levelname)s - %(message)s\n%(exc_info)s"
+            ))
+            self.error_logger.addHandler(error_handler)
+            
+            # Security handler
+            security_handler = logging.FileHandler("./logs/auth_failures.log")
+            security_handler.setFormatter(logging.Formatter(
+                "%(asctime)s - %(name)s - %(levelname)s - %(message)s"
+            ))
+            self.security_logger.addHandler(security_handler)
+    
+    async def __call__(self, request: Request, call_next: Callable) -> Response:
+        """
+        Process logging for incoming requests.
+        
+        Args:
+            request: FastAPI request object
+            call_next: Next function in the middleware chain
+            
+        Returns:
+            Response from next middleware with logging
+        """
+        start_time = time.time()
+        request_timestamp = datetime.now(timezone.utc)
+        
+        # Generate request ID for tracking
+        request_id = f"{int(start_time * 1000)}-{id(request)}"
+        request.state.request_id = request_id
+        
+        # Log incoming request
+        await self.log_request(request, request_id, request_timestamp)
+        
+        try:
+            # Process request
+            response = await call_next(request)
+            
+            # Calculate processing time
+            process_time = time.time() - start_time
+            
+            # Log successful response
+            await self.log_response(request, response, request_id, process_time)
+            
+            # Log performance metrics if slow
+            if process_time > 1.0:  # Log slow requests (> 1 second)
+                self.performance_logger.warning(
+                    f"Slow request detected - ID: {request_id}, "
+                    f"Method: {request.method}, Path: {request.url.path}, "
+                    f"Duration: {process_time:.3f}s"
+                )
+            
+            # Add request ID to response headers for debugging
+            response.headers["X-Request-ID"] = request_id
+            
+            return response
+            
+        except HTTPException as e:
+            process_time = time.time() - start_time
+            await self.log_http_exception(request, e, request_id, process_time)
+            raise
+            
+        except Exception as e:
+            process_time = time.time() - start_time
+            await self.log_error(request, e, request_id, process_time)
+            
+            # Return generic error response
+            return JSONResponse(
+                status_code=status.HTTP_500_INTERNAL_SERVER_ERROR,
+                content={
+                    "success": False,
+                    "error": "Internal Server Error",
+                    "code": "SERVER_ERROR",
+                    "request_id": request_id
+                },
+                headers={"X-Request-ID": request_id}
+            )
+    
+    async def log_request(self, request: Request, request_id: str, timestamp: datetime):
+        """Log incoming request details."""
+        client_ip = getattr(request.client, 'host', 'unknown') if request.client else 'unknown'
+        user_agent = request.headers.get('user-agent', 'unknown')
+        
+        log_data = {
+            "request_id": request_id,
+            "timestamp": timestamp.isoformat(),
+            "method": request.method,
+            "url": str(request.url),
+            "path": request.url.path,
+            "client_ip": client_ip,
+            "user_agent": user_agent,
+            "headers": dict(request.headers) if self.log_level <= logging.DEBUG else None
+        }
+        
+        # Log request body for debugging (be careful with sensitive data)
+        if self.log_body and self.log_level <= logging.DEBUG:
+            try:
+                body = await request.body()
+                if body and len(body) <= self.max_body_size:
+                    try:
+                        log_data["body"] = json.loads(body.decode())
+                    except (json.JSONDecodeError, UnicodeDecodeError):
+                        log_data["body"] = body.decode('utf-8', errors='ignore')[:self.max_body_size]
+            except Exception:
+                pass  # Skip body logging if it fails
+        
+        self.request_logger.info(f"Request started: {json.dumps(log_data, default=str)}")
+    
+    async def log_response(self, request: Request, response: Response, request_id: str, process_time: float):
+        """Log successful response details."""
+        log_data = {
+            "request_id": request_id,
+            "status_code": response.status_code,
+            "process_time": f"{process_time:.3f}s",
+            "response_headers": dict(response.headers) if self.log_level <= logging.DEBUG else None
+        }
+        
+        self.request_logger.info(f"Request completed: {json.dumps(log_data, default=str)}")
+    
+    async def log_http_exception(self, request: Request, exc: HTTPException, request_id: str, process_time: float):
+        """Log HTTP exceptions with context."""
+        log_data = {
+            "request_id": request_id,
+            "method": request.method,
+            "path": request.url.path,
+            "status_code": exc.status_code,
+            "detail": exc.detail,
+            "process_time": f"{process_time:.3f}s"
+        }
+        
+        # Log security-related HTTP errors
+        if exc.status_code in [401, 403]:
+            client_ip = getattr(request.client, 'host', 'unknown') if request.client else 'unknown'
+            self.security_logger.warning(
+                f"Authentication/Authorization failure - "
+                f"IP: {client_ip}, Path: {request.url.path}, "
+                f"Status: {exc.status_code}, Request ID: {request_id}"
+            )
+        
+        if exc.status_code >= 500:
+            self.error_logger.error(f"HTTP Exception: {json.dumps(log_data, default=str)}")
+        else:
+            self.request_logger.warning(f"HTTP Exception: {json.dumps(log_data, default=str)}")
+    
+    async def log_error(self, request: Request, exc: Exception, request_id: str, process_time: float):
+        """Log unhandled exceptions with full context."""
+        client_ip = getattr(request.client, 'host', 'unknown') if request.client else 'unknown'
+        
+        error_data = {
+            "request_id": request_id,
+            "method": request.method,
+            "url": str(request.url),
+            "path": request.url.path,
+            "client_ip": client_ip,
+            "error_type": type(exc).__name__,
+            "error_message": str(exc),
+            "process_time": f"{process_time:.3f}s",
+            "traceback": traceback.format_exc()
+        }
+        
+        self.error_logger.error(f"Unhandled exception: {json.dumps(error_data, default=str)}")
+
+
+def setup_enhanced_logging():
+    """
+    Setup enhanced logging configuration for FastAPI.
+    
+    This function configures the logging system with appropriate
+    handlers and formatters for production use.
+    """
+    # Create logs directory if it doesn't exist
+    import os
+    os.makedirs("./logs", exist_ok=True)
+    
+    # Configure root logger
+    logging.basicConfig(
+        level=logging.INFO,
+        format='%(asctime)s - %(name)s - %(levelname)s - %(message)s',
+        handlers=[
+            logging.FileHandler('./logs/aniworld.log'),
+            logging.StreamHandler()
+        ]
+    )
+    
+    # Reduce noise from external libraries
+    logging.getLogger("urllib3.connectionpool").setLevel(logging.WARNING)
+    logging.getLogger("charset_normalizer").setLevel(logging.WARNING)
+    logging.getLogger("uvicorn.access").setLevel(logging.WARNING)
+    
+    return logging.getLogger("aniworld")
+
+
+# Initialize enhanced logging
+enhanced_logger = setup_enhanced_logging()

web_todo.md

@@ -106,7 +106,7 @@ This document contains tasks for migrating the web application from Flask to Fas
 -   [x] Convert Flask middleware to FastAPI middleware
 -   [x] Update error handling from Flask error handlers to FastAPI exception handlers
 -   [x] Migrate request/response interceptors
--   [ ] Update logging middleware if used
+-   [x] Update logging middleware if used
 
 ## 🧪 Testing and Validation