[jboss-user] [JCA/JBoss] - JCA concurrent acces to ManagedConnection problem

Hello, I'm using jBoss 4.2.2GA with jdk 1.5.0_12. For my transactional monitor (a Tuxedo clone but a little faster :-)), I'm developing a JCA connector based on JCA specifications 1.0. Until now, everything was working fine until I tried to add XA functionality. When jBoss is under stress, it seems that ManagedConnections can be used concurrently by 2 (or more) separated threads. As my implementation of ManagedConnection isn't thread-safe, I have troubles. Is it normal that a ManagedConnection can be used by several threads ? I thought the pooling mechanism was built to avoid such cases. I give you my trace just in case of I'm wrong in interpreting it. I add the thread id to the log4j pattern to known from which thread the message is coming from. As you can see, the thread http-7 is performing those steps: 1- gets the ManagedConnection@468c66b6 from the pool 2- sends message 548 (xa_start) 3- gets response 548 (XA_OK) 4- sends message 551 (service call) 5- gets response 551 (call OK) 6- sends message 559 (xa_end(TM_SUSPEND)) 7- gets response 559 (XA_OK) 8- puts the ManagedConnection@468c66b6 back to the pool 9- sends message 560 (xa_end(TM_SUCCESS)) 10- gets wrong response (overwrite by response) !!!! Between step 9 and 10 of thread http-7, thread http-4 gets the same ManagedConnection@468c66b6 from the pool and begins its work: 1- gets the ManagedConnection@468c66b6 from the pool 2- sends message 561 (xa_start) 3- gets wrong response (overwrite by response 560) !!!! I noticed that the problem always comes from XA orders sent after the ManagedConnection is returned to the pool. Please help me. Thanks in advance, Pierre Brico 13:56:17,897-http-172.18.4.104-8180-7 TRACE [JBossManagedConnectionPool] supplying ManagedConnection from pool: org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@284ac3e1[state=NORMAL mc=tsdjca.TSDManagedConnection@468c66b6 handles=0 lastUse=1214999777767 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@2be8ac6f context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@3890c1ee xaResource=org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper@4481fd71 txSync=null] 13:56:17,898-http-172.18.4.104-8180-7 TRACE [JBossManagedConnectionPool] Got connection from pool org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@284ac3e1[state=NORMAL mc=tsdjca.TSDManagedConnection@468c66b6 handles=0 lastUse=1214999777767 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@2be8ac6f context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@3890c1ee xaResource=org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper@4481fd71 txSync=null] [InUse/Available/Max]: [1/19/20] 13:56:17,898-http-172.18.4.104-8180-7 TRACE [TxConnectionManager] Pre-enlist: org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@284ac3e1[state=NORMAL mc=tsdjca.TSDManagedConnection@468c66b6 handles=0 lastUse=1214999777767 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@2be8ac6f context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@3890c1ee xaResource=org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper@4481fd71 txSync=null] threadTx=TransactionImple < ac, BasicAction: -53edfb98:e7a2:486b6b91:2abf status: ActionStatus.RUNNING > 13:56:17,898-http-172.18.4.104-8180-7 TRACE [TxConnectionManager] Get synchronizer org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@284ac3e1[state=NORMAL mc=tsdjca.TSDManagedConnection@468c66b6 handles=0 lastUse=1214999777767 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@2be8ac6f context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@3890c1ee xaResource=org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper@4481fd71 txSync=null] threadTx=TransactionImple < ac, BasicAction: -53edfb98:e7a2:486b6b91:2abf status: ActionStatus.RUNNING > 13:56:17,898-http-172.18.4.104-8180-7 TRACE [TxConnectionManager] Enlisting resource org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@284ac3e1[state=NORMAL mc=tsdjca.TSDManagedConnection@468c66b6 handles=0 lastUse=1214999777767 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@2be8ac6f context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@3890c1ee xaResource=org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper@4481fd71 txSync=TxSync731292857{tx=TransactionImple < ac, BasicAction: -53edfb98:e7a2:486b6b91:2abf status: ActionStatus.RUNNING > wasTrackByTx=false enlisted=false}] 13:56:17,899-http-172.18.4.104-8180-7 INFO [STDOUT] Sent header 548 tsdjca.TSDManagedConnection@468c66b6 13:56:17,900-http-172.18.4.104-8180-7 INFO [STDOUT] Sent body 548 tsdjca.TSDManagedConnection@468c66b6 13:56:17,980-http-172.18.4.104-8180-7 INFO [STDOUT] Received header 548 tsdjca.TSDManagedConnection@468c66b6 13:56:17,980-http-172.18.4.104-8180-7 INFO [STDOUT] Received body 548 tsdjca.TSDManagedConnection@468c66b6 13:56:17,980-http-172.18.4.104-8180-7 TRACE [TxConnectionManager] Enlisted resource org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@284ac3e1[state=NORMAL mc=tsdjca.TSDManagedConnection@468c66b6 handles=0 lastUse=1214999777767 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@2be8ac6f context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@3890c1ee xaResource=org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper@4481fd71 txSync=TxSync731292857{tx=TransactionImple < ac, BasicAction: -53edfb98:e7a2:486b6b91:2abf status: ActionStatus.RUNNING > wasTrackByTx=false enlisted=false}] 13:56:17,980-http-172.18.4.104-8180-7 TRACE [TxConnectionManager] Check enlisted org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@284ac3e1[state=NORMAL mc=tsdjca.TSDManagedConnection@468c66b6 handles=0 lastUse=1214999777767 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@2be8ac6f context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@3890c1ee xaResource=org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper@4481fd71 txSync=TxSync731292857{tx=TransactionImple < ac, BasicAction: -53edfb98:e7a2:486b6b91:2abf status: ActionStatus.RUNNING > wasTrackByTx=false enlisted=true}] threadTx=TransactionImple < ac, BasicAction: -53edfb98:e7a2:486b6b91:2abf status: ActionStatus.RUNNING > 13:56:17,983-http-172.18.4.104-8180-7 INFO [STDOUT] Sent header 551 tsdjca.TSDManagedConnection@468c66b6 13:56:17,999-http-172.18.4.104-8180-7 INFO [STDOUT] Sent body 551 tsdjca.TSDManagedConnection@468c66b6 13:56:18,378-http-172.18.4.104-8180-7 INFO [STDOUT] Received header 551 tsdjca.TSDManagedConnection@468c66b6 13:56:18,442-http-172.18.4.104-8180-7 INFO [STDOUT] Received body 551 tsdjca.TSDManagedConnection@468c66b6 13:56:18,448-http-172.18.4.104-8180-7 TRACE [TxConnectionManager] connectionClosed called mc=tsdjca.TSDManagedConnection@468c66b6 13:56:18,448-http-172.18.4.104-8180-7 TRACE [TxConnectionManager] isManagedConnectionFree=true mc=tsdjca.TSDManagedConnection@468c66b6 13:56:18,448-http-172.18.4.104-8180-7 TRACE [TxConnectionManager] delisting org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@284ac3e1[state=NORMAL mc=tsdjca.TSDManagedConnection@468c66b6 handles=0 lastUse=1214999777767 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@2be8ac6f context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@3890c1ee xaResource=org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper@4481fd71 txSync=TxSync731292857{tx=TransactionImple < ac, BasicAction: -53edfb98:e7a2:486b6b91:2abf status: ActionStatus.RUNNING > wasTrackByTx=false enlisted=true}] 13:56:18,449-http-172.18.4.104-8180-7 INFO [STDOUT] Sent header 559 tsdjca.TSDManagedConnection@468c66b6 13:56:18,450-http-172.18.4.104-8180-7 INFO [STDOUT] Sent body 559 tsdjca.TSDManagedConnection@468c66b6 13:56:18,719-http-172.18.4.104-8180-7 INFO [STDOUT] Received header 559 tsdjca.TSDManagedConnection@468c66b6 13:56:18,720-http-172.18.4.104-8180-7 INFO [STDOUT] Received body 559 tsdjca.TSDManagedConnection@468c66b6 13:56:18,720-http-172.18.4.104-8180-7 TRACE [JBossManagedConnectionPool] putting ManagedConnection back into pool kill=false cl=org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@284ac3e1[state=NORMAL mc=tsdjca.TSDManagedConnection@468c66b6 handles=0 lastUse=1214999777767 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@2be8ac6f context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@3890c1ee xaResource=org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper@4481fd71 txSync=null] 13:56:18,720-http-172.18.4.104-8180-7 TRACE [JBossManagedConnectionPool] Returning connection to pool org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@284ac3e1[state=NORMAL mc=tsdjca.TSDManagedConnection@468c66b6 handles=0 lastUse=1214999778720 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@2be8ac6f context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@3890c1ee xaResource=org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper@4481fd71 txSync=null] [InUse/Available/Max]: [2/18/20] 13:56:18,720-http-172.18.4.104-8180-7 INFO [STDOUT] Sent header 560 tsdjca.TSDManagedConnection@468c66b6 13:56:18,722-http-172.18.4.104-8180-7 INFO [STDOUT] Sent body 560 tsdjca.TSDManagedConnection@468c66b6 13:56:18,783-http-172.18.4.104-8180-4 TRACE [JBossManagedConnectionPool] supplying ManagedConnection from pool: org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@284ac3e1[state=NORMAL mc=tsdjca.TSDManagedConnection@468c66b6 handles=0 lastUse=1214999778720 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@2be8ac6f context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@3890c1ee xaResource=org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper@4481fd71 txSync=null] 13:56:18,783-http-172.18.4.104-8180-4 TRACE [JBossManagedConnectionPool] Got connection from pool org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@284ac3e1[state=NORMAL mc=tsdjca.TSDManagedConnection@468c66b6 handles=0 lastUse=1214999778720 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@2be8ac6f context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@3890c1ee xaResource=org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper@4481fd71 txSync=null] [InUse/Available/Max]: [3/17/20] 13:56:18,784-http-172.18.4.104-8180-4 TRACE [TxConnectionManager] No transaction, no need to enlist: org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@284ac3e1[state=NORMAL mc=tsdjca.TSDManagedConnection@468c66b6 handles=0 lastUse=1214999778720 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@2be8ac6f context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@3890c1ee xaResource=org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper@4481fd71 txSync=null] 13:56:18,786-http-172.18.4.104-8180-4 INFO [STDOUT] Sent header 561 tsdjca.TSDManagedConnection@468c66b6 13:56:18,791-http-172.18.4.104-8180-4 INFO [STDOUT] Sent body 561 tsdjca.TSDManagedConnection@468c66b6 13:56:18,990-http-172.18.4.104-8180-7 INFO [STDOUT] Received header 560 tsdjca.TSDManagedConnection@468c66b6 13:56:28,979-http-172.18.4.104-8180-4 INFO [STDOUT] Received header 12293 tsdjca.TSDManagedConnection@468c66b6 13:56:28,980-http-172.18.4.104-8180-4 TRACE [TxConnectionManager] connectionClosed called mc=tsdjca.TSDManagedConnection@468c66b6 13:56:28,980-http-172.18.4.104-8180-4 TRACE [TxConnectionManager] isManagedConnectionFree=true mc=tsdjca.TSDManagedConnection@468c66b6 13:56:28,980-http-172.18.4.104-8180-4 TRACE [TxConnectionManager] delisting org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@284ac3e1[state=NORMAL mc=tsdjca.TSDManagedConnection@468c66b6 handles=0 lastUse=1214999778720 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@2be8ac6f context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@3890c1ee xaResource=org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper@4481fd71 txSync=null] 13:56:28,980-http-172.18.4.104-8180-4 TRACE [JBossManagedConnectionPool] putting ManagedConnection back into pool kill=false cl=org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@284ac3e1[state=NORMAL mc=tsdjca.TSDManagedConnection@468c66b6 handles=0 lastUse=1214999778720 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@2be8ac6f context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@3890c1ee xaResource=org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper@4481fd71 txSync=null] 13:56:28,980-http-172.18.4.104-8180-4 TRACE [JBossManagedConnectionPool] Returning connection to pool org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@284ac3e1[state=NORMAL mc=tsdjca.TSDManagedConnection@468c66b6 handles=0 lastUse=1214999788980 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@2be8ac6f context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@3890c1ee xaResource=org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper@4481fd71 txSync=null] [InUse/Available/Max]: [5/15/20] View the original post : http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4162043#... Reply to the post : http://www.jboss.com/index.html?module=bb&op=posting&mode=reply&a...