add some logging to authentication

jhub_apps/service/auth.py

@@ -1,34 +1,45 @@
+import logging
 import os
 import typing
 from datetime import timedelta, datetime
 
 import jwt
 from fastapi import HTTPException, status
 
+logger = logging.getLogger(__name__)
+
 
 def create_access_token(data: dict, expires_delta: typing.Optional[timedelta] = None):
+    logger.info(f"Creating access token: {data}")
     to_encode = data.copy()
     if expires_delta:
         expire = datetime.utcnow() + expires_delta
     else:
         expire = datetime.utcnow() + timedelta(minutes=15)
     to_encode.update({"exp": expire})
     secret_key = os.environ["JWT_SECRET_KEY"]
+    logger.info(f"JWT secret key: {secret_key}")
     encoded_jwt = jwt.encode(to_encode, secret_key, algorithm="HS256")
     return encoded_jwt
 
 
 def get_jhub_token_from_jwt_token(token):
+    logger.info(f"Trying to get JHUB Apps token from JWT Token: {token}")
     credentials_exception = HTTPException(
         status_code=status.HTTP_401_UNAUTHORIZED,
-        detail="Could not validate credentials",
+        detail={
+            "msg": "Could not validate credentials"
+        },
         headers={"WWW-Authenticate": "Bearer"},
     )
     try:
         payload = jwt.decode(token, os.environ["JWT_SECRET_KEY"], algorithms=["HS256"])
         access_token_data: dict = payload.get("sub")
         if access_token_data is None:
             raise credentials_exception
-    except jwt.PyJWTError:
+    except jwt.PyJWTError as e:
+        logger.warning(f"Authentication failed for token: {token}, JWT_SECRET_KEY: {os.environ['JWT_SECRET_KEY']}")
+        logger.exception(e)
         raise credentials_exception
+    logger.info("Fetched access token from JWT Token")
     return access_token_data["access_token"]

jhub_apps/service/service.py

@@ -42,6 +42,7 @@ async def get_token(code: str):
     "Callback function for OAuth2AuthorizationCodeBearer scheme"
     # The only thing we need in this form post is the code
     # Everything else we can hardcode / pull from env
+    logger.info(f"Getting token for code {code}")
     async with get_client() as client:
         redirect_uri = (
             os.environ["PUBLIC_HOST"] + os.environ["JUPYTERHUB_OAUTH_CALLBACK_URL"],
@@ -60,12 +61,13 @@ async def get_token(code: str):
     )
     ### resp.json() is {'access_token': <token>, 'token_type': 'Bearer'}
     response = RedirectResponse(os.environ["PUBLIC_HOST"] + "/hub/home", status_code=302)
-    response.set_cookie(key="access_token",value=access_token, httponly=True)
+    response.set_cookie(key="access_token", value=access_token, httponly=True)
     return response
 
 
 @router.get("/jhub-login", description="Login via OAuth2")
 async def login(request: Request):
+    logger.info(f"Logging in: {request}")
     authorization_url = os.environ["PUBLIC_HOST"] + "/hub/api/oauth2/authorize?response_type=code&client_id=service-japps"
     return RedirectResponse(authorization_url, status_code=302)