Help ? Non-federation, custom meta-data ?
Robert Roll
Robert.Roll at utah.edu
Thu Jul 18 13:08:03 EDT 2013
We have a new SAS Service provider HireVue. They seem to be able to do either SP initiated or IDP initiated login.
I managed to get their meta-data to seem to work for the IDP initiated login, but the SP initiated is pretty confusing
to me.. It looks like it tries to add meta-data on the fly ? In any case I get the following error:
Message did not meet security requirements
org.opensaml.ws.security.SecurityPolicyException: Validation of protocol message signature failed
below are the logs I believe are associated with this request ? I don't know if the "No session associated with session ID"
have anything to do with this or not, but they were in the time frame, so I included them .
Any insight would be much appreciated ?
Thanks,
Robert
10:34:19.961 - DEBUG [edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter:160] - No session associated with session ID YmEzODNlMTE3MjdlY2Y1MTQwOTc4MTM2MzQ2MmQxOTRlMjZmZDM5YzlhNTdmNjI2YmRlN2QyZjcxMjVmZGYxYQ== - session must have timed out
10:34:19.963 - INFO [Shibboleth-Access:74] - 20130718T163419Z|155.98.206.24|testidp.acs.utah.edu:443|/profile/SAML2/POST/SSO|
10:34:19.963 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /SAML2/POST/SSO
10:34:19.964 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler
10:34:19.965 - DEBUG [edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:325] - LoginContext key cookie was not present in request
10:34:19.965 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:186] - Incoming request does not contain a login context, processing as first leg of request
10:34:19.966 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:337] - Decoding message with decoder binding 'urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST'
10:34:19.976 - DEBUG [PROTOCOL_MESSAGE:113] -
<?xml version="1.0" encoding="UTF-8"?><ns0:AuthnRequest xmlns:ns0="urn:oasis:names:tc:SAML:2.0:protocol" Destination="https://testidp.acs.utah.edu/idp/profile/SAML2/POST/SSO" ID="id-2932874784652d36cb7eb853551c0471" IssueInstant="2013-07-18T16:34:14Z" ProtocolBinding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST" Version="2.0" xmlns:ns1="urn:oasis:names:tc:SAML:2.0:assertion" xmlns:ns2="http://www.w3.org/2000/09/xmldsig#">
<ns1:Issuer Format="urn:oasis:names:tc:SAML:2.0:nameid-format:entity">urn:federation:hirevue.com:saml:sp:staging</ns1:Issuer>
<ns2:Signature Id="Signature1">
<ns2:SignedInfo>
<ns2:CanonicalizationMethod Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"/>
<ns2:SignatureMethod Algorithm="http://www.w3.org/2000/09/xmldsig#rsa-sha1"/>
<ns2:Reference URI="#id-2932874784652d36cb7eb853551c0471">
<ns2:Transforms>
<ns2:Transform Algorithm="http://www.w3.org/2000/09/xmldsig#enveloped-signature"/>
<ns2:Transform Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"/>
</ns2:Transforms>
<ns2:DigestMethod Algorithm="http://www.w3.org/2000/09/xmldsig#sha1"/>
<ns2:DigestValue>Ia5DC4IjkelCafqy3xBU8A/w/nE=</ns2:DigestValue>
</ns2:Reference>
</ns2:SignedInfo>
<ns2:SignatureValue>ik+4ybIJA/gNeNL5Xtv6oqxJsSRLK+rzEk5JPblMQfC7xGPQ3GOT+cJHDxkIHU2Y
/PfP80zvtB/t89fItUN9Hs0p738p2siXTcDc26t1K9oEnRpYEirzVIBHEZ/DJTib
+UveA4afVzkSB/0YuRRNLLVcVVmrUfc28GnBA/nREgZatCcSEbxDPIDPlon79K9k
4J1InI6sr43UTv+bxT+qcvdMk13ags+X/Bfo5moBQ+Jcylp/FYOWkwbt3BYkoizE
JH315+OkruiREWDpMK2eNFPqSxlEXrWbqyEazmdNav67o1fjYrj/RspOyBbJy0Bz
6fqJAWj6jsv64RhhowtNLw==</ns2:SignatureValue>
<ns2:KeyInfo>
<ns2:X509Data>
<ns2:X509Certificate>MIIDtTCCAp2gAwIBAgIJALp4unzXVm/zMA0GCSqGSIb3DQEBBQUAMHExCzAJBgNVBAYTAlVTMQ0wCwYDVQQIDARVdGFoMRUwEwYDVQQHDAxTb3V0aCBKb3JkYW4xFjAUBgNVBAoMDUhpcmVWdWUsIEluYy4xJDAiBgNVBAMMG2ZlZGVyYXRlZHNlY3VyaXR5LnN0Z2h2LmNvbTAeFw0xMzA2MjYyMDUwMDdaFw0xNDA2MjYyMDUwMDdaMHExCzAJBgNVBAYTAlVTMQ0wCwYDVQQIDARVdGFoMRUwEwYDVQQHDAxTb3V0aCBKb3JkYW4xFjAUBgNVBAoMDUhpcmVWdWUsIEluYy4xJDAiBgNVBAMMG2ZlZGVyYXRlZHNlY3VyaXR5LnN0Z2h2LmNvbTCCASIwDQYJKoZIhvcNAQEBBQADggEPADCCAQoCggEBAKHNUAOmnf48gu5Ddvsf7H139aL8fXUdMwtTu6I9qqJ8EUL2reITBPN2SPLLo9EoR2oIlPGJWgpp3CJUruN/PHH1orqWFnUb7Uq+zvoAXAXKIjbtJ62txpt1PDBpMjwR50xGcvPAX3Vjp9sHFT3qoN8zb15AOIKN6QWkQQx2vLYUpnegC3yLYen1u13U7ANzfome8obbtORFrk+g60+gHtMvXQxsXir5CEu18KoH0gzY/MAJgnkOYzyjD8QKAqeoxoDOMmZ1E9ADSom4dJr7k4qqwGsZJ0j684DhM53TF7pqncy7llOdoQNZysMKhBid/jFSsEtqPsYoo6cvsdCJHJECAwEAAaNQME4wHQYDVR0OBBYEFIktxReDKfdxzVQZK97Pw2az1aXVMB8GA1UdIwQYMBaAFIktxReDKfdxzVQZK97Pw2az1aXVMAwGA1UdEwQFMAMBAf8wDQYJKoZIhvcNAQEFBQADggEBADtd5MIW/xsqyiY7cgrBQYLpPKSNdRhz6m76xjhPc1HCvcnAl0gYhBXwR7PZ78SXnK7/CUxf0xNl6t3U448o9uqBdvvrpiQHDCw4WeBeENdlxK5kixM33+QxvidzE77cf2hrBMhbmgfg0mQDUuZLQVnYnU7OFs162OpRXurVEsHl19jHRNGNSNhiNwln8NdPC6HomDie8zFgTfeycSzESbcudmzSMmivpu1G9YK/YOz25WAZ1HPSo4wcgNN0mm4z+v6cbqIF4uRC8XaxTDYa4N8k5ksZny0xaOkGSb+MJZxYIu6V0QTL43eoxXrB9H4URnTnie4NFYT7Lv86HDW5DbY=</ns2:X509Certificate>
</ns2:X509Data>
</ns2:KeyInfo>
</ns2:Signature>
<ns0:NameIDPolicy AllowCreate="true" Format="urn:oasis:names:tc:SAML:1.1:nameid-format:unspecified"/>
</ns0:AuthnRequest>
10:34:19.977 - DEBUG [edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:128] - Looking up relying party configuration for urn:federation:hirevue.com:saml:sp:staging
10:34:19.978 - DEBUG [edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:130] - Custom relying party configuration found for urn:federation:hirevue.com:saml:sp:staging
10:34:19.992 - DEBUG [edu.internet2.middleware.shibboleth.common.security.MetadataPKIXValidationInformationResolver:189] - Forcing on-demand metadata provider refresh if necessary
10:34:19.994 - DEBUG [edu.internet2.middleware.shibboleth.common.security.MetadataPKIXValidationInformationResolver:601] - Attempting to retrieve trusted names from cache using index: [urn:federation:hirevue.com:saml:sp:staging,{urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor,urn:oasis:names:tc:SAML:2.0:protocol,SIGNING]
10:34:19.994 - DEBUG [edu.internet2.middleware.shibboleth.common.security.MetadataPKIXValidationInformationResolver:604] - Read lock over cache acquired
10:34:19.995 - DEBUG [edu.internet2.middleware.shibboleth.common.security.MetadataPKIXValidationInformationResolver:615] - Read lock over cache released
10:34:19.996 - DEBUG [edu.internet2.middleware.shibboleth.common.security.MetadataPKIXValidationInformationResolver:618] - Unable to retrieve trusted names from cache using index: [urn:federation:hirevue.com:saml:sp:staging,{urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor,urn:oasis:names:tc:SAML:2.0:protocol,SIGNING]
10:34:19.997 - DEBUG [edu.internet2.middleware.shibboleth.common.security.MetadataPKIXValidationInformationResolver:438] - Attempting to retrieve trusted names for PKIX validation from metadata for entity: urn:federation:hirevue.com:saml:sp:staging
10:34:19.998 - DEBUG [edu.internet2.middleware.shibboleth.common.security.MetadataPKIXValidationInformationResolver:672] - Write lock over cache acquired
10:34:19.999 - DEBUG [edu.internet2.middleware.shibboleth.common.security.MetadataPKIXValidationInformationResolver:675] - Added new PKIX info to entity cache with key: [urn:federation:hirevue.com:saml:sp:staging,{urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor,urn:oasis:names:tc:SAML:2.0:protocol,SIGNING]
10:34:20.000 - DEBUG [edu.internet2.middleware.shibboleth.common.security.MetadataPKIXValidationInformationResolver:678] - Write lock over cache released
10:34:20.001 - DEBUG [edu.internet2.middleware.shibboleth.common.security.MetadataPKIXValidationInformationResolver:152] - Forcing on-demand metadata provider refresh if necessary
10:34:20.002 - DEBUG [edu.internet2.middleware.shibboleth.common.security.MetadataPKIXValidationInformationResolver:531] - Attempting to retrieve PKIX validation info from cache using index: [urn:federation:hirevue.com:saml:sp:staging,{urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor,urn:oasis:names:tc:SAML:2.0:protocol,SIGNING]
10:34:20.002 - DEBUG [edu.internet2.middleware.shibboleth.common.security.MetadataPKIXValidationInformationResolver:534] - Read lock over cache acquired
10:34:20.003 - DEBUG [edu.internet2.middleware.shibboleth.common.security.MetadataPKIXValidationInformationResolver:545] - Read lock over cache released
10:34:20.004 - DEBUG [edu.internet2.middleware.shibboleth.common.security.MetadataPKIXValidationInformationResolver:548] - Unable to retrieve PKIX validation info from cache using index: [urn:federation:hirevue.com:saml:sp:staging,{urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor,urn:oasis:names:tc:SAML:2.0:protocol,SIGNING]
10:34:20.005 - DEBUG [edu.internet2.middleware.shibboleth.common.security.MetadataPKIXValidationInformationResolver:259] - Attempting to retrieve PKIX validation info from metadata for entity: urn:federation:hirevue.com:saml:sp:staging
10:34:20.006 - DEBUG [edu.internet2.middleware.shibboleth.common.security.MetadataPKIXValidationInformationResolver:631] - Write lock over cache acquired
10:34:20.007 - DEBUG [edu.internet2.middleware.shibboleth.common.security.MetadataPKIXValidationInformationResolver:634] - Added new PKIX info to entity cache with key: [urn:federation:hirevue.com:saml:sp:staging,{urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor,urn:oasis:names:tc:SAML:2.0:protocol,SIGNING]
10:34:20.008 - DEBUG [edu.internet2.middleware.shibboleth.common.security.MetadataPKIXValidationInformationResolver:637] - Write lock over cache released
10:34:20.020 - WARN [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:377] - 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:138) ~[opensaml-2.5.3.jar:na]
at org.opensaml.common.binding.security.SAMLProtocolMessageXMLSignatureSecurityPolicyRule.evaluate(SAMLProtocolMessageXMLSignatureSecurityPolicyRule.java:107) ~[opensaml-2.5.3.jar:na]
at org.opensaml.ws.security.provider.BasicSecurityPolicy.evaluate(BasicSecurityPolicy.java:51) ~[openws-1.4.4.jar:na]
at org.opensaml.ws.message.decoder.BaseMessageDecoder.processSecurityPolicy(BaseMessageDecoder.java:132) ~[openws-1.4.4.jar:na]
at org.opensaml.ws.message.decoder.BaseMessageDecoder.decode(BaseMessageDecoder.java:83) ~[openws-1.4.4.jar:na]
at org.opensaml.saml2.binding.decoding.BaseSAML2MessageDecoder.decode(BaseSAML2MessageDecoder.java:70) ~[opensaml-2.5.3.jar:na]
at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.decodeRequest(SSOProfileHandler.java:357) [shibboleth-identityprovider-2.3.8.jar:na]
at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.performAuthentication(SSOProfileHandler.java:209) [shibboleth-identityprovider-2.3.8.jar:na]
at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.processRequest(SSOProfileHandler.java:187) [shibboleth-identityprovider-2.3.8.jar:na]
at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.processRequest(SSOProfileHandler.java:88) [shibboleth-identityprovider-2.3.8.jar:na]
at edu.internet2.middleware.shibboleth.common.profile.ProfileRequestDispatcherServlet.service(ProfileRequestDispatcherServlet.java:84) [shibboleth-common-1.3.7.jar:na]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:717) [tomcat6-servlet-2.5-api-6.0.24.jar:na]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) [catalina-6.0.24.jar:na]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.24.jar:na]
at edu.internet2.middleware.shibboleth.idp.util.NoCacheFilter.doFilter(NoCacheFilter.java:50) [shibboleth-identityprovider-2.3.8.jar:na]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina-6.0.24.jar:na]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.24.jar:na]
at edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter.doFilter(IdPSessionFilter.java:81) [shibboleth-identityprovider-2.3.8.jar:na]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina-6.0.24.jar:na]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.24.jar:na]
at edu.internet2.middleware.shibboleth.common.log.SLF4JMDCCleanupFilter.doFilter(SLF4JMDCCleanupFilter.java:52) [shibboleth-common-1.3.7.jar:na]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina-6.0.24.jar:na]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.24.jar:na]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219) [catalina-6.0.24.jar:na]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [catalina-6.0.24.jar:na]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [catalina-6.0.24.jar:na]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) [catalina-6.0.24.jar:na]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [catalina-6.0.24.jar:na]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298) [catalina-6.0.24.jar:na]
at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190) [tomcat-coyote-6.0.24.jar:na]
at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291) [tomcat-coyote-6.0.24.jar:na]
at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:769) [tomcat-coyote-6.0.24.jar:na]
at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:698) [tomcat-coyote-6.0.24.jar:na]
at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:891) [tomcat-coyote-6.0.24.jar:na]
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690) [tomcat-coyote-6.0.24.jar:na]
at java.lang.Thread.run(Thread.java:679) [na:1.6.0_24]
10:34:20.024 - DEBUG [edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:325] - LoginContext key cookie was not present in request
10:34:20.024 - DEBUG [edu.internet2.middleware.shibboleth.idp.ui.ServiceContactTag:177] - No relying party, nothing to display
10:34:20.297 - DEBUG [edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter:160] - No session associated with session ID YmEzODNlMTE3MjdlY2Y1MTQwOTc4MTM2MzQ2MmQxOTRlMjZmZDM5YzlhNTdmNjI2YmRlN2QyZjcxMjVmZGYxYQ== - session must have timed out
More information about the users
mailing list