diff --git a/.env b/.env index 3ba6479..6a77a29 100644 --- a/.env +++ b/.env @@ -1,5 +1,5 @@ ENV=development -LOG_LEVEL=ERROR +LOG_LEVEL=INFO PORT=3021 HOST=0.0.0.0 diff --git a/src/auth/service.py b/src/auth/service.py index 82516f6..9bb8347 100644 --- a/src/auth/service.py +++ b/src/auth/service.py @@ -44,6 +44,17 @@ class JWTBearer(HTTPBearer): ) request.state.user = message + + from src.context import set_user_id, set_username, set_role + if hasattr(message, "user_id"): + set_user_id(str(message.user_id)) + if hasattr(message, "username"): + set_username(message.username) + elif hasattr(message, "name"): + set_username(message.name) + if hasattr(message, "role"): + set_role(message.role) + return message else: raise HTTPException(status_code=403, detail="Invalid authorization code.") diff --git a/src/config.py b/src/config.py index d7c92b7..4015d58 100644 --- a/src/config.py +++ b/src/config.py @@ -45,7 +45,7 @@ def get_config(): config = get_config() -LOG_LEVEL = config("LOG_LEVEL", default=logging.WARNING) +LOG_LEVEL = config("LOG_LEVEL", default="INFO") ENV = config("ENV", default="local") PORT = config("PORT", cast=int, default=8000) HOST = config("HOST", default="localhost") diff --git a/src/context.py b/src/context.py index 4c968a2..779a3e4 100644 --- a/src/context.py +++ b/src/context.py @@ -2,8 +2,14 @@ from contextvars import ContextVar from typing import Optional, Final REQUEST_ID_CTX_KEY: Final[str] = "request_id" -_request_id_ctx_var: ContextVar[Optional[str]] = ContextVar( - REQUEST_ID_CTX_KEY, default=None) +USER_ID_CTX_KEY: Final[str] = "user_id" +USERNAME_CTX_KEY: Final[str] = "username" +ROLE_CTX_KEY: Final[str] = "role" + +_request_id_ctx_var: ContextVar[Optional[str]] = ContextVar(REQUEST_ID_CTX_KEY, default=None) +_user_id_ctx_var: ContextVar[Optional[str]] = ContextVar(USER_ID_CTX_KEY, default=None) +_username_ctx_var: ContextVar[Optional[str]] = ContextVar(USERNAME_CTX_KEY, default=None) +_role_ctx_var: ContextVar[Optional[str]] = ContextVar(ROLE_CTX_KEY, default=None) def get_request_id() -> Optional[str]: @@ -16,3 +22,21 @@ def set_request_id(request_id: str): def reset_request_id(token): _request_id_ctx_var.reset(token) + +def get_user_id() -> Optional[str]: + return _user_id_ctx_var.get() + +def set_user_id(user_id: str): + return _user_id_ctx_var.set(user_id) + +def get_username() -> Optional[str]: + return _username_ctx_var.get() + +def set_username(username: str): + return _username_ctx_var.set(username) + +def get_role() -> Optional[str]: + return _role_ctx_var.get() + +def set_role(role: str): + return _role_ctx_var.set(role) diff --git a/src/contribution_util.py b/src/contribution_util.py index 84644d7..b77a6f2 100644 --- a/src/contribution_util.py +++ b/src/contribution_util.py @@ -256,12 +256,12 @@ def calculate_contribution_accurate(availabilities: Dict[str, float], structure_ key=lambda x: x[1]['birnbaum_importance'], reverse=True) - print("\n=== COMPONENT IMPORTANCE ANALYSIS ===") - print(f"System Availability: {system_info['system_availability']:.6f} ({system_info['system_availability']*100:.4f}%)") - print(f"System Unavailability: {system_info['system_unavailability']:.6f}") - print("\nComponent Rankings (by Birnbaum Importance):") - print(f"{'Component':<20} {'Availability':<12} {'Birnbaum':<12} {'Criticality':<12} {'F-V':<12} {'Contribution%':<12}") - print("-" * 92) + # print("\n=== COMPONENT IMPORTANCE ANALYSIS ===") + # print(f"System Availability: {system_info['system_availability']:.6f} ({system_info['system_availability']*100:.4f}%)") + # print(f"System Unavailability: {system_info['system_unavailability']:.6f}") + # print("\nComponent Rankings (by Birnbaum Importance):") + # print(f"{'Component':<20} {'Availability':<12} {'Birnbaum':<12} {'Criticality':<12} {'F-V':<12} {'Contribution%':<12}") + # print("-" * 92) for component, measures in sorted_components: print(f"{component:<20} {measures['component_availability']:<12.6f} " diff --git a/src/exceptions.py b/src/exceptions.py index bd74c4a..593b089 100644 --- a/src/exceptions.py +++ b/src/exceptions.py @@ -105,15 +105,38 @@ def handle_exception(request: Request, exc: Exception): """ Global exception handler for Fastapi application. """ + import uuid + error_id = str(uuid.uuid1()) request_info = get_request_context(request) + + # Store error_id in request.state for middleware/logging + request.state.error_id = error_id if isinstance(exc, RateLimitExceeded): - return _rate_limit_exceeded_handler(request, exc) + log.warning( + f"Rate limit exceeded | Error ID: {error_id}", + extra={ + "error_id": error_id, + "error_category": "rate_limit", + "request": request_info, + "detail": str(exc.description) if hasattr(exc, "description") else str(exc), + }, + ) + return JSONResponse( + status_code=429, + content={ + "data": None, + "message": "Rate limit exceeded", + "status": ResponseStatus.ERROR, + "error_id": error_id + } + ) if isinstance(exc, RequestValidationError): - log.error( - "Validation error occurred", + log.warning( + f"Validation error occurred | Error ID: {error_id}", extra={ + "error_id": error_id, "error_category": "validation", "errors": exc.errors(), "request": request_info, @@ -122,17 +145,18 @@ def handle_exception(request: Request, exc: Exception): return JSONResponse( status_code=422, content={ - "data": None, + "data": exc.errors(), "message": "Validation Error", "status": ResponseStatus.ERROR, - "errors": exc.errors(), + "error_id": error_id }, ) if isinstance(exc, (HTTPException, StarletteHTTPException)): log.error( - "HTTP exception occurred", + f"HTTP exception occurred | Error ID: {error_id}", extra={ + "error_id": error_id, "error_category": "http", "status_code": exc.status_code, "detail": exc.detail if hasattr(exc, "detail") else str(exc), @@ -146,19 +170,16 @@ def handle_exception(request: Request, exc: Exception): "data": None, "message": str(exc.detail) if hasattr(exc, "detail") else str(exc), "status": ResponseStatus.ERROR, - "errors": [ - ErrorDetail( - message=str(exc.detail) if hasattr(exc, "detail") else str(exc) - ).model_dump() - ], + "error_id": error_id }, ) if isinstance(exc, SQLAlchemyError): error_message, status_code = handle_sqlalchemy_error(exc) log.error( - "Database error occurred", + f"Database error occurred | Error ID: {error_id}", extra={ + "error_id": error_id, "error_category": "database", "error_message": error_message, "request": request_info, @@ -172,14 +193,15 @@ def handle_exception(request: Request, exc: Exception): "data": None, "message": error_message, "status": ResponseStatus.ERROR, - "errors": [ErrorDetail(message=error_message).model_dump()], + "error_id": error_id }, ) # Log unexpected errors log.error( - "Unexpected error occurred", + f"Unexpected error occurred | Error ID: {error_id}", extra={ + "error_id": error_id, "error_category": "unexpected", "error_message": str(exc), "request": request_info, @@ -191,10 +213,9 @@ def handle_exception(request: Request, exc: Exception): status_code=500, content={ "data": None, - "message": str(exc), + "message": "An unexpected error occurred", "status": ResponseStatus.ERROR, - "errors": [ - ErrorDetail(message="An unexpected error occurred.").model_dump() - ], + "error_id": error_id }, ) + diff --git a/src/logging.py b/src/logging.py index 32d9316..7266016 100644 --- a/src/logging.py +++ b/src/logging.py @@ -35,29 +35,45 @@ class JSONFormatter(logging.Formatter): Custom formatter to output logs in JSON format. """ def format(self, record): - from src.context import get_request_id - + from src.context import get_request_id, get_user_id, get_username, get_role request_id = None + user_id = None + username = None + role = None + try: request_id = get_request_id() + user_id = get_user_id() + username = get_username() + role = get_role() except Exception: pass + # Standard fields from requirements log_record = { - "timestamp": datetime.datetime.fromtimestamp(record.created).astimezone().isoformat(), + "timestamp": datetime.datetime.fromtimestamp(record.created).strftime("%Y-%m-%d %H:%M:%S"), "level": record.levelname, + "name": record.name, "message": record.getMessage(), - "logger_name": record.name, - "location": f"{record.module}:{record.funcName}:{record.lineno}", - "module": record.module, - "funcName": record.funcName, - "lineno": record.lineno, - "pid": os.getpid(), - "request_id": request_id, } - + # 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: + log_record["request_id"] = request_id + + # Add Error context if available + if hasattr(record, "error_id"): + log_record["error_id"] = record.error_id + elif "error_id" in record.__dict__: + log_record["error_id"] = record.error_id + # Capture exception info if available if record.exc_info: log_record["exception"] = self.formatException(record.exc_info) @@ -67,15 +83,14 @@ class JSONFormatter(logging.Formatter): log_record["stack_trace"] = self.formatStack(record.stack_info) # Add any extra attributes passed to the log call - # We skip standard attributes to avoid duplication standard_attrs = { "args", "asctime", "created", "exc_info", "exc_text", "filename", "funcName", "levelname", "levelno", "lineno", "module", "msecs", "message", "msg", "name", "pathname", "process", "processName", - "relativeCreated", "stack_info", "thread", "threadName" + "relativeCreated", "stack_info", "thread", "threadName", "error_id" } for key, value in record.__dict__.items(): - if key not in standard_attrs: + if key not in standard_attrs and not key.startswith("_"): log_record[key] = value log_json = json.dumps(log_record) diff --git a/src/main.py b/src/main.py index e1225a7..d6110cf 100644 --- a/src/main.py +++ b/src/main.py @@ -51,7 +51,7 @@ app.add_exception_handler(Exception, handle_exception) app.add_exception_handler(HTTPException, handle_exception) app.add_exception_handler(StarletteHTTPException, handle_exception) app.add_exception_handler(RequestValidationError, handle_exception) -app.add_exception_handler(RateLimitExceeded, _rate_limit_exceeded_handler) +app.add_exception_handler(RateLimitExceeded, handle_exception) app.state.limiter = limiter app.add_middleware(GZipMiddleware, minimum_size=1000) @@ -147,22 +147,67 @@ async def db_session_middleware(request: Request, call_next): response = await call_next(request) process_time = (time.time() - start_time) * 1000 + 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 + username = get_username() + role = get_role() + user_id = get_user_id() + + user_obj = getattr(request.state, "user", None) + if user_obj: + # message is UserBase dict/obj in this project + if isinstance(user_obj, dict): + u_id = user_obj.get("user_id") + u_name = user_obj.get("name") or user_obj.get("username") + u_role = user_obj.get("role") + else: + u_id = getattr(user_obj, "user_id", None) + u_name = getattr(user_obj, "name", None) or getattr(user_obj, "username", None) + u_role = getattr(user_obj, "role", None) + + if not user_id and u_id: + user_id = str(u_id) + set_user_id(user_id) + if not username and u_name: + username = u_name + set_username(username) + if not role and u_role: + role = u_role + set_role(role) + + user_info_str = "" + if username: + user_info_str = f" | User: {username}" + if role: + user_info_str += f" ({role})" + log.info( - "Request finished", + f"HTTP {request.method} {request.url.path} completed in {round(process_time, 2)}ms{user_info_str}", extra={ "method": request.method, "path": request.url.path, "status_code": response.status_code, "duration_ms": round(process_time, 2), + "user_id": user_id, + "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( - "Request failed", + f"Request failed | Error ID: {error_id}", extra={ "method": request.method, "path": request.url.path, "error": str(e), + "error_id": error_id, }, exc_info=True, )