From 66a3895eff9ebb404cc6dc3719bbcfcae10a0294 Mon Sep 17 00:00:00 2001 From: Eduardo Silva Date: Mon, 16 Mar 2026 11:26:16 -0300 Subject: [PATCH] enhance logging and error handling in authentication process --- .../auth_gateway/config_loader.py | 11 +++++++++-- containers/auth-gateway/auth_gateway/main.py | 19 ++++++++++++++++++- .../auth_gateway/web/login_routes.py | 13 +++++++++++++ containers/auth-gateway/entrypoint.sh | 2 +- 4 files changed, 41 insertions(+), 4 deletions(-) diff --git a/containers/auth-gateway/auth_gateway/config_loader.py b/containers/auth-gateway/auth_gateway/config_loader.py index 8a1a556..cbc791a 100644 --- a/containers/auth-gateway/auth_gateway/config_loader.py +++ b/containers/auth-gateway/auth_gateway/config_loader.py @@ -14,8 +14,15 @@ logger = logging.getLogger(__name__) def _load_json(path: Path) -> dict | None: if not path.exists(): return None - with path.open("r", encoding="utf-8") as handle: - return json.load(handle) + try: + with path.open("r", encoding="utf-8") as handle: + content = handle.read() + if not content.strip(): + return None + return json.loads(content) + except json.JSONDecodeError: + logger.warning("Failed to parse '%s' — file may be mid-write, will retry on next request.", path.name) + return None def _is_valid_provider_url(method_name: str, method: OIDCMethodModel) -> bool: diff --git a/containers/auth-gateway/auth_gateway/main.py b/containers/auth-gateway/auth_gateway/main.py index f911891..f86d82a 100644 --- a/containers/auth-gateway/auth_gateway/main.py +++ b/containers/auth-gateway/auth_gateway/main.py @@ -1,3 +1,5 @@ +import logging +import time from contextlib import asynccontextmanager from pathlib import Path @@ -8,11 +10,12 @@ from auth_gateway.settings import settings from auth_gateway.storage.sqlite import SQLiteStorage from auth_gateway.web.auth_routes import router as auth_router from auth_gateway.web.login_routes import router as login_router -from fastapi import FastAPI +from fastapi import FastAPI, Request from fastapi.staticfiles import StaticFiles from fastapi.templating import Jinja2Templates BASE_DIR = Path(__file__).resolve().parent +_access_logger = logging.getLogger("uvicorn.error") @asynccontextmanager @@ -27,6 +30,20 @@ async def lifespan(app: FastAPI): app = FastAPI(title="Auth Gateway", lifespan=lifespan) + + +@app.middleware("http") +async def access_log(request: Request, call_next): + start = time.monotonic() + response = await call_next(request) + if request.url.path == "/auth/check" and response.status_code == 200: + return response + ms = (time.monotonic() - start) * 1000 + client = request.client.host if request.client else "-" + _access_logger.info('%s - "%s %s" %d (%.0fms)', client, request.method, request.url.path, response.status_code, ms) + return response + + app.mount("/static", StaticFiles(directory=str(BASE_DIR / "static")), name="static") app.include_router(auth_router) app.include_router(login_router) diff --git a/containers/auth-gateway/auth_gateway/web/login_routes.py b/containers/auth-gateway/auth_gateway/web/login_routes.py index 6b89013..ead37ab 100644 --- a/containers/auth-gateway/auth_gateway/web/login_routes.py +++ b/containers/auth-gateway/auth_gateway/web/login_routes.py @@ -1,4 +1,8 @@ +import logging + from auth_gateway.models.auth import OIDCMethodModel + +logger = logging.getLogger("uvicorn.error") from auth_gateway.services.oidc_service import is_oidc_identity_allowed from auth_gateway.services.password_service import verify_user_password from auth_gateway.services.policy_engine import evaluate_ip_access, extract_client_ip @@ -121,8 +125,10 @@ async def login_password_submit(request: Request, next: str = Form("/"), usernam user = verify_user_password(username, password, runtime_config.users) if not user: + logger.warning("AUTH password failed for '%s' (policy: %s)", username, context.policy_name) return _render(request, "login_password.html", status_code=401, next=next, application_name=context.application.name, error="Invalid username or password.") if effective_policy.allowed_users and username not in effective_policy.allowed_users: + logger.warning("AUTH password denied for '%s' — not in allowed_users (policy: %s)", username, context.policy_name) return _render(request, "login_password.html", status_code=403, next=next, application_name=context.application.name, error="This user is not allowed by the active policy.") groups = [ @@ -141,7 +147,9 @@ async def login_password_submit(request: Request, next: str = Form("/"), usernam ) if effective_policy.totp_method_names: + logger.info("AUTH password ok for '%s' → totp required (policy: %s)", username, context.policy_name) return _redirect_with_cookie(request, build_external_url(request, "/login/totp", next=next), session) + logger.info("AUTH login ok for '%s' (policy: %s)", username, context.policy_name) return _redirect_with_cookie(request, next, session) @@ -182,6 +190,7 @@ async def login_totp_submit(request: Request, next: str = Form("/"), token: str secret = user.totp_secret if not verify_totp(secret, token): + logger.warning("AUTH totp failed for '%s' (policy: %s)", session.username if session else "?", context.policy_name) return _render(request, "login_totp.html", status_code=401, next=next, application_name=context.application.name, error="Invalid verification code.") session_service = request.app.state.session_service @@ -190,6 +199,7 @@ async def login_totp_submit(request: Request, next: str = Form("/"), token: str add_factors=["totp"], expires_in_minutes=get_effective_expiration(request, effective_policy, ["totp"]), ) + logger.info("AUTH login ok for '%s' via password+totp (policy: %s)", refreshed_session.username, context.policy_name) return _redirect_with_cookie(request, next, refreshed_session) @@ -246,7 +256,10 @@ async def login_oidc_callback(request: Request, state: str): def _do_logout(request: Request, next_url: str = "/") -> RedirectResponse: session_cookie = request.cookies.get(request.app.state.settings.cookie_name) + session = request.app.state.session_service.get_session(session_cookie) request.app.state.session_service.delete_session(session_cookie) + if session: + logger.info("AUTH logout for '%s'", session.username or session.email or "unknown") response = RedirectResponse(next_url or "/", status_code=303) response.delete_cookie(request.app.state.settings.cookie_name, path="/") return response diff --git a/containers/auth-gateway/entrypoint.sh b/containers/auth-gateway/entrypoint.sh index d485250..f8cba3e 100644 --- a/containers/auth-gateway/entrypoint.sh +++ b/containers/auth-gateway/entrypoint.sh @@ -2,4 +2,4 @@ set -eu -exec uvicorn auth_gateway.main:app --host 0.0.0.0 --port 9091 +exec uvicorn auth_gateway.main:app --host 0.0.0.0 --port 9091 --no-access-log