javax.naming.OperationNotSupportedException: [LDAP: error code 53 - UNWILLING_TO_PERFORM: Bind failed: Cannot Bind for Dn uid=admin, ou=system]
Farrukh Najmi
farrukh at wellfleetsoftware.com
Wed Jun 5 18:00:32 EDT 2013
Hi Guys,
In my attempt to get LDAP authentication with privileged user I am now
using latest Apache DS 2.0.0-M12 . In my server apacheds server
configuration the server side password hashing is disabled.
I am providing the password for the admin user as plain text in both the
ShibUserPassAuth in login.config (shown in my previous messages included
below). I am also providng the following in attribute-resolver.xml:
<resolver:DataConnector id="myLDAP" xsi:type="dc:LDAPDirectory"
ldapURL="ldap://wellfleet1.wellfleetsoftware.com:10389/"
baseDN="dc=springframework,dc=org"
principal="uid=admin,ou=system"
principalCredential="ldap1"
>
<dc:FilterTemplate>
<![CDATA[
(uid=$requestContext.principalName)
]]>
</dc:FilterTemplate>
</resolver:DataConnector>
<resolver:AttributeDefinition xsi:type="Simple"
xmlns="urn:mace:shibboleth:2.0:resolver:ad"
id="uidNameID"
sourceAttributeID="uid">
<!--
The data connector expected to provide the source attribute,
email. Note how the
value of the 'ref' attribute is the identifier given to the
LDAP data connector.
-->
<resolver:Dependency ref="myLDAP" />
<!-- Encoder that transforms the attribute into a SAML2 NameID -->
<resolver:AttributeEncoder xsi:type="SAML2StringNameID"
xmlns="urn:mace:shibboleth:2.0:attribute:encoder"
nameFormat="urn:oasis:names:tc:SAML:1.1:nameid-format:transient" />
</resolver:AttributeDefinition>
My login.config file looks like this:
ShibUserPassAuth {
edu.vt.middleware.ldap.jaas.LdapLoginModule required
ldapUrl="ldap://wellfleet1.wellfleetsoftware.com:10389/"
baseDn="dc=springframework,dc=org"
bindDn="uid=admin,ou=system"
bindCredentials="ldap1"
ssl="false"
userFilter="uid={0}"
subtreeSearch="true";
};
I can connect to the LDAP server using every other means I have tried
(spring-security, JExplorer, Apache Directory Studio. But my SAML Web
SSO Authentication fails still. The following is the log from
idp-process.log with debug messages turned on:
17:30:54.517 - DEBUG
[edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter:180] -
No session associated with session ID
e6ccf00bfbd5a2b74f500bb5fd0be2d2052242b0bfc637731638803be455d241 -
session must have timed out
17:30:54.518 - DEBUG
[edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginServlet:170]
- Attempting to authenticate user rod
17:30:54.567 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:144] -
Begin initialize
17:30:54.568 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:180] -
useFirstPass = false
17:30:54.568 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:181] -
tryFirstPass = false
17:30:54.569 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:182] -
storePass = false
17:30:54.569 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:183] -
clearPass = false
17:30:54.569 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:184] -
setLdapPrincipal = true
17:30:54.570 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:185] -
setLdapDnPrincipal = false
17:30:54.570 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:186] -
setLdapCredential = true
17:30:54.571 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:187] -
defaultRole = []
17:30:54.571 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:188] -
principalGroupName = null
17:30:54.571 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:189] -
roleGroupName = null
17:30:54.572 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:77] -
userRoleAttribute = []
17:30:54.581 - TRACE
[edu.vt.middleware.ldap.auth.AuthenticatorConfig:1385] - setting
searchScope: ONELEVEL
17:30:54.588 - TRACE
[edu.vt.middleware.ldap.auth.AuthenticatorConfig:1770] - setting
property bindCredentials: ldap1
17:30:54.589 - TRACE
[edu.vt.middleware.ldap.auth.AuthenticatorConfig:427] - setting
subtreeSearch: true
17:30:54.589 - TRACE
[edu.vt.middleware.ldap.auth.AuthenticatorConfig:1385] - setting
searchScope: SUBTREE
17:30:54.590 - TRACE
[edu.vt.middleware.ldap.auth.AuthenticatorConfig:1370] - setting baseDn:
dc=springframework,dc=org
17:30:54.590 - TRACE
[edu.vt.middleware.ldap.auth.AuthenticatorConfig:1834] - setting ssl: false
17:30:54.591 - TRACE
[edu.vt.middleware.ldap.auth.AuthenticatorConfig:1168] - setting
ldapUrl: ldap://wellfleet1.wellfleetsoftware.com:10389/
17:30:54.591 - TRACE
[edu.vt.middleware.ldap.auth.AuthenticatorConfig:1276] - setting bindDn:
uid=admin,ou=system
17:30:54.592 - TRACE
[edu.vt.middleware.ldap.auth.AuthenticatorConfig:290] - setting
userFilter: uid={0}
17:30:54.595 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:83] -
Created authenticator:
edu.vt.middleware.ldap.auth.AuthenticatorConfig at 1328104401::env={java.naming.provider.url=ldap://wellfleet1.wellfleetsoftware.com:10389/,
java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory,
bindCredentials=ldap1}
17:30:54.596 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:412] -
Begin getCredentials
17:30:54.597 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:413]
- useFistPass = false
17:30:54.597 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:414]
- tryFistPass = false
17:30:54.598 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:415]
- useCallback = false
17:30:54.598 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:416] -
callbackhandler class =
javax.security.auth.login.LoginContext$SecureCallbackHandler
17:30:54.598 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:419]
- name callback class = javax.security.auth.callback.NameCallback
17:30:54.599 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:421]
- password callback class = javax.security.auth.callback.PasswordCallback
17:30:54.601 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:102]
- Looking up DN using userFilter
17:30:54.601 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:193]
- Search with the following parameters:
17:30:54.602 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:194]
- dn = dc=springframework,dc=org
17:30:54.602 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:195]
- filter = uid={0}
17:30:54.603 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:196]
- filterArgs = [rod]
17:30:54.603 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:197]
- searchControls = javax.naming.directory.SearchControls at 7e4d935b
17:30:54.604 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:198]
- handler =
[edu.vt.middleware.ldap.handler.FqdnSearchResultHandler at 17057c25]
17:30:54.604 - TRACE [edu.vt.middleware.ldap.auth.SearchDnResolver:200]
- config =
{java.naming.provider.url=ldap://wellfleet1.wellfleetsoftware.com:10389/, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory,
bindCredentials=ldap1}
17:30:54.605 - TRACE
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:93] - setting
connectionStrategy: DEFAULT
17:30:54.605 - TRACE
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:110] - setting
connectionRetryExceptions: [class javax.naming.NamingException]
17:30:54.606 - TRACE
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:152] - {0}
Attempting connection to ldap://wellfleet1.wellfleetsoftware.com:10389/
for strategy DEFAULT
17:30:54.606 - DEBUG
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:74] - Bind with
the following parameters:
17:30:54.606 - DEBUG
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:75] - authtype
= simple
17:30:54.607 - DEBUG
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:76] - dn =
uid=admin,ou=system
17:30:54.607 - DEBUG
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:83] -
credential = <suppressed>
17:30:54.608 - TRACE
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:87] - env =
{java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory,
java.naming.provider.url=ldap://wellfleet1.wellfleetsoftware.com:10389/,
bindCredentials=ldap1}
17:30:54.615 - DEBUG
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:163] - Error
connecting to LDAP URL: ldap://wellfleet1.wellfleetsoftware.com:10389/
javax.naming.OperationNotSupportedException: [LDAP: error code 53 -
UNWILLING_TO_PERFORM: Bind failed: Cannot Bind for Dn uid=admin,ou=system]
at com.sun.jndi.ldap.LdapCtx.mapErrorCode(LdapCtx.java:3160)
~[na:1.7.0_21]
at com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:3033)
~[na:1.7.0_21]
at com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:2835)
~[na:1.7.0_21]
at com.sun.jndi.ldap.LdapCtx.connect(LdapCtx.java:2749) ~[na:1.7.0_21]
at com.sun.jndi.ldap.LdapCtx.<init>(LdapCtx.java:316) ~[na:1.7.0_21]
at
com.sun.jndi.ldap.LdapCtxFactory.getUsingURL(LdapCtxFactory.java:193)
~[na:1.7.0_21]
at
com.sun.jndi.ldap.LdapCtxFactory.getUsingURLs(LdapCtxFactory.java:211)
~[na:1.7.0_21]
at
com.sun.jndi.ldap.LdapCtxFactory.getLdapCtxInstance(LdapCtxFactory.java:154)
~[na:1.7.0_21]
at
com.sun.jndi.ldap.LdapCtxFactory.getInitialContext(LdapCtxFactory.java:84)
~[na:1.7.0_21]
at
javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:684)
~[na:1.7.0_21]
at
javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:307)
~[na:1.7.0_21]
at javax.naming.InitialContext.init(InitialContext.java:242)
~[na:1.7.0_21]
at
javax.naming.ldap.InitialLdapContext.<init>(InitialLdapContext.java:153)
~[na:1.7.0_21]
at
edu.vt.middleware.ldap.handler.DefaultConnectionHandler.connectInternal(DefaultConnectionHandler.java:134)
~[vt-ldap-3.3.6.jar:na]
at
edu.vt.middleware.ldap.handler.AbstractConnectionHandler.connect(AbstractConnectionHandler.java:156)
~[vt-ldap-3.3.6.jar:na]
at
edu.vt.middleware.ldap.AbstractLdap.connect(AbstractLdap.java:1006)
[vt-ldap-3.3.6.jar:na]
at
edu.vt.middleware.ldap.AbstractLdap.getContext(AbstractLdap.java:1058)
[vt-ldap-3.3.6.jar:na]
at
edu.vt.middleware.ldap.AbstractLdap.search(AbstractLdap.java:214)
[vt-ldap-3.3.6.jar:na]
at
edu.vt.middleware.ldap.auth.SearchDnResolver.resolve(SearchDnResolver.java:139)
[vt-ldap-3.3.6.jar:na]
at
edu.vt.middleware.ldap.auth.Authenticator.getDn(Authenticator.java:106)
[vt-ldap-3.3.6.jar:na]
at
edu.vt.middleware.ldap.jaas.JaasAuthenticator.authenticate(JaasAuthenticator.java:74)
[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_21]
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
~[na:1.7.0_21]
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
~[na:1.7.0_21]
at java.lang.reflect.Method.invoke(Method.java:601) ~[na:1.7.0_21]
at
javax.security.auth.login.LoginContext.invoke(LoginContext.java:784)
[na:1.7.0_21]
at
javax.security.auth.login.LoginContext.access$000(LoginContext.java:203)
[na:1.7.0_21]
at
javax.security.auth.login.LoginContext$4.run(LoginContext.java:698)
[na:1.7.0_21]
at
javax.security.auth.login.LoginContext$4.run(LoginContext.java:696)
[na:1.7.0_21]
at java.security.AccessController.doPrivileged(Native Method)
[na:1.7.0_21]
at
javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:695)
[na:1.7.0_21]
at
javax.security.auth.login.LoginContext.login(LoginContext.java:594)
[na:1.7.0_21]
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:848)
[servlet-api-3.0.jar:na]
at
org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:681)
[jetty-servlet-9.0.3.v20130506.jar:9.0.3.v20130506]
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1452)
[jetty-servlet-9.0.3.v20130506.jar:9.0.3.v20130506]
at
edu.internet2.middleware.shibboleth.idp.util.NoCacheFilter.doFilter(NoCacheFilter.java:50)
[shibboleth-identityprovider-2.4.0.jar:na]
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1423)
[jetty-servlet-9.0.3.v20130506.jar:9.0.3.v20130506]
at
edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter.doFilter(IdPSessionFilter.java:87)
[shibboleth-identityprovider-2.4.0.jar:na]
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1423)
[jetty-servlet-9.0.3.v20130506.jar:9.0.3.v20130506]
at
edu.internet2.middleware.shibboleth.common.log.SLF4JMDCCleanupFilter.doFilter(SLF4JMDCCleanupFilter.java:52)
[shibboleth-common-1.4.0.jar:na]
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1423)
[jetty-servlet-9.0.3.v20130506.jar:9.0.3.v20130506]
at
org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:450)
[jetty-servlet-9.0.3.v20130506.jar:9.0.3.v20130506]
at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:138)
[jetty-server-9.0.3.v20130506.jar:9.0.3.v20130506]
at
org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:540)
[jetty-security-9.0.3.v20130506.jar:9.0.3.v20130506]
at
org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:213)
[jetty-server-9.0.3.v20130506.jar:9.0.3.v20130506]
at
org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1083)
[jetty-server-9.0.3.v20130506.jar:9.0.3.v20130506]
at
org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:379) [jetty-servlet-9.0.3.v20130506.jar:9.0.3.v20130506]
at
org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:175)
[jetty-server-9.0.3.v20130506.jar:9.0.3.v20130506]
at
org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1017)
[jetty-server-9.0.3.v20130506.jar:9.0.3.v20130506]
at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:136)
[jetty-server-9.0.3.v20130506.jar:9.0.3.v20130506]
at
org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:258)
[jetty-server-9.0.3.v20130506.jar:9.0.3.v20130506]
at
org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:109)
[jetty-server-9.0.3.v20130506.jar:9.0.3.v20130506]
at
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)
[jetty-server-9.0.3.v20130506.jar:9.0.3.v20130506]
at
org.eclipse.jetty.rewrite.handler.RewriteHandler.handle(RewriteHandler.java:317)
[jetty-rewrite-9.0.3.v20130506.jar:9.0.3.v20130506]
at
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)
[jetty-server-9.0.3.v20130506.jar:9.0.3.v20130506]
at org.eclipse.jetty.server.Server.handle(Server.java:445)
[jetty-server-9.0.3.v20130506.jar:9.0.3.v20130506]
at
org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:260)
[jetty-server-9.0.3.v20130506.jar:9.0.3.v20130506]
at
org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:225)
[jetty-server-9.0.3.v20130506.jar:9.0.3.v20130506]
at
org.eclipse.jetty.io.AbstractConnection$ReadCallback.run(AbstractConnection.java:358)
[jetty-io-9.0.3.v20130506.jar:9.0.3.v20130506]
at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:596)
[jetty-util-9.0.3.v20130506.jar:9.0.3.v20130506]
at
org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:527)
[jetty-util-9.0.3.v20130506.jar:9.0.3.v20130506]
at java.lang.Thread.run(Thread.java:722) [na:1.7.0_21]
Could any one please give me some guidance on what I could be doing
wrong, how to debug this further.
--
Regards,
Farrukh Najmi
Web: http://www.wellfleetsoftware.com
More information about the users
mailing list