-
1. Re: reuse of destroyed connection
bruces Jun 20, 2002 7:22 PM (in response to 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 Jun 21, 2002 12:31 AM (in response to bruces)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 Jun 21, 2002 4:46 PM (in response to 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 Jun 21, 2002 5:10 PM (in response to 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 Jun 22, 2002 1:28 AM (in response to bruces)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 Jun 24, 2002 3:16 PM (in response to 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 Jun 24, 2002 6:05 PM (in response to bruces)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.