diff --git a/Dockerfile b/Dockerfile index 2c4af21..b98c980 100644 --- a/Dockerfile +++ b/Dockerfile @@ -73,4 +73,44 @@ EXPOSE 8000 RUN chmod +x /code/docker-entrypoint.sh ENTRYPOINT ["bash","/code/docker-entrypoint.sh"] -CMD ["uvicorn", "DataSpace.asgi:application", "--host", "0.0.0.0", "--port", "8000"] + +# Served with multiple workers, which is what keeps this from exhausting +# Postgres. +# +# Django runs sync views under ASGI via sync_to_async(thread_sensitive=True), +# which executes them on ONE shared thread per process. With a single worker +# that means exactly one sync request is processed at a time, no matter how +# many arrive. Measured on dev before this change: 12 concurrent calls to +# /api/auth/keycloak/login/ returned in 4s, 7s, 10s, 14s ... 36s - near-perfect +# ~3s increments, queued behind each other. +# +# That queue is what killed the database. Every in-flight request holds a +# connection while it waits its turn - measured at one connection per request, +# so 20 concurrent calls took the connection count from 6 to 26. Deep enough +# queues reached max_connections (100) and Postgres started refusing with +# "FATAL: sorry, too many clients already", which surfaced as 500s, while +# requests that waited past nginx's 60s proxy timeout surfaced as 504s. It +# also broke deploys, because manage.py could not get a connection either. +# +# Workers are processes, so N workers give N concurrent sync requests and the +# queue drains N times faster. The work here is I/O-bound (waiting on +# Keycloak), so this helps well beyond the 2 CPUs on the dev box. +# +# UVICORN_LIMIT_CONCURRENCY is the backstop: total in-flight requests are +# capped at workers x limit, which must stay under Postgres max_connections +# minus headroom for other clients. Excess requests get a fast 503 instead of +# queueing until the database runs out of slots - shedding load is recoverable, +# exhausting connections takes the deploy pipeline down with it. +# Sized to the dev box, not to a formula. One worker measured at 740MB +# resident with only ~2.4GB available on the host, so 4 workers risked an OOM +# that would have been a worse outage than the one this fixes. Two workers land +# near 1.3GB and match the 2 CPUs. +# +# Two workers alone would only double throughput, but the commit that removes +# two of the three Keycloak round-trips cuts per-request time as well, and the +# two compound. Raise UVICORN_WORKERS on a bigger box - it is env-tunable for +# exactly that reason, and worth revisiting if memory there grows. +ENV UVICORN_WORKERS=2 \ + UVICORN_LIMIT_CONCURRENCY=15 + +CMD ["sh", "-c", "exec uvicorn DataSpace.asgi:application --host 0.0.0.0 --port 8000 --workers ${UVICORN_WORKERS} --limit-concurrency ${UVICORN_LIMIT_CONCURRENCY}"] diff --git a/api/utils/keycloak_utils.py b/api/utils/keycloak_utils.py index f6937d7..d6f4f46 100644 --- a/api/utils/keycloak_utils.py +++ b/api/utils/keycloak_utils.py @@ -54,12 +54,19 @@ def get_token(self, username: str, password: str) -> Dict[str, Any]: logger.error(f"Error getting token: {e}") raise - def validate_token(self, token: str) -> Dict[str, Any]: + def validate_token( + self, token: str, token_info: Optional[Dict[str, Any]] = None + ) -> Dict[str, Any]: """ Validate a token (Django JWT or Keycloak) and return the user info. Args: token: The token to validate + token_info: An introspection response for this token, if the caller + already has one. Passing it avoids a second introspect call to + Keycloak - callers that need the introspection data themselves + (for roles and organizations) would otherwise cause two + identical network round-trips per request. Returns: Dict containing the user information @@ -107,14 +114,36 @@ def validate_token(self, token: str) -> Dict[str, Any]: # If Django JWT validation failed, try Keycloak token validation try: - # Verify the token is valid - token_info = self.keycloak_openid.introspect(token) + # Verify the token is valid. Reuses the caller's introspection when + # one was supplied, rather than repeating the round-trip. + if token_info is None: + token_info = self.keycloak_openid.introspect(token) if not token_info.get("active", False): logger.warning("Token is not active") return {} - # Try to get user info from the userinfo endpoint - # If that fails (403), fall back to token introspection data + # Introspection often already carries everything needed. Calling + # userinfo anyway costs a round-trip that, on deployments where the + # client lacks the scope for it, is guaranteed to fail with 403 and + # fall through to exactly the same data - measured as roughly a + # third of this request's latency on dev. + if token_info.get("sub") and ( + token_info.get("email") or token_info.get("preferred_username") + ): + user_info = { + "sub": token_info.get("sub"), + "preferred_username": token_info.get("username") + or token_info.get("preferred_username"), + "email": token_info.get("email"), + "email_verified": token_info.get("email_verified", False), + "name": token_info.get("name"), + "given_name": token_info.get("given_name"), + "family_name": token_info.get("family_name"), + } + return {k: v for k, v in user_info.items() if v is not None} + + # Otherwise ask userinfo, falling back to introspection data if it + # is not available to this client. try: user_info = self.keycloak_openid.userinfo(token) if isinstance(user_info, bytes): diff --git a/api/views/auth.py b/api/views/auth.py index 94d98dc..98b1029 100644 --- a/api/views/auth.py +++ b/api/views/auth.py @@ -24,17 +24,20 @@ def post(self, request: Request) -> Response: status=status.HTTP_400_BAD_REQUEST, ) + # Introspect once and reuse it. This used to introspect twice per + # request - once inside validate_token and again here for roles and + # organizations - which is a wasted round-trip to Keycloak on every + # login while a database connection is held open. + token_info = keycloak_manager.keycloak_openid.introspect(keycloak_token) + # Validate the token and get user info - user_info = keycloak_manager.validate_token(keycloak_token) + user_info = keycloak_manager.validate_token(keycloak_token, token_info=token_info) if not user_info: return Response( {"error": "Invalid or expired token"}, status=status.HTTP_401_UNAUTHORIZED, ) - # Get token introspection data for roles and organizations - token_info = keycloak_manager.keycloak_openid.introspect(keycloak_token) - # Get user roles and organizations from the token introspection data roles = keycloak_manager.get_user_roles_from_token_info(token_info) organizations = keycloak_manager.get_user_organizations_from_token_info(token_info) diff --git a/api/views/health.py b/api/views/health.py index a9684b3..9f1d0d8 100644 --- a/api/views/health.py +++ b/api/views/health.py @@ -5,7 +5,7 @@ import structlog from django.conf import settings from django.core.cache import cache -from django.db import connection +from django.db import connection, connections from django.http import HttpRequest, JsonResponse from elasticsearch import Elasticsearch from opentelemetry import trace @@ -32,16 +32,38 @@ def health_check(request: HttpRequest) -> JsonResponse: "telemetry": {"status": "unknown"}, } - # Check database + # Check database. + # + # Two distinct checks, because they fail independently: + # + # 1. The request's own connection still works. + # 2. A NEW connection can still be opened. + # + # Only checking (1) is how this endpoint reported + # {"database": "healthy"} in 0.44s while Postgres was refusing new + # connections with "FATAL: sorry, too many clients already" and both the + # login endpoint and the deploy pipeline were failing on exactly that. The + # existing connection is already established, so it keeps answering + # SELECT 1 no matter how saturated the server is - which made a green + # health check actively misleading during an outage. try: with connection.cursor() as cursor: cursor.execute("SELECT 1") - status["database"] = { - "status": "healthy", - "message": "Successfully connected to database", - } - if current_span: - current_span.set_attribute("database.status", "healthy") + + # Deliberately a fresh connection, closed immediately. This is the + # check that catches connection exhaustion. + new_connection = connections.create_connection("default") + try: + new_connection.ensure_connection() + finally: + new_connection.close() + + status["database"] = { + "status": "healthy", + "message": "Successfully connected to database", + } + if current_span: + current_span.set_attribute("database.status", "healthy") except Exception as e: logger.error("Database health check failed", error=str(e)) status["database"] = {