Concerning setup of External Auth

Thu Oct 18 14:08:49 EDT 2012

To all,

I currently have a 2.3.6 IdP running on Linux under JBOSS 5.1.  It currently is configured to perform user/password using LDAP  (configured as described in shibboleth documentation using JAAS).  This works well.  I have a request to include an External Auth login provider.  A developer has created a servlet to perform this authentication and has deployed the code in the same instance as our IdP.  We have also configured the handler.xml with the following entry

<!--  Username/password login handler -->
  <ph:LoginHandler xsi:type="ph:ExternalAuthn" externalAuthnPath="https://vushib-idpguest-test.vanderbilt.edu/vushib/oauth/servlet/shibLogin">
    <ph:AuthenticationMethod>urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport</ph:AuthenticationMethod>
  </ph:LoginHandler>

For testing sake we have removed the LDAP login hander.  Now, using Test Shibboleth SP  (which I tested to work fine with the LDAP login handler),  I point the SP to the enity id of our IdP.   Our IdP is behind an F5 LTM (load balancer) which is configured to only point at one IdP at a time (fail-over).  I also only have one instance of the IdP up and running.  The VIP on the LTM is https://vushib-idpguest-test.vanderbilt.edu:443 .  What I get back from test shib is a 404 error.  Here is what I see in the logs.

09:22:00.730 - DEBUG [org.opensaml.common.binding.decoding.BaseSAMLMessageDecoder:191] [thread: http-10110-2%PARSER_ERROR[l]] - Checking SAML message intended destination endpoint against receiver endpoint
09:22:00.731 - DEBUG [org.opensaml.common.binding.decoding.BaseSAMLMessageDecoder:210] [thread: http-10110-2%PARSER_ERROR[l]] - Intended message destination endpoint: https://vushib-idpguest-test.vanderbilt.edu/idp/profile/SAML2/Redirect/SSO
09:22:00.731 - DEBUG [org.opensaml.common.binding.decoding.BaseSAMLMessageDecoder:211] [thread: http-10110-2%PARSER_ERROR[l]] - Actual message receiver endpoint: https://vushib-idpguest-test.vanderbilt.edu/idp/profile/SAML2/Redirect/SSO
09:22:00.732 - DEBUG [org.opensaml.common.binding.decoding.BaseSAMLMessageDecoder:219] [thread: http-10110-2%PARSER_ERROR[l]] - SAML message intended destination endpoint matched recipient endpoint
09:22:00.732 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:333] [thread: http-10110-2%PARSER_ERROR[l]] - Decoded request from relying party 'https://sp.testshib.org/shibboleth-sp'
09:22:00.733 - DEBUG [org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:253] [thread: http-10110-2%PARSER_ERROR[l]] - Checking child metadata provider for entity descriptor with entity ID: https://sp.testshib.org/shibboleth-sp
09:22:00.733 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:509] [thread: http-10110-2%PARSER_ERROR[l]] - Searching for entity descriptor with an entity ID of https://sp.testshib.org/shibboleth-sp
09:22:00.734 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:167] [thread: http-10110-2%PARSER_ERROR[l]] - Metadata document does not contain an EntityDescriptor with the ID https://sp.testshib.org/shibboleth-sp
09:22:00.734 - DEBUG [org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:253] [thread: http-10110-2%PARSER_ERROR[l]] - Checking child metadata provider for entity descriptor with entity ID: https://sp.testshib.org/shibboleth-sp
09:22:00.735 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:509] [thread: http-10110-2%PARSER_ERROR[l]] - Searching for entity descriptor with an entity ID of https://sp.testshib.org/shibboleth-sp
09:22:00.737 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:167] [thread: http-10110-2%PARSER_ERROR[l]] - Metadata document does not contain an EntityDescriptor with the ID https://sp.testshib.org/shibboleth-sp
09:22:00.738 - DEBUG [org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:253] [thread: http-10110-2%PARSER_ERROR[l]] - Checking child metadata provider for entity descriptor with entity ID: https://sp.testshib.org/shibboleth-sp
09:22:00.738 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:509] [thread: http-10110-2%PARSER_ERROR[l]] - Searching for entity descriptor with an entity ID of https://sp.testshib.org/shibboleth-sp
09:22:00.739 - DEBUG [edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:127] [thread: http-10110-2%PARSER_ERROR[l]] - Looking up relying party configuration for https://sp.testshib.org/shibboleth-sp
09:22:00.739 - DEBUG [edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:129] [thread: http-10110-2%PARSER_ERROR[l]] - Custom relying party configuration found for https://sp.testshib.org/shibboleth-sp
09:22:00.740 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:203] [thread: http-10110-2%PARSER_ERROR[l]] - Creating login context and transferring control to authentication engine
09:22:00.745 - DEBUG [edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:169] [thread: http-10110-2%PARSER_ERROR[l]] - Storing LoginContext to StorageService partition loginContexts, key 3e9be40a-4839-455c-b7e1-56931e1feb77
09:22:00.746 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:216] [thread: http-10110-2%PARSER_ERROR[l]] - Redirecting user to authentication engine at https://vushib-idpguest-test.vanderbilt.edu:443/idp/AuthnEngine
09:22:00.761 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:202] [thread: http-10110-2%PARSER_ERROR[l]] - Processing incoming request
09:22:00.761 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:233] [thread: http-10110-2%PARSER_ERROR[l]] - Beginning user authentication process.
09:22:00.762 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:279] [thread: http-10110-2%PARSER_ERROR[l]] - Filtering configured LoginHandlers: {urn:oasis:names:tc:SAML:2.0:ac:classes:PreviousSession=edu.internet2.middleware.shibboleth.idp.authn.provider.PreviousSessionLoginHandler at 112740e8, urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport=edu.internet2.middleware.shibboleth.idp.authn.provider.ExternalAuthnSystemLoginHandler at 28164824}
09:22:00.762 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:328] [thread: http-10110-2%PARSER_ERROR[l]] - Filtering out previous session login handler because there is no existing IdP session
09:22:00.763 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:460] [thread: http-10110-2%PARSER_ERROR[l]] - Selecting appropriate login handler from filtered set {urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport=edu.internet2.middleware.shibboleth.idp.authn.provider.ExternalAuthnSystemLoginHandler at 28164824}
09:22:00.763 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:493] [thread: http-10110-2%PARSER_ERROR[l]] - Authenticating user with login handler of type edu.internet2.middleware.shibboleth.idp.authn.provider.ExternalAuthnSystemLoginHandler
09:22:00.764 - DEBUG [edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:169] [thread: http-10110-2%PARSER_ERROR[l]] - Storing LoginContext to StorageService partition loginContexts, key 5a98aff0-a463-4c32-8139-2e643909f467
09:22:00.764 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.provider.RemoteUserLoginHandler:100] [thread: http-10110-2%PARSER_ERROR[l]] - Forwarding authentication request to https://vushib-idpguest-test.vanderbilt.edu/vushib/oauth/servlet/shibLogin

So it appears that the IdP is attempting to forward  to the correct URL... but that is the last thing that we see... and the browser reports a 404.  If I use the URL  https://vushib-idpguest-test.vanderbilt.edu/vushib/oauth/servlet/shibLogin directly from the browser I get the login page for the external auth.
As well the developer attempted to examine the RemoteUSerLoginHandler source code (as found online) and it only contains 78 lines , so no line 100 as listed above

Does anyone have any ideas?
Lee Brewer

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