Merge pull request #870 from lsst-sqre/tickets/DM-41075

DM-41075: Log OIDC exceptions properly

changelog.d/20231006_082903_rra_DM_41075.md

@@ -0,0 +1,3 @@
+### Bug fixes
+
+- Log exceptions encountered while parsing OpenID Connect responses from upstream providers, not just the deduced error message. Include the body of the response from the token endpoint if it could not be parsed as JSON.

changelog.d/20231006_083302_rra_DM_41075.md

@@ -0,0 +1,3 @@
+### Other changes
+
+- Include curl in the Gafaelfawr container for manual debugging of web request problems.

scripts/install-base-packages.sh

@@ -26,11 +26,11 @@ apt-get update
 # Install security updates:
 apt-get -y upgrade
 
-# git is required by setuptools-scm. libpq-dev is required by psycopg2. The
-# other packages are required by bonsai for LDAP binds or to manage the
-# Kerberos ticket cache. (krb5-user is not strictly needed, but it's useful
-# for debugging.)
-apt-get -y install --no-install-recommends git krb5-user kstart         \
+# git is required by setuptools-scm. libpq-dev is required by psycopg2. Most
+# of the other packages are required by bonsai for LDAP binds or to manage the
+# Kerberos ticket cache. curl and krb5-user are not strictly needed, but are
+# useful for debugging.
+apt-get -y install --no-install-recommends curl git krb5-user kstart    \
         libldap2-dev libldap-common libsasl2-dev libsasl2-modules       \
         libsasl2-modules-gssapi-mit libpq-dev
 

src/gafaelfawr/providers/oidc.py

@@ -130,14 +130,15 @@ async def create_user_info(
             provider.
         """
         token_url = self._config.token_url
+        logger = self._logger.bind(token_url=token_url)
         data = {
             "grant_type": "authorization_code",
             "client_id": self._config.client_id,
             "client_secret": self._config.client_secret,
             "code": code,
             "redirect_uri": self._config.redirect_url,
         }
-        self._logger.info("Retrieving ID token", token_url=token_url)
+        logger.info("Retrieving ID token")
 
         # If the call failed, try to extract an error from the reply.  If that
         # fails, just raise an exception for the HTTP status.
@@ -161,6 +162,7 @@ async def create_user_info(
             raise OIDCWebError.from_exception(e) from e
         except Exception as e:
             msg = f"Response from {token_url} not valid JSON"
+            logger.exception(msg, response=r.text)
             raise OIDCError(msg) from e
         if "id_token" not in result:
             msg = f"No id_token in token reply from {token_url}"
@@ -176,6 +178,7 @@ async def create_user_info(
         except MissingUsernameClaimError as e:
             raise OIDCNotEnrolledError(str(e)) from e
         except (jwt.InvalidTokenError, VerifyTokenError) as e:
+            logger.exception("Error verifying ID token", msg=str(e))
             msg = f"OpenID Connect token verification failed: {e!s}"
             raise OIDCError(msg) from e