Authentication failed 2 or 3 times, then it works

[delphine_]

Hello

We have a problem we can't solve.

We use the multi-ldap authentication. The configuration is ok but we have a problem :

When a user wants to authenticate, it has from time to time an error appears. But after 2 or 3 times with the same login/pass, it works.

Here the error :

2013-02-26 10:03:38,964 ERROR [org.nuxeo.ecm.platform.login.NuxeoLoginModule] Authentication failed: failed to fetch the ldap entry for d.xxxxx
org.nuxeo.ecm.directory.DirectoryException: failed to fetch the ldap entry for d.xxxxx
	at org.nuxeo.ecm.directory.ldap.LDAPSession.authenticate(LDAPSession.java:1001)
	at org.nuxeo.ecm.directory.multi.MultiDirectorySession.authenticate(MultiDirectorySession.java:394)
	at org.nuxeo.ecm.platform.usermanager.UserManagerImpl.checkUsernamePassword(UserManagerImpl.java:382)
	at org.nuxeo.ecm.platform.login.NuxeoLoginModule.validateUserIdentity(NuxeoLoginModule.java:321)
	at org.nuxeo.ecm.platform.login.NuxeoLoginModule.getPrincipal(NuxeoLoginModule.java:210)
	at org.nuxeo.ecm.platform.login.NuxeoLoginModule.login(NuxeoLoginModule.java:261)
	at org.nuxeo.runtime.api.LoginModuleWrapper.login(LoginModuleWrapper.java:77)
	at sun.reflect.GeneratedMethodAccessor57.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at javax.security.auth.login.LoginContext.invoke(LoginContext.java:769)
	at javax.security.auth.login.LoginContext.access$000(LoginContext.java:186)
	at javax.security.auth.login.LoginContext$4.run(LoginContext.java:683)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:680)
	at javax.security.auth.login.LoginContext.login(LoginContext.java:579)
	at org.nuxeo.ecm.platform.ui.web.auth.NuxeoAuthenticationFilter.doAuthenticate(NuxeoAuthenticationFilter.java:233)
	at org.nuxeo.ecm.platform.ui.web.auth.NuxeoAuthenticationFilter.doFilterInternal(NuxeoAuthenticationFilter.java:484)
	at org.nuxeo.ecm.platform.ui.web.auth.service.NuxeoAuthFilterChain.doFilter(NuxeoAuthFilterChain.java:35)
	at org.nuxeo.ecm.platform.ui.web.auth.oauth.NuxeoOAuthFilter.doFilter(NuxeoOAuthFilter.java:116)
	at org.nuxeo.ecm.platform.ui.web.auth.service.NuxeoAuthFilterChain.doFilter(NuxeoAuthFilterChain.java:33)
	at org.nuxeo.ecm.platform.ui.web.auth.NuxeoAuthenticationFilter.doFilter(NuxeoAuthenticationFilter.java:349)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.nuxeo.ecm.platform.web.common.exceptionhandling.NuxeoExceptionFilter.doFilter(NuxeoExceptionFilter.java:79)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.nuxeo.ecm.platform.web.common.encoding.NuxeoEncodingFilter.doFilter(NuxeoEncodingFilter.java:59)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
	at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190)
	at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291)
	at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:776)
	at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:705)
	at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:898)
	at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690)
	at java.lang.Thread.run(Thread.java:662)
Caused by: javax.naming.PartialResultException [Root exception is javax.naming.ServiceUnavailableException: sudxxxxx.com:389; socket closed; remaining name '']
	at com.sun.jndi.ldap.LdapNamingEnumeration.hasMoreImpl(LdapNamingEnumeration.java:224)
	at com.sun.jndi.ldap.LdapNamingEnumeration.hasMore(LdapNamingEnumeration.java:171)
	at org.nuxeo.ecm.directory.ldap.LDAPSession.getLdapEntry(LDAPSession.java:323)
	at org.nuxeo.ecm.directory.ldap.LDAPSession.getLdapEntry(LDAPSession.java:270)
	at org.nuxeo.ecm.directory.ldap.LDAPSession.authenticate(LDAPSession.java:999)
	... 42 more
Caused by: javax.naming.ServiceUnavailableException: sudxxxxx.com:389; socket closed; remaining name ''
	at com.sun.jndi.ldap.Connection.readReply(Connection.java:419)
	at com.sun.jndi.ldap.LdapClient.getSearchReply(LdapClient.java:611)
	at com.sun.jndi.ldap.LdapClient.search(LdapClient.java:534)
	at com.sun.jndi.ldap.LdapCtx.doSearch(LdapCtx.java:1962)
	at com.sun.jndi.ldap.LdapCtx.searchAux(LdapCtx.java:1824)
	at com.sun.jndi.ldap.LdapCtx.c_search(LdapCtx.java:1749)
	at com.sun.jndi.toolkit.ctx.ComponentDirContext.p_search(ComponentDirContext.java:368)
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.search(PartialCompositeDirContext.java:338)
	at com.sun.jndi.ldap.LdapReferralContext.search(LdapReferralContext.java:639)
	at com.sun.jndi.ldap.LdapSearchEnumeration.getReferredResults(LdapSearchEnumeration.java:169)
	at com.sun.jndi.ldap.LdapNamingEnumeration.hasMoreReferrals(LdapNamingEnumeration.java:345)
	at com.sun.jndi.ldap.LdapNamingEnumeration.hasMoreImpl(LdapNamingEnumeration.java:208)
	... 46 more
2013-02-26 10:03:38,971 INFO  [org.nuxeo.ecm.platform.ui.web.auth.NuxeoAuthenticationFilter] Login failed for d.xxxxx

---- Another problem despite the parameter ----

I have modified the pameter retries with 50 but we have sometimes this error (connection reset) :

2013-03-28 09:49:43,014 ERROR [org.nuxeo.ecm.platform.login.NuxeoLoginModule] Authentication failed: failed to fetch the ldap entry for d.xxxxx
org.nuxeo.ecm.directory.DirectoryException: failed to fetch the ldap entry for d.xxxxx
	at org.nuxeo.ecm.directory.ldap.LDAPSession.authenticate(LDAPSession.java:1001)
	at org.nuxeo.ecm.directory.multi.MultiDirectorySession.authenticate(MultiDirectorySession.java:394)
	at org.nuxeo.ecm.platform.usermanager.UserManagerImpl.checkUsernamePassword(UserManagerImpl.java:382)
	at org.nuxeo.ecm.platform.login.NuxeoLoginModule.validateUserIdentity(NuxeoLoginModule.java:321)
	at org.nuxeo.ecm.platform.login.NuxeoLoginModule.getPrincipal(NuxeoLoginModule.java:210)
	at org.nuxeo.ecm.platform.login.NuxeoLoginModule.login(NuxeoLoginModule.java:261)
	at org.nuxeo.runtime.api.LoginModuleWrapper.login(LoginModuleWrapper.java:77)
	at sun.reflect.GeneratedMethodAccessor57.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at javax.security.auth.login.LoginContext.invoke(LoginContext.java:769)
	at javax.security.auth.login.LoginContext.access$000(LoginContext.java:186)
	at javax.security.auth.login.LoginContext$4.run(LoginContext.java:683)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:680)
	at javax.security.auth.login.LoginContext.login(LoginContext.java:579)
	at org.nuxeo.ecm.platform.ui.web.auth.NuxeoAuthenticationFilter.doAuthenticate(NuxeoAuthenticationFilter.java:233)
	at org.nuxeo.ecm.platform.ui.web.auth.NuxeoAuthenticationFilter.doFilterInternal(NuxeoAuthenticationFilter.java:484)
	at org.nuxeo.ecm.platform.ui.web.auth.service.NuxeoAuthFilterChain.doFilter(NuxeoAuthFilterChain.java:35)
	at org.nuxeo.ecm.platform.ui.web.auth.oauth.NuxeoOAuthFilter.doFilter(NuxeoOAuthFilter.java:116)
	at org.nuxeo.ecm.platform.ui.web.auth.service.NuxeoAuthFilterChain.doFilter(NuxeoAuthFilterChain.java:33)
	at org.nuxeo.ecm.platform.ui.web.auth.NuxeoAuthenticationFilter.doFilter(NuxeoAuthenticationFilter.java:349)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.nuxeo.ecm.platform.web.common.exceptionhandling.NuxeoExceptionFilter.doFilter(NuxeoExceptionFilter.java:79)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.nuxeo.ecm.platform.web.common.encoding.NuxeoEncodingFilter.doFilter(NuxeoEncodingFilter.java:59)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
	at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190)
	at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291)
	at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:776)
	at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:705)
	at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:898)
	at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690)
	at java.lang.Thread.run(Thread.java:662)
Caused by: javax.naming.CommunicationException: Connection reset [Root exception is java.net.SocketException: Connection reset]; remaining name 'dc=sudxxxxx,dc=com'
	at com.sun.jndi.ldap.LdapCtx.doSearch(LdapCtx.java:1979)
	at com.sun.jndi.ldap.LdapCtx.searchAux(LdapCtx.java:1824)
	at com.sun.jndi.ldap.LdapCtx.c_search(LdapCtx.java:1749)
	at com.sun.jndi.ldap.LdapCtx.c_search(LdapCtx.java:1766)
	at com.sun.jndi.toolkit.ctx.ComponentDirContext.p_search(ComponentDirContext.java:394)
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.search(PartialCompositeDirContext.java:376)
	at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.search(PartialCompositeDirContext.java:358)
	at javax.naming.directory.InitialDirContext.search(InitialDirContext.java:267)
	at sun.reflect.GeneratedMethodAccessor1262.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.nuxeo.ecm.directory.ldap.LdapRetryHandler.invoke(LdapRetryHandler.java:59)
	at $Proxy185.search(Unknown Source)
	at org.nuxeo.ecm.directory.ldap.LDAPSession.getLdapEntry(LDAPSession.java:301)
	at org.nuxeo.ecm.directory.ldap.LDAPSession.getLdapEntry(LDAPSession.java:270)
	at org.nuxeo.ecm.directory.ldap.LDAPSession.authenticate(LDAPSession.java:999)
	... 42 more
Caused by: java.net.SocketException: Connection reset
	at java.net.SocketInputStream.read(SocketInputStream.java:168)
	at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
	at java.io.BufferedInputStream.read1(BufferedInputStream.java:258)
	at java.io.BufferedInputStream.read(BufferedInputStream.java:317)
	at com.sun.jndi.ldap.Connection.run(Connection.java:808)
	... 1 more
2013-03-28 09:49:43,016 INFO  [org.nuxeo.ecm.platform.ui.web.auth.NuxeoAuthenticationFilter] Login failed for d.xxxxx

Someone can help us ? This is become urgent because users do not understand the problem and suddenly may no longer want to use the GED.

Thanks in advance.

[Julien_Carsique]

Hi,

What is your Nuxeo version?

This might be due to different (timeout?) configurations between Nuxeo and the LDAP since the socket appears as closed whereas it has been previously used a few milliseconds just before the connection attempt which fails.
/> The Sun LDAP Javadoc says:

This exception is thrown when attempting to communicate with a directory or naming service and that service is not available. It might be unavailable for different reasons. For example, the server might be too busy to service the request, ...

Was it working earlier? Do you know if something has changed (on the Nuxeo or LDAP side)? Do you have ping/availability statistics about your LDAP? Is it monitored, overloaded, ..?

Please follow LDAP debug documentation (optionally adding com.sun.jndi.ldap category with TRACE or DEBUG level) to get more details in the server logs, including timestamps between successful and failing LDAP requests.

Regards

[bharat4212_]

2013-04-10 14

[Olivier_Grisel]

A fix for this issue has been included in the hotfix releases from december 2012:

• NXP-10669
• Source code diff

Versions that include the fix:

• 5.4.2-HF31
• 5.5.0-HF18
• 5.6.0-HF07
• 5.7 (currently still under development)

[delphine_]

Many thanks for your answer.

[bharat4212_]

still getting the same issue after applying hotfix and retrie parameter

[bharat4212_]

Getting the error in nuxeo 5.7

2013-09-04 13:32:50,231 ERROR [org.nuxeo.ecm.platform.login.NuxeoLoginModule] Authentication failed: failed to fetch the ldap entry for user org.nuxeo.ecm.directory.DirectoryException: failed to fetch the ldap entry for ebharme at org.nuxeo.ecm.directory.ldap.LDAPSession.authenticate(LDAPSession.java:1014) at org.nuxeo.ecm.platform.usermanager.UserManagerImpl.checkUsernamePassword(UserManagerImpl.java:382) at org.nuxeo.ecm.platform.login.NuxeoLoginModule.validateUserIdentity(NuxeoLoginModule.java:321) at org.nuxeo.ecm.platform.login.NuxeoLoginModule.getPrincipal(NuxeoLoginModule.java:210) at org.nuxeo.ecm.platform.login.NuxeoLoginModule.login(NuxeoLoginModule.java:261) at org.nuxeo.runtime.api.LoginModuleWrapper.login(LoginModuleWrapper.java:77) at sun.reflect.GeneratedMethodAccessor54.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at javax.security.auth.login.LoginContext.invoke(LoginContext.java:784) at javax.security.auth.login.LoginContext.access$000(LoginContext.java:203) at javax.security.auth.login.LoginContext$4.run(LoginContext.java:698) at javax.security.auth.login.LoginContext$4.run(LoginContext.java:696) at java.security.AccessController.doPrivileged(Native Method) at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:695) at javax.security.auth.login.LoginContext.login(LoginContext.java:594) at org.nuxeo.ecm.platform.ui.web.auth.NuxeoAuthenticationFilter.doAuthenticate(NuxeoAuthenticationFilter.java:271) at org.nuxeo.ecm.platform.ui.web.auth.NuxeoAuthenticationFilter.doFilterInternal(NuxeoAuthenticationFilter.java:531) at org.nuxeo.ecm.platform.ui.web.auth.service.NuxeoAuthFilterChain.doFilter(NuxeoAuthFilterChain.java:35) at org.nuxeo.ecm.platform.ui.web.auth.oauth.NuxeoOAuthFilter.doFilter(NuxeoOAuthFilter.java:119) at org.nuxeo.ecm.platform.ui.web.auth.service.NuxeoAuthFilterChain.doFilter(NuxeoAuthFilterChain.java:33) at org.nuxeo.ecm.platform.ui.web.auth.NuxeoAuthenticationFilter.doFilter(NuxeoAuthenticationFilter.java:391) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) at org.nuxeo.ecm.platform.web.common.exceptionhandling.NuxeoExceptionFilter.doFilter(NuxeoExceptionFilter.java:79) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) at org.nuxeo.ecm.platform.web.common.encoding.NuxeoEncodingFilter.doFilter(NuxeoEncodingFilter.java:59) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293) at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859) at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:602) at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489) at java.lang.Thread.run(Thread.java:724) Caused by: javax.naming.CommunicationException: Connection reset [Root exception is java.net.SocketException: Connection reset]; remaining name 'DC=xxxxxx,DC=xxxx' at com.sun.jndi.ldap.LdapCtx.doSearch(LdapCtx.java:2003) at com.sun.jndi.ldap.LdapCtx.searchAux(LdapCtx.java:1847) at com.sun.jndi.ldap.LdapCtx.c_search(LdapCtx.java:1772) at com.sun.jndi.ldap.LdapCtx.c_search(LdapCtx.java:1789) at com.sun.jndi.toolkit.ctx.ComponentDirContext.p_search(ComponentDirContext.java:412) at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.search(PartialCompositeDirContext.java:394) at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.search(PartialCompositeDirContext.java:376) at javax.naming.directory.InitialDirContext.search(InitialDirContext.java:286) at sun.reflect.GeneratedMethodAccessor399.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.nuxeo.ecm.directory.ldap.LdapRetryHandler.invoke(LdapRetryHandler.java:59) at com.sun.proxy.$Proxy182.search(Unknown Source) at org.nuxeo.ecm.directory.ldap.LDAPSession.getLdapEntry(LDAPSession.java:303) at org.nuxeo.ecm.directory.ldap.LDAPSession.getLdapEntry(LDAPSession.java:272) at org.nuxeo.ecm.directory.ldap.LDAPSession.authenticate(LDAPSession.java:1012) ... 39 more Caused by: java.net.SocketException: Connection reset at java.net.SocketInputStream.read(SocketInputStream.java:189) at java.net.SocketInputStream.read(SocketInputStream.java:121) at java.io.BufferedInputStream.fill(BufferedInputStream.java:235) at java.io.BufferedInputStream.read1(BufferedInputStream.java:275) at java.io.BufferedInputStream.read(BufferedInputStream.java:334) at com.sun.jndi.ldap.Connection.run(Connection.java:849) ... 1 more 2013-09-04 13:32:50,236 INFO [org.nuxeo.ecm.platform.ui.web.auth.NuxeoAuthenticationFilter] Login failed for user

[bharat4212_]

please suggest me on above error asap, getting error again and again even i have tried it with retries parameter.

[Florent_Guillau]

1. please don't use "asap" in a free public forum, it doesn't look good.

[Florent_Guillau]

java.net.SocketException: Connection reset basically means that your sever or your network is broken. Nuxeo can only do so much to do retries and work around that, but at some point you'll have to fix your server or your network.