Cayenne
  1. Cayenne
  2. CAY-1652

Deadlock within DefaultEventManager while creating a new ObjectContext

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 3.1M3
    • Fix Version/s: None
    • Component/s: Core Library
    • Labels:
      None
    • Environment:
      OpenJDK Runtime Environment (build 1.6.0-b23)
      OpenJDK 64-Bit Server VM (build 20.0-b11, mixed mode)

      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)
      1. ThreadDump.txt
        1.16 MB
        Anton Sakalouski

        Issue Links

          Activity

          Hide
          Anton Sakalouski added a comment -

          Full thread dump from the deadlocked application.

          Show
          Anton Sakalouski added a comment - Full thread dump from the deadlocked application.
          Hide
          Andrus Adamchik added a comment -

          Anton,

          Just removed one cause of the deadlock per CAY-1653. This may actually resolve your case (addListener). However there is a very simple unit test at CAY-957 that shows that there's another deadlock situation remains with multiple nested contexts... I will work on that next, but appreciate if you could try the CAY-1653 fix, which is committed to trunk. If you only care about this change, and don't want the rest of the M4 stuff, you can locally build Cayenne with r1234971 and r1234984 applied.

          Show
          Andrus Adamchik added a comment - Anton, Just removed one cause of the deadlock per CAY-1653 . This may actually resolve your case (addListener). However there is a very simple unit test at CAY-957 that shows that there's another deadlock situation remains with multiple nested contexts... I will work on that next, but appreciate if you could try the CAY-1653 fix, which is committed to trunk. If you only care about this change, and don't want the rest of the M4 stuff, you can locally build Cayenne with r1234971 and r1234984 applied.
          Hide
          Andrus Adamchik added a comment -

          should be fixed per other related jiras.

          Show
          Andrus Adamchik added a comment - should be fixed per other related jiras.

            People

            • Assignee:
              Andrus Adamchik
              Reporter:
              Anton Sakalouski
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development