AuthnFailed and SP IdP test configuration

Fri Jun 7 19:11:35 EDT 2013

Looking at this from afar (meaning, I don't have access to either server myself), I see two possible issues in the AuthnRequest you are sending:

A missing NameIDPolicy Format and a missing "RequestedAuthnContext" section.

If I change the SAML you're generating from this:

<samlp:AuthnRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol"
                    AssertionConsumerServiceURL="https://nuxeo-dev.cdlib.org/Shibboleth.sso/SAML2/POST"
                    Destination="https://idt1.ucop.edu/idp/profile/SAML2/Redirect/SSO"
                    ID="_6d74840da8429abbcc655b947b9af644"
                    IssueInstant="2013-06-07T22:11:58Z"
                    ProtocolBinding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST"
                    Version="2.0"
                    >
    <saml:Issuer xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion">https://nuxeo.cdlib.org/sp</saml:Issuer>
    <samlp:NameIDPolicy AllowCreate="1" />
</samlp:AuthnRequest>

To include both the NameID Format and the RequestedAuthnContext elements (elements added in boldface, below):

<samlp:AuthnRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol"
                    AssertionConsumerServiceURL="https://nuxeo-dev.cdlib.org/Shibboleth.sso/SAML2/POST"
                    Destination="https://idt1.ucop.edu/idp/profile/SAML2/Redirect/SSO"
                    ID="_6d74840da8429abbcc655b947b9af644"
                    IssueInstant="2013-06-07T22:11:58Z"
                    ProtocolBinding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST"
                    Version="2.0"
                    >
    <saml:Issuer xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion">https://nuxeo.cdlib.org/sp</saml:Issuer>
    <samlp:NameIDPolicy AllowCreate="1" Format="urn:oasis:names:tc:SAML:2.0:nameid-format:transient" />
    <samlp:RequestedAuthnContext Comparison="exact">
        <saml:AuthnContextClassRef xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion">urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport</saml:AuthnContextClassRef>
    </samlp:RequestedAuthnContext>
</samlp:AuthnRequest>

Then I am prompted for login as expected, and (since I have an account on said IdP) I get back to https://nuxeo-dev/cdlib.org with the generic "It works!" message. (I did this at 4:05PM, if you want to see if the logs reflect my connection and/or indicate any other parsing errors).

I'll have to defer to people on this list as to whether the original request is malformed, or whether the IdP is failing to handle a valid configuration, but if you can change the format of your request, it looks like you will at least get the login prompt and a return back to your application.

--- Eric

From: users-bounces at shibboleth.net [mailto:users-bounces at shibboleth.net] On Behalf Of Brian Tingle
Sent: Friday, June 07, 2013 3:00 PM
To: Shib Users
Subject: AuthnFailed and SP IdP test configuration

Hi,

I'm trying to hook my test SP to a test IdP that my identity management group controls.

I installed the metadata provider XML that they sent me, and I set my SSO element to point to them; but I'm getting the errors below.

https://nuxeo-dev.cdlib.org/nuxeo/ is protected and worked with testshib.org -- going there now I get redirected around and end up here (without it ever prompting me to enter a username/password):
opensaml::FatalProfileException

The system encountered an error at Fri Jun 7 13:42:12 2013

To report this problem, please contact the site administrator at root at localhost<mailto:root at localhost>.

Please include the following message in any email:

opensaml::FatalProfileException at (https://nuxeo-dev.cdlib.org/Shibboleth.sso/SAML2/POST)

SAML response contained an error.

Error from identity provider:
Status: urn:oasis:names:tc:SAML:2.0:status:Responder
Sub-Status: urn:oasis:names:tc:SAML:2.0:status:AuthnFailed

==> servers/shibboleth/var/log/httpd/native_warn.log <==

2013-06-07 14:13:22 ERROR Shibboleth.Listener [22881] shib_handler: remoted message returned an error: SAML response contained an error.

2013-06-07 14:13:22 ERROR Shibboleth.Apache [22881] shib_handler: SAML response contained an error.

==> servers/shibboleth/var/log/shibboleth/shibd.log <==

2013-06-07 14:13:22 DEBUG Shibboleth.Listener [2]: dispatching message (default/SAML2/POST)

2013-06-07 14:13:22 DEBUG OpenSAML.MessageDecoder.SAML2POST [2]: validating input

2013-06-07 14:13:22 DEBUG OpenSAML.MessageDecoder.SAML2POST [2]: decoded SAML message:

<?xml version="1.0" encoding="UTF-8"?><saml2p:Response xmlns:saml2p="urn:oasis:names:tc:SAML:2.0:protocol" Destination="https://nuxeo-dev.cdlib.org/Shibboleth.sso/SAML2/POST" ID="_5d32eef9dc33f2720aa5eb59937b8f5a" InResponseTo="_b8415074b602040366fb259249ffa6b9" IssueInstant="2013-06-07T21:13:21.010Z" Version="2.0"><saml2:Issuer xmlns:saml2="urn:oasis:names:tc:SAML:2.0:assertion" Format="urn:oasis:names:tc:SAML:2.0:nameid-format:entity">https://idt1.ucop.edu/idp/shibboleth</saml2:Issuer><saml2p:Status><saml2p:StatusCode<https://idt1.ucop.edu/idp/shibboleth%3c/saml2:Issuer%3e%3csaml2p:Status%3e%3csaml2p:StatusCode> Value="urn:oasis:names:tc:SAML:2.0:status:Responder"><saml2p:StatusCode Value="urn:oasis:names:tc:SAML:2.0:status:AuthnFailed"/></saml2p:StatusCode></saml2p:Status></saml2p:Response>

2013-06-07 14:13:22 DEBUG OpenSAML.MessageDecoder.SAML2 [2]: extracting issuer from SAML 2.0 protocol message

2013-06-07 14:13:22 DEBUG OpenSAML.MessageDecoder.SAML2 [2]: message from (https://idt1.ucop.edu/idp/shibboleth)

2013-06-07 14:13:22 DEBUG OpenSAML.MessageDecoder.SAML2 [2]: searching metadata for message issuer...

2013-06-07 14:13:22 DEBUG OpenSAML.SecurityPolicyRule.MessageFlow [2]: evaluating message flow policy (replay checking on, expiration 60)

2013-06-07 14:13:22 DEBUG XMLTooling.StorageService [2]: inserted record (_5d32eef9dc33f2720aa5eb59937b8f5a) in context (MessageFlow) with expiration (1370641461)

2013-06-07 14:13:22 DEBUG XMLTooling.StorageService [2]: deleted record (4570afd04ef5eaa8fb7fcf69d044c04d) in context (RelayState)

2013-06-07 14:13:22 DEBUG Shibboleth.SSO.SAML2 [2]: processing message against SAML 2.0 SSO profile

more logs here  https://gist.github.com/tingletech/5732472 if they are helpful

I asked my IdP for his idp-process.log and he sent it to me.  I find this error in his logs every time I tried to log in:

14:13:20.995 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.provider.RemoteUserAuthServlet:77] - No remote user information was present in the request

14:13:20.995 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:144] - Returning control to authentication engine

14:13:20.995 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:209] - Processing incoming request

14:13:20.995 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:514] - Completing user authentication process

14:13:20.996 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:585] - Validating authentication was performed successfully

14:13:20.996 - ERROR [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:618] - No user identified by login handler.

14:13:20.997 - ERROR [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:563] - Authentication failed with the error:

edu.internet2.middleware.shibboleth.idp.authn.AuthenticationException: No user identified by login handler.

        at edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine.validateSuccessfulAuthentication(AuthenticationEngine.java:619) [shibboleth-identityprovider-2.3.8.jar:na]

        at edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine.completeAuthentication(AuthenticationEngine.java:537) [shibboleth-identityprovider-2.3.8.jar:na]

        at edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine.service(AuthenticationEngine.java:225) [shibboleth-identityprovider-2.3.8.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 org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:646) [catalina.jar:6.0.29]

        at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:436) [catalina.jar:6.0.29]

        at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:374) [catalina.jar:6.0.29]

        at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:302) [catalina.jar:6.0.29]

        at edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine.forwardRequest(AuthenticationEngine.java:196) [shibboleth-identityprovider-2.3.8.jar:na]

        at edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine.returnToAuthenticationEngine(AuthenticationEngine.java:150) [shibboleth-identityprovider-2.3.8.jar:na]

How can we make sure that remote user information is present in the request so that a user is identified by the login handler?  Is this an issue on the SP end, or the IdP end?

Thanks -- Brian

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