1 2 Previous Next 16 Replies Latest reply: Apr 19, 2012 8:58 PM by Stephane Gamard RSS

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

Stephane Gamard Newbie

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 pai Master

    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
    Stephane Gamard Newbie

    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
    Stephane Gamard Newbie

    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 pai Master

    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
    Stephane Gamard Newbie

    @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 pai Master

    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.

  • 8. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
    Scott Marlow Master

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

  • 9. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
    Scott Marlow Master

    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
    Stephane Gamard Newbie

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

  • 11. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
    Scott Marlow Master

    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
    Andrew Janowczyk Newbie

    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

  • 14. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
    Scott Marlow Master

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

1 2 Previous Next