mirror of
https://github.com/taylanbakircioglu/haproxy-openmanager.git
synced 2026-09-18 08:35:28 +00:00
a6b223c0e7
PRODUCTION STABILITY FIX - Detailed Logging for Malformed Agent Payloads PROBLEM: - demo-agent1 and demo-agent2 sending malformed JSON - Error: JSON decode error at body position 322 - No visibility into WHAT is malformed or WHY - Impossible to debug without raw payload inspection ROOT CAUSE: - FastAPI consumes request body before error handler - Pydantic validation fails but does not show raw input - Agent script might be generating invalid JSON - No logging of actual problematic payload SOLUTION - ENHANCED ERROR HANDLING: 1. MIDDLEWARE ENHANCEMENT (error_handler.py): - Extract RAW body in validation error handler - Parse agent name from JSON (even if malformed) - Log first 500 chars of problematic payload - Add body size to error details - Special handling for /heartbeat endpoint - Detailed logging for json_invalid errors 2. HEARTBEAT ENDPOINT (agent.py): - Added Request parameter for raw body access - Enhanced docstring with troubleshooting info BENEFITS: - Instant visibility into malformed JSON - Agent name logged even on parse failure - Exact payload position + preview - No performance impact (only on errors) - Backward compatible (does not change API) NEXT STEPS (After Deploy): 1. Check logs for CRITICAL JSON PARSE ERROR 2. Identify exact field causing parse failure 3. Fix agent script if needed 4. Or fix backend to be more tolerant This enables root cause analysis without SSH access to agent servers
375 lines
14 KiB
Python
375 lines
14 KiB
Python
"""
|
|
Production-Ready Error Handling Middleware
|
|
Provides global exception handling, request/response logging, and error tracking
|
|
"""
|
|
|
|
import time
|
|
import logging
|
|
import traceback
|
|
from typing import Callable, Any
|
|
from fastapi import Request, Response, HTTPException
|
|
from fastapi.responses import JSONResponse
|
|
from starlette.middleware.base import BaseHTTPMiddleware
|
|
from starlette.types import ASGIApp
|
|
|
|
from utils.logging_config import (
|
|
get_correlation_id, correlation_id_context, get_error_tracker,
|
|
log_api_request, log_api_response, log_with_correlation
|
|
)
|
|
|
|
logger = logging.getLogger("haproxy_openmanager.error_handler")
|
|
|
|
class GlobalExceptionHandler:
|
|
"""Global exception handler for comprehensive error management"""
|
|
|
|
@staticmethod
|
|
def create_error_response(
|
|
status_code: int,
|
|
message: str,
|
|
error_type: str = None,
|
|
correlation_id: str = None,
|
|
details: Any = None
|
|
) -> JSONResponse:
|
|
"""Create standardized error response"""
|
|
|
|
error_response = {
|
|
"error": {
|
|
"message": message,
|
|
"type": error_type or "ApplicationError",
|
|
"timestamp": time.time(),
|
|
"correlation_id": correlation_id or get_correlation_id()
|
|
}
|
|
}
|
|
|
|
if details and isinstance(details, dict):
|
|
error_response["error"]["details"] = details
|
|
|
|
return JSONResponse(
|
|
status_code=status_code,
|
|
content=error_response
|
|
)
|
|
|
|
@staticmethod
|
|
async def handle_http_exception(request: Request, exc: HTTPException) -> JSONResponse:
|
|
"""Handle FastAPI HTTP exceptions"""
|
|
correlation_id = get_correlation_id()
|
|
|
|
# Log HTTP exception with more detail for debugging
|
|
log_level = "ERROR" if exc.status_code >= 500 else "WARNING"
|
|
log_with_correlation(
|
|
logger, log_level,
|
|
f"HTTP Exception: {exc.status_code} - {exc.detail}",
|
|
status_code=exc.status_code,
|
|
path=str(request.url.path),
|
|
method=request.method,
|
|
client_ip=request.client.host if request.client else "unknown",
|
|
correlation_id=correlation_id
|
|
)
|
|
|
|
# For 400 errors, also log at INFO level to ensure visibility
|
|
if exc.status_code == 400:
|
|
logger.info(f"🚫 CLIENT ERROR 400: {exc.detail} | Path: {request.url.path} | Method: {request.method} | IP: {request.client.host if request.client else 'unknown'}")
|
|
|
|
return GlobalExceptionHandler.create_error_response(
|
|
status_code=exc.status_code,
|
|
message=exc.detail,
|
|
error_type="HTTPException",
|
|
correlation_id=correlation_id
|
|
)
|
|
|
|
@staticmethod
|
|
async def handle_validation_error(request: Request, exc: Exception) -> JSONResponse:
|
|
"""Handle validation errors (Pydantic, FastAPI) with enhanced debugging for agent heartbeats"""
|
|
correlation_id = get_correlation_id()
|
|
|
|
# Extract validation details
|
|
if hasattr(exc, 'errors'):
|
|
validation_errors = exc.errors()
|
|
error_details = {
|
|
"validation_errors": [
|
|
{
|
|
"field": " -> ".join(str(loc) for loc in error.get("loc", [])),
|
|
"message": error.get("msg", ""),
|
|
"type": error.get("type", "")
|
|
}
|
|
for error in validation_errors
|
|
]
|
|
}
|
|
else:
|
|
error_details = {"raw_error": str(exc)}
|
|
|
|
# ENHANCED: For heartbeat endpoint, try to extract RAW body for debugging
|
|
raw_body_preview = None
|
|
agent_name = "unknown"
|
|
if "/heartbeat" in str(request.url.path):
|
|
try:
|
|
# Try to get raw body (might fail if already consumed)
|
|
raw_body = await request.body()
|
|
if raw_body:
|
|
raw_body_str = raw_body.decode('utf-8', errors='replace')
|
|
# Extract agent name from JSON if possible
|
|
import json
|
|
try:
|
|
body_json = json.loads(raw_body_str)
|
|
agent_name = body_json.get('name', 'unknown')
|
|
except:
|
|
# Try simple regex to extract name
|
|
import re
|
|
name_match = re.search(r'"name"\s*:\s*"([^"]+)"', raw_body_str)
|
|
if name_match:
|
|
agent_name = name_match.group(1)
|
|
|
|
# Log first 500 characters for debugging (don't log full body - too large)
|
|
raw_body_preview = raw_body_str[:500] if len(raw_body_str) > 500 else raw_body_str
|
|
error_details["raw_body_preview"] = raw_body_preview
|
|
error_details["body_size_bytes"] = len(raw_body)
|
|
except Exception as body_error:
|
|
logger.debug(f"Could not extract raw body for debugging: {body_error}")
|
|
|
|
# Enhanced log message for agent heartbeats
|
|
log_message = f"Validation error: {str(exc)}"
|
|
if agent_name != "unknown":
|
|
log_message = f"Agent '{agent_name}' heartbeat validation error: {str(exc)}"
|
|
|
|
# Log validation error with enhanced details
|
|
log_with_correlation(
|
|
logger, "WARNING",
|
|
log_message,
|
|
path=str(request.url.path),
|
|
method=request.method,
|
|
client_ip=request.client.host if request.client else "unknown",
|
|
validation_details=error_details,
|
|
agent_name=agent_name if agent_name != "unknown" else None
|
|
)
|
|
|
|
# CRITICAL: For JSON decode errors at specific position, log exact context
|
|
for error in error_details.get("validation_errors", []):
|
|
if error.get("type") == "json_invalid" and "body ->" in error.get("field", ""):
|
|
logger.error(
|
|
f"CRITICAL JSON PARSE ERROR for agent '{agent_name}': {error.get('message')} "
|
|
f"at position {error.get('field')} | "
|
|
f"Body preview (first 500 chars): {raw_body_preview[:500] if raw_body_preview else 'N/A'}"
|
|
)
|
|
|
|
return GlobalExceptionHandler.create_error_response(
|
|
status_code=422,
|
|
message="Validation error in request data",
|
|
error_type="ValidationError",
|
|
correlation_id=correlation_id,
|
|
details=error_details
|
|
)
|
|
|
|
@staticmethod
|
|
async def handle_database_error(request: Request, exc: Exception) -> JSONResponse:
|
|
"""Handle database-related errors"""
|
|
correlation_id = get_correlation_id()
|
|
error_tracker = get_error_tracker()
|
|
|
|
# Track database error
|
|
error_tracker.track_error(exc, {
|
|
"category": "database",
|
|
"path": str(request.url.path),
|
|
"method": request.method
|
|
})
|
|
|
|
# Log database error with full traceback
|
|
log_with_correlation(
|
|
logger, "ERROR",
|
|
f"Database error: {str(exc)}",
|
|
path=str(request.url.path),
|
|
method=request.method,
|
|
client_ip=request.client.host if request.client else "unknown",
|
|
error_traceback=traceback.format_exc()
|
|
)
|
|
|
|
return GlobalExceptionHandler.create_error_response(
|
|
status_code=500,
|
|
message="Database operation failed",
|
|
error_type="DatabaseError",
|
|
correlation_id=correlation_id,
|
|
details={"category": "database", "recoverable": True}
|
|
)
|
|
|
|
@staticmethod
|
|
async def handle_generic_exception(request: Request, exc: Exception) -> JSONResponse:
|
|
"""Handle all other unhandled exceptions"""
|
|
correlation_id = get_correlation_id()
|
|
error_tracker = get_error_tracker()
|
|
|
|
# Track generic error
|
|
error_tracker.track_error(exc, {
|
|
"category": "application",
|
|
"path": str(request.url.path),
|
|
"method": request.method
|
|
})
|
|
|
|
# Log generic error with full context
|
|
log_with_correlation(
|
|
logger, "ERROR",
|
|
f"Unhandled exception: {str(exc)}",
|
|
path=str(request.url.path),
|
|
method=request.method,
|
|
client_ip=request.client.host if request.client else "unknown",
|
|
error_type=type(exc).__name__,
|
|
error_traceback=traceback.format_exc()
|
|
)
|
|
|
|
return GlobalExceptionHandler.create_error_response(
|
|
status_code=500,
|
|
message="Internal server error",
|
|
error_type=type(exc).__name__,
|
|
correlation_id=correlation_id,
|
|
details={"category": "application", "recoverable": False}
|
|
)
|
|
|
|
class RequestLoggingMiddleware(BaseHTTPMiddleware):
|
|
"""Middleware for comprehensive request/response logging and error handling"""
|
|
|
|
def __init__(self, app: ASGIApp, exclude_paths: list = None):
|
|
super().__init__(app)
|
|
self.exclude_paths = exclude_paths or ["/api/health/", "/docs", "/redoc", "/openapi.json"]
|
|
|
|
async def dispatch(self, request: Request, call_next: Callable) -> Response:
|
|
# Skip logging for excluded paths
|
|
if any(request.url.path.startswith(path) for path in self.exclude_paths):
|
|
return await call_next(request)
|
|
|
|
# Generate correlation ID for this request
|
|
correlation_id = get_correlation_id()
|
|
correlation_id_context.set(correlation_id)
|
|
|
|
# Start timing
|
|
start_time = time.time()
|
|
|
|
# Extract client information
|
|
client_ip = request.client.host if request.client else "unknown"
|
|
user_agent = request.headers.get("user-agent", "unknown")
|
|
|
|
# Log incoming request
|
|
log_api_request(
|
|
logger,
|
|
method=request.method,
|
|
path=str(request.url.path),
|
|
client_ip=client_ip,
|
|
user_agent=user_agent,
|
|
query_params=dict(request.query_params) if request.query_params else None
|
|
)
|
|
|
|
try:
|
|
# Process request
|
|
response = await call_next(request)
|
|
|
|
# Calculate duration
|
|
duration_ms = round((time.time() - start_time) * 1000, 2)
|
|
|
|
# Log successful response
|
|
log_api_response(
|
|
logger,
|
|
method=request.method,
|
|
path=str(request.url.path),
|
|
status_code=response.status_code,
|
|
duration_ms=duration_ms,
|
|
client_ip=client_ip
|
|
)
|
|
|
|
# Add correlation ID to response headers
|
|
response.headers["X-Correlation-ID"] = correlation_id
|
|
|
|
return response
|
|
|
|
except HTTPException as exc:
|
|
# Handle HTTP exceptions
|
|
duration_ms = round((time.time() - start_time) * 1000, 2)
|
|
response = await GlobalExceptionHandler.handle_http_exception(request, exc)
|
|
response.headers["X-Correlation-ID"] = correlation_id
|
|
|
|
log_api_response(
|
|
logger,
|
|
method=request.method,
|
|
path=str(request.url.path),
|
|
status_code=exc.status_code,
|
|
duration_ms=duration_ms,
|
|
client_ip=client_ip
|
|
)
|
|
|
|
return response
|
|
|
|
except Exception as exc:
|
|
# Handle all other exceptions
|
|
duration_ms = round((time.time() - start_time) * 1000, 2)
|
|
|
|
# Categorize exception type
|
|
if "database" in str(exc).lower() or "connection" in str(exc).lower():
|
|
response = await GlobalExceptionHandler.handle_database_error(request, exc)
|
|
elif hasattr(exc, 'errors'): # Validation errors
|
|
response = await GlobalExceptionHandler.handle_validation_error(request, exc)
|
|
else:
|
|
response = await GlobalExceptionHandler.handle_generic_exception(request, exc)
|
|
|
|
response.headers["X-Correlation-ID"] = correlation_id
|
|
|
|
log_api_response(
|
|
logger,
|
|
method=request.method,
|
|
path=str(request.url.path),
|
|
status_code=response.status_code,
|
|
duration_ms=duration_ms,
|
|
client_ip=client_ip,
|
|
error=True
|
|
)
|
|
|
|
return response
|
|
|
|
class PerformanceMonitoringMiddleware(BaseHTTPMiddleware):
|
|
"""Middleware for performance monitoring and slow request detection"""
|
|
|
|
def __init__(self, app: ASGIApp, slow_request_threshold_ms: float = 1000):
|
|
super().__init__(app)
|
|
self.slow_request_threshold_ms = slow_request_threshold_ms
|
|
|
|
async def dispatch(self, request: Request, call_next: Callable) -> Response:
|
|
start_time = time.time()
|
|
|
|
response = await call_next(request)
|
|
|
|
duration_ms = round((time.time() - start_time) * 1000, 2)
|
|
|
|
# Log slow requests
|
|
if duration_ms > self.slow_request_threshold_ms:
|
|
log_with_correlation(
|
|
logger, "WARNING",
|
|
f"Slow request detected: {request.method} {request.url.path}",
|
|
method=request.method,
|
|
path=str(request.url.path),
|
|
duration_ms=duration_ms,
|
|
threshold_ms=self.slow_request_threshold_ms,
|
|
client_ip=request.client.host if request.client else "unknown"
|
|
)
|
|
|
|
# Add performance headers
|
|
response.headers["X-Response-Time"] = f"{duration_ms}ms"
|
|
|
|
return response
|
|
|
|
# Error statistics endpoint data
|
|
_error_stats = {"requests": 0, "errors": 0, "error_types": {}}
|
|
|
|
def get_error_statistics() -> dict:
|
|
"""Get current error statistics"""
|
|
global _error_stats
|
|
error_tracker = get_error_tracker()
|
|
|
|
return {
|
|
"total_requests": _error_stats["requests"],
|
|
"total_errors": _error_stats["errors"],
|
|
"error_rate": round(_error_stats["errors"] / max(_error_stats["requests"], 1) * 100, 2),
|
|
"error_types": error_tracker.get_error_summary(),
|
|
"timestamp": time.time()
|
|
}
|
|
|
|
def increment_request_stats(is_error: bool = False):
|
|
"""Increment request statistics"""
|
|
global _error_stats
|
|
_error_stats["requests"] += 1
|
|
if is_error:
|
|
_error_stats["errors"] += 1 |