search

afimb / chouette

chouette is a Java program for validating and exchanging Public Transport datas. Comes with a ruby web app : https://github.com/afimb/chouette2
http://www.chouette.mobi
Other
23 stars 22 forks source link

Concurrent access timeout when under load #33

Open seime opened 8 years ago

seime commented 8 years ago

When we run several data imports in parallel, an exception is thrown and import fails:

15:09:58,437 ERROR [org.jboss.as.ejb3.invocation] (default task-37) JBAS014134: EJB Invocation failed on component Scheduler for method public void mobi.chouette.scheduler.Scheduler.schedule(java.lang.String): javax.ejb.ConcurrentAccessTimeoutException: JBAS014373: EJB 3.1 PFD2 4.8.5.5.1 concurrent access timeout on org.jboss.invocation.InterceptorContext$Invocation@330d0761 - could not obtain lock within 5000MILLISECONDS
    at org.jboss.as.ejb3.concurrency.ContainerManagedConcurrencyInterceptor.processInvocation(ContainerManagedConcurrencyInterceptor.java:100) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:407)
    at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:46) [weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]
    at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:83) [wildfly-weld-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45) [wildfly-ee-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:21)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
    at org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:53)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.ejb3.component.singleton.SingletonComponentInstanceAssociationInterceptor.processInvocation(SingletonComponentInstanceAssociationInterceptor.java:52) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInNoTx(CMTTxInterceptor.java:260) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.notSupported(CMTTxInterceptor.java:324) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:237) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:43) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:95) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:55) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:326)
    at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:439)
    at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:61)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:326)
    at org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
    at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:185)
    at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:182)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
    at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:73)
    at mobi.chouette.scheduler.Scheduler$$$view9.schedule(Unknown Source) [mobi.chouette.service.jar:]
    at mobi.chouette.service.JobServiceManager.create(JobServiceManager.java:131) [mobi.chouette.service.jar:]
    at sun.reflect.GeneratedMethodAccessor163.invoke(Unknown Source) [:1.8.0_92]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_92]
    at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_92]
    at org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53)
    at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:407)
    at org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:82) [wildfly-weld-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:93) [wildfly-weld-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53)
    at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.jpa.interceptor.SBInvocationInterceptor.processInvocation(SBInvocationInterceptor.java:47) [wildfly-jpa-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:407)
    at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:46) [weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]
    at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:83) [wildfly-weld-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45) [wildfly-ee-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:21)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
    at org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:53)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.ejb3.component.interceptors.NonPooledEJBComponentInstanceAssociatingInterceptor.processInvocation(NonPooledEJBComponentInstanceAssociatingInterceptor.java:59) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInNoTx(CMTTxInterceptor.java:260) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.notSupported(CMTTxInterceptor.java:324) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:237) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:43) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:95) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:55) [wildfly-ejb3-8.2.1.Final.jar:8.2.1.Final]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:326)
    at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:448)
    at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:61)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:326)
    at org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
    at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:185)
    at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:182)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
    at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
    at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:73)
    at mobi.chouette.service.JobServiceManager$$$view4.create(Unknown Source) [mobi.chouette.service.jar:]
    at sun.reflect.GeneratedMethodAccessor163.invoke(Unknown Source) [:1.8.0_92]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_92]
    at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_92]
    at org.jboss.weld.util.reflection.Reflections.invokeAndUnwrap(Reflections.java:414) [weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]
    at org.jboss.weld.bean.proxy.EnterpriseBeanProxyMethodHandler.invoke(EnterpriseBeanProxyMethodHandler.java:127) [weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]
    at org.jboss.weld.bean.proxy.EnterpriseTargetBeanInstance.invoke(EnterpriseTargetBeanInstance.java:56) [weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]
    at org.jboss.weld.bean.proxy.InjectionPointPropagatingEnterpriseTargetBeanInstance.invoke(InjectionPointPropagatingEnterpriseTargetBeanInstance.java:65) [weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]
    at org.jboss.weld.bean.proxy.ProxyMethodHandler.invoke(ProxyMethodHandler.java:100) [weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]
    at mobi.chouette.service.JobServiceManager$Proxy$_$$_Weld$EnterpriseProxy$.create(Unknown Source) [mobi.chouette.service.jar:]
    at mobi.chouette.ws.RestService.upload(RestService.java:89)
    at mobi.chouette.ws.RestService$Proxy$_$$_WeldClientProxy.upload(Unknown Source)
    at sun.reflect.GeneratedMethodAccessor243.invoke(Unknown Source) [:1.8.0_92]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_92]
    at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_92]
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:137) [resteasy-jaxrs-3.0.10.Final.jar:]
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:296) [resteasy-jaxrs-3.0.10.Final.jar:]
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:250) [resteasy-jaxrs-3.0.10.Final.jar:]
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:237) [resteasy-jaxrs-3.0.10.Final.jar:]
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:356) [resteasy-jaxrs-3.0.10.Final.jar:]
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:179) [resteasy-jaxrs-3.0.10.Final.jar:]
    at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:220) [resteasy-jaxrs-3.0.10.Final.jar:]
    at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56) [resteasy-jaxrs-3.0.10.Final.jar:]
    at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51) [resteasy-jaxrs-3.0.10.Final.jar:]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) [jboss-servlet-api_3.1_spec-1.0.0.Final.jar:1.0.0.Final]
    at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:86)
    at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
    at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
    at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
    at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131)
    at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
    at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
    at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
    at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:58)
    at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:70)
    at io.undertow.security.handlers.SecurityInitialHandler.handleRequest(SecurityInitialHandler.java:76)
    at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
    at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:261)
    at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:248)
    at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:77)
    at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:167)
    at io.undertow.server.Connectors.executeRootHandler(Connectors.java:199)
    at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:761)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_92]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_92]
    at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_92]
seime commented 8 years ago

The Scheduler object is marked as @Singleton. The default mode in Java EE is to guard all methods against concurrent calls. This is unnecessary and caps concurrent performance.

http://www.thoughts-on-java.org/java-ee-pitfalls-1-ignore-default-lock/

metienne commented 8 years ago

Changing Scheduler mode is not an easy topic; we have to refactor startedFuture Map management and the PostConstruct step. We will see how after holidays. If you make a pull request for it before, we will try it ASAP. Thanks