LDAP Stopped Working (11.1)

Which error did you get ? You reported several very different things in that thread.

Created Jira Issue: https://jira.xwiki.org/browse/LDAP-70

Which error did you get ? You reported several very different things in that thread.

Do you mean the displayed error? The only thing we ever get in the UI is this:

image

In the logs, there have been no errors consistent (timing-wise) with the failure. I’ve posted several that occurred within days of the failure, and one that seems to happen during the restart of the service, but today this one does appear to have happened during the attempt to login and before the restart:

22-Mar-2019 09:12:13.967 SEVERE [https://xwiki01.pridedallas.com:8443/xwiki/bin/view/Main/IT%20Department%20Contacts/] org.apache.catalina.core.StandardHostValve.invoke Exception Processing /xwiki/bin/view/Main/IT%20Department%20Contacts/
java.lang.NullPointerException
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:245)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:595)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:80)
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:650)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:799)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1457)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)

When you have “Invalid credential” the best would be to enable debug log to see exactly why the authentication failed and report this. The error you pasted does not really seems to have anything to do with the authenticator (but I have no idea what this error means, does not even seems to be related to XWiki in general).

How do I do that? I looked at https://www.xwiki.org/xwiki/bin/view/Documentation/AdminGuide/Logging and at https://dev.xwiki.org/xwiki/bin/view/Community/Debugging, but I’m not clear what the “debug log” is or how to enable that. Do you mean using this method:

Debug mode

[Since 7.1]

It's possible to enable debug log by adding debug=true (as 
in http://127.0.0.1:8080/xwiki/bin/Main/WebHome?debug=true) to the URL. 
This provide various details 
on what exactly happens during the request.

Or by some other method?

Nop.

I’m referring to https://extensions.xwiki.org/xwiki/bin/view/Extension/LDAP/Authenticator/#HEnableLDAPdebuglog.
By default only INFO, WARNING and ERROR log is written but it’s possible to selectively enable DEBUG level in the context of the LDAP authentication to get a step by step detail about what exactly happen and what went wrong written in the log file.

Of course, I tried to do that via the Admin UI and the issue is occurring right now. :frowning: I’ll enable and restart, but that means 3-5 days before it happens again. Will that cause a performance issue?

I can mean a pretty huge log file if there is a lot of users login in.

I know it’s probably not related, but we are still getting that error from time to time:

23-Mar-2019 06:18:37.014 SEVERE [localhost-startStop-2] org.apache.catalina.core.StandardContext.listenerStop Exception sending context destroyed event to listener instance of class [org.xwiki.container.servlet.XWikiServletContextListener]
org.infinispan.IllegalLifecycleStateException: ISPN000323: Cache ‘user.membership.members’ is in ‘TERMINATED’ state and so it does not accept new invocations. Either restart it or recreate the cache container.
at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:97)
at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:79)
at org.infinispan.commands.AbstractVisitor.visitClearCommand(AbstractVisitor.java:58)
at org.infinispan.commands.write.ClearCommand.acceptVisitor(ClearCommand.java:44)
at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:335)
at org.infinispan.cache.impl.CacheImpl.clear(CacheImpl.java:591)
at org.infinispan.cache.impl.CacheImpl.clear(CacheImpl.java:582)
at org.xwiki.cache.infinispan.internal.InfinispanCache.removeAll(InfinispanCache.java:107)
at org.xwiki.user.internal.group.AbstractGroupCache.removeAll(AbstractGroupCache.java:302)
at org.xwiki.user.internal.group.AbstractGroupCache.dispose(AbstractGroupCache.java:323)
at org.xwiki.component.embed.EmbeddableComponentManager.dispose(EmbeddableComponentManager.java:685)
at org.xwiki.container.servlet.XWikiServletContextListener.contextDestroyed(XWikiServletContextListener.java:161)
at org.apache.catalina.core.StandardContext.listenerStop(StandardContext.java:4792)
at org.apache.catalina.core.StandardContext.stopInternal(StandardContext.java:5429)
at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:226)
at org.apache.catalina.core.ContainerBase$StopChild.call(ContainerBase.java:1435)
at org.apache.catalina.core.ContainerBase$StopChild.call(ContainerBase.java:1424)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)

This one is a different cache but it’s the same kind of issue it seems. Note that Infinispan has been upgraded in the currently being released 11.2, maybe it will help.

Created XWIKI-16260

Should I create a Jira issue for this? The exception is no thrown on every restart of Apache Tomcat:

25-Mar-2019 08:19:48.607 SEVERE [localhost-startStop-2] org.apache.catalina.core.StandardContext.listenerStop Exception sending context destroyed event to listener instance of class [org.xwiki.container.servlet.XWikiServletContextListener]
org.infinispan.IllegalLifecycleStateException: ISPN000323: Cache ‘user.membership.members’ is in ‘TERMINATED’ state and so it does not accept new invocations. Either restart it or recreate the cache container.

I made this change. I’m seeing nothing in the logs, but the failure has not occurred. Shouldn’t I see something even without a failure?

image

You definitely should see tons of LDAP log. Have you restarted ?

Yes.

And you are sure you have xwiki.authentication.authclass=org.xwiki.contrib.ldap.XWikiLDAPAuthServiceImpl in xwiki.cfg ?

image

What log(s) should these non-failure debug messages show up in? Maybe I’m looking in the wrong ones (but I’ve scanned on current ones in here:

image

In general you should have various log with “XWikiLDAPAuthServiceImpl” at the beginning (logback print the logger name for each log).

For example you should get somehting like the following log for every single page refresh:

XWikiUser: XWiki.MyUser

And when a user actually authenticate you should get a lot of step by step debug log about what happen during that authentication. Here are some examples:

Connection to LDAP server [host:port]"

Binding to LDAP server with credentials login=[somedn]

Do you mean it will have “XWikiLDAPAuthServiceImpl” in the file name? I can’t find log files with that in the file name (and I’ve searched the entire drive). Where would those normally be created?

No, each log line is generally prefixed with the logger name.

Ok, well, I’ve searched every log and that is not showing up.