feat: Introduce user context and unique error IDs for enhanced logging and error traceability.

.env

@@ -1,5 +1,5 @@
 ENV=development
-LOG_LEVEL=ERROR
+LOG_LEVEL=INFO
 PORT=3021
 HOST=0.0.0.0
 

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.")

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")

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)

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} "

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
         },
     )
+

src/logging.py

@@ -35,28 +35,44 @@ 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:
@@ -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)

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,
         )