XWiki hangs intermittently

tmortagne · June 23, 2019, 12:29pm

@unadequate I commend in the issue but as explain in the description this happen when the key store does not trust the certificate so this is a setup issue.

unadequate · June 23, 2019, 5:49pm

Negative. Just checked - I do not have ldap ssl enabled in xwiki.cfg.
So, it’s definitely an issue with LDAP extension, but not JIRA LDAP-6…
I’ve also just realized that update for LDAP authenticator is available. Set it up and will see if the issue reproduces.

unadequate · June 24, 2019, 10:52am

Situation is the same.
1516 threads:

"Thread-325898" #325986 daemon prio=5 os_prio=0 tid=0x00007f3fd46fb800 nid=0x771 runnable [0x00007f3ee510b000]
   java.lang.Thread.State: RUNNABLE
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
	at java.net.SocketInputStream.read(SocketInputStream.java:171)
	at java.net.SocketInputStream.read(SocketInputStream.java:141)
	at java.net.SocketInputStream.read(SocketInputStream.java:224)
	at com.novell.ldap.asn1.ASN1Identifier.<init>(ASN1Identifier.java:129)
	at com.novell.ldap.Connection$ReaderThread.run(Connection.java:1269)
	at java.lang.Thread.run(Thread.java:748)

Result: JVM performance degradation, application becomes unresponsive. Restart it required.

Reported https://jira.xwiki.org/browse/LDAP-76

unadequate · June 27, 2019, 9:14am

So, I managed to determine full scenario of how to reproduce this:

Set up LDAP authentication
Create local XWiki user (say, XWiki.bot)
Create a script that will frequently (several times per second during 3-4 minutes) and periodically (every 15 minutes) access some restricted pages via rest API using XWiki.bot credentials.
Logs will be flooded with the following:

2019-06-26 21:40:59,027 [https://xwiki.domain.local/rest/wikis/xwiki/spaces/Main/spaces/space1/pages/page1] DEBUG x.c.l.XWikiLDAPAuthServiceImpl - Trying authentication against XWiki DB
2019-06-26 21:40:59,028 [https://xwiki.domain.local/rest/wikis/xwiki/spaces/Main/spaces/space1/pages/page1] DEBUG x.c.l.XWikiLDAPAuthServiceImpl - LDAP authentication succeed with principal [XWiki.bot]
2019-06-26 21:40:59,028 [https://xwiki.domain.local/rest/wikis/xwiki/spaces/Main/spaces/space1/pages/page1] DEBUG x.c.l.XWikiLDAPAuthServiceImpl - XWikiUser: XWiki.bot
2019-06-26 21:40:59,028 [https://xwiki.domain.local/rest/wikis/xwiki/spaces/Main/spaces/space1/pages/page1] DEBUG o.x.c.l.XWikiLDAPConfig - remoteUserParser: null
2019-06-26 21:40:59,028 [https://xwiki.domain.local/rest/wikis/xwiki/spaces/Main/spaces/space1/pages/page1] DEBUG o.x.c.l.XWikiLDAPConfig - ldap_group_classes: [groupofnames, posixgroup, apple-group, groupofuniquenames, dynamicgroup, groupwisedistributionlist, group, dynamicgroupaux]
2019-06-26 21:40:59,029 [https://xwiki.domain.local/rest/wikis/xwiki/spaces/Main/spaces/space1/pages/page1] DEBUG o.x.c.l.XWikiLDAPConfig - ldap_group_memberfields: [uniquemember, memberuid, member]
2019-06-26 21:40:59,029 [https://xwiki.domain.local/rest/wikis/xwiki/spaces/Main/spaces/space1/pages/page1] DEBUG o.x.c.l.XWikiLDAPConnection - Connection to LDAP server [dc01.domain.local:389]
2019-06-26 21:40:59,034 [https://xwiki.domain.local/rest/wikis/xwiki/spaces/Main/spaces/space1/pages/page1] DEBUG o.x.c.l.XWikiLDAPConnection - Binding to LDAP server with credentials login=[bot@domain.local]
2019-06-26 21:40:59,035 [https://xwiki.domain.local/rest/wikis/xwiki/spaces/Main/spaces/space1/pages/page1] DEBUG x.c.l.XWikiLDAPAuthServiceImpl - Local LDAP authentication failed.
org.xwiki.contrib.ldap.XWikiLDAPException: Error number 0 in 5: LDAP bind failed with LDAPException.
at org.xwiki.contrib.ldap.XWikiLDAPConnection.open(XWikiLDAPConnection.java:227)
at org.xwiki.contrib.ldap.XWikiLDAPConnection.open(XWikiLDAPConnection.java:155)
at org.xwiki.contrib.ldap.XWikiLDAPAuthServiceImpl.ldapAuthenticateInContext(XWikiLDAPAuthServiceImpl.java:550)
at org.xwiki.contrib.ldap.XWikiLDAPAuthServiceImpl.ldapAuthenticate(XWikiLDAPAuthServiceImpl.java:366)
at org.xwiki.contrib.ldap.XWikiLDAPAuthServiceImpl.authenticate(XWikiLDAPAuthServiceImpl.java:300)
at com.xpn.xwiki.user.impl.xwiki.MyBasicAuthenticator.authenticate(MyBasicAuthenticator.java:180)
at com.xpn.xwiki.user.impl.xwiki.MyBasicAuthenticator.checkLogin(MyBasicAuthenticator.java:101)
at com.xpn.xwiki.user.impl.xwiki.MyFormAuthenticator.processLogin(MyFormAuthenticator.java:119)
at com.xpn.xwiki.user.impl.xwiki.XWikiAuthServiceImpl.checkAuth(XWikiAuthServiceImpl.java:239)
at org.xwiki.contrib.ldap.XWikiLDAPAuthServiceImpl.checkAuth(XWikiLDAPAuthServiceImpl.java:167)
at com.xpn.xwiki.XWiki.checkAuth(XWiki.java:4136)
at org.xwiki.rest.internal.XWikiAuthentication.authenticate(XWikiAuthentication.java:113)
at org.restlet.security.Authenticator.beforeHandle(Authenticator.java:193)
at org.restlet.routing.Filter.handle(Filter.java:195)
at org.restlet.routing.Filter.doHandle(Filter.java:150)
at org.restlet.routing.Filter.handle(Filter.java:197)
at org.restlet.routing.Filter.doHandle(Filter.java:150)
at org.restlet.routing.Filter.handle(Filter.java:197)
at org.restlet.routing.Filter.doHandle(Filter.java:150)
at org.restlet.routing.Filter.handle(Filter.java:197)
at org.restlet.routing.Filter.doHandle(Filter.java:150)
at org.restlet.engine.application.StatusFilter.doHandle(StatusFilter.java:140)
at org.restlet.routing.Filter.handle(Filter.java:197)
at org.restlet.routing.Filter.doHandle(Filter.java:150)
at org.restlet.routing.Filter.handle(Filter.java:197)
at org.restlet.engine.CompositeHelper.handle(CompositeHelper.java:202)
at org.restlet.engine.application.ApplicationHelper.handle(ApplicationHelper.java:77)
at org.restlet.Application.handle(Application.java:385)
at org.restlet.routing.Filter.doHandle(Filter.java:150)
at org.restlet.routing.Filter.handle(Filter.java:197)
at org.restlet.routing.Router.doHandle(Router.java:422)
at org.restlet.routing.Router.handle(Router.java:641)
at org.restlet.routing.Filter.doHandle(Filter.java:150)
at org.restlet.routing.Filter.handle(Filter.java:197)
at org.restlet.routing.Router.doHandle(Router.java:422)
at org.restlet.routing.Router.handle(Router.java:641)
at org.restlet.routing.Filter.doHandle(Filter.java:150)
at org.restlet.routing.Filter.handle(Filter.java:197)
at org.restlet.engine.CompositeHelper.handle(CompositeHelper.java:202)
at org.restlet.Component.handle(Component.java:408)
at org.restlet.Server.handle(Server.java:507)
at org.restlet.engine.connector.ServerHelper.handle(ServerHelper.java:63)
at org.restlet.engine.adapter.HttpServerHelper.handle(HttpServerHelper.java:143)
at org.restlet.ext.servlet.ServerServlet.service(ServerServlet.java:1117)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.xwiki.wysiwyg.filter.XWikiContextInitializationFilter.doFilter(XWikiContextInitializationFilter.java:85)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.xwiki.container.servlet.filters.internal.SetHTTPHeaderFilter.doFilter(SetHTTPHeaderFilter.java:63)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.xwiki.container.servlet.filters.internal.SavedRequestRestorerFilter.doFilter(SavedRequestRestorerFilter.java:208)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.xwiki.container.servlet.filters.internal.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:111)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.xwiki.resource.servlet.RoutingFilter.doFilter(RoutingFilter.java:132)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:493)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:137)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81)
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:660)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:679)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:798)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:808)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1498)
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)
Caused by: com.novell.ldap.LDAPException: Invalid Credentials
at com.novell.ldap.LDAPResponse.getResultException(LDAPResponse.java:407)
at com.novell.ldap.LDAPResponse.chkResultCode(LDAPResponse.java:370)
at com.novell.ldap.LDAPConnection.chkResultCode(LDAPConnection.java:3959)
at com.novell.ldap.LDAPConnection.bind(LDAPConnection.java:1408)
at com.novell.ldap.LDAPConnection.bind(LDAPConnection.java:1361)
at org.xwiki.contrib.ldap.XWikiLDAPConnection.bind(XWikiLDAPConnection.java:261)
at org.xwiki.contrib.ldap.XWikiLDAPConnection.open(XWikiLDAPConnection.java:223)
… 79 common frames omitted

XWikiLDAPAuthServiceImpl spawns lots of threads (that’s expected), but for some reason they are not terminated in a timely manner, that consequently leads to performance degradation and in fact makes the whole application unresponsive.

This bug allows to perform a DOS attack against XWiki. I cannot even imagine why XWikiLDAPAuthServiceImpl threads do not exit immediately after catching Invalid Credentials exception.

As a workaround I made pages available without authentication.

tmortagne · June 27, 2019, 10:06am

Thanks for the analysis @unadequate. I answered on the jira issue.

unadequate · July 11, 2019, 1:54pm

I can confirm the issue is 100% resolved.
The workaround was to completely disable authentication in my scripts that parses bunch of pages via RestAPI.

Unfortunately that won’t work if you need RestAPI access to restricted pages.
I hope https://jira.xwiki.org/browse/LDAP-18 will be implemented soon.