fix exception logging

main
Cizz22 6 days ago
parent d9a6687ba7
commit 22ff523ccd

@ -122,12 +122,12 @@ def handle_exception(request: Request, exc: Exception):
) )
log.warning( log.warning(
f"Rate limit exceeded | Error ID: {error_id}", f"Rate limit exceeded: {str(exc.description) if hasattr(exc, 'description') else str(exc)} | Error ID: {error_id}",
extra={ extra={
"error_id": error_id, "error_id": error_id,
"error_category": "rate_limit", "error_category": "rate_limit",
"request": request_info,
"detail": str(exc.description) if hasattr(exc, "description") else str(exc), "detail": str(exc.description) if hasattr(exc, "description") else str(exc),
"request": request_info,
}, },
) )
return JSONResponse( return JSONResponse(
@ -142,7 +142,7 @@ def handle_exception(request: Request, exc: Exception):
if isinstance(exc, RequestValidationError): if isinstance(exc, RequestValidationError):
log.warning( log.warning(
f"Validation error occurred | Error ID: {error_id}", f"Validation error: {exc.errors()} | Error ID: {error_id}",
extra={ extra={
"error_id": error_id, "error_id": error_id,
"error_category": "validation", "error_category": "validation",
@ -165,28 +165,17 @@ def handle_exception(request: Request, exc: Exception):
status_code = exc.status_code if hasattr(exc, "status_code") else 500 status_code = exc.status_code if hasattr(exc, "status_code") else 500
detail = exc.detail if hasattr(exc, "detail") else str(exc) detail = exc.detail if hasattr(exc, "detail") else str(exc)
if 400 <= status_code < 500: log_level = logging.WARNING if 400 <= status_code < 500 else logging.ERROR
log.warning( log.log(
f"HTTP {status_code} occurred | Error ID: {error_id} | Detail: {detail}", log_level,
extra={ f"HTTP {status_code}: {detail} | Error ID: {error_id}",
"error_id": error_id, extra={
"error_category": "http", "error_id": error_id,
"status_code": status_code, "error_category": "http",
"detail": detail, "status_code": status_code,
"request": request_info, "request": request_info,
}, },
) )
else:
log.error(
f"HTTP {status_code} occurred | Error ID: {error_id} | Detail: {detail}",
extra={
"error_id": error_id,
"error_category": "http",
"status_code": status_code,
"detail": detail,
"request": request_info,
},
)
return JSONResponse( return JSONResponse(
status_code=status_code, status_code=status_code,
@ -201,28 +190,17 @@ def handle_exception(request: Request, exc: Exception):
if isinstance(exc, SQLAlchemyError): if isinstance(exc, SQLAlchemyError):
error_message, status_code = handle_sqlalchemy_error(exc) error_message, status_code = handle_sqlalchemy_error(exc)
# Log integrity errors as warning, others as error # Log integrity errors as warning, others as error
if 400 <= status_code < 500: log_level = logging.WARNING if 400 <= status_code < 500 else logging.ERROR
log.warning( log.log(
f"Database integrity/validation error occurred | Error ID: {error_id}", log_level,
extra={ f"Database error: {error_message} | Error ID: {error_id}",
"error_id": error_id, extra={
"error_category": "database", "error_id": error_id,
"error_message": error_message, "error_category": "database",
"request": request_info, "violation": str(exc).split('\n')[0],
"exception": str(exc), "request": request_info,
}, },
) )
else:
log.error(
f"Database error occurred | Error ID: {error_id}",
extra={
"error_id": error_id,
"error_category": "database",
"error_message": error_message,
"request": request_info,
"exception": str(exc),
},
)
return JSONResponse( return JSONResponse(
status_code=status_code, status_code=status_code,
@ -236,14 +214,12 @@ def handle_exception(request: Request, exc: Exception):
# Log unexpected errors # Log unexpected errors
log.error( log.error(
f"Unexpected error occurred | Error ID: {error_id}", f"Unexpected error: {str(exc)} | Error ID: {error_id}",
extra={ extra={
"error_id": error_id, "error_id": error_id,
"error_category": "unexpected", "error_category": "unexpected",
"error_message": str(exc),
"request": request_info, "request": request_info,
}, },
exc_info=True,
) )
return JSONResponse( return JSONResponse(

@ -54,19 +54,14 @@ class JSONFormatter(logging.Formatter):
log_record = { log_record = {
"timestamp": datetime.datetime.fromtimestamp(record.created).strftime("%Y-%m-%d %H:%M:%S"), "timestamp": datetime.datetime.fromtimestamp(record.created).strftime("%Y-%m-%d %H:%M:%S"),
"level": record.levelname, "level": record.levelname,
"name": record.name,
"message": record.getMessage(), "message": record.getMessage(),
} }
# Add Context information if available # Add Context information if available
if user_id:
log_record["user_id"] = user_id
if username:
log_record["username"] = username
if role:
log_record["role"] = role
if request_id: if request_id:
log_record["request_id"] = request_id log_record["request_id"] = request_id
if role:
log_record["role"] = role
# Add Error context if available # Add Error context if available
if hasattr(record, "error_id"): if hasattr(record, "error_id"):
@ -74,13 +69,8 @@ class JSONFormatter(logging.Formatter):
elif "error_id" in record.__dict__: elif "error_id" in record.__dict__:
log_record["error_id"] = record.error_id log_record["error_id"] = record.error_id
# Capture exception info if available if user_id:
if record.exc_info: log_record["user_id"] = user_id
log_record["exception"] = self.formatException(record.exc_info)
# Capture stack info if available
if record.stack_info:
log_record["stack_trace"] = self.formatStack(record.stack_info)
# Add any extra attributes passed to the log call # Add any extra attributes passed to the log call
standard_attrs = { standard_attrs = {

@ -147,6 +147,10 @@ async def db_session_middleware(request: Request, call_next):
response = await call_next(request) response = await call_next(request)
process_time = (time.time() - start_time) * 1000 process_time = (time.time() - start_time) * 1000
# Skip logging in middleware if it's an error (already logged in handle_exception)
if response.status_code >= 400:
return response
from src.context import get_username, get_role, get_user_id, set_user_id, set_username, set_role from src.context import get_username, get_role, get_user_id, set_user_id, set_username, set_role
# Pull from context or fallback to request.state.user # Pull from context or fallback to request.state.user
@ -182,8 +186,13 @@ async def db_session_middleware(request: Request, call_next):
if role: if role:
user_info_str += f" ({role})" user_info_str += f" ({role})"
error_id = getattr(request.state, "error_id", None)
log_msg = f"HTTP {request.method} {request.url.path} completed in {round(process_time, 2)}ms{user_info_str}"
if error_id:
log_msg += f" | Error ID: {error_id}"
log.info( log.info(
f"HTTP {request.method} {request.url.path} completed in {round(process_time, 2)}ms{user_info_str}", log_msg,
extra={ extra={
"method": request.method, "method": request.method,
"path": request.url.path, "path": request.url.path,
@ -191,27 +200,9 @@ async def db_session_middleware(request: Request, call_next):
"duration_ms": round(process_time, 2), "duration_ms": round(process_time, 2),
"user_id": user_id, "user_id": user_id,
"role": role, "role": role,
},
)
except Exception as e:
# Generate an error_id here if it hasn't been generated yet
error_id = getattr(request.state, "error_id", None)
if not error_id:
import uuid
error_id = str(uuid.uuid1())
request.state.error_id = error_id
log.error(
f"Request failed | Error ID: {error_id}",
extra={
"method": request.method,
"path": request.url.path,
"error": str(e),
"error_id": error_id, "error_id": error_id,
}, },
exc_info=True,
) )
raise e from None
finally: finally:
await request.state.db.close() await request.state.db.close()
await request.state.collector_db.close() await request.state.collector_db.close()

@ -193,35 +193,30 @@ def inspect_value(value: str, source: str):
if XSS_PATTERN.search(value): if XSS_PATTERN.search(value):
log.warning(f"Security violation: Potential XSS payload detected in {source}")
raise HTTPException( raise HTTPException(
status_code=422, status_code=422,
detail=f"Potential XSS payload detected in {source}", detail=f"Potential XSS payload detected in {source}",
) )
if SQLI_PATTERN.search(value): if SQLI_PATTERN.search(value):
log.warning(f"Security violation: Potential SQL injection payload detected in {source}")
raise HTTPException( raise HTTPException(
status_code=422, status_code=422,
detail=f"Potential SQL injection payload detected in {source}", detail=f"Potential SQL injection payload detected in {source}",
) )
if RCE_PATTERN.search(value): if RCE_PATTERN.search(value):
log.warning(f"Security violation: Potential RCE payload detected in {source}")
raise HTTPException( raise HTTPException(
status_code=422, status_code=422,
detail=f"Potential RCE payload detected in {source}", detail=f"Potential RCE payload detected in {source}",
) )
if TRAVERSAL_PATTERN.search(value): if TRAVERSAL_PATTERN.search(value):
log.warning(f"Security violation: Potential Path Traversal payload detected in {source}")
raise HTTPException( raise HTTPException(
status_code=422, status_code=422,
detail=f"Potential Path Traversal payload detected in {source}", detail=f"Potential Path Traversal payload detected in {source}",
) )
if has_control_chars(value): if has_control_chars(value):
log.warning(f"Security violation: Invalid control characters detected in {source}")
raise HTTPException( raise HTTPException(
status_code=422, status_code=422,
detail=f"Invalid control characters detected in {source}", detail=f"Invalid control characters detected in {source}",
@ -232,14 +227,12 @@ def inspect_json(obj, path="body", check_whitelist=True):
if isinstance(obj, dict): if isinstance(obj, dict):
for key, value in obj.items(): for key, value in obj.items():
if key in FORBIDDEN_JSON_KEYS: if key in FORBIDDEN_JSON_KEYS:
log.warning(f"Security violation: Forbidden JSON key detected: {path}.{key}")
raise HTTPException( raise HTTPException(
status_code=422, status_code=422,
detail=f"Forbidden JSON key detected: {path}.{key}", detail=f"Forbidden JSON key detected: {path}.{key}",
) )
if check_whitelist and key not in ALLOWED_DATA_PARAMS: if check_whitelist and key not in ALLOWED_DATA_PARAMS:
log.warning(f"Security violation: Unknown JSON key detected: {path}.{key}")
raise HTTPException( raise HTTPException(
status_code=422, status_code=422,
detail=f"Unknown JSON key detected: {path}.{key}", detail=f"Unknown JSON key detected: {path}.{key}",
@ -273,7 +266,6 @@ class RequestValidationMiddleware(BaseHTTPMiddleware):
ALLOW_DUPLICATE_HEADERS = {'accept', 'accept-encoding', 'accept-language', 'accept-charset', 'cookie'} ALLOW_DUPLICATE_HEADERS = {'accept', 'accept-encoding', 'accept-language', 'accept-charset', 'cookie'}
real_duplicates = [h for h in duplicate_headers if h not in ALLOW_DUPLICATE_HEADERS] real_duplicates = [h for h in duplicate_headers if h not in ALLOW_DUPLICATE_HEADERS]
if real_duplicates: if real_duplicates:
log.warning(f"Security violation: Duplicate headers detected: {real_duplicates}")
raise HTTPException( raise HTTPException(
status_code=422, status_code=422,
detail=f"Duplicate headers are not allowed: {real_duplicates}", detail=f"Duplicate headers are not allowed: {real_duplicates}",
@ -284,7 +276,6 @@ class RequestValidationMiddleware(BaseHTTPMiddleware):
if unknown_headers: if unknown_headers:
filtered_unknown = [h for h in unknown_headers if not h.startswith('sec-')] filtered_unknown = [h for h in unknown_headers if not h.startswith('sec-')]
if filtered_unknown: if filtered_unknown:
log.warning(f"Security violation: Unknown headers detected: {filtered_unknown}")
raise HTTPException( raise HTTPException(
status_code=422, status_code=422,
detail=f"Unknown headers detected: {filtered_unknown}", detail=f"Unknown headers detected: {filtered_unknown}",
@ -299,7 +290,6 @@ class RequestValidationMiddleware(BaseHTTPMiddleware):
# 1. Query string limits # 1. Query string limits
# ------------------------- # -------------------------
if len(request.url.query) > MAX_QUERY_LENGTH: if len(request.url.query) > MAX_QUERY_LENGTH:
log.warning(f"Security violation: Query string too long")
raise HTTPException( raise HTTPException(
status_code=422, status_code=422,
detail="Query string too long", detail="Query string too long",
@ -308,7 +298,6 @@ class RequestValidationMiddleware(BaseHTTPMiddleware):
params = request.query_params.multi_items() params = request.query_params.multi_items()
if len(params) > MAX_QUERY_PARAMS: if len(params) > MAX_QUERY_PARAMS:
log.warning(f"Security violation: Too many query parameters")
raise HTTPException( raise HTTPException(
status_code=422, status_code=422,
detail="Too many query parameters", detail="Too many query parameters",
@ -317,7 +306,6 @@ class RequestValidationMiddleware(BaseHTTPMiddleware):
# Check for unknown query parameters # Check for unknown query parameters
unknown_params = [key for key, _ in params if key not in ALLOWED_DATA_PARAMS] unknown_params = [key for key, _ in params if key not in ALLOWED_DATA_PARAMS]
if unknown_params: if unknown_params:
log.warning(f"Security violation: Unknown query parameters detected: {unknown_params}")
raise HTTPException( raise HTTPException(
status_code=422, status_code=422,
detail=f"Unknown query parameters detected: {unknown_params}", detail=f"Unknown query parameters detected: {unknown_params}",
@ -333,7 +321,6 @@ class RequestValidationMiddleware(BaseHTTPMiddleware):
] ]
if duplicates: if duplicates:
log.warning(f"Security violation: Duplicate query parameters detected: {duplicates}")
raise HTTPException( raise HTTPException(
status_code=422, status_code=422,
detail=f"Duplicate query parameters are not allowed: {duplicates}", detail=f"Duplicate query parameters are not allowed: {duplicates}",
@ -351,19 +338,16 @@ class RequestValidationMiddleware(BaseHTTPMiddleware):
try: try:
size_val = int(value) size_val = int(value)
if size_val > 50: if size_val > 50:
log.warning(f"Security violation: Pagination size too large ({size_val})")
raise HTTPException( raise HTTPException(
status_code=422, status_code=422,
detail=f"Pagination size '{key}' cannot exceed 50", detail=f"Pagination size '{key}' cannot exceed 50",
) )
if size_val % 5 != 0: if size_val % 5 != 0:
log.warning(f"Security violation: Pagination size not multiple of 5 ({size_val})")
raise HTTPException( raise HTTPException(
status_code=422, status_code=422,
detail=f"Pagination size '{key}' must be a multiple of 5", detail=f"Pagination size '{key}' must be a multiple of 5",
) )
except ValueError: except ValueError:
log.warning(f"Security violation: Pagination size invalid value ({value})")
raise HTTPException( raise HTTPException(
status_code=422, status_code=422,
detail=f"Pagination size '{key}' must be an integer", detail=f"Pagination size '{key}' must be an integer",
@ -377,7 +361,6 @@ class RequestValidationMiddleware(BaseHTTPMiddleware):
content_type.startswith(t) content_type.startswith(t)
for t in ("application/json", "multipart/form-data", "application/x-www-form-urlencoded") for t in ("application/json", "multipart/form-data", "application/x-www-form-urlencoded")
): ):
log.warning(f"Security violation: Unsupported Content-Type: {content_type}")
raise HTTPException(status_code=422, detail="Unsupported Content-Type") raise HTTPException(status_code=422, detail="Unsupported Content-Type")
# ------------------------- # -------------------------
@ -394,7 +377,6 @@ class RequestValidationMiddleware(BaseHTTPMiddleware):
has_body = True has_body = True
if has_query and has_body: if has_query and has_body:
log.warning(f"Security violation: Mixed parameters (query + JSON body)")
raise HTTPException( raise HTTPException(
status_code=422, status_code=422,
detail="Parameters must be from a single source (query string or JSON body), mixed sources are not allowed", detail="Parameters must be from a single source (query string or JSON body), mixed sources are not allowed",

Loading…
Cancel
Save