Initial Setup -- Cannot Get SP and IDP Talking

Mon Nov 25 04:10:10 EST 2013

OK, figured out debug logging on SP. Here is the debug version of the SP side of it. Again, looks like it decrypts message OK but doesn't know what to do with it:

2013-11-25 12:05:36 DEBUG OpenSAML.MessageDecoder.SAML2 [2]: message from (https://idpt.qatar-med.cornell.edu:8443/idp/shibboleth)
2013-11-25 12:05:36 DEBUG OpenSAML.MessageDecoder.SAML2 [2]: searching metadata for message issuer...
2013-11-25 12:05:36 DEBUG OpenSAML.SecurityPolicyRule.MessageFlow [2]: evaluating message flow policy (replay checking on, expiration 60)
2013-11-25 12:05:36 DEBUG XMLTooling.StorageService [2]: inserted record (_80f4c1df42380fb62acfa6dfce839b31) in context (MessageFlow) with expiration (1385370575)
2013-11-25 12:05:36 DEBUG Shibboleth.SSO.SAML2 [2]: processing message against SAML 2.0 SSO profile
2013-11-25 12:05:36 DEBUG XMLTooling.CredentialCriteria [2]: key algorithm didn't match ('AES' != 'RSA')
2013-11-25 12:05:36 DEBUG Shibboleth.SSO.SAML2 [2]: decrypted Assertion: <saml2:Assertion xmlns:saml2="urn:oasis:names:tc:SAML:2.0:assertion" ID="_4d16eaa7eb0a62bd986db112e23330ec" IssueInstant="2013-11-25T09:05:35.906Z" Version="2.0"><saml2:Issuer Format="urn:oasis:names:tc:SAML:2.0:nameid-format:entity">https://idpt.qatar-med.cornell.edu:8443/idp/shibboleth</saml2:Issuer><ds:Signature xmlns:ds="http://www.w3.org/2000/09/xmldsig#"><ds:SignedInfo><ds:CanonicalizationMethod Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"/><ds:SignatureMethod Algorithm="http://www.w3.org/2000/09/xmldsig#rsa-sha1"/><ds:Reference URI="#_4d16eaa7eb0a62bd986db112e23330ec"><ds:Transforms><ds:Transform Algorithm="http://www.w3.org/2000/09/xmldsig#enveloped-signature"/><ds:Transform Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"/></ds:Transforms><ds:DigestMethod Algorithm="http://www.w3.org/2000/09/xmldsig#sha1"/><ds:DigestValue>TO8z+MRVauzVnq8vagmo2zDykdo=</ds:DigestValue></ds:Reference></ds:SignedInfo><ds:SignatureValue>jIbFxjk77RF0Q16aLfSL/xieGKIucO5/Jo6cUEGIEdE+iDaUSdr6v5UWRim+oHKldM/iqwgDh2wonWww6dLnr9T0bdAJfd4RwC9a9w3SjYorfCL0lul5Rl3z0TIds5eL7phIieZEy8B13GVkoW4KtCCAqFi4KkRssXicE7dQenEa/b6uquI31+gMaTdW58iU6R0JYBE3zlXbe9cwKdC0wKtIHVNkEwtxb0LaUEWqo2UJxKp46JxDNHWQL6sJWlc+ZJoMFZG+xmT/KY/Iu663xyLMOGRTr+zBi7Spemhgf48rLhpyDUkdP6fW8qVOEms74zSfCF3HR1K9DBrpeIbgIA==</ds:SignatureValue><ds:KeyInfo><ds:X509Data><ds:X509Certificate>MIIDVDCCAjygAwIBAgIVAJ8yKHKyn+jtv2SGeaU0ssFAVLaYMA0GCSqGSIb3DQEBBQUAMCUxIzAh
BgNVBAMTGmlkcHQucWF0YXItbWVkLmNvcm5lbGwuZWR1MB4XDTEzMTExNDA1MzIwNloXDTMzMTEx
NDA1MzIwNlowJTEjMCEGA1UEAxMaaWRwdC5xYXRhci1tZWQuY29ybmVsbC5lZHUwggEiMA0GCSqG
SIb3DQEBAQUAA4IBDwAwggEKAoIBAQC+Oo5QLdGh0Y4OrLUQjD8jvByohVgExTf8ZHaaFhklpzST
TsgM0H0ObX2+lBE/7T5vmfBBXnbKG5YaGEZXiY+iAM/6PSXynfKXArHmj5yE2tq+Kj3GU3SqYt0R
dVkpy5X8pJxp6PPyowh7yNHa3QnqHfqw+v3Hccey9NVI+YNUWPQPpNH2zTVDePajCNSGyMJWFjuI
Cz8zmKXukZZ69mloZtWLmZLAUF1VDXZija/UBxXSAAXEJNH5bt+3VOk80NpGsfhEyhhKBrdrVJeQ
cE4E11ZwgWPMRq27UJQvl39HjfwMRqSIVPUbby3d/tMqduUz1LaPWEgFR85o2xweDTCJAgMBAAGj
ezB5MFgGA1UdEQRRME+CGmlkcHQucWF0YXItbWVkLmNvcm5lbGwuZWR1hjFodHRwczovL2lkcHQu
cWF0YXItbWVkLmNvcm5lbGwuZWR1L2lkcC9zaGliYm9sZXRoMB0GA1UdDgQWBBRTabVogvg9BMur
5/f86IGwgUoYSzANBgkqhkiG9w0BAQUFAAOCAQEANC2iz+LhfSYxEZPprWKGVj3+y2tROJvHhUdf
CwDzJxEMZelOqDF1uLBfzvx51YU/yG7I53MprvN2m+saFKfr2WxTqyLUhaROESwRbSFH97lpLFQT
8Mz3fZR+bhFCfGT3c/BhErZH63r5aZIZRpJm5vCf6UaL2PYpYtiEC2eMl2Sr7iwCYsiCsKds/E0s
PICmT447oOLMzkFSgy1VP9OjAtqoo7xN5TthGfo8hQ9LgoGE6s4faoBu8mJ+OULd8PE7i5WTtQcJ
7++qq3HEvemQ2Y38G66TtbfXEKquXPC62taHiqxW4outfP3OAHSOvE1x648N5GSI+BtjeJIovqdZ
9w==</ds:X509Certificate></ds:X509Data></ds:KeyInfo></ds:Signature><saml2:Subject><saml2:NameID Format="urn:oasis:names:tc:SAML:2.0:nameid-format:transient" NameQualifier="https://idpt.qatar-med.cornell.edu:8443/idp/shibboleth" SPNameQualifier="https://unixadmin.qatar-med.cornell.edu">_8447b609ae9fcdb3b780a3bf49ade90b</saml2:NameID><saml2:SubjectConfirmation Method="urn:oasis:names:tc:SAML:2.0:cm:bearer"><saml2:SubjectConfirmationData Address="207.162.244.209" InResponseTo="_d9393154b17020f6044a0a70eefff6aa" NotOnOrAfter="2013-11-25T09:10:35.906Z" Recipient="https://unixadmin.qatar-med.cornell.edu/Shibboleth.sso/SAML2/POST"/></saml2:SubjectConfirmation></saml2:Subject><saml2:Conditions NotBefore="2013-11-25T09:05:35.906Z" NotOnOrAfter="2013-11-25T09:10:35.906Z"><saml2:AudienceRestriction><saml2:Audience>https://unixadmin.qatar-med.cornell.edu</saml2:Audience></saml2:AudienceRestriction></saml2:Conditions><saml2:AuthnStatement AuthnInstant="2013-11-25T09:05:35.761Z" SessionIndex="_815ce11ee2b19d24679a898219ffcdc0"><saml2:SubjectLocality Address="207.162.244.209"/><saml2:AuthnContext><saml2:AuthnContextClassRef>urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport</saml2:AuthnContextClassRef></saml2:AuthnContext></saml2:AuthnStatement></saml2:Assertion>
2013-11-25 12:05:36 DEBUG Shibboleth.SSO.SAML2 [2]: extracting issuer from SAML 2.0 assertion
2013-11-25 12:05:36 DEBUG OpenSAML.SecurityPolicyRule.MessageFlow [2]: evaluating message flow policy (replay checking on, expiration 60)
2013-11-25 12:05:36 DEBUG XMLTooling.StorageService [2]: inserted record (_4d16eaa7eb0a62bd986db112e23330ec) in context (MessageFlow) with expiration (1385370575)
2013-11-25 12:05:36 DEBUG OpenSAML.SecurityPolicyRule.BearerConfirmation [2]: assertion satisfied bearer confirmation requirements
2013-11-25 12:05:36 WARN Shibboleth.SSO.SAML2 [2]: detected a problem with assertion: Unable to establish security of incoming assertion.

On Nov 25, 2013, at 8:46 AM, Sam Agnew wrote:

I turned on debug logging for IDP. I see a certificate sent in the exchange. It seems to be the right one. I see this cert in the SAML response from my IDP (idpt):

      <ds:SignatureValue>ZKwMuET4qDGL2CdwIuOjJOpz1QuMNWZvcew+AnsgBJB6znL19zdCAVBBuScMhqJ8OQJynZBmskp5xhxS9Gnr0GEfr9eLcHh+GBP3eSrjoaMwhPznUSrBe84KIwSZNPexVgf7egCS/c05c+v7RK2xrcDs33I6qcVTxPF+6i0ViM5cLP7RMRkvqKOJ82jSEk8zPxUQhlzd7AwJY4YIBFe84fYidfNxWxqdop8iOglUScJ2R0Tl1NtzsZUCL7oVf65tU9sPoD3TmSbbbvvNw84AxPIE5tgrANGxCAs8uSyI1KnesdTlorta3Z+DzlkFlg8TaIwwkZL2zvoXC+0dGrrG5Q==</ds:SignatureValue>
      <ds:KeyInfo>
         <ds:X509Data>
            <ds:X509Certificate>MIIDVDCCAjygAwIBAgIVAJ8yKHKyn+jtv2SGeaU0ssFAVLaYMA0GCSqGSIb3DQEBBQUAMCUxIzAh
BgNVBAMTGmlkcHQucWF0YXItbWVkLmNvcm5lbGwuZWR1MB4XDTEzMTExNDA1MzIwNloXDTMzMTEx
NDA1MzIwNlowJTEjMCEGA1UEAxMaaWRwdC5xYXRhci1tZWQuY29ybmVsbC5lZHUwggEiMA0GCSqG
SIb3DQEBAQUAA4IBDwAwggEKAoIBAQC+Oo5QLdGh0Y4OrLUQjD8jvByohVgExTf8ZHaaFhklpzST
TsgM0H0ObX2+lBE/7T5vmfBBXnbKG5YaGEZXiY+iAM/6PSXynfKXArHmj5yE2tq+Kj3GU3SqYt0R
dVkpy5X8pJxp6PPyowh7yNHa3QnqHfqw+v3Hccey9NVI+YNUWPQPpNH2zTVDePajCNSGyMJWFjuI
Cz8zmKXukZZ69mloZtWLmZLAUF1VDXZija/UBxXSAAXEJNH5bt+3VOk80NpGsfhEyhhKBrdrVJeQ
cE4E11ZwgWPMRq27UJQvl39HjfwMRqSIVPUbby3d/tMqduUz1LaPWEgFR85o2xweDTCJAgMBAAGj
ezB5MFgGA1UdEQRRME+CGmlkcHQucWF0YXItbWVkLmNvcm5lbGwuZWR1hjFodHRwczovL2lkcHQu
cWF0YXItbWVkLmNvcm5lbGwuZWR1L2lkcC9zaGliYm9sZXRoMB0GA1UdDgQWBBRTabVogvg9BMur
5/f86IGwgUoYSzANBgkqhkiG9w0BAQUFAAOCAQEANC2iz+LhfSYxEZPprWKGVj3+y2tROJvHhUdf
CwDzJxEMZelOqDF1uLBfzvx51YU/yG7I53MprvN2m+saFKfr2WxTqyLUhaROESwRbSFH97lpLFQT
8Mz3fZR+bhFCfGT3c/BhErZH63r5aZIZRpJm5vCf6UaL2PYpYtiEC2eMl2Sr7iwCYsiCsKds/E0s
PICmT447oOLMzkFSgy1VP9OjAtqoo7xN5TthGfo8hQ9LgoGE6s4faoBu8mJ+OULd8PE7i5WTtQcJ
7++qq3HEvemQ2Y38G66TtbfXEKquXPC62taHiqxW4outfP3OAHSOvE1x648N5GSI+BtjeJIovqdZ
9w==</ds:X509Certificate>
         </ds:X509Data>
      </ds:KeyInfo>
   </ds:Signature>
   <saml2:Subject>
      <saml2:NameID Format="urn:oasis:names:tc:SAML:2.0:nameid-format:transient" NameQualifier="https://idpt.qatar-med.cornell.edu:8443/idp/shibboleth" SPNameQualifier="https://unixadmin.qatar-med.cornell.edu<https://unixadmin.qatar-med.cornell.edu/>">_e221f54691ae1319a99d6505bb0f6562</saml2:NameID>
      <saml2:SubjectConfirmation Method="urn:oasis:names:tc:SAML:2.0:cm:bearer">
         <saml2:SubjectConfirmationData Address="207.162.245.59" InResponseTo="_70375afcf2a3ff695a2929bdf8237cda" NotOnOrAfter="2013-11-25T05:14:47.997Z" Recipient="https://unixadmin.qatar-med.cornell<https://unixadmin.qatar-med.cornell/>.
edu/Shibboleth.sso/SAML2/POST"/>

If I take a chunk of that and search for it on the SP I find that it is in the idp metadata file:
[root at unixadmin ~]# grep -R BgNVBAMTGmlkcHQucWF0YXItbWVkLmNvcm5lbGwuZWR1MB4XDTE /etc/shibboleth/
/etc/shibboleth/idp-metadata.xml:BQUAMCUxIzAhBgNVBAMTGmlkcHQucWF0YXItbWVkLmNvcm5lbGwuZWR1MB4XDTEz
/etc/shibboleth/idp-metadata.xml:BQUAMCUxIzAhBgNVBAMTGmlkcHQucWF0YXItbWVkLmNvcm5lbGwuZWR1MB4XDTEz
/etc/shibboleth/partner-metadata.xml:      BQUAMCUxIzAhBgNVBAMTGmlkcHQucWF0YXItbWVkLmNvcm5lbGwuZWR1MB4XDTEz
/etc/shibboleth/partner-metadata.xml:    BQUAMCUxIzAhBgNVBAMTGmlkcHQucWF0YXItbWVkLmNvcm5lbGwuZWR1MB4XDTEz
/etc/shibboleth/idp-metadata.xml_sam_2013-11-20:BQUAMCUxIzAhBgNVBAMTGmlkcHQucWF0YXItbWVkLmNvcm5lbGwuZWR1MB4XDTEz
/etc/shibboleth/idp-metadata.xml_sam_2013-11-20:BQUAMCUxIzAhBgNVBAMTGmlkcHQucWF0YXItbWVkLmNvcm5lbGwuZWR1MB4XDTEz

This is the metadata file specified in shibboleth2.xml:
         <MetadataProvider type="XML" uri="https://idpt.qatar-med.cornell.edu/idp/profile/Metadata/SAML"
                backingFilePath="idp-metadata.xml" reloadInterval="7200">
        </MetadataProvider>

In going through the debug log it looks to me as if the encoding succeeds:
08:09:48.513 - DEBUG [org.opensaml.ws.message.encoder.BaseMessageEncoder:56] - Successfully encoded message.
08:09:48.525 - INFO [Shibboleth-Audit:1028] - 20131125T050948Z|urn:oasis:names:tc:SAML:2.0:bindings:HTTP-Redirect|_70375afcf2a3ff695a2929bdf8237cda|https://unixadmin.qatar-med.cornell.edu|urn:mace:shibboleth:2.0:profiles:saml2:sso|https://idpt.qatar-med.cornell.edu:8443/idp/shibboleth|urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST|_5ae8946acd47a082e0a4282246bf3298|saa2012|urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport||_e221f54691ae1319a99d6505bb0f6562||

It is the SP that is not accepting the response somehow:
2013-11-25 08:09:48 WARN Shibboleth.SSO.SAML2 [2]: detected a problem with assertion: Unable to establish security of incoming assertion.

Is there some similar debug logging I can enable on the SP side? There are all of these options about different -- I don't know what to call them -- ways of getting responses (I seem to be using HTTP-POST). I'm not sure if I should be configuring something there but everything I read suggests to me that I should be able to get things working without customising any of that.

I feel it is close to success. Hopefully someone can spot where I am going wrong. I can post any logs or configs if they will help.

Sam

On Nov 24, 2013, at 11:45 AM, Nate Klingenstein wrote:

Sam,

How can I see what key is in the SAML response?

The easy way is to turn the Shibboleth SP's shibd.logger to DEBUG and look at shibd.log when an assertion comes in.  It will log everything in the response.

If the response is not encrypted, then you can also look at it in a browser using a tool like SAML tracer for Firefox or even a generic web console.

What can I check to narrow things down?

The SP's logs will tell you exactly what went wrong.  It's likely the keys, as Paul suggested, if your clocks are on.

Thanks,
Nate.
--
To unsubscribe from this list send an email to users-unsubscribe at shibboleth.net<mailto:users-unsubscribe at shibboleth.net>

--
Sam Agnew
System Administrator
IT Department
Weill Cornell Medical College in Qatar

--
To unsubscribe from this list send an email to users-unsubscribe at shibboleth.net<mailto:users-unsubscribe at shibboleth.net>

--
Sam Agnew
System Administrator
IT Department
Weill Cornell Medical College in Qatar

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://shibboleth.net/pipermail/users/attachments/20131125/e4c80d55/attachment-0001.html 