[Shib-Users] IdP to ECP: Validation of signature failed on AuthnRequest

706 views
Skip to first unread message

Kobe

unread,
Mar 25, 2011, 5:25:43 PM3/25/11
to shibbole...@internet2.edu
(I have looked at other messages with similar topic and I believe my problem
is different - pl bear with me).

I am using Shibboleth Idp 2.1.2 with Opensso 0.95 as the SP with a custom
ECP client.

When my ECP client forwards the AuthnRequest received from the SP to the
IdP, the IdP
fails to verify the signature of the assertion. I tried these avenues:
a) import the certificate of the SP in the keystore and cacerts used by
the IdP's tomcat
b) made sure that the signing key of the SP was included in the SP
metadata in the IdP
c) tried to force IdP to not require signed assertions and requests in the
DefaultRelyingParty
(although i am not sure this affects verification of signatures of
incoming AuthnRequests):


I tried to disable the SP from signing to assertion - but despite that
configuration, the Authnequest
issued to the ECP client is signed.

I am producing the logs below. From the excerpt below, it appears that IdP
tries to use
the KeyInfo embedded in the signature for validation. Is there a way to
force the IdP
to no force signature verification?


13:52:43.458 - DEBUG
[org.opensaml.xml.signature.impl.BaseSignatureTrustEngine:91] - Attempting
to verify signature and establish trust using KeyInfo-derived credentials
13:52:43.458 - DEBUG
[org.opensaml.xml.signature.impl.BaseSignatureTrustEngine:111] - Signature
contained no KeyInfo element, could not resolve verification credentials
13:52:43.458 - DEBUG
[org.opensaml.xml.signature.impl.BaseSignatureTrustEngine:114] - Failed to
verify signature and/or establish trust using any KeyInfo-derived
credentials

Any help greatly appreciated!

thanks,

/K

Full logs:


13:52:43.406 - DEBUG
[org.opensaml.saml2.binding.decoding.HTTPSOAP11Decoder:147] - Decoded SOAP
messaged which included SAML message of type
{urn:oasis:names:tc:SAML:2.0:protocol}AuthnRequest
13:52:43.406 - DEBUG
[org.opensaml.saml2.binding.decoding.BaseSAML2MessageDecoder:111] -
Extracting ID, issuer and issue instant from request
13:52:43.406 - DEBUG
[org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:199] -
Checking child metadata provider for entity descriptor with entity ID: mySP
13:52:43.407 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:509] -
Searching for entity descriptor with an entity ID of mySP
13:52:43.407 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:522] -
Metadata root is an entity descriptor, checking if it's the one we're
looking for.
13:52:43.407 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:529] - Found
entity descriptor for entity with ID mySP but it is no longer valid,
skipping it.
13:52:43.407 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:166] -
Metadata document does not contain an EntityDescriptor with the ID mySP
13:52:43.407 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:170] -
Metadata document contained an EntityDescriptor with the ID mySP, but it was
no longer valid
13:52:43.408 - DEBUG
[org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:199] -
Checking child metadata provider for entity descriptor with entity ID: mySP
13:52:43.408 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:509] -
Searching for entity descriptor with an entity ID of mySP
13:52:43.408 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:522] -
Metadata root is an entity descriptor, checking if it's the one we're
looking for.
13:52:43.408 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:543] -
Located entity descriptor, creating an index to it for faster lookups
13:52:43.412 - DEBUG [PROTOCOL_MESSAGE:91] -
<?xml version="1.0" encoding="UTF-8"?>



mySP

bj/70yC7lBztVOYgFooua5/aW2A=

AVObpKFJrT7nEH+YwLliN3zXJdcLBrs3Y6u+ZaxntyI4roGG2tf3iM+SQX0UywnoNb+KJ7Bd46He
mAARzA3b+jIfopWCFLFAKB4l3jLKAKLIh0q6OxMU6FkOlKHFbSgvNXB3Be0vl0B3QPCXnCfKWkfb
6uQV1vTgjdpkLihFoDA=



urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport


13:52:43.412 - DEBUG
[org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:199] -
Checking child metadata provider for entity descriptor with entity ID: mySP
13:52:43.412 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:509] -
Searching for entity descriptor with an entity ID of mySP
13:52:43.413 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:522] -
Metadata root is an entity descriptor, checking if it's the one we're
looking for.
13:52:43.413 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:529] - Found
entity descriptor for entity with ID mySP but it is no longer valid,
skipping it.
13:52:43.413 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:166] -
Metadata document does not contain an EntityDescriptor with the ID mySP
13:52:43.413 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:170] -
Metadata document contained an EntityDescriptor with the ID mySP, but it was
no longer valid
13:52:43.413 - DEBUG
[org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:199] -
Checking child metadata provider for entity descriptor with entity ID: mySP
13:52:43.414 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:509] -
Searching for entity descriptor with an entity ID of mySP
13:52:43.414 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:513] - Entity
descriptor for the ID mySP was found in index cache, returning
13:52:43.414 - DEBUG
[org.opensaml.ws.message.decoder.BaseMessageDecoder:108] - Evaluating
security policy of type
'edu.internet2.middleware.shibboleth.common.security.ShibbolethSecurityPolicy'
for decoded message
13:52:43.414 - DEBUG [org.opensaml.util.storage.ReplayCache:91] - Attempting
to acquire lock for replay cache check
13:52:43.415 - DEBUG [org.opensaml.util.storage.ReplayCache:93] - Lock
acquired
13:52:43.415 - DEBUG [org.opensaml.util.storage.ReplayCache:104] - Message
ID s24b45fa31e86de151b2994777ce65eb52a39906a5 was not a replay
13:52:43.415 - DEBUG [org.opensaml.util.storage.ReplayCache:131] - Writing
message ID mySPs24b45fa31e86de151b2994777ce65eb52a39906a5 to replay cache
with expiration time 2011-03-25T13:57:43.415-07:00
13:52:43.417 - DEBUG
[org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:254] -
Checking child metadata provider for entity descriptor with entity ID: mySP
13:52:43.417 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:509] -
Searching for entity descriptor with an entity ID of mySP
13:52:43.417 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:522] -
Metadata root is an entity descriptor, checking if it's the one we're
looking for.
13:52:43.417 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:529] - Found
entity descriptor for entity with ID mySP but it is no longer valid,
skipping it.
13:52:43.418 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:250] -
Metadata document did not contain a descriptor for entity mySP
13:52:43.418 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:317] -
Metadata document did not contain any role descriptors of type
{urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor for entity mySP
13:52:43.418 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:286] -
Metadata document does not contain a role of type
{urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor supporting protocol
urn:oasis:names:tc:SAML:2.0:protocol for entity mySP
13:52:43.418 - DEBUG
[org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:254] -
Checking child metadata provider for entity descriptor with entity ID: mySP
13:52:43.418 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:509] -
Searching for entity descriptor with an entity ID of mySP
13:52:43.418 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:513] - Entity
descriptor for the ID mySP was found in index cache, returning
13:52:43.419 - DEBUG
[org.opensaml.saml2.binding.security.SAML2AuthnRequestsSignedRule:91] -
SPSSODescriptor for entity ID 'mySP' does not require AuthnRequests to be
signed
13:52:43.423 - DEBUG
[org.opensaml.security.SAMLSignatureProfileValidator:185] - Saw Enveloped
signature transform
13:52:43.424 - DEBUG
[org.opensaml.security.SAMLSignatureProfileValidator:189] - Saw Exclusive
C14N signature transform
13:52:43.424 - DEBUG
[org.opensaml.common.binding.security.SAMLProtocolMessageXMLSignatureSecurityPolicyRule:124]
- Attempting to verify signature on signed SAML protocol message using
context issuer message type:
{urn:oasis:names:tc:SAML:2.0:protocol}AuthnRequest
13:52:43.428 - DEBUG [org.opensaml.security.MetadataCredentialResolver:157]
- Forcing on-demand metadata provider refresh if necessary
13:52:43.430 - DEBUG [org.opensaml.security.MetadataCredentialResolver:205]
- Attempting to retrieve credentials from cache using index:
[mySP,{urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor,urn:oasis:names:tc:SAML:2.0:protocol,SIGNING]
13:52:43.430 - TRACE [org.opensaml.security.MetadataCredentialResolver:208]
- Read lock over cache acquired
13:52:43.430 - TRACE [org.opensaml.security.MetadataCredentialResolver:219]
- Read lock over cache released
13:52:43.431 - DEBUG [org.opensaml.security.MetadataCredentialResolver:222]
- Unable to retrieve credentials from cache using index:
[mySP,{urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor,urn:oasis:names:tc:SAML:2.0:protocol,SIGNING]
13:52:43.431 - DEBUG [org.opensaml.security.MetadataCredentialResolver:242]
- Attempting to retrieve credentials from metadata for entity: mySP
13:52:43.431 - DEBUG [org.opensaml.security.MetadataCredentialResolver:314]
- Retrieving metadata for entity 'mySP' in role
'{urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor' for protocol
'urn:oasis:names:tc:SAML:2.0:protocol'
13:52:43.431 - DEBUG
[org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:254] -
Checking child metadata provider for entity descriptor with entity ID: mySP
13:52:43.432 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:509] -
Searching for entity descriptor with an entity ID of mySP
13:52:43.432 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:522] -
Metadata root is an entity descriptor, checking if it's the one we're
looking for.
13:52:43.432 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:529] - Found
entity descriptor for entity with ID mySP but it is no longer valid,
skipping it.
13:52:43.432 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:250] -
Metadata document did not contain a descriptor for entity mySP
13:52:43.432 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:317] -
Metadata document did not contain any role descriptors of type
{urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor for entity mySP
13:52:43.432 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:286] -
Metadata document does not contain a role of type
{urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor supporting protocol
urn:oasis:names:tc:SAML:2.0:protocol for entity mySP
13:52:43.433 - DEBUG
[org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:254] -
Checking child metadata provider for entity descriptor with entity ID: mySP
13:52:43.433 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:509] -
Searching for entity descriptor with an entity ID of mySP
13:52:43.433 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:513] - Entity
descriptor for the ID mySP was found in index cache, returning
13:52:43.433 - TRACE [org.opensaml.security.MetadataCredentialResolver:344]
- Write lock over cache acquired
13:52:43.434 - DEBUG [org.opensaml.security.MetadataCredentialResolver:347]
- Added new credential collection to cache with key:
[mySP,{urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor,urn:oasis:names:tc:SAML:2.0:protocol,SIGNING]
13:52:43.434 - TRACE [org.opensaml.security.MetadataCredentialResolver:350]
- Write lock over cache released
13:52:43.439 - DEBUG
[org.opensaml.xml.security.credential.criteria.EvaluableCredentialCriteriaRegistry:187]
- Loading default evaluable credential criteria mappings
13:52:43.441 - DEBUG
[org.opensaml.xml.security.credential.criteria.EvaluableCredentialCriteriaRegistry:130]
- Registering class
org.opensaml.xml.security.credential.criteria.EvaluableKeyAlgorithmCredentialCriteria
as evaluator for class
org.opensaml.xml.security.criteria.KeyAlgorithmCriteria
13:52:43.442 - DEBUG
[org.opensaml.xml.security.credential.criteria.EvaluableCredentialCriteriaRegistry:130]
- Registering class
org.opensaml.xml.security.credential.criteria.EvaluableKeyLengthCredentialCriteria
as evaluator for class org.opensaml.xml.security.criteria.KeyLengthCriteria
13:52:43.443 - DEBUG
[org.opensaml.xml.security.credential.criteria.EvaluableCredentialCriteriaRegistry:130]
- Registering class
org.opensaml.xml.security.credential.criteria.EvaluableX509SubjectKeyIdentifierCredentialCriteria
as evaluator for class
org.opensaml.xml.security.x509.X509SubjectKeyIdentifierCriteria
13:52:43.444 - DEBUG
[org.opensaml.xml.security.credential.criteria.EvaluableCredentialCriteriaRegistry:130]
- Registering class
org.opensaml.xml.security.credential.criteria.EvaluablePublicKeyCredentialCriteria
as evaluator for class org.opensaml.xml.security.criteria.PublicKeyCriteria
13:52:43.445 - DEBUG
[org.opensaml.xml.security.credential.criteria.EvaluableCredentialCriteriaRegistry:130]
- Registering class
org.opensaml.xml.security.credential.criteria.EvaluableX509IssuerSerialCredentialCriteria
as evaluator for class
org.opensaml.xml.security.x509.X509IssuerSerialCriteria
13:52:43.446 - DEBUG
[org.opensaml.xml.security.credential.criteria.EvaluableCredentialCriteriaRegistry:130]
- Registering class
org.opensaml.xml.security.credential.criteria.EvaluableUsageCredentialCriteria
as evaluator for class org.opensaml.xml.security.criteria.UsageCriteria
13:52:43.447 - DEBUG
[org.opensaml.xml.security.credential.criteria.EvaluableCredentialCriteriaRegistry:130]
- Registering class
org.opensaml.xml.security.credential.criteria.EvaluableEntityIDCredentialCriteria
as evaluator for class org.opensaml.xml.security.criteria.EntityIDCriteria
13:52:43.448 - DEBUG
[org.opensaml.xml.security.credential.criteria.EvaluableCredentialCriteriaRegistry:130]
- Registering class
org.opensaml.xml.security.credential.criteria.EvaluableKeyNameCredentialCriteria
as evaluator for class org.opensaml.xml.security.criteria.KeyNameCriteria
13:52:43.449 - DEBUG
[org.opensaml.xml.security.credential.criteria.EvaluableCredentialCriteriaRegistry:130]
- Registering class
org.opensaml.xml.security.credential.criteria.EvaluableX509SubjectNameCredentialCriteria
as evaluator for class
org.opensaml.xml.security.x509.X509SubjectNameCriteria
13:52:43.449 - DEBUG
[org.opensaml.xml.security.credential.criteria.EvaluableCredentialCriteriaRegistry:73]
- Registry located evaluable criteria class
org.opensaml.xml.security.credential.criteria.EvaluableUsageCredentialCriteria
for criteria class org.opensaml.xml.security.criteria.UsageCriteria
13:52:43.449 - DEBUG
[org.opensaml.xml.security.credential.criteria.EvaluableCredentialCriteriaRegistry:73]
- Registry located evaluable criteria class
org.opensaml.xml.security.credential.criteria.EvaluableEntityIDCredentialCriteria
for criteria class org.opensaml.xml.security.criteria.EntityIDCriteria
13:52:43.450 - DEBUG
[org.opensaml.xml.security.credential.criteria.EvaluableCredentialCriteriaRegistry:73]
- Registry located evaluable criteria class
org.opensaml.xml.security.credential.criteria.EvaluableKeyAlgorithmCredentialCriteria
for criteria class org.opensaml.xml.security.criteria.KeyAlgorithmCriteria
13:52:43.450 - DEBUG
[org.opensaml.xml.security.credential.criteria.EvaluableCredentialCriteriaRegistry:104]
- Registry could not locate evaluable criteria for criteria class
org.opensaml.security.MetadataCriteria
13:52:43.451 - DEBUG
[org.opensaml.xml.signature.impl.BaseSignatureTrustEngine:91] - Attempting
to verify signature and establish trust using KeyInfo-derived credentials
13:52:43.451 - DEBUG
[org.opensaml.xml.signature.impl.BaseSignatureTrustEngine:111] - Signature
contained no KeyInfo element, could not resolve verification credentials
13:52:43.451 - DEBUG
[org.opensaml.xml.signature.impl.BaseSignatureTrustEngine:114] - Failed to
verify signature and/or establish trust using any KeyInfo-derived
credentials
13:52:43.451 - DEBUG
[org.opensaml.xml.signature.impl.ExplicitKeySignatureTrustEngine:106] -
Attempting to verify signature using trusted credentials
13:52:43.452 - DEBUG
[org.opensaml.xml.signature.impl.ExplicitKeySignatureTrustEngine:114] -
Failed to verify signature using either KeyInfo-derived or directly trusted
credentials
13:52:43.453 - DEBUG
[org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:254] -
Checking child metadata provider for entity descriptor with entity ID: mySP
13:52:43.454 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:509] -
Searching for entity descriptor with an entity ID of mySP
13:52:43.454 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:522] -
Metadata root is an entity descriptor, checking if it's the one we're
looking for.
13:52:43.454 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:529] - Found
entity descriptor for entity with ID mySP but it is no longer valid,
skipping it.
13:52:43.454 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:250] -
Metadata document did not contain a descriptor for entity mySP
13:52:43.454 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:317] -
Metadata document did not contain any role descriptors of type
{urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor for entity mySP
13:52:43.455 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:286] -
Metadata document does not contain a role of type
{urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor supporting protocol
urn:oasis:names:tc:SAML:2.0:protocol for entity mySP
13:52:43.455 - DEBUG
[org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:254] -
Checking child metadata provider for entity descriptor with entity ID: mySP
13:52:43.455 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:509] -
Searching for entity descriptor with an entity ID of mySP
13:52:43.455 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:513] - Entity
descriptor for the ID mySP was found in index cache, returning
13:52:43.455 - DEBUG
[org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:254] -
Checking child metadata provider for entity descriptor with entity ID: mySP
13:52:43.456 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:509] -
Searching for entity descriptor with an entity ID of mySP
13:52:43.456 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:522] -
Metadata root is an entity descriptor, checking if it's the one we're
looking for.
13:52:43.456 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:529] - Found
entity descriptor for entity with ID mySP but it is no longer valid,
skipping it.
13:52:43.456 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:250] -
Metadata document did not contain a descriptor for entity mySP
13:52:43.456 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:317] -
Metadata document did not contain any role descriptors of type
{urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor for entity mySP
13:52:43.457 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:286] -
Metadata document does not contain a role of type
{urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor supporting protocol
urn:oasis:names:tc:SAML:2.0:protocol for entity mySP
13:52:43.457 - DEBUG
[org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:254] -
Checking child metadata provider for entity descriptor with entity ID: mySP
13:52:43.457 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:509] -
Searching for entity descriptor with an entity ID of mySP
13:52:43.457 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:513] - Entity
descriptor for the ID mySP was found in index cache, returning
13:52:43.458 - DEBUG
[org.opensaml.xml.signature.impl.BaseSignatureTrustEngine:91] - Attempting
to verify signature and establish trust using KeyInfo-derived credentials
13:52:43.458 - DEBUG
[org.opensaml.xml.signature.impl.BaseSignatureTrustEngine:111] - Signature
contained no KeyInfo element, could not resolve verification credentials
13:52:43.458 - DEBUG
[org.opensaml.xml.signature.impl.BaseSignatureTrustEngine:114] - Failed to
verify signature and/or establish trust using any KeyInfo-derived
credentials
13:52:43.459 - DEBUG
[org.opensaml.xml.signature.impl.PKIXSignatureTrustEngine:161] - PKIX
validation of signature failed, unable to resolve valid and trusted signing
key
13:52:43.459 - DEBUG
[org.opensaml.common.binding.security.SAMLProtocolMessageXMLSignatureSecurityPolicyRule:135]
- Validation of protocol message signature failed for context issuer 'mySP',
message type: {urn:oasis:names:tc:SAML:2.0:protocol}AuthnRequest
13:52:43.467 - WARN
[edu.internet2.middleware.shibboleth.idp.ext.ecp.profile.ECPProfileHandler:326]
- Message did not meet security requirements
org.opensaml.ws.security.SecurityPolicyException: Validation of protocol
message signature failed
at
org.opensaml.common.binding.security.SAMLProtocolMessageXMLSignatureSecurityPolicyRule.doEvaluate(SAMLProtocolMessageXMLSignatureSecurityPolicyRule.java:137)
~[opensaml-2.4.1.jar:na]
at
org.opensaml.common.binding.security.SAMLProtocolMessageXMLSignatureSecurityPolicyRule.evaluate(SAMLProtocolMessageXMLSignatureSecurityPolicyRule.java:106)
~[opensaml-2.4.1.jar:na]
at
org.opensaml.ws.security.provider.BasicSecurityPolicy.evaluate(BasicSecurityPolicy.java:50)
~[openws-1.4.1.jar:na]
at
org.opensaml.ws.message.decoder.BaseMessageDecoder.processSecurityPolicy(BaseMessageDecoder.java:110)
~[openws-1.4.1.jar:na]
at
org.opensaml.ws.message.decoder.BaseMessageDecoder.decode(BaseMessageDecoder.java:79)
~[openws-1.4.1.jar:na]
at
org.opensaml.saml2.binding.decoding.BaseSAML2MessageDecoder.decode(BaseSAML2MessageDecoder.java:69)
~[opensaml-2.4.1.jar:na]
at
edu.internet2.middleware.shibboleth.idp.ext.ecp.profile.ECPProfileHandler.decodeRequest(ECPProfileHandler.java:308)
[shibboleth-idp-ext-ecp-1.2.jar:na]
at
edu.internet2.middleware.shibboleth.idp.ext.ecp.profile.ECPProfileHandler.completeAuthenticationRequest(ECPProfileHandler.java:215)
[shibboleth-idp-ext-ecp-1.2.jar:na]
at
edu.internet2.middleware.shibboleth.idp.ext.ecp.profile.ECPProfileHandler.processRequest(ECPProfileHandler.java:193)
[shibboleth-idp-ext-ecp-1.2.jar:na]
at
edu.internet2.middleware.shibboleth.idp.ext.ecp.profile.ECPProfileHandler.processRequest(ECPProfileHandler.java:110)
[shibboleth-idp-ext-ecp-1.2.jar:na]
at
edu.internet2.middleware.shibboleth.common.profile.ProfileRequestDispatcherServlet.service(ProfileRequestDispatcherServlet.java:83)
[shibboleth-common-1.2.1.jar:na]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
[servlet-api.jar:na]
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
[catalina.jar:6.0.29]
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
[catalina.jar:6.0.29]
at
edu.internet2.middleware.shibboleth.idp.util.NoCacheFilter.doFilter(NoCacheFilter.java:49)
[shibboleth-identityprovider-2.2.1.jar:na]
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
[catalina.jar:6.0.29]
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
[catalina.jar:6.0.29]
at
edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter.doFilter(IdPSessionFilter.java:77)
[shibboleth-identityprovider-2.2.1.jar:na]
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
[catalina.jar:6.0.29]
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
[catalina.jar:6.0.29]
at
edu.internet2.middleware.shibboleth.common.log.SLF4JMDCCleanupFilter.doFilter(SLF4JMDCCleanupFilter.java:51)
[shibboleth-common-1.2.1.jar:na]
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
[catalina.jar:6.0.29]
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
[catalina.jar:6.0.29]
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
[catalina.jar:6.0.29]
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
[catalina.jar:6.0.29]
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
[catalina.jar:6.0.29]
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
[catalina.jar:6.0.29]
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
[catalina.jar:6.0.29]
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
[catalina.jar:6.0.29]
at
org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:857)
[tomcat-coyote.jar:6.0.29]
at
org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:588)
[tomcat-coyote.jar:6.0.29]
at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
[tomcat-coyote.jar:6.0.29]
at java.lang.Thread.run(Thread.java:619) [na:1.6.0_21]


--
View this message in context: http://shibboleth.1660669.n2.nabble.com/IdP-to-ECP-Validation-of-signature-failed-on-AuthnRequest-tp6209223p6209223.html
Sent from the Shibboleth - Users mailing list archive at Nabble.com.

Brent Putman

unread,
Mar 25, 2011, 7:22:58 PM3/25/11
to shibbole...@internet2.edu

On 3/25/11 5:25 PM, Kobe wrote:
> I tried these avenues:
> a) import the certificate of the SP in the keystore and cacerts used by
> the IdP's tomcat

That keystore is irrelevant in SAML trust processing. Did you see
something that led you to believe this to be the case?


> b) made sure that the signing key of the SP was included in the SP
> metadata in the IdP


This is, 99.9 % of the time, the cause of this kind of signature
validation error - the IdP does not have the (valid) signing key for the
SP. That appears to be the case here. See below...

> I am producing the logs below. From the excerpt below, it appears that IdP
> tries to use
> the KeyInfo embedded in the signature for validation. Is there a way to
> force the IdP
> to no force signature verification?

Yes, you can remove the signature-related security policy rule(s) from
the relying-party.xml. But you really shouldn't do that, that's just
bypassing the problem not solving it.


> 13:52:43.417 - TRACE
> [org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:529] - Found
> entity descriptor for entity with ID mySP but it is no longer valid,
> skipping it.

I believe the IdP is failing to resolve the SP's key because the
metadata that the IdP has for the SP is expired. The key is probably
present and correct (at least you say it is), but the IdP will not use
it if the metadata is expired. You need to check the validUntil dates
on the Entity- and EntitiesDescriptors that are relevant to the SP's
metadata.


Kobe

unread,
Mar 25, 2011, 8:51:15 PM3/25/11
to shibbole...@internet2.edu
hi Brent,

would it be correct to say that the key used for signature verification is
derived from the KeyInfo if specified in the incoming message ; and if not
specified, the IdP looks for the key of the SP in the SP metadata?

>That keystore is irrelevant in SAML trust processing.
>Did you see something that led you to believe this to be the case?

I host the IdP in a servlet container which uses the cacert for hosting the
certificates it trusts - I thought it IdP might be relying on the cacerts to
locate the SP's public key. Anyway it was a long shot..

>>made sure that the signing key of the SP was included in the SP
>>metadata in the IdP

>This is, 99.9 % of the time, the cause of this kind of signature
>validation error - the IdP does not have the (valid) signing key for
the
>SP. That appears to be the case here.

>I believe the IdP is failing to resolve the SP's key because the


> metadata that the IdP has for the SP is expired. The key is probably
>present and correct (at least you say it is), but the IdP will not use

>t if the metadata is expired. You need to check the validUntil dates
>on the Entity- and EntitiesDescriptors that are relevant to the SP's
>metadata.

I have a simple definition of RP:


Is there a default expiry period? The documentation at


https://spaces.internet2.edu/display/SHIB2/IdPMetadataProvider#IdPMetadataProvider-FilesystemMetadataProvider

did not specify a way by which I could specify a lifetime for my metadata.

thanks!

/K


Brent Putman wrote:
>
> On 3/25/11 5:25 PM, Kobe wrote:

> &gt; I tried these avenues:
> &gt; a) import the certificate of the SP in the keystore and cacerts
> used by
> &gt; the IdP's tomcat


>
> That keystore is irrelevant in SAML trust processing. Did you see
> something that led you to believe this to be the case?
>
>

> &gt; b) made sure that the signing key of the SP was included in the SP
> &gt; metadata in the IdP


>
>
> This is, 99.9 % of the time, the cause of this kind of signature
> validation error - the IdP does not have the (valid) signing key for the
> SP. That appears to be the case here. See below...
>
>
>

> &gt; I am producing the logs below. From the excerpt below, it appears
> that IdP
> &gt; tries to use
> &gt; the KeyInfo embedded in the signature for validation. Is there a way
> to
> &gt; force the IdP
> &gt; to no force signature verification?


>
> Yes, you can remove the signature-related security policy rule(s) from
> the relying-party.xml. But you really shouldn't do that, that's just
> bypassing the problem not solving it.
>
>

> &gt; 13:52:43.417 - TRACE
> &gt; [org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:529] -
> Found
> &gt; entity descriptor for entity with ID mySP but it is no longer valid,
> &gt; skipping it.


>
> I believe the IdP is failing to resolve the SP's key because the
> metadata that the IdP has for the SP is expired. The key is probably
> present and correct (at least you say it is), but the IdP will not use
> it if the metadata is expired. You need to check the validUntil dates
> on the Entity- and EntitiesDescriptors that are relevant to the SP's
> metadata.
>


--
View this message in context: http://shibboleth.1660669.n2.nabble.com/IdP-to-ECP-Validation-of-signature-failed-on-AuthnRequest-tp6209223p6209653.html

Cantor, Scott E.

unread,
Mar 25, 2011, 11:58:25 PM3/25/11
to <shibboleth-users@internet2.edu>, shibbole...@internet2.edu
On Mar 26, 2011, at 1:47 AM, "Kobe" <Kbbry...@gmail.com> wrote:
> would it be correct to say that the key used for signature verification is
> derived from the KeyInfo if specified in the incoming message ; and if not
> specified, the IdP looks for the key of the SP in the SP metadata?

Not really, but it's in the ballpark.

> Is there a default expiry period? The documentation at
>
> https://spaces.internet2.edu/display/SHIB2/IdPMetadataProvider#IdPMetadataProvider-FilesystemMetadataProvider
>
> did not specify a way by which I could specify a lifetime for my metadata.

The lifetime of the metadata is up to the metadata.

-- Scott
>

Brent Putman

unread,
Mar 26, 2011, 12:46:25 AM3/26/11
to shibbole...@internet2.edu

On 3/25/11 8:51 PM, Kobe wrote:
> hi Brent,
>
> would it be correct to say that the key used for signature verification is
> derived from the KeyInfo if specified in the incoming message ; and if not
> specified, the IdP looks for the key of the SP in the SP metadata?

As Scott said, sort of. The basis for trust *always* comes from what is
in metadata. If the KeyInfo is present, the the key there is used to
validate the signature, but that is just an optimization, to avoid
validating the signature with every key you have in metadata for the
SP. The key from Signature/KeyInfo still has to be matched against what
is in metadata. If the key from Signature/KeyInfo successfully
cryptographically validates the signature, but can't be matched against
the key resolved from metadata, then the validation is considered to
have failed by the trust engine. The Signature/KeyInfo is a hint, and
is not trusted, hopefully for obvious reasons.

If the Signature/KeyInfo isn't present (or isn't valid), then the trust
engine just loops over and tries all the keys for the SP as specified in
metadata.


> I have a simple definition of RP:
>
>
>
>
> Is there a default expiry period? The documentation at
>
>
> https://spaces.internet2.edu/display/SHIB2/IdPMetadataProvider#IdPMetadataProvider-FilesystemMetadataProvider
>
> did not specify a way by which I could specify a lifetime for my metadata.

You need to look at the actual metadata document, not the IdP config.
The EntityDescriptor and EntitiesDescriptors elements in the metadata
can carry a validUntil attribute which limits their validity.

Kobe

unread,
Mar 26, 2011, 7:49:48 PM3/26/11
to shibbole...@internet2.edu
Thanks - it turned out that this was the 99.99% case you alluded to -
my metadata had a stale Keyinfo (after depositing the metadata,
the key on the SP was changed).

thanks for helping me resolve this problem. I just have two questions:
the metadata of my service provider does not explicitly identify a lifetime
-
do the SAML2 specs identify a default lifetime for a service provider
metadata or dos Shibboleth IdP have a default?

Also, is it meaningful for the IdP to disable checking of signatures even if
the SP mandated it? If so, what is the setting RelyingParty setting?

thanks,

/K

--
View this message in context: http://shibboleth.1660669.n2.nabble.com/IdP-to-ECP-Validation-of-signature-failed-on-AuthnRequest-tp6209223p6211536.html

Tom Scavo

unread,
Mar 26, 2011, 8:40:18 PM3/26/11
to shibbole...@internet2.edu, Kobe
On Sat, Mar 26, 2011 at 7:49 PM, Kobe <Kbbry...@gmail.com> wrote:
>
> the metadata of my service provider does not explicitly identify a lifetime
> -
> do the SAML2 specs identify a default lifetime for a service provider
> metadata or dos Shibboleth IdP have a default?

This is 100% deployment specific. How you specify your metadata life
cycle is completely between you and your partner (or the federation,
of one's involved).

Tom

Reply all
Reply to author
Forward
0 new messages