7 Replies Latest reply on Jun 24, 2002 6:05 PM by davidjencks

    reuse of destroyed connection

    bruces

      I'm seeing reuse of a destroyed ManagedConnection in the 3.0 product. A connection is destroyed, but then later is passed to the ManagedConnectionFactory's matchManagedConnections method. This is a minor point to me since I can allocate a new low-level connection for the mc, but it doesn't seem like it's in the spirit of the JCA spec.

      "Connection Destroy
      To manage the size of the connection pool, the application server can call ManagedConnection.destroy method [sic] to destroy a ManagedConnection. A ManagedConnection instance handles this method call by closing the physical connection to the EIS instance and releasing all system resources held by this instance.
      The application server also calls ManagedConnection.destroy when it reeives a connection error event notification that signals a fatal error on the physical connection"

      It was in the latter context that I saw a connection be destroyed and later reused. If the container thinks the connection is damaged, it seems unwise to put it back in the pool and try to reuse it. Instead, why not clobber it and, if you have to, associate any cached handles with another connection?

        • 1. Re: reuse of destroyed connection
          bruces

          Oh, here's a server log showing what I was talking about in my last posting:

          12:20:25,840 INFO [Facets] [06/20/02 12:20:25.839 PDTRMI TCP Connection(5)-10.80.10.114] #mc.notifyListeners# connection error occurred

          ^^^^^^ the jca connection notifies the container of an exception

          12:20:25,841 INFO [Facets] [06/20/02 12:20:25.840 PDTRMI TCP Connection(5)-10.80.10.114] #mc.cleanup# CC2( PM 198 (workspace 3) (inactive manual txn) inJTx=false)
          12:20:25,842 INFO [Facets] [06/20/02 12:20:25.842 PDTRMI TCP Connection(5)-10.80.10.114] #mc.destroy# CC2( PM 198 (workspace 3) (inactive manual txn) inJTx=false)

          ^^^^^^ the container destroys the connection

          12:20:25,967 INFO [Facets] [06/20/02 12:20:25.966 PDTRMI TCP Connection(5)-10.80.10.114] #xa.forget[hash=2346814,session=PM 198 (workspace 0) (shutdownPending closed txn)] xid=XidImpl [FormatId=257, GlobalId=dirt//11, BranchQual=1] trs=resource
          PDT]::::: Bean is Getting A Connection
          12:20:26,431 INFO [Facets] [06/20/02 12:20:26.427 PDTRMI TCP Connection(6)-10.80.10.114] Establishing new Facets session for connection CC2( PM 198 (workspace 0) (shutdownPending closed txn) inJTx=false)
          12:20:26,432 INFO [Facets] [06/20/02 12:20:26.432 PDTRMI TCP Connection(6)-10.80.10.114] #cf.matchManagedConnetions# created new session for CC2( PM 199 (workspace 3) (inactive manual txn) inJTx=false)
          12:20:26,434 INFO [Facets] [06/20/02 12:20:26.433 PDTRMI TCP Connection(6)-10.80.10.114] [Facets] using pooled connection CC2( PM 199 (workspace 3) (inactive manual txn) inJTx=false)

          ^^^^^^matchManagedConnections is invoked with the destroyed ManagedConnection in the selection set


          12:20:26,435 INFO [Facets] [06/20/02 12:20:26.435 PDTRMI TCP Connection(6)-10.80.10.114] #mc.getXAResource# CC2( PM 199 (workspace 3) (inactive manual txn) inJTx=false)
          12:20:26,436 INFO [Facets] [06/20/02 12:20:26.436 PDTRMI TCP Connection(6)-10.80.10.114] #xa.start[hash=2720035,session=PM 199 (workspace 3) (inactive manual txn)] xid=XidImpl [FormatId=257, GlobalId=dirt//14, BranchQual=1]
          12:20:26,439 INFO [Facets] [06/20/02 12:20:26.438 PDTRMI TCP Connection(6)-10.80.10.114] #mc.getConnection# CC2( PM 199 (workspace 3) (active manual txn) inJTx=true)

          • 2. Re: reuse of destroyed connection
            davidjencks

            This is definitely a bug somewhere. Can you file a bug report? Is there any chance you can supply a failing test case or at least a stack trace of some kind (maybe new Exception().printStackTrace() in your destroy method)? I don't see where my code is going wrong by looking at it.

            Thanks
            david jencks

            • 3. Re: reuse of destroyed connection
              bruces

              I submitted a bug report David. I'll have the test rerun with a stack trace in the destroy method.

              • 4. Re: reuse of destroyed connection
                bruces

                Here are stack dumps from the destroy and matchManagedConnections methods

                13:16:56,878 INFO [Facets] [06/21/02 13:16:56.878 PDTRMI TCP Connection(5)-10.80.10.114] #mc.notifyListeners# connection error occurred
                13:16:56,880 INFO [Facets] [06/21/02 13:16:56.879 PDTRMI TCP Connection(5)-10.80.10.114] #mc.cleanup# CC2( PM 342 (workspace 2) (inactive manual txn) inJTx=false)
                13:16:56,881 INFO [Facets] [06/21/02 13:16:56.880 PDTRMI TCP Connection(5)-10.80.10.114] #mc.destroy# CC2( PM 342 (workspace 2) (inactive manual txn) inJTx=false)
                13:16:56,882 ERROR [STDERR] java.lang.Exception: Stack trace
                13:16:56,883 ERROR [STDERR] at java.lang.Thread.dumpStack(Thread.java:992)
                13:16:56,883 ERROR [STDERR] at com.gemstone.persistence.connection.internal.ContainerConnection.destroy(ContainerConnection.java:105)
                13:16:56,884 ERROR [STDERR] at org.jboss.resource.connectionmanager.InternalManagedConnectionPool.doDestroy(InternalManagedConnectionPool.java:250)
                13:16:56,884 ERROR [STDERR] at org.jboss.resource.connectionmanager.InternalManagedConnectionPool.returnConnection(InternalManagedConnectionPool.java:140)
                13:16:56,885 ERROR [STDERR] at org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool.returnConnection(JBossManagedConnectionPool.java:487)
                13:16:56,885 ERROR [STDERR] at org.jboss.resource.connectionmanager.BaseConnectionManager2.returnManagedConnection(BaseConnectionManager2.java:494)
                13:16:56,886 ERROR [STDERR] at org.jboss.resource.connectionmanager.XATxConnectionManager$XAConnectionEventListener.connectionErrorOccurred(XATxConnectionManager.java:388)
                13:16:56,886 ERROR [STDERR] at com.gemstone.persistence.connection.internal.ContainerConnection.notifyListeners(ContainerConnection.java:294)
                13:16:56,887 ERROR [STDERR] at com.gemstone.persistence.connection.internal.ContainerConnection.notifyListeners(ContainerConnection.java:254)
                13:16:56,887 ERROR [STDERR] at com.gemstone.persistence.connection.internal.ContainerXAResource.logException(ContainerXAResource.java:447)
                13:16:56,888 ERROR [STDERR] at com.gemstone.persistence.connection.internal.ContainerXAResource.commit(ContainerXAResource.java:136)
                13:16:56,888 ERROR [STDERR] at org.jboss.tm.TxCapsule.commitResources(TxCapsule.java:1656)
                13:16:56,889 ERROR [STDERR] at org.jboss.tm.TxCapsule.commit(TxCapsule.java:357)
                13:16:56,889 ERROR [STDERR] at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:74)
                13:16:56,890 ERROR [STDERR] at org.jboss.tm.TxManager.commit(TxManager.java:138)
                13:16:56,890 ERROR [STDERR] at org.jboss.ejb.EnterpriseContext$UserTransactionImpl.commit(EnterpriseContext.java:439)
                13:16:56,891 ERROR [STDERR] at jca.ejb.bmtx.TestServiceBean.testSessionCallChain_Bean_Tx(TestServiceBean.java:720)
                13:16:56,891 ERROR [STDERR] at java.lang.reflect.Method.invoke(Native Method)
                13:16:56,892 ERROR [STDERR] at org.jboss.ejb.StatefulSessionContainer$ContainerInterceptor.invoke(StatefulSessionContainer.java:823)
                13:16:56,892 ERROR [STDERR] at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:129)
                13:16:56,895 ERROR [STDERR] at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:186)
                13:16:56,896 ERROR [STDERR] at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:96)
                13:16:56,896 ERROR [STDERR] at org.jboss.ejb.plugins.AbstractTxInterceptorBMT.invokeNext(AbstractTxInterceptorBMT.java:144)
                13:16:56,897 ERROR [STDERR] at org.jboss.ejb.plugins.TxInterceptorBMT.invoke(TxInterceptorBMT.java:62)
                13:16:56,898 ERROR [STDERR] at org.jboss.ejb.plugins.StatefulSessionInstanceInterceptor.invoke(StatefulSessionInstanceInterceptor.java:266)
                13:16:56,899 ERROR [STDERR] at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:166)
                13:16:56,899 ERROR [STDERR] at org.jboss.ejb.StatefulSessionContainer.invoke(StatefulSessionContainer.java:380)
                13:16:56,900 ERROR [STDERR] at org.jboss.ejb.Container.invoke(Container.java:705)
                13:16:56,900 ERROR [STDERR] at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:491)
                13:16:56,901 ERROR [STDERR] at org.jboss.invocation.jrmp.server.JRMPInvoker.invoke(JRMPInvoker.java:362)
                13:16:56,902 ERROR [STDERR] at java.lang.reflect.Method.invoke(Native Method)
                13:16:56,902 ERROR [STDERR] at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:236)
                13:16:56,904 ERROR [STDERR] at sun.rmi.transport.Transport$1.run(Transport.java:147)
                13:16:56,904 ERROR [STDERR] at java.security.AccessController.doPrivileged(Native Method)
                13:16:56,905 ERROR [STDERR] at sun.rmi.transport.Transport.serviceCall(Transport.java:143)
                13:16:56,905 ERROR [STDERR] at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:460)
                13:16:56,906 ERROR [STDERR] at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:701)
                13:16:56,908 ERROR [STDERR] at java.lang.Thread.run(Thread.java:479)
                13:16:57,015 WARN [TxCapsule] XAException: tx=XidImpl [FormatId=257, GlobalId=dirt//11, BranchQual=] errorCode=XAER_NOTA
                javax.transaction.xa.XAException
                at com.gemstone.persistence.connection.internal.ContainerXAResource.commit(ContainerXAResource.java:137)
                at org.jboss.tm.TxCapsule.commitResources(TxCapsule.java:1656)
                at org.jboss.tm.TxCapsule.commit(TxCapsule.java:357)
                at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:74)
                at org.jboss.tm.TxManager.commit(TxManager.java:138)
                at org.jboss.ejb.EnterpriseContext$UserTransactionImpl.commit(EnterpriseContext.java:439)
                at jca.ejb.bmtx.TestServiceBean.testSessionCallChain_Bean_Tx(TestServiceBean.java:720)
                at java.lang.reflect.Method.invoke(Native Method)
                at org.jboss.ejb.StatefulSessionContainer$ContainerInterceptor.invoke(StatefulSessionContainer.java:823)
                at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:129)
                at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:186)
                at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:96)
                at org.jboss.ejb.plugins.AbstractTxInterceptorBMT.invokeNext(AbstractTxInterceptorBMT.java:144)
                at org.jboss.ejb.plugins.TxInterceptorBMT.invoke(TxInterceptorBMT.java:62)
                at org.jboss.ejb.plugins.StatefulSessionInstanceInterceptor.invoke(StatefulSessionInstanceInterceptor.java:266)
                at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:166)
                at org.jboss.ejb.StatefulSessionContainer.invoke(StatefulSessionContainer.java:380)
                at org.jboss.ejb.Container.invoke(Container.java:705)
                at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:491)
                at org.jboss.invocation.jrmp.server.JRMPInvoker.invoke(JRMPInvoker.java:362)
                at java.lang.reflect.Method.invoke(Native Method)
                at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:236)
                at sun.rmi.transport.Transport$1.run(Transport.java:147)
                at java.security.AccessController.doPrivileged(Native Method)
                at sun.rmi.transport.Transport.serviceCall(Transport.java:143)
                at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:460)
                at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:701)
                at java.lang.Thread.run(Thread.java:479)
                13:16:57,047 INFO [Facets] [06/21/02 13:16:57.046 PDTRMI TCP Connection(5)-10.80.10.114] #xa.forget[hash=2511113,session=PM 342 (workspace 0) (shutdownPending closed txn)] xid=XidImpl [FormatId=257, GlobalId=dirt//11, BranchQual=1] trs=resource
                13:16:57,052 INFO [Facets] [06/21/02 13:16:57.051 PDTRMI TCP Connection(5)-10.80.10.114] #mc.cleanup# CC1( PM 341 (workspace 1) (inactive manual txn) inJTx=false)
                13:16:57,053 INFO [Facets] [06/21/02 13:16:57.053 PDTRMI TCP Connection(5)-10.80.10.114] #mc.getXAResource# CC1( PM 341 (workspace 1) (inactive manual txn) inJTx=false)
                13:16:57,145 INFO [STDOUT] [06/21/02 13:16:57.145 PDT]::::: CMTX INITIALIZE :::::
                13:16:57,147 INFO [STDOUT] [06/21/02 13:16:57.146 PDT]::::: PID: 24878 :::::
                13:16:57,147 INFO [STDOUT] [06/21/02 13:16:57.147 PDT]::::: Getting Connection
                13:16:57,491 INFO [Facets] [06/21/02 13:16:57.491 PDTRMI TCP Connection(6)-10.80.10.114] Establishing new Facets session for connection CC2( PM 342 (workspace 0) (shutdownPending closed txn) inJTx=false)
                13:16:57,493 INFO [Facets] [06/21/02 13:16:57.492 PDTRMI TCP Connection(6)-10.80.10.114] #cf.matchManagedConnetions# created new session for CC2( PM 343 (workspace 2) (inactive manual txn) inJTx=false)
                13:16:57,494 ERROR [STDERR] java.lang.Exception: Stack trace
                13:16:57,494 ERROR [STDERR] at java.lang.Thread.dumpStack(Thread.java:992)
                13:16:57,495 ERROR [STDERR] at com.gemstone.persistence.connection.internal.ConnFactory.matchManagedConnections(ConnFactory.java:173)
                13:16:57,496 ERROR [STDERR] at org.jboss.resource.connectionmanager.InternalManagedConnectionPool.getConnection(InternalManagedConnectionPool.java:89)
                13:16:57,497 ERROR [STDERR] at org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool.getConnection(JBossManagedConnectionPool.java:482)
                13:16:57,498 ERROR [STDERR] at org.jboss.resource.connectionmanager.BaseConnectionManager2.getManagedConnection(BaseConnectionManager2.java:467)
                13:16:57,498 ERROR [STDERR] at org.jboss.resource.connectionmanager.BaseConnectionManager2.allocateConnection(BaseConnectionManager2.java:532)
                13:16:57,499 ERROR [STDERR] at org.jboss.resource.connectionmanager.BaseConnectionManager2$ConnectionManagerProxy.allocateConnection(BaseConnectionManager2.java:812)
                13:16:57,499 ERROR [STDERR] at com.gemstone.persistence.connection.internal.ContainerConnFactory.getConnection(ContainerConnFactory.java:60)
                13:16:57,501 ERROR [STDERR] at jca.ejb.cmtx.AbstractBeanBehavior.getConnection(AbstractBeanBehavior.java:132)
                13:16:57,501 ERROR [STDERR] at jca.ejb.cmtx.AbstractBeanBehavior.initialize(AbstractBeanBehavior.java:72)
                13:16:57,502 ERROR [STDERR] at java.lang.reflect.Method.invoke(Native Method)
                13:16:57,503 ERROR [STDERR] at org.jboss.ejb.StatefulSessionContainer$ContainerInterceptor.invoke(StatefulSessionContainer.java:823)
                13:16:57,504 ERROR [STDERR] at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:129)
                13:16:57,504 ERROR [STDERR] at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:186)
                13:16:57,505 ERROR [STDERR] at org.jboss.ejb.plugins.StatefulSessionInstanceInterceptor.invoke(StatefulSessionInstanceInterceptor.java:266)
                13:16:57,506 ERROR [STDERR] at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:96)
                13:16:57,507 ERROR [STDERR] at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:167)
                13:16:57,507 ERROR [STDERR] at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:61)
                13:16:57,508 ERROR [STDERR] at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:166)
                13:16:57,509 ERROR [STDERR] at org.jboss.ejb.StatefulSessionContainer.invoke(StatefulSessionContainer.java:380)
                13:16:57,510 ERROR [STDERR] at org.jboss.ejb.Container.invoke(Container.java:705)
                13:16:57,510 ERROR [STDERR] at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:491)
                13:16:57,511 ERROR [STDERR] at org.jboss.invocation.jrmp.server.JRMPInvoker.invoke(JRMPInvoker.java:362)
                13:16:57,511 ERROR [STDERR] at java.lang.reflect.Method.invoke(Native Method)
                13:16:57,512 ERROR [STDERR] at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:236)
                13:16:57,513 ERROR [STDERR] at sun.rmi.transport.Transport$1.run(Transport.java:147)
                13:16:57,514 ERROR [STDERR] at java.security.AccessController.doPrivileged(Native Method)
                13:16:57,514 ERROR [STDERR] at sun.rmi.transport.Transport.serviceCall(Transport.java:143)
                13:16:57,515 ERROR [STDERR] at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:460)
                13:16:57,515 ERROR [STDERR] at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:701)
                13:16:57,517 ERROR [STDERR] at java.lang.Thread.run(Thread.java:479)
                13:16:57,518 INFO [Facets] [06/21/02 13:16:57.517 PDTRMI TCP Connection(6)-10.80.10.114] [Facets] using pooled connection CC2( PM 343 (workspace 2) (inactive manual txn) inJTx=false)
                13:16:57,519 INFO [Facets] [06/21/02 13:16:57.519 PDTRMI TCP Connection(6)-10.80.10.114] #mc.getXAResource# CC2( PM 343 (workspace 2) (inactive manual txn) inJTx=false)
                13:16:57,521 INFO [Facets] [06/21/02 13:16:57.520 PDTRMI TCP Connection(6)-10.80.10.114] #xa.start[hash=3174071,session=PM 343 (workspace 2) (inactive manual txn)] xid=XidImpl [FormatId=257, GlobalId=dirt//14, BranchQual=1]
                13:16:57,523 INFO [Facets] [06/21/02 13:16:57.522 PDTRMI TCP Connection(6)-10.80.10.114] #mc.getConnection# CC2( PM 343 (workspace 2) (active manual txn) inJTx=true)
                13:16:57,524 INFO [Facets] [06/21/02 13:16:57.524 PDTRMI TCP Connection(6)-10.80.10.114] [Facets] no user/password for CC2( PM 343 (workspace 2) (active manual txn) inJTx=true)

                • 5. Re: reuse of destroyed connection
                  davidjencks

                  Thanks! can you provide a guide to what I'm looking at?
                  What are these pieces of info and where do they come from... and are you sure they are unique;-)

                  Many thanks
                  david jencks

                  13:16:57,518 INFO [Facets]

                  [06/21/02 13:16:57.517 PDTRMI TCP connection(6)-10.80.10.114]

                  [Facets] using pooled connection

                  CC2

                  ( PM 343

                  (workspace 2)

                  (inactive manual txn)

                  inJTx=false)

                  • 6. Re: reuse of destroyed connection
                    bruces

                    13:16:57,518 INFO [Facets]

                    ^^^^ "[Facets]" is put in log messages for my connector by the jboss logging service. These are messages that are being logged by the connector

                    [06/21/02 13:16:57.517 PDTRMI TCP connection(6)-10.80.10.114]

                    ^^^^ there is one client program that is creating beans and sending them messages. This is its connection.


                    [Facets] using pooled connection

                    ^^^^ this is a message logged in matchManagedConnections in my MCF when it is returning a match

                    CC2

                    ^^^^ this is the name of a managed connection. They get numbered sequentially starting at 1 and have the prefix "CC", standing for "container connection".

                    ( PM 343 (workspace 2) (inactive manual txn)

                    ^^^^ this is a description of the low-level database connection, which calls itself a PersistenceManager (PM). It is using a shared-memory workspace numbered "2" and is currently in non-chained (manual) transaction mode and is not in a transaction (inactive).

                    BTW, the scenario seems to be this:
                    bean 1 starts transaction
                    bean 1 gets connection
                    bean 1 closes connection
                    container returns connection to pool
                    container commits transaction
                    connection gets exception, reports it to container
                    container destroys connection
                    bean 2 starts transaction
                    bean 2 gets connection
                    >>>container gives bean 2 a destroyed connection
                    bean 2 uses connection and gets exception

                    It looks like there are other bug reports @ SourceForge describing this same problem with other connectors.

                    • 7. Re: reuse of destroyed connection
                      davidjencks

                      Thanks!!

                      There is indeed a bug here, I was assuming that ConnectionErrors would only happen when the connection was out of the pool. (despite some of the jms guys talking with me about the possibility).

                      I will fix this shortly.

                      Many thanks for identifying at least one of the problems.