[CAY-1652] Deadlock within DefaultEventManager while creating a new ObjectContext

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 3.1M3
• Component/s: Core Library
• Environment: OpenJDK Runtime Environment (build 1.6.0-b23); OpenJDK 64-Bit Server VM (build 20.0-b11, mixed mode)
• Assignee: Andrus Adamchik
• Reporter: Anton Sakalouski
• Created: 23/Jan/12 08:45
• Updated: 16/Sep/12 18:06
• Resolved: 16/Sep/12 18:06

Description

We have apache cxf application which creates a new ObjectContext and writes some changes to the database in one of its soap request interceptors. Approximately once in day we experience the deadlock within DefaultEventManager. Here are brief details, I am enclosing the full thread dump as well.

Found one Java-level deadlock:
=============================
"ajp-apr-/10.100.48.1-9201-exec-962":
waiting to lock monitor 0x000000093579d378 (object 0x00000008277ea450, a org.apache.cayenne.event.DispatchQueue),
which is held by "cayenne-edt-665651215-1"
"cayenne-edt-665651215-1":
waiting to lock monitor 0x00000009415bec40 (object 0x000000082ac3aa78, a org.apache.cayenne.access.ObjectStore),
which is held by "ajp-apr-/10.100.48.1-9201-exec-956"
"ajp-apr-/10.100.48.1-9201-exec-956":
waiting to lock monitor 0x000000093579bf20 (object 0x000000082ac36d00, a org.apache.cayenne.access.ObjectStore),
which is held by "cayenne-edt-665651215-1"

Java stack information for the threads listed above:
===================================================
"ajp-apr-/10.100.48.1-9201-exec-962":
at org.apache.cayenne.event.DispatchQueue.addInvocation(DispatchQueue.java:63)

• waiting to lock <0x00000008277ea450> (a org.apache.cayenne.event.DispatchQueue)
  at org.apache.cayenne.event.DefaultEventManager.addListener(DefaultEventManager.java:217)
  at org.apache.cayenne.event.DefaultEventManager.addListener(DefaultEventManager.java:171)
  at org.apache.cayenne.util.EventUtil.listenForSubjects(EventUtil.java:90)
  at org.apache.cayenne.util.EventUtil.listenForChannelEvents(EventUtil.java:57)
  at org.apache.cayenne.access.DataContext.attachToChannel(DataContext.java:162)
  at org.apache.cayenne.access.DataContext.<init>(DataContext.java:105)
  at ish.oncourse.services.persistence.ISHObjectContext.<init>(ISHObjectContext.java:24)
  at ish.oncourse.services.persistence.ISHObjectContextFactory.createdFromDataDomain(ISHObjectContextFactory.java:58)
  at org.apache.cayenne.configuration.server.DataContextFactory.createContext(DataContextFactory.java:54)
  at org.apache.cayenne.configuration.CayenneRuntime.getContext(CayenneRuntime.java:182)
  at ish.oncourse.services.persistence.CayenneService.newContext(CayenneService.java:65)
  at ish.oncourse.services.persistence.CayenneService.newNonReplicatingContext(CayenneService.java:73)
  at $ICayenneService_135046b9a1f.newNonReplicatingContext($ICayenneService_135046b9a1f.java)
  at ish.oncourse.services.system.CollegeService.recordWSAccess(CollegeService.java:141)
  at $ICollegeService_135046b9a1d.recordWSAccess($ICollegeService_135046b9a1d.java)
  at ish.oncourse.webservices.soap.v4.interceptors.CollegeRequestInterceptor.handleMessage(CollegeRequestInterceptor.java:69)
  at ish.oncourse.webservices.soap.v4.interceptors.CollegeRequestInterceptor.handleMessage(CollegeRequestInterceptor.java:35)
  at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:263)
• locked <0x000000082b19f640> (a org.apache.cxf.phase.PhaseInterceptorChain)
  at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:118)
  at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:208)
  at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:223)
  at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:205)
  at org.apache.cxf.transport.servlet.CXFNonSpringServlet.invoke(CXFNonSpringServlet.java:113)
  at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleRequest(AbstractHTTPServlet.java:184)
  at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doPost(AbstractHTTPServlet.java:107)
  at javax.servlet.http.HttpServlet.service(HttpServlet.java:641)
  at org.apache.cxf.transport.servlet.AbstractHTTPServlet.service(AbstractHTTPServlet.java:163)
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:304)
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
  at org.apache.tapestry5.TapestryFilter.doFilter(TapestryFilter.java:151)
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
  at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:207)
  at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
  at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:472)
  at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:164)
  at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:100)
  at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:929)
  at org.apache.catalina.authenticator.SingleSignOn.invoke(SingleSignOn.java:308)
  at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
  at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:405)
  at org.apache.coyote.ajp.AjpAprProcessor.process(AjpAprProcessor.java:188)
  at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:515)
  at org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.run(AprEndpoint.java:1773)
• locked <0x000000082b19f770> (a org.apache.tomcat.util.net.SocketWrapper)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
  at java.lang.Thread.run(Thread.java:679)
  "cayenne-edt-665651215-1":
  at org.apache.cayenne.access.ObjectStore.processSnapshotEvent(ObjectStore.java:581)
• waiting to lock <0x000000082ac3aa78> (a org.apache.cayenne.access.ObjectStore)
  at org.apache.cayenne.access.DataContextMergeHandler.graphChanged(DataContextMergeHandler.java:99)
  at sun.reflect.GeneratedMethodAccessor125.invoke(Unknown Source)
  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
  at java.lang.reflect.Method.invoke(Method.java:616)
  at org.apache.cayenne.util.Invocation.fire(Invocation.java:202)
  at org.apache.cayenne.event.DefaultEventManager$Dispatch.fire(DefaultEventManager.java:400)
  at org.apache.cayenne.event.DispatchQueue.dispatchEvent(DispatchQueue.java:156)
  at org.apache.cayenne.event.DispatchQueue.dispatchEvent(DispatchQueue.java:57)
• locked <0x00000008277ea450> (a org.apache.cayenne.event.DispatchQueue)
  at org.apache.cayenne.event.DefaultEventManager.dispatchEvent(DefaultEventManager.java:339)
  at org.apache.cayenne.event.DefaultEventManager.postEvent(DefaultEventManager.java:310)
  at org.apache.cayenne.BaseContext.fireDataChannelChanged(BaseContext.java:424)
  at org.apache.cayenne.access.DataContext.fireDataChannelChanged(DataContext.java:1244)
  at org.apache.cayenne.access.ObjectStore.processSnapshotEvent(ObjectStore.java:610)
• locked <0x000000082ac36d00> (a org.apache.cayenne.access.ObjectStore)
  at org.apache.cayenne.access.ObjectStore.snapshotsChanged(ObjectStore.java:572)
  at sun.reflect.GeneratedMethodAccessor66.invoke(Unknown Source)
  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
  at java.lang.reflect.Method.invoke(Method.java:616)
  at org.apache.cayenne.util.Invocation.fire(Invocation.java:202)
  at org.apache.cayenne.event.DefaultEventManager$InvocationDispatch.fire(DefaultEventManager.java:420)
  at org.apache.cayenne.event.DefaultEventManager$DispatchThread.run(DefaultEventManager.java:469)
  "ajp-apr-/10.100.48.1-9201-exec-956":
  at org.apache.cayenne.access.ObjectStore.registerDiff(ObjectStore.java:183)
• waiting to lock <0x000000082ac36d00> (a org.apache.cayenne.access.ObjectStore)
  at org.apache.cayenne.access.ObjectStore.arcDeleted(ObjectStore.java:1000)
  at org.apache.cayenne.util.ObjectContextGraphAction.handleArcPropertyChange(ObjectContextGraphAction.java:81)
  at org.apache.cayenne.util.ObjectContextGraphAction.handlePropertyChange(ObjectContextGraphAction.java:65)
  at org.apache.cayenne.BaseContext.propertyChanged(BaseContext.java:335)
  at org.apache.cayenne.CayenneDataObject.setToOneTarget(CayenneDataObject.java:278)
  at org.apache.cayenne.reflect.generic.DataObjectToOneProperty.setTarget(DataObjectToOneProperty.java:74)
  at org.apache.cayenne.graph.ChildDiffLoader$3.visitToOne(ChildDiffLoader.java:254)
  at org.apache.cayenne.reflect.generic.DataObjectToOneProperty.visit(DataObjectToOneProperty.java:87)
  at org.apache.cayenne.graph.ChildDiffLoader.arcDeleted(ChildDiffLoader.java:217)
  at org.apache.cayenne.access.ObjectDiff$ArcOperation.apply(ObjectDiff.java:440)
  at org.apache.cayenne.graph.CompoundDiff.apply(CompoundDiff.java:91)
  at org.apache.cayenne.access.ObjectStoreGraphDiff.apply(ObjectStoreGraphDiff.java:134)
  at org.apache.cayenne.access.DataContext.onContextFlush(DataContext.java:769)
  at org.apache.cayenne.BaseContext.onSync(BaseContext.java:373)
  at ish.oncourse.services.persistence.ISHObjectContext.onSync(ISHObjectContext.java:72)
  at org.apache.cayenne.access.DataContext.flushToParent(DataContext.java:816)
• locked <0x000000082ac3aa78> (a org.apache.cayenne.access.ObjectStore)
  at org.apache.cayenne.access.DataContext.commitChangesToParent(DataContext.java:746)
  at ish.oncourse.webservices.replication.services.TransactionGroupProcessorImpl.deleteObject(TransactionGroupProcessorImpl.java:248)
  at ish.oncourse.webservices.replication.services.TransactionGroupProcessorImpl.processStub(TransactionGroupProcessorImpl.java:185)
  at ish.oncourse.webservices.replication.services.TransactionGroupProcessorImpl.processGroup(TransactionGroupProcessorImpl.java:98)
  at $ITransactionGroupProcessor_135046b9aa3.processGroup($ITransactionGroupProcessor_135046b9aa3.java)
  at $ITransactionGroupProcessor_135046b9a4d.processGroup($ITransactionGroupProcessor_135046b9a4d.java)
  at ish.oncourse.webservices.replication.services.ReplicationServiceImpl.sendRecords(ReplicationServiceImpl.java:79)
  at $IReplicationService_135046b9a4a.sendRecords($IReplicationService_135046b9a4a.java)
  at $IReplicationService_135046b9a1e.sendRecords($IReplicationService_135046b9a1e.java)
  at ish.oncourse.webservices.soap.v4.ReplicationPortTypeImpl.sendRecords(ReplicationPortTypeImpl.java:342)
  at sun.reflect.GeneratedMethodAccessor114.invoke(Unknown Source)
  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
  at java.lang.reflect.Method.invoke(Method.java:616)
  at org.apache.cxf.service.invoker.AbstractInvoker.performInvocation(AbstractInvoker.java:173)
  at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:89)
  at org.apache.cxf.jaxws.JAXWSMethodInvoker.invoke(JAXWSMethodInvoker.java:61)
  at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:75)
  at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:58)
  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
  at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
  at java.util.concurrent.FutureTask.run(FutureTask.java:166)
  at org.apache.cxf.workqueue.SynchronousExecutor.execute(SynchronousExecutor.java:37)
  at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:106)
• locked <0x000000082ac3abe8> (a org.apache.cxf.interceptor.ServiceInvokerInterceptor$2)
  at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:263)
• locked <0x000000082ac65410> (a org.apache.cxf.phase.PhaseInterceptorChain)
  at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:118)
  at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:208)
  at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:223)
  at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:205)
  at org.apache.cxf.transport.servlet.CXFNonSpringServlet.invoke(CXFNonSpringServlet.java:113)
  at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleRequest(AbstractHTTPServlet.java:184)
  at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doPost(AbstractHTTPServlet.java:107)
  at javax.servlet.http.HttpServlet.service(HttpServlet.java:641)
  at org.apache.cxf.transport.servlet.AbstractHTTPServlet.service(AbstractHTTPServlet.java:163)
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:304)
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
  at org.apache.tapestry5.TapestryFilter.doFilter(TapestryFilter.java:151)
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
  at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:207)
  at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
  at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:472)
  at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:164)
  at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:100)
  at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:929)
  at org.apache.catalina.authenticator.SingleSignOn.invoke(SingleSignOn.java:308)
  at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
  at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:405)
  at org.apache.coyote.ajp.AjpAprProcessor.process(AjpAprProcessor.java:188)
  at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:515)
  at org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.run(AprEndpoint.java:1773)
• locked <0x000000082aeb47e8> (a org.apache.tomcat.util.net.SocketWrapper)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
  at java.lang.Thread.run(Thread.java:679)

Issue Links

• relates to: CAY-720 While using nested DataContexts contexts and while a child commits to parent, parent is being refreshed via an event, resulting in a deadlock.
• relates to: CAY-957 Deadlock in nested contexts