cleanup hot path

This commit is contained in:
2025-09-18 14:45:59 +02:00
parent e8742e1948
commit 745a72aedb
3 changed files with 92 additions and 57 deletions

View File

@@ -1,6 +1,5 @@
"""Authentication API endpoints""" """Authentication API endpoints"""
import asyncio
import logging import logging
from datetime import datetime, timedelta from datetime import datetime, timedelta
from typing import Optional from typing import Optional
@@ -172,54 +171,6 @@ async def login(
bcrypt_rounds=settings.BCRYPT_ROUNDS, bcrypt_rounds=settings.BCRYPT_ROUNDS,
) )
# DEBUG: Check Redis connection (keep lightweight to avoid request stalls)
if settings.APP_DEBUG:
try:
logger.info("LOGIN_REDIS_CHECK_START", redis_url=redis_url)
import redis.asyncio as redis
redis_url = settings.REDIS_URL
logger.info(f"Redis URL: {redis_url}")
redis_client = redis.from_url(
redis_url,
socket_connect_timeout=1.0,
socket_timeout=1.0,
)
test_start = datetime.utcnow()
try:
await asyncio.wait_for(redis_client.ping(), timeout=1.5)
test_end = datetime.utcnow()
logger.info(
"LOGIN_REDIS_CHECK_SUCCESS",
duration_seconds=(test_end - test_start).total_seconds(),
)
except asyncio.TimeoutError:
logger.warning("LOGIN_REDIS_CHECK_TIMEOUT", timeout_seconds=1.5)
finally:
await redis_client.close()
except Exception as e:
logger.error("LOGIN_REDIS_CHECK_FAILURE", error=str(e))
# DEBUG: Check database connection with timeout
if settings.APP_DEBUG:
try:
logger.info("LOGIN_DB_PING_START")
test_start = datetime.utcnow()
await asyncio.wait_for(db.execute(select(1)), timeout=3.0)
test_end = datetime.utcnow()
logger.info(
"LOGIN_DB_PING_SUCCESS",
duration_seconds=(test_end - test_start).total_seconds(),
)
except asyncio.TimeoutError:
logger.warning("LOGIN_DB_PING_TIMEOUT", timeout_seconds=3.0)
except Exception as e:
logger.error("LOGIN_DB_PING_FAILURE", error=str(e))
raise HTTPException(
status_code=status.HTTP_500_INTERNAL_SERVER_ERROR,
detail="Database connection error"
)
start_time = datetime.utcnow() start_time = datetime.utcnow()
# Get user by email # Get user by email

View File

@@ -2,6 +2,8 @@
Security utilities for authentication and authorization Security utilities for authentication and authorization
""" """
import asyncio
import concurrent.futures
import logging import logging
from datetime import datetime, timedelta from datetime import datetime, timedelta
from typing import Optional, Dict, Any from typing import Optional, Dict, Any
@@ -33,19 +35,29 @@ security = HTTPBearer()
def verify_password(plain_password: str, hashed_password: str) -> bool: def verify_password(plain_password: str, hashed_password: str) -> bool:
"""Verify a password against its hash""" """Verify a password against its hash"""
import time import time
start_time = time.time() start_time = time.time()
logger.info(f"=== PASSWORD VERIFICATION START === BCRYPT_ROUNDS: {settings.BCRYPT_ROUNDS}") logger.info(f"=== PASSWORD VERIFICATION START === BCRYPT_ROUNDS: {settings.BCRYPT_ROUNDS}")
try: try:
result = pwd_context.verify(plain_password, hashed_password) # Run password verification in a thread with timeout
with concurrent.futures.ThreadPoolExecutor(max_workers=1) as executor:
future = executor.submit(pwd_context.verify, plain_password, hashed_password)
result = future.result(timeout=5.0) # 5 second timeout
end_time = time.time() end_time = time.time()
duration = end_time - start_time duration = end_time - start_time
logger.info(f"=== PASSWORD VERIFICATION END === Duration: {duration:.3f}s, Result: {result}") logger.info(f"=== PASSWORD VERIFICATION END === Duration: {duration:.3f}s, Result: {result}")
if duration > 5: if duration > 1:
logger.warning(f"PASSWORD VERIFICATION TOOK TOO LONG: {duration:.3f}s") logger.warning(f"PASSWORD VERIFICATION TOOK TOO LONG: {duration:.3f}s")
return result return result
except concurrent.futures.TimeoutError:
end_time = time.time()
duration = end_time - start_time
logger.error(f"=== PASSWORD VERIFICATION TIMEOUT === Duration: {duration:.3f}s")
return False # Treat timeout as verification failure
except Exception as e: except Exception as e:
end_time = time.time() end_time = time.time()
duration = end_time - start_time duration = end_time - start_time

View File

@@ -1,9 +1,9 @@
""" """Main FastAPI application entry point"""
Main FastAPI application entry point
"""
import asyncio
import logging import logging
import sys import sys
import time
from contextlib import asynccontextmanager from contextlib import asynccontextmanager
from fastapi import FastAPI from fastapi import FastAPI
@@ -14,10 +14,13 @@ from fastapi.exceptions import RequestValidationError
from starlette.exceptions import HTTPException from starlette.exceptions import HTTPException
from starlette.middleware.sessions import SessionMiddleware from starlette.middleware.sessions import SessionMiddleware
from sqlalchemy import select
from sqlalchemy.exc import SQLAlchemyError
from app.core.config import settings from app.core.config import settings
from app.core.logging import setup_logging from app.core.logging import setup_logging
from app.core.security import get_current_user from app.core.security import get_current_user
from app.db.database import init_db from app.db.database import init_db, async_session_factory
from app.api.internal_v1 import internal_api_router from app.api.internal_v1 import internal_api_router
from app.api.public_v1 import public_api_router from app.api.public_v1 import public_api_router
from app.utils.exceptions import CustomHTTPException from app.utils.exceptions import CustomHTTPException
@@ -32,6 +35,68 @@ setup_logging()
logger = logging.getLogger(__name__) logger = logging.getLogger(__name__)
async def _check_redis_startup():
"""Validate Redis connectivity during startup."""
if not settings.REDIS_URL:
logger.info("Startup Redis check skipped: REDIS_URL not configured")
return
try:
import redis.asyncio as redis
except ModuleNotFoundError:
logger.warning("Startup Redis check skipped: redis library not installed")
return
client = redis.from_url(
settings.REDIS_URL,
socket_connect_timeout=1.0,
socket_timeout=1.0,
)
start = time.perf_counter()
try:
await asyncio.wait_for(client.ping(), timeout=3.0)
duration = time.perf_counter() - start
logger.info(
"Startup Redis check succeeded",
extra={"redis_url": settings.REDIS_URL, "duration_seconds": round(duration, 3)},
)
except Exception as exc: # noqa: BLE001
logger.warning(
"Startup Redis check failed",
extra={"error": str(exc), "redis_url": settings.REDIS_URL},
)
finally:
await client.close()
async def _check_database_startup():
"""Validate database connectivity during startup."""
start = time.perf_counter()
try:
async with async_session_factory() as session:
await asyncio.wait_for(session.execute(select(1)), timeout=3.0)
duration = time.perf_counter() - start
logger.info(
"Startup database check succeeded",
extra={"duration_seconds": round(duration, 3)},
)
except (asyncio.TimeoutError, SQLAlchemyError) as exc:
logger.error(
"Startup database check failed",
extra={"error": str(exc)},
)
raise
async def run_startup_dependency_checks():
"""Run dependency checks once during application startup."""
logger.info("Running startup dependency checks...")
await _check_redis_startup()
await _check_database_startup()
logger.info("Startup dependency checks complete")
@asynccontextmanager @asynccontextmanager
async def lifespan(app: FastAPI): async def lifespan(app: FastAPI):
""" """
@@ -47,6 +112,13 @@ async def lifespan(app: FastAPI):
except Exception as e: except Exception as e:
logger.warning(f"Core cache service initialization failed: {e}") logger.warning(f"Core cache service initialization failed: {e}")
# Run one-time dependency checks (non-blocking for auth requests)
try:
await run_startup_dependency_checks()
except Exception:
logger.error("Critical dependency check failed during startup")
raise
# Initialize database # Initialize database
await init_db() await init_db()