LdapDataAccessException

[yelyad]

If I let my login page sit for a period of time(several minutes) and then attempt to login the following exception occurs. If I refresh (repost the data) it works no problem.

org.acegisecurity.ldap.LdapDataAccessException: LdapCallback;Request: 4 cancelled; nested exception is javax.naming.CommunicationException: Request: 4 cancelled; remaining name ''
	at org.acegisecurity.ldap.LdapTemplate$LdapExceptionTranslator.translate(LdapTemplate.java:290)
	at org.acegisecurity.ldap.LdapTemplate.execute(LdapTemplate.java:128)
	at org.acegisecurity.ldap.LdapTemplate.searchForSingleEntry(LdapTemplate.java:242)
	at org.acegisecurity.ldap.search.FilterBasedLdapUserSearch.searchForUser(FilterBasedLdapUserSearch.java:121)
	at org.acegisecurity.providers.ldap.authenticator.BindAuthenticator.authenticate(BindAuthenticator.java:66)
	at org.acegisecurity.providers.ldap.LdapAuthenticationProvider.retrieveUser(LdapAuthenticationProvider.java:160)
	at org.acegisecurity.providers.dao.AbstractUserDetailsAuthenticationProvider.authenticate(AbstractUserDetailsAuthenticationProvider.java:115)
	at org.acegisecurity.providers.ProviderManager.doAuthentication(ProviderManager.java:183)
	at org.acegisecurity.AbstractAuthenticationManager.authenticate(AbstractAuthenticationManager.java:45)
	at org.acegisecurity.ui.webapp.AuthenticationProcessingFilter.attemptAuthentication(AuthenticationProcessingFilter.java:71)
	at org.acegisecurity.ui.AbstractProcessingFilter.doFilter(AbstractProcessingFilter.java:198)
	at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
	at org.acegisecurity.context.HttpSessionContextIntegrationFilter.doFilter(HttpSessionContextIntegrationFilter.java:195)
	at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
	at org.acegisecurity.util.FilterChainProxy.doFilter(FilterChainProxy.java:148)
	at org.acegisecurity.util.FilterToBeanProxy.doFilter(FilterToBeanProxy.java:90)
	at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
	at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:3151)
	at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)
	at weblogic.security.service.SecurityManager.runAs(SecurityManager.java:121)
	at weblogic.servlet.internal.WebAppServletContext.securedExecute(WebAppServletContext.java:1973)
	at weblogic.servlet.internal.WebAppServletContext.execute(WebAppServletContext.java:1880)
	at weblogic.servlet.internal.ServletRequestImpl.run(ServletRequestImpl.java:1310)
	at weblogic.work.ExecuteThread.execute(ExecuteThread.java:207)
	at weblogic.work.ExecuteThread.run(ExecuteThread.java:179)
Caused by: javax.naming.CommunicationException: Request: 4 cancelled; remaining name ''
	at com.sun.jndi.ldap.LdapRequest.getReplyBer(LdapRequest.java:60)
	at com.sun.jndi.ldap.Connection.readReply(Connection.java:405)
	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:1944)
	at com.sun.jndi.ldap.LdapCtx.searchAux(LdapCtx.java:1806)
	at com.sun.jndi.ldap.LdapCtx.c_search(LdapCtx.java:1731)
	at com.sun.jndi.ldap.LdapCtx.c_search(LdapCtx.java:1748)
	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 org.acegisecurity.ldap.LdapTemplate$3.doInDirContext(LdapTemplate.java:245)
	at org.acegisecurity.ldap.LdapTemplate.execute(LdapTemplate.java:126)

Any ideas as to why this might be happening?

[Luke Taylor]

Well it looks like a problem connecting to your LDAP server, but you don't say what you're using.

Pasting the error message into google comes up with a specific issue using Lotus Domino server...

Is that the server you are using ???

If so then I would do more research on that front. And try switching off ldap connection pooling, or don't use bind authentication.

[yelyad]

Well, it turned out to be an issue with the session timing out. Thanks, for your help.

[Luke Taylor]

Could you expand on that please? It seems curious that a session timeout would result in an exception like that and I'd like to know what actually caused it, 'cos the LDAP provider shouldn't be linked to HTTP sessions in any way. The connection pool will be maintained separately by the Sun LDAP implementation.

[yelyad]

Okay. I agree this seems odd. I didn't have much time to look at it yesterday, but what I did was implement a HttpSessionListener to watch for when the session was being destroyed. Once it was destroyed, I tried to login and I got the exception. This may have been coincidence (probably) but I didn't have much time to look into it further, so I will this morning.

FYI, the ldap server is part of IBM's SecureWay package.

Thanks again.

[yelyad]

Well, I set the session to timeout after 1 minute and after it was destroyed I tried to login and it worked. So as you suspected the exception did not occur because of a session timout. Here is what I see in the debug log:

2006-07-06 10:30:54,984 DEBUG org.acegisecurity.providers.ProviderManager - Authentication attempt using org.acegisecurity.providers.ldap.LdapAuthenticationProvider
2006-07-06 10:30:54,984 DEBUG org.acegisecurity.providers.ldap.LdapAuthenticationProvider - Retrieving user {username}
2006-07-06 10:30:54,984 DEBUG org.acegisecurity.ldap.DefaultInitialDirContextFactory - Creating InitialDirContext with environment {java.naming.provider.url=ldap://{server}/{path}, java.naming.factory.initial=com.sun.jndi.ld
ap.LdapCtxFactory, java.naming.security.principal={admin}, com.sun.jndi.ldap.connect.pool=true, java.naming.security.authentication=simple, java.naming.security.credentials=******}
2006-07-06 10:30:54,984 DEBUG org.acegisecurity.ldap.search.FilterBasedLdapUserSearch - Searching for user '{username}', in context javax.naming.directory.InitialDirContext@135348f, with user search [ searchFilter: '(uid={0})'
, searchBase: '', scope: subtreesearchTimeLimit: 0derefLinkFlag: false ]
2006-07-06 10:30:54,984 DEBUG org.acegisecurity.ldap.DefaultInitialDirContextFactory - Creating InitialDirContext with environment {java.naming.provider.url=ldap://{server}/{path}, java.naming.factory.initial=com.sun.jndi.ld
ap.LdapCtxFactory, java.naming.security.principal={admin}, com.sun.jndi.ldap.connect.pool=true, java.naming.security.authentication=simple, java.naming.security.credentials=******}
2006-07-06 10:30:55,062 DEBUG org.acegisecurity.context.HttpSessionContextIntegrationFilter - SecurityContextHolder set to new context, as request processing completed
<Jul 6, 2006 10:30:55 AM MDT> <Error> <HTTP> <BEA-101020> <[weblogic.servlet.internal.WebAppServletContext@e37431 - name: 'app.war', context-path: '/app'] Servlet failed with Exception
org.acegisecurity.ldap.LdapDataAccessException: LdapCallback;Request: 7 cancelled; nested exception is javax.naming.CommunicationException: Request: 7 cancelled; remaining name ''
        at org.acegisecurity.ldap.LdapTemplate$LdapExceptionTranslator.translate(LdapTemplate.java:290)
        at org.acegisecurity.ldap.LdapTemplate.execute(LdapTemplate.java:128)
        at org.acegisecurity.ldap.LdapTemplate.searchForSingleEntry(LdapTemplate.java:242)
        at org.acegisecurity.ldap.search.FilterBasedLdapUserSearch.searchForUser(FilterBasedLdapUserSearch.java:121)
        at org.acegisecurity.providers.ldap.authenticator.BindAuthenticator.authenticate(BindAuthenticator.java:66)
        Truncated. see log file for complete stacktrace
javax.naming.CommunicationException: Request: 7 cancelled; remaining name ''
        at com.sun.jndi.ldap.LdapRequest.getReplyBer(LdapRequest.java:60)
        at com.sun.jndi.ldap.Connection.readReply(Connection.java:405)
        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:1944)
        Truncated. see log file for complete stacktrace
>

[Luke Taylor]

It may be a connection timeout with the LDAP server connections. The LDAP server may be closing sessions which the client is trying to use (similar to the sort of thing that could happen with JDBC). Did you try disabling connection pooling, or modifying the JDK LDAP connection pool setup?

It might be helpful if you could also give some indication of your Acegi LDAP configuration. E.g. are you using doing a search for the user before attempting to bind?

[ranjithid]

Hi,

I am getting the below exection occasionally in my application. I am able to look up objects from the InitialContext (singleton object) that I have created. the looks fails sometimes, not sure what is the problem. I don't have a timeout for the connection and no connection pooling too.

Is that the InitialContext became stale after sometimes??
and if I create a new Context will that work??


[javax.naming.CommunicationException: Request: 4 cancelled; remaining name 'cn=QuestMgrQueue']
com.sun.jndi.ldap.LdapRequest.getReplyBer(LdapRequ est.java(Inlined Compiled Code))
com.sun.jndi.ldap.Connection.readReply(Connection. java(Compiled Code))
com.sun.jndi.ldap.LdapClient.getSearchReply(LdapCl ient.java(Compiled Code))
com.sun.jndi.ldap.LdapClient.search(LdapClient.jav a:641)
com.sun.jndi.ldap.LdapCtx.doSearch(LdapCtx.java:19 64)
com.sun.jndi.ldap.LdapCtx.doSearchOnce(LdapCtx.jav a:1913)
com.sun.jndi.ldap.LdapCtx.c_lookup(LdapCtx.java:10 09)
com.sun.jndi.toolkit.ctx.ComponentContext.p_lookup (ComponentContext.java:541)
com.sun.jndi.toolkit.ctx.PartialCompositeContext.l ookup(PartialCompositeContext.java:173)
com.sun.jndi.toolkit.ctx.PartialCompositeContext.l ookup(PartialCompositeContext.java:162)
javax.naming.InitialContext.lookup(InitialContext. java(Compiled Code))
com.utils.JndiObjectLocator.lookup(JndiObjectLocat or.java:95)