New Shib 2.4 installation with Active Directory, Cannot authenticate dn, invalid dn error
Mauro Minella
Mauro.Minella at microsoft.com
Sun Mar 16 14:58:21 EDT 2014
Dear ShibUsers,
I've just installed Shib 2.4.0 on Windows Server 2012 R2 (Domain Controller), with Java 7u51 (32bit).
I configured Shib to rely on AD through the adreader user (adreader at eduteamit.com).
Before federating with Office 365, I tested it from https://www.testshib.org/register.html where I uploaded the file https://sts.eduteamit.com:444/idp-metadata-444.xml, which seemed to work. In fact, if I open https://sp.testshib.org/ and enter https://sts.eduteamit.com/idp/shibboleth, I'm correctly redirected to my authentication page https://sts.eduteamit.com:444/idp/Authn/UserPassword
However, when I enter a myuser at eduteamit.com<mailto:myuser at eduteamit.com>'s credentials (myuser, aaa111AAA or even myuser at eduteamit.com<mailto:myuser at eduteamit.com>, aaa111AAA), I get the error "Login has failed"
Looking at idpprocess.log, it says the following. Thank you for any help
Mauro
19:54:35.730 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginServlet:170] - Attempting to authenticate user myuser
19:54:35.730 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:180] - useFirstPass = false
19:54:35.730 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:181] - tryFirstPass = false
19:54:35.730 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:182] - storePass = false
19:54:35.730 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:183] - clearPass = false
19:54:35.730 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:184] - setLdapPrincipal = true
19:54:35.730 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:185] - setLdapDnPrincipal = false
19:54:35.730 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:186] - setLdapCredential = true
19:54:35.730 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:187] - defaultRole = []
19:54:35.730 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:188] - principalGroupName = null
19:54:35.730 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:189] - roleGroupName = null
19:54:35.730 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:77] - userRoleAttribute = [sAMAccountName]
19:54:35.733 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:83] - Created authenticator: edu.vt.middleware.ldap.auth.AuthenticatorConfig at 4749977::env={java.naming.provider.url=ldap://localhost:389, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}
19:54:35.733 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:108] - Looking up DN using userField
19:54:35.733 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:193] - Search with the following parameters:
19:54:35.733 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:194] - dn = CN=Users,DC=eduteamit,DC=com
19:54:35.733 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:195] - filter = (samAccountName={0})
19:54:35.733 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:196] - filterArgs = [myuser]
19:54:35.734 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:197] - searchControls = javax.naming.directory.SearchControls at 68ec99
19:54:35.734 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:198] - handler = [edu.vt.middleware.ldap.handler.FqdnSearchResultHandler at 854bb0]
19:54:35.734 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:74] - Bind with the following parameters:
19:54:35.734 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:75] - authtype = simple
19:54:35.734 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:76] - dn = adreader at eduteamit.com
19:54:35.735 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:83] - credential = <suppressed>
19:54:35.742 - INFO [edu.vt.middleware.ldap.auth.SearchDnResolver:161] - Search for user: myuser failed using filter: (samAccountName={0})
19:54:35.743 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:136] - Authentication failed
javax.naming.AuthenticationException: Cannot authenticate dn, invalid dn
at edu.vt.middleware.ldap.auth.AbstractAuthenticator.authenticateAndAuthorize(AbstractAuthenticator.java:160) ~[vt-ldap-3.3.6.jar:na]
at edu.vt.middleware.ldap.jaas.JaasAuthenticator.authenticate(JaasAuthenticator.java:83) ~[vt-ldap-3.3.6.jar:na]
at edu.vt.middleware.ldap.auth.Authenticator.authenticate(Authenticator.java:320) ~[vt-ldap-3.3.6.jar:na]
at edu.vt.middleware.ldap.auth.Authenticator.authenticate(Authenticator.java:277) ~[vt-ldap-3.3.6.jar:na]
at edu.vt.middleware.ldap.jaas.JaasAuthenticator.authenticate(JaasAuthenticator.java:60) ~[vt-ldap-3.3.6.jar:na]
at edu.vt.middleware.ldap.jaas.LdapLoginModule.login(LdapLoginModule.java:103) ~[vt-ldap-3.3.6.jar:na]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_51]
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[na:1.7.0_51]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:1.7.0_51]
at java.lang.reflect.Method.invoke(Unknown Source) ~[na:1.7.0_51]
at javax.security.auth.login.LoginContext.invoke(Unknown Source) [na:1.7.0_51]
at javax.security.auth.login.LoginContext.access$000(Unknown Source) [na:1.7.0_51]
at javax.security.auth.login.LoginContext$4.run(Unknown Source) [na:1.7.0_51]
at javax.security.auth.login.LoginContext$4.run(Unknown Source) [na:1.7.0_51]
at java.security.AccessController.doPrivileged(Native Method) [na:1.7.0_51]
at javax.security.auth.login.LoginContext.invokePriv(Unknown Source) [na:1.7.0_51]
at javax.security.auth.login.LoginContext.login(Unknown Source) [na:1.7.0_51]
at edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginServlet.authenticateUser(UsernamePasswordLoginServlet.java:177) [shibboleth-identityprovider-2.4.0.jar:na]
at edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginServlet.service(UsernamePasswordLoginServlet.java:123) [shibboleth-identityprovider-2.4.0.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.36]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.36]
at edu.internet2.middleware.shibboleth.idp.util.NoCacheFilter.doFilter(NoCacheFilter.java:50) [shibboleth-identityprovider-2.4.0.jar:na]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.36]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.36]
at edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter.doFilter(IdPSessionFilter.java:87) [shibboleth-identityprovider-2.4.0.jar:na]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.36]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.36]
at edu.internet2.middleware.shibboleth.common.log.SLF4JMDCCleanupFilter.doFilter(SLF4JMDCCleanupFilter.java:52) [shibboleth-common-1.4.0.jar:na]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.36]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.36]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) [catalina.jar:6.0.36]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [catalina.jar:6.0.36]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [catalina.jar:6.0.36]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [catalina.jar:6.0.36]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [catalina.jar:6.0.36]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293) [catalina.jar:6.0.36]
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:861) [tomcat-coyote.jar:6.0.36]
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:606) [tomcat-coyote.jar:6.0.36]
at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489) [tomcat-coyote.jar:6.0.36]
at java.lang.Thread.run(Unknown Source) [na:1.7.0_51]
19:54:35.744 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginServlet:194] - User authentication for myuser failed
javax.security.auth.login.LoginException: Cannot authenticate dn, invalid dn
at edu.vt.middleware.ldap.jaas.LdapLoginModule.login(LdapLoginModule.java:138) ~[vt-ldap-3.3.6.jar:na]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_51]
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[na:1.7.0_51]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:1.7.0_51]
at java.lang.reflect.Method.invoke(Unknown Source) ~[na:1.7.0_51]
at javax.security.auth.login.LoginContext.invoke(Unknown Source) ~[na:1.7.0_51]
at javax.security.auth.login.LoginContext.access$000(Unknown Source) ~[na:1.7.0_51]
at javax.security.auth.login.LoginContext$4.run(Unknown Source) ~[na:1.7.0_51]
at javax.security.auth.login.LoginContext$4.run(Unknown Source) ~[na:1.7.0_51]
at java.security.AccessController.doPrivileged(Native Method) ~[na:1.7.0_51]
at javax.security.auth.login.LoginContext.invokePriv(Unknown Source) ~[na:1.7.0_51]
at javax.security.auth.login.LoginContext.login(Unknown Source) ~[na:1.7.0_51]
at edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginServlet.authenticateUser(UsernamePasswordLoginServlet.java:177) [shibboleth-identityprovider-2.4.0.jar:na]
at edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginServlet.service(UsernamePasswordLoginServlet.java:123) [shibboleth-identityprovider-2.4.0.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.36]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.36]
at edu.internet2.middleware.shibboleth.idp.util.NoCacheFilter.doFilter(NoCacheFilter.java:50) [shibboleth-identityprovider-2.4.0.jar:na]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.36]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.36]
at edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter.doFilter(IdPSessionFilter.java:87) [shibboleth-identityprovider-2.4.0.jar:na]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.36]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.36]
at edu.internet2.middleware.shibboleth.common.log.SLF4JMDCCleanupFilter.doFilter(SLF4JMDCCleanupFilter.java:52) [shibboleth-common-1.4.0.jar:na]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.36]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.36]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) [catalina.jar:6.0.36]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [catalina.jar:6.0.36]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [catalina.jar:6.0.36]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [catalina.jar:6.0.36]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [catalina.jar:6.0.36]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293) [catalina.jar:6.0.36]
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:861) [tomcat-coyote.jar:6.0.36]
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:606) [tomcat-coyote.jar:6.0.36]
at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489) [tomcat-coyote.jar:6.0.36]
at java.lang.Thread.run(Unknown Source) [na:1.7.0_51]
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://shibboleth.net/pipermail/users/attachments/20140316/fd2d3c5e/attachment-0001.html
More information about the users
mailing list