CAS 6.6.x - SAML (Shibboleth), Unable to Decrypt EncryptedData

[Chris Durham]

Hi,

We've got CAS 6.6.x running beautifully with delegated IDP logins to multiple SAML providers, but the most recent one we've had to integrate with is causing me some headaches.

The initial redirect works fine, but when it comes back CAS displays the SAML message but then fails to decrypt the SAML message and I can't figure out why - has anyone come across anything similar before?

Chris

Logs.. 

63ff8111b2f8 [1;31m2023-03-30 20:01:28,342 ERROR [org.apereo.cas.web.flow.actions.DelegatedClientAuthenticationAction] - <No valid subject assertion found in response
63ff8111b2f8 [1;31m2023-03-30 20:01:28,341 ERROR [org.pac4j.saml.sso.impl.SAML2AuthnResponseValidator] - <Decryption of assertion failed, continue with the next one> [m
63ff8111b2f8 [1;31m2023-03-30 20:01:28,341 ERROR [org.opensaml.saml.saml2.encryption.Decrypter] - <SAML Decrypter encountered an error decrypting element content: Failed to decrypt EncryptedData> [m
63ff8111b2f8 [1;31m2023-03-30 20:01:28,341 ERROR [org.opensaml.xmlsec.encryption.support.Decrypter] - <Failed to decrypt EncryptedData using either EncryptedData KeyInfoCredentialResolver or EncryptedKeyResolver + EncryptedKey KeyInfoCredentialResolver> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,341 DEBUG [org.opensaml.xmlsec.encryption.support.Decrypter] - <Failed to decrypt EncryptedData using EncryptedKeyResolver> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,341 DEBUG [org.opensaml.xmlsec.encryption.support.ChainingEncryptedKeyResolver$ChainingIterator] - <No more resolvers available in the resolver chain> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,341 DEBUG [org.opensaml.xmlsec.encryption.support.ChainingEncryptedKeyResolver$ChainingIterator] - <Getting key iterator from next resolver: class org.opensaml.xmlsec.encryption.support.SimpleRetrievalMethodEncryptedKeyResolver> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,341 DEBUG [org.opensaml.xmlsec.encryption.support.ChainingEncryptedKeyResolver$ChainingIterator] - <Getting key iterator from next resolver: class org.opensaml.saml.saml2.encryption.EncryptedElementTypeEncryptedKeyResolver> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,341 DEBUG [org.opensaml.xmlsec.encryption.support.Decrypter] - <Attempt to decrypt EncryptedData using key extracted from EncryptedKey failed: > [m
63ff8111b2f8 [1;31m2023-03-30 20:01:28,341 ERROR [org.opensaml.xmlsec.encryption.support.Decrypter] - <Failed to decrypt EncryptedKey, valid decryption key could not be resolved> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,341 DEBUG [org.opensaml.xmlsec.encryption.support.Decrypter] - <Attempt to decrypt EncryptedKey using credential from KEK KeyInfo resolver failed: > [m
63ff8111b2f8 [1;31m2023-03-30 20:01:28,341 ERROR [org.opensaml.xmlsec.encryption.support.Decrypter] - <Error decrypting encrypted key: Unwrapping failed> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,338 DEBUG [org.opensaml.xmlsec.algorithm.AlgorithmSupport] - <Saw null algorithm include list, nothing to evaluate> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,338 DEBUG [org.opensaml.xmlsec.algorithm.AlgorithmSupport] - <Saw null algorithm exclude list, nothing to evaluate> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,338 DEBUG [org.opensaml.xmlsec.encryption.support.Decrypter] - <Validating algorithm URI against include and exclude lists: algorithm: http://www.w3.org/2009/xmlenc11#mgf1sha1, included: null, excluded: null> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,338 DEBUG [org.opensaml.xmlsec.algorithm.AlgorithmSupport] - <Saw null algorithm include list, nothing to evaluate> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,338 DEBUG [org.opensaml.xmlsec.algorithm.AlgorithmSupport] - <Saw null algorithm exclude list, nothing to evaluate> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,338 DEBUG [org.opensaml.xmlsec.encryption.support.Decrypter] - <Validating algorithm URI against include and exclude lists: algorithm: http://www.w3.org/2000/09/xmldsig#sha1, included: null, excluded: null> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,338 DEBUG [org.opensaml.xmlsec.algorithm.AlgorithmSupport] - <Saw null algorithm include list, nothing to evaluate> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,338 DEBUG [org.opensaml.xmlsec.algorithm.AlgorithmSupport] - <Saw null algorithm exclude list, nothing to evaluate> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,338 DEBUG [org.opensaml.xmlsec.encryption.support.Decrypter] - <Validating algorithm URI against include and exclude lists: algorithm: http://www.w3.org/2001/04/xmlenc#rsa-oaep-mgf1p, included: null, excluded: null> [m
63ff8111b2f8 [32m2023-03-30 20:01:28,338 INFO [org.opensaml.xmlsec.algorithm.AlgorithmSupport] - <Mapping from algorithm URI http://www.w3.org/2001/04/xmlenc#rsa-oaep-mgf1p to key length not available> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,338 DEBUG [org.opensaml.xmlsec.encryption.support.Decrypter] - <Added decryption key algorithm criteria: RSA> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,338 DEBUG [org.opensaml.xmlsec.encryption.support.ChainingEncryptedKeyResolver$ChainingIterator] - <Found matching encrypted key: org.opensaml.xmlsec.encryption.impl.EncryptedKeyImpl@3c8b684a> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,337 DEBUG [org.opensaml.xmlsec.encryption.support.ChainingEncryptedKeyResolver$ChainingIterator] - <Getting key iterator from next resolver: class org.opensaml.xmlsec.encryption.support.InlineEncryptedKeyResolver> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,337 DEBUG [org.pac4j.saml.sso.impl.SAML2AuthnResponseValidator] - <Comparing issuer https://shib.oit.duke.edu/shibboleth-idp against https://xxx.xxx.xxx.xxx/shibboleth-idp> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,337 DEBUG [org.pac4j.saml.sso.impl.SAML2AuthnResponseValidator] - <Successfully validated signature for entity id https://shib.oit.duke.edu/shibboleth-idp> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,337 DEBUG [org.opensaml.xmlsec.signature.support.impl.BaseSignatureTrustEngine] - <Successfully established trust of KeyInfo-derived credential> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,337 DEBUG [org.opensaml.security.trust.impl.ExplicitKeyTrustEvaluator] - <Successfully validated untrusted credential against trusted key> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,337 DEBUG [org.opensaml.xmlsec.signature.support.impl.BaseSignatureTrustEngine] - <Attempting to establish trust of KeyInfo-derived credential> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,337 DEBUG [org.opensaml.xmlsec.signature.support.impl.BaseSignatureTrustEngine] - <Successfully verified signature using KeyInfo-derived credential> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,337 DEBUG [org.opensaml.xmlsec.signature.support.impl.BaseSignatureTrustEngine] - <Signature validation using candidate credential was successful> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,337 DEBUG [org.opensaml.xmlsec.signature.support.impl.provider.ApacheSantuarioSignatureValidationProviderImpl] - <Signature validated with key from supplied credential> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,335 DEBUG [org.opensaml.xmlsec.signature.support.impl.provider.ApacheSantuarioSignatureValidationProviderImpl] - <Validation credential key algorithm 'RSA', key instance class 'sun.security.rsa.RSAPublicKeyImpl'> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,335 DEBUG [org.opensaml.xmlsec.signature.support.impl.provider.ApacheSantuarioSignatureValidationProviderImpl] - <Validating signature with signature algorithm URI: http://www.w3.org/2001/04/xmldsig-more#rsa-sha256> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,335 DEBUG [org.opensaml.xmlsec.signature.support.impl.provider.ApacheSantuarioSignatureValidationProviderImpl] - <Accessing XMLSignature object> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,335 DEBUG [org.opensaml.xmlsec.signature.support.impl.provider.ApacheSantuarioSignatureValidationProviderImpl] - <Attempting to validate signature using key from supplied credential> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,335 DEBUG [org.opensaml.xmlsec.signature.support.SignatureValidationProvider] - <Using a validation provider of implementation: org.opensaml.xmlsec.signature.support.impl.provider.ApacheSantuarioSignatureValidationProviderImpl> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,335 DEBUG [org.opensaml.security.credential.criteria.impl.EvaluableCredentialCriteriaRegistry] - <Registry could not locate evaluable criteria for criteria class org.opensaml.xmlsec.keyinfo.KeyInfoCriterion> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,335 DEBUG [org.opensaml.xmlsec.keyinfo.impl.BasicProviderKeyInfoCredentialResolver] - <A total of 1 credentials were resolved> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,335 DEBUG [org.opensaml.xmlsec.keyinfo.impl.BasicProviderKeyInfoCredentialResolver] - <Credentials successfully extracted from child {http://www.w3.org/2000/09/xmldsig#}X509Data by provider org.opensaml.xmlsec.keyinfo.impl.provider.InlineX509DataProvider> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,335 DEBUG [org.opensaml.xmlsec.keyinfo.impl.provider.InlineX509DataProvider] - <Single certificate was present, treating as end-entity certificate> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,335 DEBUG [org.opensaml.xmlsec.keyinfo.impl.provider.InlineX509DataProvider] - <Found 0 X509CRLs> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,335 DEBUG [org.opensaml.xmlsec.keyinfo.impl.provider.InlineX509DataProvider] - <Found 1 X509Certificates> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.xmlsec.keyinfo.impl.provider.InlineX509DataProvider] - <Attempting to extract credential from an X509Data> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.xmlsec.keyinfo.impl.BasicProviderKeyInfoCredentialResolver] - <Processing KeyInfo child {http://www.w3.org/2000/09/xmldsig#}X509Data with provider org.opensaml.xmlsec.keyinfo.impl.provider.InlineX509DataProvider> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.xmlsec.keyinfo.impl.BasicProviderKeyInfoCredentialResolver] - <Provider org.opensaml.xmlsec.keyinfo.impl.provider.DEREncodedKeyValueProvider doesn't handle objects of type {http://www.w3.org/2000/09/xmldsig#}X509Data, skipping> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.xmlsec.keyinfo.impl.BasicProviderKeyInfoCredentialResolver] - <Provider org.opensaml.xmlsec.keyinfo.impl.provider.ECKeyValueProvider doesn't handle objects of type {http://www.w3.org/2000/09/xmldsig#}X509Data, skipping> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.xmlsec.keyinfo.impl.BasicProviderKeyInfoCredentialResolver] - <Provider org.opensaml.xmlsec.keyinfo.impl.provider.DSAKeyValueProvider doesn't handle objects of type {http://www.w3.org/2000/09/xmldsig#}X509Data, skipping> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.xmlsec.keyinfo.impl.BasicProviderKeyInfoCredentialResolver] - <Provider org.opensaml.xmlsec.keyinfo.impl.provider.RSAKeyValueProvider doesn't handle objects of type {http://www.w3.org/2000/09/xmldsig#}X509Data, skipping> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.xmlsec.keyinfo.impl.BasicProviderKeyInfoCredentialResolver] - <Processing KeyInfo child with QName: {http://www.w3.org/2000/09/xmldsig#}X509Data> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.xmlsec.keyinfo.impl.BasicProviderKeyInfoCredentialResolver] - <Found 0 key names: []> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.xmlsec.signature.support.impl.BaseSignatureTrustEngine] - <Attempting to verify signature and establish trust using KeyInfo-derived credentials> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.security.credential.criteria.impl.EvaluableCredentialCriteriaRegistry] - <Registry located evaluable criteria class org.opensaml.security.credential.criteria.impl.EvaluableUsageCredentialCriterion for criteria class org.opensaml.security.criteria.UsageCriterion> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.security.credential.criteria.impl.EvaluableCredentialCriteriaRegistry] - <Registry could not locate evaluable criteria for criteria class org.opensaml.saml.criterion.ProtocolCriterion> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.security.credential.criteria.impl.EvaluableCredentialCriteriaRegistry] - <Registry could not locate evaluable criteria for criteria class org.opensaml.saml.criterion.EntityRoleCriterion> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.security.credential.criteria.impl.EvaluableCredentialCriteriaRegistry] - <Registry located evaluable criteria class org.opensaml.security.credential.criteria.impl.EvaluableEntityIDCredentialCriterion for criteria class org.opensaml.core.criterion.EntityIdCriterion> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.security.credential.criteria.impl.EvaluableCredentialCriteriaRegistry] - <Registry located evaluable criteria class org.opensaml.security.credential.criteria.impl.EvaluableKeyAlgorithmCredentialCriterion for criteria class org.opensaml.security.criteria.KeyAlgorithmCriterion> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.saml.security.impl.MetadataCredentialResolver] - <Resolved cached credentials from KeyDescriptor object metadata> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.saml.metadata.resolver.impl.PredicateRoleDescriptorResolver] - <After predicate filtering 1 RoleDescriptors remain> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.saml.metadata.resolver.impl.PredicateRoleDescriptorResolver] - <Attempting to filter candidate RoleDescriptors via resolved Predicates> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.saml.metadata.resolver.impl.PredicateRoleDescriptorResolver] - <Resolved 1 RoleDescriptor candidates via role criteria, performing predicate filtering> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.saml.metadata.resolver.impl.PredicateRoleDescriptorResolver] - <Resolved 1 source EntityDescriptors> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.saml.metadata.resolver.impl.AbstractMetadataResolver] - <Metadata Resolver DOMMetadataResolver org.opensaml.saml.metadata.resolver.impl.DOMMetadataResolver: After predicate filtering 1 EntityDescriptors remain> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.saml.metadata.resolver.impl.AbstractMetadataResolver] - <Metadata Resolver DOMMetadataResolver org.opensaml.saml.metadata.resolver.impl.DOMMetadataResolver: Attempting to filter candidate EntityDescriptors via resolved Predicates> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.saml.metadata.resolver.impl.AbstractBatchMetadataResolver] - <Metadata Resolver DOMMetadataResolver org.opensaml.saml.metadata.resolver.impl.DOMMetadataResolver: Resolved 1 candidates via EntityIdCriterion: EntityIdCriterion [id=https://shib.oit.duke.edu/shibboleth-idp]> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.saml.security.impl.MetadataCredentialResolver] - <Retrieving role descriptor metadata for entity 'https://xxxx.xxx.xxx.xxx/shibboleth-idp' in role '{urn:oasis:names:tc:SAML:2.0:metadata}IDPSSODescriptor' for protocol 'urn:oasis:names:tc:SAML:2.0:protocol'> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.saml.security.impl.MetadataCredentialResolver] - <Resolving credentials from metadata using entityID: https://xxxx.xxx.xxx.xxx/shibboleth-idp, role: {urn:oasis:names:tc:SAML:2.0:metadata}IDPSSODescriptor, protocol: urn:oasis:names:tc:SAML:2.0:protocol, usage: SIGNING> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.pac4j.saml.sso.impl.SAML2AuthnResponseValidator] - <Validating signature via trust engine for entity id https://xxxx.xxx.xxx.xxx/shibboleth-idp> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.saml.security.impl.SAMLSignatureProfileValidator] - <Saw Exclusive C14N signature transform> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,334 DEBUG [org.opensaml.saml.security.impl.SAMLSignatureProfileValidator] - <Saw Enveloped signature transform> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,333 DEBUG [org.pac4j.saml.sso.impl.SAML2AuthnResponseValidator] - <Validating profile signature for entity id https://xxxx.xxx.xxxx.xxx/shibboleth-idp> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,333 DEBUG [org.opensaml.storage.ReplayCache] - <Value '_c2f60f96fecc11e9809339258596ad16' was not a replay, adding to cache with expiration time 2023-03-30T20:06:25.331Z> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,333 DEBUG [org.opensaml.storage.AbstractMapBackedStorageService] - <Read failed, key '_c2f60f96fecc11e9809339258596ad16' not found in context 'org.opensaml.saml.common.binding.security.impl.MessageReplaySecurityHandler'> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,333 DEBUG [org.opensaml.saml.common.binding.security.impl.MessageReplaySecurityHandler] - <Message Handler:  Evaluating message replay for message ID '_c2f60f96fecc11e9809339258596ad16', issue instant '2023-03-30T20:01:25.331Z', entityID 'https://xxxx.xxx.xxxx.xxx/shibboleth-idp'> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,333 DEBUG [org.opensaml.messaging.handler.AbstractMessageHandler] - <Message Handler:  Activation condition for handler returned true> [m
63ff8111b2f8 [36m2023-03-30 20:01:28,332 DEBUG [org.pac4j.saml.metadata.SAML2IdentityProviderMetadataResolver] - <lastModified: 1678473598041 / newLastModified: 1678473598041 -> hasChanged: false> [m

[Jeffrey Ramsay]

Check the system times (ntp) between the two hosts.

-Jeff

--
- Website: https://apereo.github.io/cas
- Gitter Chatroom: https://gitter.im/apereo/cas
- List Guidelines: https://goo.gl/1VRrw7
- Contributions: https://goo.gl/mh7qDG
---
You received this message because you are subscribed to the Google Groups "CAS Community" group.
To unsubscribe from this group and stop receiving emails from it, send an email to cas-user+u...@apereo.org.
To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/4b61d448-9e08-42aa-a677-635051bc449an%40apereo.org.

[Ray Bon]

Chris,

It could be that the vendor is using an encryption certificate different from the one you are expecting.

Ray

On Thu, 2023-03-30 at 19:58 -0700, 'Chris Durham' via CAS Community wrote:

Notice: This message was sent from outside the University of Victoria email system. Please be cautious with links and sensitive information.

[Chris Durham]

Hey

Thanks for those suggestions - finally got to the bottom of it - and Ray, you were on the right lines...

The IDP metadata we had got from the client was 'prettily' formatted, which included helpfully adding carriage returns and spaces after the X509Certificate start tag and before the end tag - grr.. removing those and giving CAS those resolved the problem.  Will go back to the client and let them know not to do that for anyone else either!

Thanks for the help!

Chris

[Chris Durham]

Second update - I can reproduce this error with the samltest.id website - which also uses a Shib 3.0 based solution.

Would anyone else be willing to create a test against that site to validate whether it's just my configuration or potentially a general CAS issue?

Thanks in advance!

[Chris Durham]

Turns out my earlier 'solution' was a red herring.

So I'm still stuck with the problem that I can't get CAS to handle this particular IDP which send encrypted responses.  I've confirmed that the cert that they are using matches the one in the metadata etc.

I'm assuming that if there was a mismatch in times, then that would show up as a skew error rather than a failure to decrypt the message?  I'm also assuming that since CAS is trying to decode it, it at least knows it is encrypted - is it possible that the key is not where it's expecting it (and is that a CAS issue for not looking or a provider one for being 'different') - obviously this is a bit of a stretch suggestion as I don't know if it would even be possible to return it in different places within the response!

Thanks

Chris

On Friday, 31 March 2023 at 23:34:19 UTC-5 Chris Durham wrote: