enonic / xp

Enonic XP
https://enonic.com
GNU General Public License v3.0
201 stars 34 forks source link

Applications from market don't get started #8022

Open rymsha opened 4 years ago

rymsha commented 4 years ago

It happens under significant load. Application appears installed, but does not start. In cluster other nodes don't get it even installed.

jsi commented 4 years ago

This is reproducible on QA. Using JMeter I started 50 threads requesting the front-page continuously. That is enough to reproduce it:

This may be tried for all nodes. I installed one app on each node. 2-3 minutes later, I stopped the JMeter-script. At that point, the last app I had installed spread to all nodes and started, but the first two apps stayed stopped on the nodes where it was installed, and did not appear on any other nodes.

I also tried uninstalling a simple app that was started on all nodes. There was no problems with this. It was removed from all nodes.

rymsha commented 4 years ago

Which page Jmeter tries to access, @jsi ?

rymsha commented 4 years ago

8110 could be the reason

jsi commented 4 years ago

@rymsha I was experimenting with JMeter and set up two Thread Groups. One repeated the Home Page and the Pricing Page over and over again. The other Thread Group did the same with the Home Page and the Case Study page. - So 50% of the requests went to the Home page, 25% to each of the two others.

rymsha commented 4 years ago

It appears to be similar to #5421

What happens:

What does not happen:

jsi commented 4 years ago

Reproduced on QA again, with 7.3.0-RC2. Here is stacktrace and other events that seem related from log. Full log is available on enonic-xpqa-cluster-node1 :


11:27:44.713 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Installed application com.enonic.app.chucknorris bundle 157
11:27:44.716 INFO  E.Bundle.com.enonic.app.chucknorris - BundleEvent INSTALLED
11:27:44.716 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering application com.enonic.app.chucknorris bundle 157
11:27:59.916 ERROR c.e.x.r.i.e.executor.StoreExecutor - Failed to store document with id [8105f72c-9cc7-40dd-b262-22b7a5013778] in index [search-system-repo] branch master
org.elasticsearch.ElasticsearchTimeoutException: Timeout waiting for task.
    at org.elasticsearch.action.support.AdapterActionFuture.actionGet(AdapterActionFuture.java:70)
    at org.elasticsearch.action.support.AdapterActionFuture.actionGet(AdapterActionFuture.java:62)
    at org.elasticsearch.action.support.AdapterActionFuture.actionGet(AdapterActionFuture.java:52)
    at com.enonic.xp.repo.impl.elasticsearch.executor.StoreExecutor.execute(StoreExecutor.java:48)
    at com.enonic.xp.repo.impl.elasticsearch.storage.StorageDaoImpl.store(StorageDaoImpl.java:77)
    at com.enonic.xp.repo.impl.storage.IndexDataServiceImpl.store(IndexDataServiceImpl.java:108)
    at com.enonic.xp.repo.impl.storage.NodeStorageServiceImpl.indexNode(NodeStorageServiceImpl.java:491)
    at com.enonic.xp.repo.impl.storage.NodeStorageServiceImpl.store(NodeStorageServiceImpl.java:75)
    at com.enonic.xp.repo.impl.node.StoreNodeCommand.execute(StoreNodeCommand.java:43)
    at com.enonic.xp.repo.impl.node.CreateNodeCommand.execute(CreateNodeCommand.java:107)
    at com.enonic.xp.repo.impl.node.NodeServiceImpl.doCreate(NodeServiceImpl.java:461)
    at com.enonic.xp.repo.impl.node.NodeServiceImpl.create(NodeServiceImpl.java:449)
    at com.enonic.xp.core.impl.app.ApplicationRepoServiceImpl.createApplicationNode(ApplicationRepoServiceImpl.java:52)
    at com.enonic.xp.core.impl.app.ApplicationServiceImpl.installOrUpdateApplication(ApplicationServiceImpl.java:423)
    at com.enonic.xp.core.impl.app.ApplicationServiceImpl.doInstallGlobalApplication(ApplicationServiceImpl.java:201)
    at com.enonic.xp.core.impl.app.ApplicationServiceImpl.doInstallGlobalApplicationFromUrl(ApplicationServiceImpl.java:196)
    at com.enonic.xp.core.impl.app.ApplicationServiceImpl.lambda$installGlobalApplication$2(ApplicationServiceImpl.java:104)
    at com.enonic.xp.context.ContextImpl.callWith(ContextImpl.java:102)
    at com.enonic.xp.core.impl.app.ApplicationHelper.callWithContext(ApplicationHelper.java:136)
    at com.enonic.xp.core.impl.app.ApplicationServiceImpl.installGlobalApplication(ApplicationServiceImpl.java:104)
    at com.enonic.xp.admin.impl.rest.resource.application.ApplicationResource.installApplication(ApplicationResource.java:420)
    at com.enonic.xp.admin.impl.rest.resource.application.ApplicationResource.lambda$installUrl$10(ApplicationResource.java:359)
    at com.enonic.xp.admin.impl.rest.resource.application.ApplicationResource.lock(ApplicationResource.java:605)
    at com.enonic.xp.admin.impl.rest.resource.application.ApplicationResource.installUrl(ApplicationResource.java:359)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
    at java.base/java.lang.reflect.Method.invoke(Unknown Source)
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:138)
    at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:526)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:415)
    at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$0(ResourceMethodInvoker.java:376)
    at org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:356)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:378)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:347)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:320)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:440)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:229)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:135)
    at org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:356)
    at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:138)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:215)
    at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:227)
    at com.enonic.xp.jaxrs.impl.JaxRsServlet.service(JaxRsServlet.java:42)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
    at com.enonic.xp.web.impl.dispatch.mapping.ServletDefinitionImpl.service(ServletDefinitionImpl.java:40)
    at com.enonic.xp.web.impl.dispatch.pipeline.ServletPipelineImpl.service(ServletPipelineImpl.java:40)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:45)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at com.enonic.app.slowlog.SlowLogger.doHandle(SlowLogger.java:61)
    at com.enonic.xp.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:31)
    at com.enonic.xp.web.filter.BaseWebFilter.doFilter(BaseWebFilter.java:33)
    at com.enonic.xp.web.impl.dispatch.mapping.FilterDefinitionImpl.doFilter(FilterDefinitionImpl.java:41)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:50)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at com.enonic.xp.portal.impl.idprovider.IdProviderFilter.doHandle(IdProviderFilter.java:45)
    at com.enonic.xp.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:31)
    at com.enonic.xp.web.filter.BaseWebFilter.doFilter(BaseWebFilter.java:33)
    at com.enonic.xp.web.impl.dispatch.mapping.FilterDefinitionImpl.doFilter(FilterDefinitionImpl.java:41)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:50)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at com.enonic.xp.web.impl.auth.BasicAuthFilter.doHandle(BasicAuthFilter.java:34)
    at com.enonic.xp.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:31)
    at com.enonic.xp.web.filter.BaseWebFilter.doFilter(BaseWebFilter.java:33)
    at com.enonic.xp.web.impl.dispatch.mapping.FilterDefinitionImpl.doFilter(FilterDefinitionImpl.java:41)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:50)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at com.enonic.xp.web.impl.context.ContextFilter.lambda$doHandle$0(ContextFilter.java:33)
    at com.enonic.xp.context.ContextImpl.callWith(ContextImpl.java:102)
    at com.enonic.xp.web.impl.context.ContextFilter.doHandle(ContextFilter.java:32)
    at com.enonic.xp.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:31)
    at com.enonic.xp.web.filter.BaseWebFilter.doFilter(BaseWebFilter.java:33)
    at com.enonic.xp.web.impl.dispatch.mapping.FilterDefinitionImpl.doFilter(FilterDefinitionImpl.java:41)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:50)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at com.enonic.xp.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:26)
    at com.enonic.xp.web.filter.BaseWebFilter.doFilter(BaseWebFilter.java:33)
    at com.enonic.xp.web.impl.dispatch.mapping.FilterDefinitionImpl.doFilter(FilterDefinitionImpl.java:41)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:50)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at com.enonic.xp.web.impl.dos.DosFilterWrapper.doFilter(DosFilterWrapper.java:65)
    at com.enonic.xp.web.impl.dispatch.mapping.FilterDefinitionImpl.doFilter(FilterDefinitionImpl.java:41)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:50)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at com.enonic.xp.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:26)
    at com.enonic.xp.web.filter.BaseWebFilter.doFilter(BaseWebFilter.java:33)
    at com.enonic.xp.web.impl.dispatch.mapping.FilterDefinitionImpl.doFilter(FilterDefinitionImpl.java:41)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:50)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterPipelineImpl.filter(FilterPipelineImpl.java:39)
    at com.enonic.xp.web.impl.dispatch.DispatchServletImpl.service(DispatchServletImpl.java:52)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:763)
    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:551)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
    at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:625)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235)
    at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1610)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1363)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:489)
    at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1580)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1278)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
    at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:220)
    at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:79)
    at com.enonic.xp.web.vhost.impl.VirtualHostFilter.doHandle(VirtualHostFilter.java:53)
    at com.enonic.xp.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:31)
    at com.enonic.xp.web.filter.BaseWebFilter.doFilter(BaseWebFilter.java:33)
    at com.enonic.xp.web.impl.dispatch.mapping.FilterDefinitionImpl.doFilter(FilterDefinitionImpl.java:41)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:50)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at com.enonic.xp.web.impl.dos.DosFilterWrapper.doFilter(DosFilterWrapper.java:65)
    at com.enonic.xp.web.impl.dispatch.mapping.FilterDefinitionImpl.doFilter(FilterDefinitionImpl.java:41)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:50)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at org.eclipse.jetty.servlets.HeaderFilter.doFilter(HeaderFilter.java:117)
    at com.enonic.xp.web.impl.header.HeaderFilterWrapper.doHandle(HeaderFilterWrapper.java:51)
    at com.enonic.xp.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:31)
    at com.enonic.xp.web.filter.BaseWebFilter.doFilter(BaseWebFilter.java:33)
    at com.enonic.xp.web.impl.dispatch.mapping.FilterDefinitionImpl.doFilter(FilterDefinitionImpl.java:41)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:50)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterPipelineImpl.filter(FilterPipelineImpl.java:39)
    at com.enonic.xp.web.impl.dispatch.DispatchServletImpl.service(DispatchServletImpl.java:52)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:763)
    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:551)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
    at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:717)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235)
    at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1610)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1363)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:489)
    at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1580)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1278)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
    at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:221)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
    at com.codahale.metrics.jetty9.InstrumentedHandler.handle(InstrumentedHandler.java:249)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
    at org.eclipse.jetty.server.Server.handle(Server.java:500)
    at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383)
    at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:547)
    at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375)
    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273)
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
    at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
    at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
    at java.base/java.lang.Thread.run(Unknown Source)
11:27:59.918 ERROR c.e.x.a.i.r.r.a.ApplicationResource - Failed to process application from https://repo.enonic.com/public/com/enonic/app/chucknorris/2.1.0/chucknorris-2.1.0.jar
com.enonic.xp.repository.IndexException: Failed to store document with id [8105f72c-9cc7-40dd-b262-22b7a5013778] in index [search-system-repo] branch master
    at com.enonic.xp.repo.impl.elasticsearch.executor.StoreExecutor.execute(StoreExecutor.java:57)
    at com.enonic.xp.repo.impl.elasticsearch.storage.StorageDaoImpl.store(StorageDaoImpl.java:77)
    at com.enonic.xp.repo.impl.storage.IndexDataServiceImpl.store(IndexDataServiceImpl.java:108)
    at com.enonic.xp.repo.impl.storage.NodeStorageServiceImpl.indexNode(NodeStorageServiceImpl.java:491)
    at com.enonic.xp.repo.impl.storage.NodeStorageServiceImpl.store(NodeStorageServiceImpl.java:75)
    at com.enonic.xp.repo.impl.node.StoreNodeCommand.execute(StoreNodeCommand.java:43)
    at com.enonic.xp.repo.impl.node.CreateNodeCommand.execute(CreateNodeCommand.java:107)
    at com.enonic.xp.repo.impl.node.NodeServiceImpl.doCreate(NodeServiceImpl.java:461)
    at com.enonic.xp.repo.impl.node.NodeServiceImpl.create(NodeServiceImpl.java:449)
    at com.enonic.xp.core.impl.app.ApplicationRepoServiceImpl.createApplicationNode(ApplicationRepoServiceImpl.java:52)
    at com.enonic.xp.core.impl.app.ApplicationServiceImpl.installOrUpdateApplication(ApplicationServiceImpl.java:423)
    at com.enonic.xp.core.impl.app.ApplicationServiceImpl.doInstallGlobalApplication(ApplicationServiceImpl.java:201)
    at com.enonic.xp.core.impl.app.ApplicationServiceImpl.doInstallGlobalApplicationFromUrl(ApplicationServiceImpl.java:196)
    at com.enonic.xp.core.impl.app.ApplicationServiceImpl.lambda$installGlobalApplication$2(ApplicationServiceImpl.java:104)
    at com.enonic.xp.context.ContextImpl.callWith(ContextImpl.java:102)
    at com.enonic.xp.core.impl.app.ApplicationHelper.callWithContext(ApplicationHelper.java:136)
    at com.enonic.xp.core.impl.app.ApplicationServiceImpl.installGlobalApplication(ApplicationServiceImpl.java:104)
    at com.enonic.xp.admin.impl.rest.resource.application.ApplicationResource.installApplication(ApplicationResource.java:420)
    at com.enonic.xp.admin.impl.rest.resource.application.ApplicationResource.lambda$installUrl$10(ApplicationResource.java:359)
    at com.enonic.xp.admin.impl.rest.resource.application.ApplicationResource.lock(ApplicationResource.java:605)
    at com.enonic.xp.admin.impl.rest.resource.application.ApplicationResource.installUrl(ApplicationResource.java:359)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
    at java.base/java.lang.reflect.Method.invoke(Unknown Source)
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:138)
    at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:526)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:415)
    at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$0(ResourceMethodInvoker.java:376)
    at org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:356)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:378)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:347)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:320)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:440)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:229)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:135)
    at org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:356)
    at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:138)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:215)
    at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:227)
    at com.enonic.xp.jaxrs.impl.JaxRsServlet.service(JaxRsServlet.java:42)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
    at com.enonic.xp.web.impl.dispatch.mapping.ServletDefinitionImpl.service(ServletDefinitionImpl.java:40)
    at com.enonic.xp.web.impl.dispatch.pipeline.ServletPipelineImpl.service(ServletPipelineImpl.java:40)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:45)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at com.enonic.app.slowlog.SlowLogger.doHandle(SlowLogger.java:61)
    at com.enonic.xp.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:31)
    at com.enonic.xp.web.filter.BaseWebFilter.doFilter(BaseWebFilter.java:33)
    at com.enonic.xp.web.impl.dispatch.mapping.FilterDefinitionImpl.doFilter(FilterDefinitionImpl.java:41)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:50)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at com.enonic.xp.portal.impl.idprovider.IdProviderFilter.doHandle(IdProviderFilter.java:45)
    at com.enonic.xp.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:31)
    at com.enonic.xp.web.filter.BaseWebFilter.doFilter(BaseWebFilter.java:33)
    at com.enonic.xp.web.impl.dispatch.mapping.FilterDefinitionImpl.doFilter(FilterDefinitionImpl.java:41)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:50)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at com.enonic.xp.web.impl.auth.BasicAuthFilter.doHandle(BasicAuthFilter.java:34)
    at com.enonic.xp.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:31)
    at com.enonic.xp.web.filter.BaseWebFilter.doFilter(BaseWebFilter.java:33)
    at com.enonic.xp.web.impl.dispatch.mapping.FilterDefinitionImpl.doFilter(FilterDefinitionImpl.java:41)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:50)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at com.enonic.xp.web.impl.context.ContextFilter.lambda$doHandle$0(ContextFilter.java:33)
    at com.enonic.xp.context.ContextImpl.callWith(ContextImpl.java:102)
    at com.enonic.xp.web.impl.context.ContextFilter.doHandle(ContextFilter.java:32)
    at com.enonic.xp.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:31)
    at com.enonic.xp.web.filter.BaseWebFilter.doFilter(BaseWebFilter.java:33)
    at com.enonic.xp.web.impl.dispatch.mapping.FilterDefinitionImpl.doFilter(FilterDefinitionImpl.java:41)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:50)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at com.enonic.xp.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:26)
    at com.enonic.xp.web.filter.BaseWebFilter.doFilter(BaseWebFilter.java:33)
    at com.enonic.xp.web.impl.dispatch.mapping.FilterDefinitionImpl.doFilter(FilterDefinitionImpl.java:41)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:50)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at com.enonic.xp.web.impl.dos.DosFilterWrapper.doFilter(DosFilterWrapper.java:65)
    at com.enonic.xp.web.impl.dispatch.mapping.FilterDefinitionImpl.doFilter(FilterDefinitionImpl.java:41)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:50)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at com.enonic.xp.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:26)
    at com.enonic.xp.web.filter.BaseWebFilter.doFilter(BaseWebFilter.java:33)
    at com.enonic.xp.web.impl.dispatch.mapping.FilterDefinitionImpl.doFilter(FilterDefinitionImpl.java:41)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:50)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterPipelineImpl.filter(FilterPipelineImpl.java:39)
    at com.enonic.xp.web.impl.dispatch.DispatchServletImpl.service(DispatchServletImpl.java:52)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:763)
    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:551)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
    at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:625)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235)
    at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1610)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1363)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:489)
    at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1580)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1278)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
    at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:220)
    at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:79)
    at com.enonic.xp.web.vhost.impl.VirtualHostFilter.doHandle(VirtualHostFilter.java:53)
    at com.enonic.xp.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:31)
    at com.enonic.xp.web.filter.BaseWebFilter.doFilter(BaseWebFilter.java:33)
    at com.enonic.xp.web.impl.dispatch.mapping.FilterDefinitionImpl.doFilter(FilterDefinitionImpl.java:41)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:50)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at com.enonic.xp.web.impl.dos.DosFilterWrapper.doFilter(DosFilterWrapper.java:65)
    at com.enonic.xp.web.impl.dispatch.mapping.FilterDefinitionImpl.doFilter(FilterDefinitionImpl.java:41)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:50)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at org.eclipse.jetty.servlets.HeaderFilter.doFilter(HeaderFilter.java:117)
    at com.enonic.xp.web.impl.header.HeaderFilterWrapper.doHandle(HeaderFilterWrapper.java:51)
    at com.enonic.xp.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:31)
    at com.enonic.xp.web.filter.BaseWebFilter.doFilter(BaseWebFilter.java:33)
    at com.enonic.xp.web.impl.dispatch.mapping.FilterDefinitionImpl.doFilter(FilterDefinitionImpl.java:41)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:50)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterChainImpl.doFilter(FilterChainImpl.java:36)
    at com.enonic.xp.web.impl.dispatch.pipeline.FilterPipelineImpl.filter(FilterPipelineImpl.java:39)
    at com.enonic.xp.web.impl.dispatch.DispatchServletImpl.service(DispatchServletImpl.java:52)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:763)
    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:551)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
    at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:717)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235)
    at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1610)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1363)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:489)
    at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1580)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1278)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
    at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:221)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
    at com.codahale.metrics.jetty9.InstrumentedHandler.handle(InstrumentedHandler.java:249)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
    at org.eclipse.jetty.server.Server.handle(Server.java:500)
    at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383)
    at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:547)
    at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375)
    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273)
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
    at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
    at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
    at java.base/java.lang.Thread.run(Unknown Source)
Caused by: org.elasticsearch.ElasticsearchTimeoutException: Timeout waiting for task.
    at org.elasticsearch.action.support.AdapterActionFuture.actionGet(AdapterActionFuture.java:70)
    at org.elasticsearch.action.support.AdapterActionFuture.actionGet(AdapterActionFuture.java:62)
    at org.elasticsearch.action.support.AdapterActionFuture.actionGet(AdapterActionFuture.java:52)
    at com.enonic.xp.repo.impl.elasticsearch.executor.StoreExecutor.execute(StoreExecutor.java:48)
    ... 160 common frames omitted
11:27:59.928 ERROR com.enonic.app.slowlog.SlowLogger - [/admin/rest/application/installUrl] [16853ms]```
rymsha commented 3 years ago

The application should be stored into node storage BEFORE there is an attempt to install it - they would fix part of the problem.

Currently store happens after installation, to not persist "poisoned pills". The argument is rather weak

We need to discuss it with @sigdestad

Another part of this issue is a started flag persistence. Under heavy load ES may decline it, so application won't appear started after cluster restart. But will be a way more expected behaviour.

sigdestad commented 3 years ago

Applications should indeed be persisted before we attempt to start them imho. If we want to perform scans or checks before persisting that is fine, but booting the app before it is actually stored will only complicate things afaik.

I guess an interesting feature would be to "deploy apps" without persisting them. Might be useful when developing against a cluster or similar to avoid piling up node versions? I.e. we could have the option to "deploy" via management API, and it would install the app, but not persist it? Not something I would prioritize though

rymsha commented 3 years ago

current flow:

  1. download app jar
  2. install app bundle
  3. persist app jar in node store
  4. tell other nodes to install app
  5. tell other nodes to start app
  6. start app
  7. persist app started flag

any step may fail for any reason in case of an error at any step, flow aborts and no following steps are done.

proposed flow :

  1. download app jar
  2. persist app jar in node store
  3. tell other nodes to install app
  4. install app bundle
  5. persist app started flag
  6. tell other nodes to start app
  7. start app
sigdestad commented 3 years ago

If this "node started flag" is already present, then this seems like a plan Sergey!