Added more logging.

Depending on web framework the dpop header may come under different names.
Improved the dump method to allow dictionary representation beside a Message instance.

Author: rohe

example/flask_op/private/cookie_jwks.json

@@ -1 +1 @@
-{"keys": [{"kty": "oct", "use": "enc", "kid": "enc", "k": "GEmhZ9UKLSq60zECQRyAtmMLG5smRpCl"}, {"kty": "oct", "use": "sig", "kid": "sig", "k": "Px8EGB-oWk-DfMlYWXBHTjED372mvtBt"}]}
+{"keys": [{"kty": "oct", "use": "enc", "kid": "enc", "k": "HqZu6WO7HyvyCfAwfCdzwSLUuEeVPiIv"}, {"kty": "oct", "use": "sig", "kid": "sig", "k": "Y3sPFaO2qJuG-Q2O-UzpRIYk-I1KLPZo"}]}

src/idpyoidc/claims.py

@@ -1,3 +1,4 @@
+import logging
 from typing import Callable
 from typing import Optional
 
@@ -10,6 +11,7 @@
 from idpyoidc.util import add_path
 from idpyoidc.util import qualified_name
 
+logger = logging.getLogger(__name__)
 
 def claims_dump(info, exclude_attributes):
     return {qualified_name(info.__class__): info.dump(exclude_attributes=exclude_attributes)}
@@ -138,6 +140,7 @@ def handle_keys(self,
                     configuration: dict,
                     keyjar: Optional[KeyJar] = None,
                     entity_id: Optional[str] = ""):
+        logger.debug(f"configuration: {configuration}")
         _jwks = _jwks_uri = None
         _id = self.get_id(configuration)
         keyjar, uri_path = self._keyjar(keyjar, configuration, entity_id=_id)

src/idpyoidc/client/oauth2/add_on/par.py

@@ -76,10 +76,7 @@ def push_authorization(request_args, service, **kwargs):
             _req[param] = request_args.get(param)
         request_args = _req
     else:
-        raise ConnectionError(
-            f"Could not connect to "
-            f'{_context.provider_info["pushed_authorization_request_endpoint"]}'
-        )
+        raise ConnectionError(f"Could not connect to {_par_endpoint}")
 
     return request_args
 

src/idpyoidc/impexp.py

@@ -1,4 +1,6 @@
 import base64
+import inspect
+import logging
 from typing import Any
 from typing import List
 from typing import Optional
@@ -10,6 +12,7 @@
 from idpyoidc.message import Message
 from idpyoidc.storage import DictType
 
+logger = logging.getLogger(__name__)
 
 def fully_qualified_name(cls):
     return cls.__module__ + "." + cls.__class__.__name__
@@ -41,6 +44,7 @@ def __init__(self):
         pass
 
     def dump_attr(self, cls, item, exclude_attributes: Optional[List[str]] = None) -> dict:
+        logger.debug(f"dump_attr:: cls: {cls}, item: {item}")
         if cls in [None, 0, "", bool]:
             val = item
         elif cls == b"":
@@ -74,9 +78,29 @@ def dump_attr(self, cls, item, exclude_attributes: Optional[List[str]] = None) -
             val = qualified_name(item)
         elif isinstance(cls, list):
             val = [self.dump_attr(cls[0], v, exclude_attributes) for v in item]
+        elif inspect.isclass(cls):
+            logger.debug(f"class instance: {cls}")
+            _dump = getattr(cls, "dump", None)
+            if _dump:
+                val = _dump(item, exclude_attributes=exclude_attributes)
+            else:
+                if isinstance(item, cls):
+                    val = {qualified_name(cls): item.to_dict()}
+                elif isinstance(item, dict):
+                    val = {qualified_name(cls): item}
+                else:
+                    logger.error(f"Can't dump {item} as {cls}")
         else:
-            val = item.dump(exclude_attributes=exclude_attributes)
+            _dump = getattr(item, "dump", None)
+            if _dump:
+                val = _dump(exclude_attributes=exclude_attributes)
+            elif isinstance(item, dict):
+                val = item
+            else:
+                logger.error(f"Do not know how to dump: {item}")
+                raise AttributeError()
 
+        logger.debug(f"-> {val}")
         return val
 
     def dump(self, exclude_attributes: Optional[List[str]] = None) -> dict:
@@ -154,7 +178,11 @@ def load_attr(
             val = [_cls(**_args).load(v, **_kwargs) for v in item]
         elif issubclass(cls, Message):
             _cls_name = list(item.keys())[0]
-            _cls = importer(_cls_name)
+            try:
+                _cls = importer(_cls_name)
+            except Exception as err:
+                logger.error(f"Could not import {item}: {err}")
+                raise
             val = _cls().from_dict(item[_cls_name])
         else:
             if issubclass(cls, ImpExp) and init_args:

src/idpyoidc/server/claims/oidc.py

@@ -1,6 +1,7 @@
 from typing import Optional
 
 from idpyoidc import metadata
+from idpyoidc.message import Message
 from idpyoidc.message.oidc import ProviderConfigurationResponse
 from idpyoidc.message.oidc import RegistrationRequest
 from idpyoidc.message.oidc import RegistrationResponse
@@ -91,7 +92,7 @@ def verify_rules(self, supports):
             self.set_preference("id_token_encryption_alg_values_supported", [])
             self.set_preference("id_token_encryption_enc_values_supported", [])
 
-    def provider_info(self, supports):
+    def provider_info(self, supports, schema: Optional[Message] = None):
         _info = {}
         for key in ProviderConfigurationResponse.c_param.keys():
             _val = self.get_preference(key, supports.get(key, None))

src/idpyoidc/server/client_authn.py

@@ -488,6 +488,8 @@ def verify_client(
     if not allowed_methods:
         allowed_methods = list(methods.keys())  # If not specific for this endpoint then all
 
+    logger.info(f"Allowed client authentication methods: {allowed_methods}")
+
     _method = None
     _cdb = _cinfo = None
     _tested = []
@@ -504,8 +506,8 @@ def verify_client(
                 endpoint=endpoint,
                 get_client_id_from_token=get_client_id_from_token,
             )
-        except (BearerTokenAuthenticationError, ClientAuthenticationError):
-            raise
+        # except (BearerTokenAuthenticationError, ClientAuthenticationError):
+        #     raise
         except Exception as err:
             logger.info("Verifying auth using {} failed: {}".format(_method.tag, err))
             continue
@@ -534,7 +536,7 @@ def verify_client(
                 _auto_reg = getattr(endpoint, "automatic_registration", None)
                 if _auto_reg:
                     _cinfo = {"client_id": client_id}
-                    _auto_reg.set(client_id, _cinfo)
+                    _cdb[client_id] = _cinfo
                 else:
                     raise UnknownClient("Unknown Client ID")
 

src/idpyoidc/server/endpoint.py

@@ -196,7 +196,9 @@ def parse_request(
         :return:
         """
         LOGGER.debug("- {} -".format(self.endpoint_name))
-        LOGGER.info("Request: %s" % sanitize(request))
+        LOGGER.info(f"Request: {sanitize(request)}")
+        if http_info:
+            LOGGER.info(f"HTTP info: {http_info}")
 
         _context = self.upstream_get("context")
         _keyjar = self.upstream_get("attribute", "keyjar")

src/idpyoidc/server/endpoint_context.py

@@ -241,7 +241,10 @@ def __init__(
             conf = conf.conf
         _supports = self.supports()
         self.keyjar = self.claims.load_conf(conf, supports=_supports, keyjar=keyjar)
-        metadata_schema = conf.conf.get("metadata_schema", None)
+        if isinstance(conf, dict):
+            metadata_schema = conf.get("metadata_schema", None)
+        else:
+            metadata_schema = conf.conf.get("metadata_schema", None)
         if metadata_schema:
             metadata_schema = importer(metadata_schema)
         self.provider_info = self.get_provider_info(_supports, schema=metadata_schema)

src/idpyoidc/server/oauth2/add_on/dpop.py

@@ -107,7 +107,14 @@ def token_post_parse_request(request, client_id, context, **kwargs):
     if not _http_info:
         return request
 
-    _dpop = DPoPProof().verify_header(_http_info["headers"]["dpop"])
+    _headers = _http_info['headers']
+    logger.debug(f"http headers: {_headers}")
+
+    _dpop_header = _headers.get("dpop", _headers.get("http_dpop", None))
+    if not _dpop_header:
+        raise ValueError("Missing DPoP header")
+
+    _dpop = DPoPProof().verify_header(_dpop_header)
 
     # The signature of the JWS is verified, now for checking the
     # content

src/idpyoidc/server/session/grant.py

@@ -377,7 +377,6 @@ def mint_token(
             )
 
             logger.debug(f"token_payload: {token_payload}")
-
             item.value = token_handler(
                 session_id=session_id, usage_rules=usage_rules, **token_payload
             )