-
1. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
jaikiran Mar 30, 2012 3:33 AM (in response to gamars)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 Mar 30, 2012 9:30 AM (in response to jaikiran)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
-
jboss-api.zip 145.5 KB
-
-
3. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
gamars Apr 12, 2012 11:29 AM (in response to 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 Apr 12, 2012 1:21 PM (in response to gamars)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 Apr 12, 2012 1:24 PM (in response to jaikiran)@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 Apr 12, 2012 1:30 PM (in response to gamars)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 Apr 12, 2012 1:56 PM (in response to jaikiran)I'll take a look at this.
-
8. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
smarlow Apr 12, 2012 2:19 PM (in response to 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 Apr 13, 2012 9:42 AM (in response to gamars)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
-
10. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
gamars Apr 13, 2012 9:49 AM (in response to smarlow)And you did not have any exception in the delegated Lucene Indexer?
-
11. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
smarlow Apr 13, 2012 10:00 AM (in response to gamars)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 Apr 19, 2012 11:42 AM (in response to smarlow)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
-
ds.xml 1.0 KB
-
jboss-api.zip 141.2 KB
-
server.trace.log.zip 114.1 KB
-
server.info.log.zip 7.5 KB
-
-
13. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
smarlow Apr 19, 2012 3:57 PM (in response to choosehappy)It recreates now, I got http://pastie.org/3818761
-
14. Re: [com.arjuna.ats.jta] -- java.util.ConcurrentModificationException
smarlow Apr 19, 2012 4:23 PM (in response to smarlow)That looks like a Hibernate bug that we should create a Hibernate jira for.