1 2 Previous Next 16 Replies Latest reply on Apr 19, 2012 8:58 PM by gamars

    [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException

    gamars

      Hi all,

       

      First congrats on the work on the AS 7, it looks awesome and it is a pleasure of a Application Server to work with!

       

      Second we've been having some difficulties porting our application from GF to the latest AS 7. While we sorted most of them out, there is an outstanding glitch that puzzles me and we haven't been able to get to the end of it.

       

      In our AS 7 application we use infinispan both for L2 cache and LuceneDirectory. While everything is under control (as it seems) we keep on having this error popping up for any Tx that uses the LuceneDirectory:

      {noformat}[com.arjuna.ats.jta] (http--127.0.0.1-8080-3) ARJUNA016029: SynchronizationImple.afterCompletion - failed for org.hibernate.engine.transaction.synchronization.internal.RegisteredSynchronization@14fecb2 with exception: java.util.ConcurrentModificationException{noformat}
        • 1. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
          jaikiran

          Stephane, welcome to the forums!

           

          Can you please post the entire exception stacktrace? And a bit more details on when this exception occurs?

          • 2. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
            gamars

            Hello Jaikiran and thank you for your reply.

             

            In order to best sove this problem I'm attaching a small simple Spring app (based on the demo JBoss app build by archetype). If you deploy the following app (you might have to update the infinispan config file in resource to match a RDBM that you have) you will be able to reproduce that exact error (trace below) by simply indexing a new member.

             

            To index a new member simply execute a POST on http://localhost:8080/jboss-api/rest/members/

            Post body:

             

            <member>

            <email>john@doe.com</email>

            <name>john</name>

            <phoneNumber>2386234234</phoneNumber>

            </member>

             

             

            The post will generate the following execption:

             

            15:22:34,483 WARN  [com.arjuna.ats.arjuna] (http--127.0.0.1-8080-1) ARJUNA012127: TwoPhaseCoordinator.afterCompletion - returned failure for SynchronizationImple< 0:ffff0a0000dd:2bfe5e53:4f75b110:2e, org.hibernate.engine.transaction.synchronization.internal.RegisteredSynchronization@893b10 >

            15:22:38,692 WARN  [com.arjuna.ats.jta] (http--127.0.0.1-8080-1) ARJUNA016029: SynchronizationImple.afterCompletion - failed for org.hibernate.engine.transaction.synchronization.internal.RegisteredSynchronization@20e147 with exception: java.util.ConcurrentModificationException

                      at java.util.LinkedHashMap$LinkedHashIterator.nextEntry(LinkedHashMap.java:373) [classes.jar:1.6.0_29]

                      at java.util.LinkedHashMap$KeyIterator.next(LinkedHashMap.java:384) [classes.jar:1.6.0_29]

                      at org.hibernate.engine.transaction.internal.SynchronizationRegistryImpl.notifySynchronizationsAfterTransactionCompletion(SynchronizationRegistryImpl.java:78) [hibernate-core-4.0.1.Final.jar:4.0.1.Final]

                      at org.hibernate.engine.transaction.internal.TransactionCoordinatorImpl.sendAfterTransactionCompletionNotifications(TransactionCoordinatorImpl.java:333) [hibernate-core-4.0.1.Final.jar:4.0.1.Final]

                      at org.hibernate.engine.transaction.internal.TransactionCoordinatorImpl.afterTransaction(TransactionCoordinatorImpl.java:145) [hibernate-core-4.0.1.Final.jar:4.0.1.Final]

                      at org.hibernate.engine.transaction.synchronization.internal.SynchronizationCallbackCoordinatorImpl.afterCompletion(SynchronizationCallbackCoordinatorImpl.java:126) [hibernate-core-4.0.1.Final.jar:4.0.1.Final]

                      at org.hibernate.engine.transaction.synchronization.internal.RegisteredSynchronization.afterCompletion(RegisteredSynchronization.java:61) [hibernate-core-4.0.1.Final.jar:4.0.1.Final]

                      at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.afterCompletion(SynchronizationImple.java:96)

                      at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.afterCompletion(TwoPhaseCoordinator.java:402)

                      at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:103)

                      at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:164)

                      at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1165)

                      at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:117)

                      at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)

                      at org.jboss.tm.usertx.client.ServerVMClientUserTransaction.commit(ServerVMClientUserTransaction.java:167)

                      at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1010) [spring-tx-3.1.0.RELEASE.jar:3.1.0.RELEASE]

                      at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:754) [spring-tx-3.1.0.RELEASE.jar:3.1.0.RELEASE]

                      at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:723) [spring-tx-3.1.0.RELEASE.jar:3.1.0.RELEASE]

                      at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:393) [spring-tx-3.1.0.RELEASE.jar:3.1.0.RELEASE]

                      at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:120) [spring-tx-3.1.0.RELEASE.jar:3.1.0.RELEASE]

                      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [spring-aop-3.1.0.RELEASE.jar:3.1.0.RELEASE]

                      at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:622) [spring-aop-3.1.0.RELEASE.jar:3.1.0.RELEASE]

                      at test.salsadev.rest.MemberResourceRESTService$$EnhancerByCGLIB$$55fce1a5.addMember(<generated>) [cglib-2.2.jar:]

                      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [classes.jar:1.6.0_29]

                      at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [classes.jar:1.6.0_29]

                      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [classes.jar:1.6.0_29]

                      at java.lang.reflect.Method.invoke(Method.java:597) [classes.jar:1.6.0_29]

                      at org.springframework.web.bind.annotation.support.HandlerMethodInvoker.invokeHandlerMethod(HandlerMethodInvoker.java:176) [spring-web-3.1.0.RELEASE.jar:3.1.0.RELEASE]

                      at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.invokeHandlerMethod(AnnotationMethodHandlerAdapter.java:436) [spring-webmvc-3.1.0.RELEASE.jar:3.1.0.RELEASE]

                      at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.handle(AnnotationMethodHandlerAdapter.java:424) [spring-webmvc-3.1.0.RELEASE.jar:3.1.0.RELEASE]

                      at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:900) [spring-webmvc-3.1.0.RELEASE.jar:3.1.0.RELEASE]

                      at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:827) [spring-webmvc-3.1.0.RELEASE.jar:3.1.0.RELEASE]

                      at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:882) [spring-webmvc-3.1.0.RELEASE.jar:3.1.0.RELEASE]

                      at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:789) [spring-webmvc-3.1.0.RELEASE.jar:3.1.0.RELEASE]

                      at javax.servlet.http.HttpServlet.service(HttpServlet.java:754) [jboss-servlet-api_3.0_spec-1.0.0.Final.jar:1.0.0.Final]

                      at javax.servlet.http.HttpServlet.service(HttpServlet.java:847) [jboss-servlet-api_3.0_spec-1.0.0.Final.jar:1.0.0.Final]

                      at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:329) [jbossweb-7.0.13.Final.jar:]

                      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:248) [jbossweb-7.0.13.Final.jar:]

                      at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:275) [jbossweb-7.0.13.Final.jar:]

                      at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:161) [jbossweb-7.0.13.Final.jar:]

                      at org.jboss.as.jpa.interceptor.WebNonTxEmCloserValve.invoke(WebNonTxEmCloserValve.java:50) [jboss-as-jpa-7.1.1.Final.jar:7.1.1.Final]

                      at org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:153) [jboss-as-web-7.1.1.Final.jar:7.1.1.Final]

                      at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:155) [jbossweb-7.0.13.Final.jar:]

                      at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) [jbossweb-7.0.13.Final.jar:]

                      at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [jbossweb-7.0.13.Final.jar:]

                      at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:368) [jbossweb-7.0.13.Final.jar:]

                      at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:877) [jbossweb-7.0.13.Final.jar:]

                      at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:671) [jbossweb-7.0.13.Final.jar:]

                      at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:930) [jbossweb-7.0.13.Final.jar:]

                      at java.lang.Thread.run(Thread.java:680) [classes.jar:1.6.0_29]

             

             

            15:22:38,713 WARN  [com.arjuna.ats.arjuna] (http--127.0.0.1-8080-1) ARJUNA012127: TwoPhaseCoordinator.afterCompletion - returned failure for SynchronizationImple< 0:ffff0a0000dd:2bfe5e53:4f75b110:31, org.hibernate.engine.transaction.synchronization.internal.RegisteredSynchronization@20e147 >

             

             

            Please note that we're  not using a managed connection for the infinispan cachestore due to a bug in ISPN (https://jira.jboss.org/browse/ISPN-604):

            <property name="connectionFactoryClass" value="org.infinispan.loaders.jdbc.connectionfactory.PooledConnectionFactory"/>

                        <property name="connectionUrl" value="jdbc:mysql://127.0.0.1:3306/jb_lucene"/>

                        <property name="userName" value="XXXX"/>

                        <property name="password" value="XXXX"/>

                        <property name="driverClass" value="com.mysql.jdbc.Driver"/>

             

            Attaching sample Spring-Jboss-Infinispan application

            • 3. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
              gamars

              Has anyone checked this? This might turn out to be a major problem between Spring and Infinispan/Jboss/Hibernate... We are at the point of thinking to drop Spring alltogether if not solved

              • 4. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
                jaikiran

                I haven't had a chance to look more into this one. But a java.util.ConcurrentModificationException isn't really a good sign and might indicate a bug somewhere.

                • 5. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
                  gamars

                  @jaikiran agreed. I am most astonished as this is pretty much out of the box UCase. Also very astonished I couldn't find more post/information about it...

                  • 6. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
                    jaikiran

                    Can you please attach the entire server.log which contains this exception stacktrace and log messages? I'll see if someone else can take a look at this and if not maybe get back to this sometime later.

                    • 7. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
                      smarlow

                      I'll take a look at this.

                      • 8. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
                        smarlow

                        We still need the rest of the exception call stack and log messages to proceed.

                        • 9. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
                          smarlow

                          By the way, the attached test case worked for me on the latest AS7 build.  You can get the latest AS7 build here to test with.

                           

                           

                          200 OK

                           

                          <?xml version="1.0" encoding="UTF-8" standalone="yes"?><member><email>john@doe.com</email><id>2</id><name>john</name><phoneNumber>2386234234</phoneNumber></member>

                           

                          • 10. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
                            gamars

                            And you did not have any exception in the delegated Lucene Indexer?

                            • 11. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
                              smarlow

                              The AS7 console contains no exceptions or errors.  Here is what I see on the console from deployment started, to shutting down the AS7 server after running the test. 

                               

                              09:39:15,336 INFO  [org.springframework.web.servlet.DispatcherServlet] (MSC service thread 1-7) FrameworkServlet 'jboss-test': initialization completed in 753 ms

                              09:39:15,343 INFO  [org.jboss.web] (MSC service thread 1-7) JBAS018210: Registering web context: /jboss-api

                              09:39:15,349 INFO  [org.jboss.as] (MSC service thread 1-2) JBAS015951: Admin console listening on http://127.0.0.1:9990

                              09:39:15,352 INFO  [org.jboss.as] (MSC service thread 1-2) JBAS015874: JBoss AS 7.1.2.Final-SNAPSHOT "Brontes" started in 12966ms - Started 228 of 307 services (78 services are passive or on-demand)

                              09:39:15,489 INFO  [org.jboss.as.server] (DeploymentScanner-threads - 2) JBAS018559: Deployed "jboss-api.war"

                               

                               

                               

                              ^C09:44:40,642 INFO  [org.jboss.as.logging] JBAS011503: Restored bootstrap log handlers

                              09:44:40,644 INFO  [org.apache.catalina.core.StandardContext] Container org.apache.catalina.core.ContainerBase.[jboss.web].[default-host].[/] has not been started

                              09:44:40,646 INFO  [org.apache.catalina.core.ContainerBase.[jboss.web].[default-host].[/jboss-api]] Destroying Spring FrameworkServlet 'jboss-test'

                              09:44:40,654 INFO  [org.jboss.as.osgi] JBAS011942: Stopping OSGi Framework

                              09:44:40,652 INFO  [org.springframework.web.context.support.XmlWebApplicationContext] Closing WebApplicationContext for namespace 'jboss-test-servlet': startup date [Fri Apr 13 09:39:14 EDT 2012]; root of context hierarchy

                              09:44:40,674 INFO  [org.springframework.beans.factory.support.DefaultListableBeanFactory] Destroying singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@3c589375: defining beans [MemberDAO,memberResourceRESTSearch,memberResourceRESTService,org.springframework.context.annotation.internalConfigurationAnnotationProcessor,org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.context.annotation.internalRequiredAnnotationProcessor,org.springframework.context.annotation.internalCommonAnnotationProcessor,org.springframework.context.annotation.internalPersistenceAnnotationProcessor,entityManagerFactory,loadTimeWeaver,org.springframework.aop.config.internalAutoProxyCreator,org.springframework.transaction.annotation.AnnotationTransactionAttributeSource#0,org.springframework.transaction.interceptor.TransactionInterceptor#0,org.springframework.transaction.config.internalTransactionAdvisor,txManager,org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter#0,conversionService,stringHttpMessageConverter,byteArrayMessageConverter,jsonHttpMessageConverter,xmlMessageConverter,org.springframework.web.servlet.view.ContentNegotiatingViewResolver#0,org.springframework.web.servlet.view.BeanNameViewResolver#0,org.springframework.web.servlet.view.InternalResourceViewResolver#0,org.springframework.context.annotation.ConfigurationClassPostProcessor$ImportAwareBeanPostProcessor#0]; root of factory hierarchy

                              09:44:40,754 INFO  [org.jboss.as.jpa] JBAS011403: Stopping Persistence Unit Service 'jboss-api.war#jBossTestPU'

                              09:44:40,757 INFO  [org.jboss.as.clustering.infinispan] JBAS010282: Stopped jboss-api.war#jBossTestPU.org.hibernate.cache.internal.StandardQueryCache cache from hibernate container

                              09:44:40,758 INFO  [org.jboss.as.clustering.infinispan] JBAS010282: Stopped jboss-api.war#jBossTestPU.org.hibernate.cache.spi.UpdateTimestampsCache cache from hibernate container

                              09:44:40,762 INFO  [org.infinispan.jmx.CacheJmxRegistration] ISPN000031: MBeans were successfully registered to the platform mbean server.

                              09:44:40,765 INFO  [org.jboss.as.clustering.infinispan] JBAS010281: Started local-query cache from hibernate container

                              09:44:40,811 INFO  [org.infinispan.remoting.transport.jgroups.JGroupsTransport] ISPN000080: Disconnecting and closing JGroups Channel

                              09:44:40,834 INFO  [org.infinispan.remoting.transport.jgroups.JGroupsTransport] ISPN000082: Stopping the RpcDispatcher

                              09:44:40,839 INFO  [com.arjuna.ats.jbossatx] ARJUNA032018: Destroying TransactionManagerService

                              09:44:40,841 INFO  [com.arjuna.ats.jbossatx] ARJUNA032014: Stopping transaction recovery manager

                              09:44:40,878 INFO  [org.jboss.as.clustering.infinispan] JBAS010282: Stopped local-query cache from hibernate container

                              09:44:40,983 INFO  [org.jboss.as.server.deployment] JBAS015877: Stopped deployment jboss-api.war in 349ms

                              09:44:40,985 INFO  [org.jboss.as] JBAS015950: JBoss AS 7.1.2.Final-SNAPSHOT "Brontes" stopped in 338ms

                               

                              Once you have reproduced the problem with the latest AS7 build, attach the server.log.  Then enable trace logging for org.hibernate and com.arjuna (see example here) and also attach that log as well (after recreating with the trace enabled).  Its possible that the problem might not recreate with trace logging enabled, which is why I want both sets of (as7/standalone/log/server.log) logs.

                              • 12. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
                                choosehappy

                                hey scott,

                                 

                                Sorry for the confusion but there was a small error in our submitted code, in the MemberDAO class on line 41 we accidently removed:


                                @Transactional(propagation= Propagation.REQUIRES_NEW)


                                adding it back in causes the error in both 7.1.1 and 7.1.2 nightly build (as downloaded from the link you supplied).


                                Please find attached the requested logs of both info/warn and trace/debug for the specified classes done with the nightly build from yesterday.

                                 

                                Also i'm attaching a corrected application .zip and a ds.xml for easy deployment/creation of data source.

                                 

                                let me know if you need anything else.

                                 

                                cheers,

                                 

                                andrew

                                • 13. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
                                  smarlow

                                  It recreates now, I got http://pastie.org/3818761

                                  • 14. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
                                    smarlow

                                    That looks like a Hibernate bug that we should create a Hibernate jira for.

                                    1 2 Previous Next