FalkorDB · gkorland · Aug 22, 2025 · Aug 22, 2025 · Aug 22, 2025 · Aug 23, 2025
diff --git a/Pipfile b/Pipfile
@@ -16,6 +16,7 @@ jsonschema = "~=4.25.0"
 tqdm = "~=4.67.1"
 python-multipart = "~=0.0.10"
 jinja2 = "~=3.1.4"
+structlog = "~=25.4.0"
 
 [dev-packages]
 pytest = "~=8.4.1"

diff --git a/Pipfile.lock b/Pipfile.lock
diff --git a/api/app_factory.py b/api/app_factory.py
@@ -1,6 +1,5 @@
 """Application factory for the text2sql FastAPI app."""
 
-import logging
 import os
 import secrets
 
@@ -11,13 +10,14 @@
 from starlette.middleware.sessions import SessionMiddleware
 from starlette.middleware.base import BaseHTTPMiddleware
 
+from api.logging_config import get_logger
-from api.logging_config import get_logger
+# api/app_factory.py
+
+# … other imports …
+
+# Replace direct import (line 13) with guarded import + fallback
+try:
+    from api.logging_config import get_logger
+except Exception:
+    import logging as _logging
+    def get_logger(name: str):
+        return _logging.getLogger(name)
+
+# … rest of factory implementation …
-from api.logging_config import get_logger
+# api/app_factory.py
+
+# … other imports …
+
+# Replace direct import (line 13) with guarded import + fallback
+try:
+    from api.logging_config import get_logger
+except Exception:
+    import logging as _logging
+    def get_logger(name: str):
+        return _logging.getLogger(name)
+
+# … rest of factory implementation …
 from api.routes.auth import auth_router, init_auth
 from api.routes.graphs import graphs_router
 from api.routes.database import database_router
 
 # Load environment variables from .env file
 load_dotenv()
-logging.basicConfig(level=logging.INFO, format="%(asctime)s - %(levelname)s - %(message)s")
+logger = get_logger(__name__)
 
 
 class SecurityMiddleware(BaseHTTPMiddleware):
@@ -55,7 +55,7 @@ def create_app():
     secret_key = os.getenv("FASTAPI_SECRET_KEY")
     if not secret_key:
         secret_key = secrets.token_hex(32)
-        logging.warning("FASTAPI_SECRET_KEY not set, using generated key. Set this in production!")
+        logger.warning("FASTAPI_SECRET_KEY not set, using generated key. Set this in production!")
 
     # Add session middleware with explicit settings to ensure OAuth state persists
     app.add_middleware(
@@ -87,8 +87,10 @@ def create_app():
     async def handle_oauth_error(request: Request, exc: Exception):
         """Handle OAuth-related errors gracefully"""
         # Check if it's an OAuth-related error
-        if "token" in str(exc).lower() or "oauth" in str(exc).lower():
-            logging.warning("OAuth error occurred: %s", exc)
+        exc_text = str(exc)
+        exc_text_lower = exc_text.lower()
+        if "token" in exc_text_lower or "oauth" in exc_text_lower:
+            logger.warning("OAuth error occurred", error=exc_text)
             request.session.clear()
             return RedirectResponse(url="/", status_code=302)
 

diff --git a/api/auth/oauth_handlers.py b/api/auth/oauth_handlers.py
@@ -4,14 +4,16 @@
 callbacks can invoke them when processing OAuth responses.
 """
 
-import logging
 from typing import Dict, Any
 
 from fastapi import FastAPI, Request
 from authlib.integrations.starlette_client import OAuth
 
+from api.logging_config import get_logger
 from .user_management import ensure_user_in_organizations
 
+logger = get_logger(__name__)
-from api.logging_config import get_logger
-from .user_management import ensure_user_in_organizations
-
-logger = get_logger(__name__)
+# File: api/logging_config.py
+from __future__ import annotations
+
+import logging
+import os
+import sys
+
+import structlog
+
+_CONFIGURED = False
+
+def _configure_logging() -> None:
+    log_level = os.getenv("LOG_LEVEL", "INFO").upper()
+    json_logs = os.getenv("JSON_LOGS", "0").lower() in {"1", "true", "yes"}
+
+    handler = logging.StreamHandler(sys.stdout)
+    from structlog.stdlib import ProcessorFormatter
+    formatter = ProcessorFormatter(
+        processor=(
+            structlog.processors.JSONRenderer()
+            if json_logs
+            else structlog.dev.ConsoleRenderer(colors=True)
+        ),
+        foreign_pre_chain=[
+            structlog.stdlib.add_log_level,
+            structlog.processors.TimeStamper(fmt="iso"),
+        ],
+    )
+    handler.setFormatter(formatter)
+
+    root = logging.getLogger()
+    root.handlers = [handler]
+    root.setLevel(log_level)
+
+    structlog.configure(
+        processors=[
+            structlog.contextvars.merge_contextvars,
+            structlog.stdlib.add_logger_name,
+            structlog.stdlib.add_log_level,
+            structlog.stdlib.PositionalArgumentsFormatter(),
+            structlog.processors.StackInfoRenderer(),
+            structlog.processors.format_exc_info,
+            structlog.stdlib.ProcessorFormatter.wrap_for_formatter,
+        ],
+        logger_factory=structlog.stdlib.LoggerFactory(),
+        cache_logger_on_first_use=True,
+    )
+
+def get_logger(name: str | None = None):
+    global _CONFIGURED
+    if not _CONFIGURED:
+        _configure_logging()
+        _CONFIGURED = True
+    return structlog.get_logger(name)
-from api.logging_config import get_logger
-from .user_management import ensure_user_in_organizations
-
-logger = get_logger(__name__)
+# File: api/logging_config.py
+from __future__ import annotations
+
+import logging
+import os
+import sys
+
+import structlog
+
+_CONFIGURED = False
+
+def _configure_logging() -> None:
+    log_level = os.getenv("LOG_LEVEL", "INFO").upper()
+    json_logs = os.getenv("JSON_LOGS", "0").lower() in {"1", "true", "yes"}
+
+    handler = logging.StreamHandler(sys.stdout)
+    from structlog.stdlib import ProcessorFormatter
+    formatter = ProcessorFormatter(
+        processor=(
+            structlog.processors.JSONRenderer()
+            if json_logs
+            else structlog.dev.ConsoleRenderer(colors=True)
+        ),
+        foreign_pre_chain=[
+            structlog.stdlib.add_log_level,
+            structlog.processors.TimeStamper(fmt="iso"),
+        ],
+    )
+    handler.setFormatter(formatter)
+
+    root = logging.getLogger()
+    root.handlers = [handler]
+    root.setLevel(log_level)
+
+    structlog.configure(
+        processors=[
+            structlog.contextvars.merge_contextvars,
+            structlog.stdlib.add_logger_name,
+            structlog.stdlib.add_log_level,
+            structlog.stdlib.PositionalArgumentsFormatter(),
+            structlog.processors.StackInfoRenderer(),
+            structlog.processors.format_exc_info,
+            structlog.stdlib.ProcessorFormatter.wrap_for_formatter,
+        ],
+        logger_factory=structlog.stdlib.LoggerFactory(),
+        cache_logger_on_first_use=True,
+    )
+
+def get_logger(name: str | None = None):
+    global _CONFIGURED
+    if not _CONFIGURED:
+        _configure_logging()
+        _CONFIGURED = True
+    return structlog.get_logger(name)
+
 
 def setup_oauth_handlers(app: FastAPI, oauth: OAuth):
     """Set up OAuth handlers for both Google and GitHub."""
@@ -30,7 +32,7 @@ async def handle_google_callback(_request: Request,
 
             # Validate required fields
             if not user_id or not email:
-                logging.error("Missing required fields from Google OAuth response")
+                logger.error("Missing required fields from Google OAuth response")
                 return False
 
             # Check if identity exists in Organizations graph, create if new
@@ -44,7 +46,7 @@ async def handle_google_callback(_request: Request,
 
             return True
         except Exception as exc:  # capture exception for logging
-            logging.error("Error handling Google OAuth callback: %s", exc)
+            logger.error("Error handling Google OAuth callback", error=str(exc))
             return False
-            logger.error("Error handling Google OAuth callback", error=str(exc))
-            return False
+        except Exception:
+            logger.exception("Error handling Google OAuth callback")
+            return False
-            logger.error("Error handling Google OAuth callback", error=str(exc))
-            return False
+        except Exception:
+            logger.exception("Error handling Google OAuth callback")
+            return False
 
     async def handle_github_callback(_request: Request,
@@ -58,7 +60,7 @@ async def handle_github_callback(_request: Request,
 
             # Validate required fields
             if not user_id or not email:
-                logging.error("Missing required fields from GitHub OAuth response")
+                logger.error("Missing required fields from GitHub OAuth response")
                 return False
 
             # Check if identity exists in Organizations graph, create if new
@@ -72,7 +74,7 @@ async def handle_github_callback(_request: Request,
 
             return True
         except Exception as exc:  # capture exception for logging
-            logging.error("Error handling GitHub OAuth callback: %s", exc)
+            logger.error("Error handling GitHub OAuth callback", error=str(exc))
             return False
-            logger.error("Error handling GitHub OAuth callback", error=str(exc))
-            return False
+        except Exception:
+            logger.exception("Error handling GitHub OAuth callback")
+            return False
-            logger.error("Error handling GitHub OAuth callback", error=str(exc))
-            return False
+        except Exception:
+            logger.exception("Error handling GitHub OAuth callback")
+            return False
 
     # Store handlers in app state for use in route callbacks

diff --git a/api/auth/user_management.py b/api/auth/user_management.py
@@ -1,16 +1,16 @@
 """User management and authentication functions for text2sql API."""
 
-import logging
 import time
 from functools import wraps
 from typing import Tuple, Optional, Dict, Any
 
-import requests
 from fastapi import Request, HTTPException, status
-from fastapi.responses import JSONResponse
 from authlib.integrations.starlette_client import OAuth
 
 from api.extensions import db
+from api.logging_config import get_logger
+
+logger = get_logger(__name__)
 
-from api.logging_config import get_logger
-
-logger = get_logger(__name__)
+try:
+    from api.logging_config import get_logger
+except Exception:  # ImportError in CI; keep app usable
+    import logging as _logging
+    def get_logger(name: str):
+        return _logging.getLogger(name)
+
+logger = get_logger(__name__)
-from api.logging_config import get_logger
-
-logger = get_logger(__name__)
+try:
+    from api.logging_config import get_logger
+except Exception:  # ImportError in CI; keep app usable
+    import logging as _logging
+    def get_logger(name: str):
+        return _logging.getLogger(name)
+
+logger = get_logger(__name__)
 
 def ensure_user_in_organizations(provider_user_id, email, name, provider, picture=None):
@@ -22,19 +22,24 @@ def ensure_user_in_organizations(provider_user_id, email, name, provider, pictur
     """
     # Input validation
     if not provider_user_id or not email or not provider:
-        logging.error("Missing required parameters: provider_user_id=%s, email=%s, provider=%s",
-                     provider_user_id, email, provider)
+        logger.error(
+            "Missing required parameters",
+            provider_user_id=provider_user_id,
+            email=email,
+            provider=provider,
+        )
+        return False, None
         return False, None
-        logger.error(
-            "Missing required parameters",
-            provider_user_id=provider_user_id,
-            email=email,
-            provider=provider,
-        )
-        return False, None
-        return False, None
+        logger.error(
+            "Missing required parameters",
+            provider_user_id=provider_user_id,
+            email=email,
+            provider=provider,
+        )
+        return False, None
-        logger.error(
-            "Missing required parameters",
-            provider_user_id=provider_user_id,
-            email=email,
-            provider=provider,
-        )
-        return False, None
-        return False, None
+        logger.error(
+            "Missing required parameters",
+            provider_user_id=provider_user_id,
+            email=email,
+            provider=provider,
+        )
+        return False, None
 
     # Validate email format (basic check)
     if "@" not in email or "." not in email:
-        logging.error("Invalid email format: %s", email)
+        logger.error("Invalid email format", email=email)
         return False, None
 
     # Validate provider is in allowed list
     allowed_providers = ["google", "github"]
     if provider not in allowed_providers:
-        logging.error("Invalid provider: %s", provider)
+        logger.error("Invalid provider", provider=provider)
         return False, None
 
     try:
@@ -99,43 +104,55 @@ def ensure_user_in_organizations(provider_user_id, email, name, provider, pictur
             # Determine the type of operation for logging
             if is_new_identity and not had_other_identities:
                 # Brand new user (first identity)
-                logging.info("NEW USER CREATED: provider=%s, provider_user_id=%s, "
-                           "email=%s, name=%s", provider, provider_user_id, email, name)
+                logger.info(
+                    "NEW USER CREATED",
+                    provider=provider,
+                    provider_user_id=provider_user_id,
+                    email=email,
+                    name=name,
+                )
                 return True, {"identity": identity, "user": user}
             elif is_new_identity and had_other_identities:
                 # New identity for existing user (cross-provider linking)
-                logging.info("NEW IDENTITY LINKED TO EXISTING USER: provider=%s, "
-                           "provider_user_id=%s, email=%s, name=%s",
-                           provider, provider_user_id, email, name)
+                logger.info(
+                    "NEW IDENTITY LINKED TO EXISTING_USER",
+                    provider=provider,
+                    provider_user_id=provider_user_id,
+                    email=email,
+                    name=name,
+                )
                 return True, {"identity": identity, "user": user}
             else:
                 # Existing identity login
-                logging.info("Existing identity found: provider=%s, email=%s", provider, email)
+                logger.info("Existing identity found", provider=provider, email=email)
                 return False, {"identity": identity, "user": user}
         else:
-            logging.error("Failed to create/update identity and user: email=%s", email)
+            logger.error("Failed to create/update identity and user", email=email)
             return False, None
 
     except (AttributeError, ValueError, KeyError) as e:
-        logging.error("Error managing user in Organizations graph: %s", e)
+        logger.error("Error managing user in Organizations graph", error=str(e))
         return False, None
     except Exception as e:
-        logging.error("Unexpected error managing user in Organizations graph: %s", e)
+        logger.error("Unexpected error managing user in Organizations graph", error=str(e))
         return False, None
 
 
 def update_identity_last_login(provider, provider_user_id):
     """Update the last login timestamp for an existing identity"""
     # Input validation
     if not provider or not provider_user_id:
-        logging.error("Missing required parameters: provider=%s, provider_user_id=%s",
-                     provider, provider_user_id)
+        logger.error(
+            "Missing required parameters",
+            provider=provider,
+            provider_user_id=provider_user_id,
+        )
         return
 
     # Validate provider is in allowed list
     allowed_providers = ["google", "github"]
     if provider not in allowed_providers:
-        logging.error("Invalid provider: %s", provider)
+        logger.error("Invalid provider", provider=provider)
         return
 
     try:
@@ -145,18 +162,32 @@ def update_identity_last_login(provider, provider_user_id):
         SET identity.last_login = timestamp()
         RETURN identity
         """
-        organizations_graph.query(update_query, {
-            "provider": provider,
-            "provider_user_id": provider_user_id
-        })
-        logging.info("Updated last login for identity: provider=%s, provider_user_id=%s",
-                    provider, provider_user_id)
+        organizations_graph.query(
+            update_query,
+            {
+                "provider": provider,
+                "provider_user_id": provider_user_id,
+            },
+        )
+        logger.info(
+            "Updated last login for identity",
+            provider=provider,
+            provider_user_id=provider_user_id,
+        )
     except (AttributeError, ValueError, KeyError) as e:
-        logging.error("Error updating last login for identity %s/%s: %s",
-                     provider, provider_user_id, e)
+        logger.error(
+            "Error updating last login for identity",
+            provider=provider,
+            provider_user_id=provider_user_id,
+            error=str(e),
+        )
     except Exception as e:
-        logging.error("Unexpected error updating last login for identity %s/%s: %s",
-                     provider, provider_user_id, e)
+        logger.error(
+            "Unexpected error updating last login for identity",
+            provider=provider,
+            provider_user_id=provider_user_id,
+            error=str(e),
+        )
 
 
 async def validate_and_cache_user(request: Request) -> Tuple[Optional[Dict[str, Any]], bool]:
@@ -192,17 +223,17 @@ async def validate_and_cache_user(request: Request) -> Tuple[Optional[Dict[str,
                         )
                         request.session["google_token"] = new_token
                         resp = await oauth.google.get("/oauth2/v2/userinfo", token=new_token)
-                        logging.info("Google access token refreshed successfully")
+                        logger.info("Google access token refreshed successfully")
                     except Exception as e:
-                        logging.error("Google token refresh failed: %s", e)
+                        logger.error("Google token refresh failed", error=str(e))
                         request.session.pop("google_token", None)
                         request.session.pop("user_info", None)
                         return None, False
 
                 if resp.status_code == 200:
                     google_user = resp.json()
                     if not google_user.get("id") or not google_user.get("email"):
-                        logging.warning("Invalid Google user data received")
+                        logger.warning("Invalid Google user data received")
                         request.session.pop("google_token", None)
                         request.session.pop("user_info", None)
                         return None, False
@@ -219,7 +250,7 @@ async def validate_and_cache_user(request: Request) -> Tuple[Optional[Dict[str,
                     request.session["token_validated_at"] = current_time
                     return user_info, True
             except Exception as e:
-                logging.warning("Google OAuth validation error: %s", e)
+                logger.warning("Google OAuth validation error", error=str(e))
                 request.session.pop("google_token", None)
                 request.session.pop("user_info", None)
 
@@ -231,7 +262,7 @@ async def validate_and_cache_user(request: Request) -> Tuple[Optional[Dict[str,
                 if resp.status_code == 200:
                     github_user = resp.json()
                     if not github_user.get("id"):
-                        logging.warning("Invalid GitHub user data received")
+                        logger.warning("Invalid GitHub user data received")
                         request.session.pop("github_token", None)
                         request.session.pop("user_info", None)
                         return None, False
@@ -248,7 +279,7 @@ async def validate_and_cache_user(request: Request) -> Tuple[Optional[Dict[str,
                             email = email_resp.json()[0].get("email")
 
                     if not email:
-                        logging.warning("No email found for GitHub user")
+                        logger.warning("No email found for GitHub user")
                         request.session.pop("github_token", None)
                         request.session.pop("user_info", None)
                         return None, False
@@ -264,7 +295,7 @@ async def validate_and_cache_user(request: Request) -> Tuple[Optional[Dict[str,
                     request.session["token_validated_at"] = current_time
                     return user_info, True
             except Exception as e:
-                logging.warning("GitHub OAuth validation error: %s", e)
+                logger.warning("GitHub OAuth validation error", error=str(e))
                 request.session.pop("github_token", None)
                 request.session.pop("user_info", None)
 
@@ -273,7 +304,7 @@ async def validate_and_cache_user(request: Request) -> Tuple[Optional[Dict[str,
         return None, False
 
     except Exception as e:
-        logging.error("Unexpected error in validate_and_cache_user: %s", e)
+        logger.error("Unexpected error in validate_and_cache_user", error=str(e))
         request.session.pop("user_info", None)
         return None, False
 
@@ -312,7 +343,7 @@ async def wrapper(request: Request, *args, **kwargs):
         except HTTPException:
             raise
         except Exception as e:
-            logging.error("Unexpected error in token_required: %s", e)
+            logger.error("Unexpected error in token_required", error=str(e))
             request.session.pop("user_info", None)
             raise HTTPException(
                 status_code=status.HTTP_401_UNAUTHORIZED,