Problem with writing JCA adapter
lgsw_sam Nov 30, 2006 7:30 AMHi!
I am running
JBoss 4.0.5.GA with ejb3
Java 1.5.0.09
and having some problems trying to get my adapter to work.
I do get connections but after 21min from closing last connection on my test application JBossManagedConnectionPool is trying to destroy 2 timedout connections. That causes IOException because those connections have been closed previously...
It seems that my connections are created, added to the pool and event listeners are created. And when I call close(), CONNECTION_CLOSED event is raised and connection returned to pool but removeConnectionEventListener() is not called.
Could this be causing these exeptions?
If you need specific codes I am happy to post them here. For now I don't know where the problem is and didn't want to put all the codes here.
Here is my server log from where the server is started and I call TestBean to the point where connections should be closed and IOException occurs.
2006-11-30 13:02:11,001 INFO [org.jboss.system.server.Server] JBoss (MX MicroKernel) [4.0.5.GA (build: CVSTag=Branch_4_0 date=200611270730)] Started in 1m:20s:482ms 2006-11-30 13:02:56,000 DEBUG [org.jboss.remoting.transport.socket.ServerThread] beginning dorun 2006-11-30 13:02:56,172 TRACE [org.jboss.tm.TransactionImpl] Created new instance for tx=TransactionImpl:XidImpl[FormatId=257, GlobalId=ws-sam/14, BranchQual=, localId=14] 2006-11-30 13:02:56,172 TRACE [org.jboss.tm.TxManager] began tx: TransactionImpl:XidImpl[FormatId=257, GlobalId=ws-sam/14, BranchQual=, localId=14] 2006-11-30 13:02:56,219 INFO [STDOUT] TestBean.doSomething kutsuttu : jmo 2006-11-30 13:02:56,219 DEBUG [fi.logiasoftware.jca.adapter.GenericConnectionFactoryImpl] GenericResource getConnection(GenericConnectionRequestInfo) 2006-11-30 13:02:56,219 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory] GManagedConnectionFactory.hashCode() 2006-11-30 13:02:56,219 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory] GManagedConnectionFactory.equals( fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory@4b29cf ) 2006-11-30 13:02:56,219 TRACE [org.jboss.resource.connectionmanager.NoTxConnectionManager] subject: null 2006-11-30 13:02:56,219 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] internalRegisterPool: registering pool with interval 900000 old interval: 9223372036854775807 2006-11-30 13:02:56,219 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] internalRegisterPool: about to notify thread: old next: 1164885026219, new next: 1164885026219 2006-11-30 13:02:56,219 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory] ManagedConnection createManagedConnection(Subject, ConnectionRequestInfo) 2006-11-30 13:02:56,234 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] GenericManagedConnection(ManagedConnectionFactory) 2006-11-30 13:02:56,234 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] cleanup() 2006-11-30 13:02:56,312 DEBUG [fi.logiasoftware.jca.handlers.FTPProtocolHandler] connect(GenericConnectionRequestInfo) 2006-11-30 13:02:56,312 DEBUG [fi.logiasoftware.jca.handlers.FTPProtocolHandler] Connecting to FTP server: wbs.software.logia.fi 21 2006-11-30 13:02:56,437 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] setConnection(AbstractProtocolHandler) 2006-11-30 13:02:56,437 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] addConnectionEventListener(ConnectionEventListener) 2006-11-30 13:02:56,437 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] supplying new ManagedConnection: org.jboss.resource.connectionmanager.NoTxConnectionManager$NoTxConnectionEventListener@b41541[state=NORMAL mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@df88d2 handles=0 lastUse=1164884576437 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@18faa02 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@e26d2e] 2006-11-30 13:02:56,437 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Got connection from pool org.jboss.resource.connectionmanager.NoTxConnectionManager$NoTxConnectionEventListener@b41541[state=NORMAL mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@df88d2 handles=0 lastUse=1164884576437 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@18faa02 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@e26d2e] [InUse/Available/Max]: [1/19/20] 2006-11-30 13:02:56,437 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] Object getConnection(Subject, ConnectionRequestInfo) 2006-11-30 13:02:56,453 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] GenericResourceImpl(AbstractProtocolHandler, GenericManagedConnection) 2006-11-30 13:02:56,453 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] Returning XMPPResource=fi.logiasoftware.jca.adapter.GenericResourceImpl@1e5052b 2006-11-30 13:02:56,453 TRACE [org.jboss.resource.connectionmanager.CachedConnectionManager] registering connection from org.jboss.resource.connectionmanager.NoTxConnectionManager@b65a68, connection : fi.logiasoftware.jca.adapter.GenericResourceImpl@1e5052b, key: null 2006-11-30 13:02:56,453 INFO [STDOUT] 1---------TestBean1 ID : 1 user : jmo : 2006-11-30 13:03:16,452 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] AbstractProtocolHandler getHandler() 2006-11-30 13:03:16,452 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] AbstractProtocolHandler getHandler() 2006-11-30 13:03:16,734 INFO [STDOUT] TestBean2.test kutsuttu : sam 2006-11-30 13:03:16,734 DEBUG [fi.logiasoftware.jca.adapter.GenericConnectionFactoryImpl] GenericResource getConnection(GenericConnectionRequestInfo) 2006-11-30 13:03:16,734 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory] GManagedConnectionFactory.hashCode() 2006-11-30 13:03:16,734 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory] GManagedConnectionFactory.equals( fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory@4b29cf ) 2006-11-30 13:03:16,734 TRACE [org.jboss.resource.connectionmanager.NoTxConnectionManager] subject: null 2006-11-30 13:03:16,734 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory] ManagedConnection createManagedConnection(Subject, ConnectionRequestInfo)----- 2006-11-30 13:03:16,734 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] GenericManagedConnection(ManagedConnectionFactory) 2006-11-30 13:03:16,734 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] cleanup() 2006-11-30 13:03:16,734 DEBUG [fi.logiasoftware.jca.handlers.FTPProtocolHandler] connect(GenericConnectionRequestInfo) 2006-11-30 13:03:16,734 DEBUG [fi.logiasoftware.jca.handlers.FTPProtocolHandler] Connecting to FTP server: wbs.software.logia.fi 21 2006-11-30 13:03:16,749 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] setConnection(AbstractProtocolHandler) 2006-11-30 13:03:16,749 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] addConnectionEventListener(ConnectionEventListener) 2006-11-30 13:03:16,749 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] supplying new ManagedConnection: org.jboss.resource.connectionmanager.NoTxConnectionManager$NoTxConnectionEventListener@18e862c[state=NORMAL mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@ab58d handles=0 lastUse=1164884596749 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@18faa02 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@e26d2e] 2006-11-30 13:03:16,749 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Got connection from pool org.jboss.resource.connectionmanager.NoTxConnectionManager$NoTxConnectionEventListener@18e862c[state=NORMAL mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@ab58d handles=0 lastUse=1164884596749 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@18faa02 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@e26d2e] [InUse/Available/Max]: [2/18/20] 2006-11-30 13:03:16,749 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] Object getConnection(Subject, ConnectionRequestInfo) 2006-11-30 13:03:16,749 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] GenericResourceImpl(AbstractProtocolHandler, GenericManagedConnection) 2006-11-30 13:03:16,749 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] Returning XMPPResource=fi.logiasoftware.jca.adapter.GenericResourceImpl@1156508 2006-11-30 13:03:16,749 TRACE [org.jboss.resource.connectionmanager.CachedConnectionManager] registering connection from org.jboss.resource.connectionmanager.NoTxConnectionManager@b65a68, connection : fi.logiasoftware.jca.adapter.GenericResourceImpl@1156508, key: null 2006-11-30 13:03:16,749 INFO [STDOUT] 2----------TestBean2 ID : 2 user : sam : 2006-11-30 13:03:26,749 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] AbstractProtocolHandler getHandler() 2006-11-30 13:03:26,765 INFO [STDOUT] TestBean4.test kutsuttu : jmo 2006-11-30 13:03:26,765 DEBUG [fi.logiasoftware.jca.adapter.GenericConnectionFactoryImpl] GenericResource getConnection(GenericConnectionRequestInfo) 2006-11-30 13:03:26,765 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory] GManagedConnectionFactory.hashCode() 2006-11-30 13:03:26,765 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory] GManagedConnectionFactory.equals( fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory@4b29cf ) 2006-11-30 13:03:26,765 TRACE [org.jboss.resource.connectionmanager.NoTxConnectionManager] subject: null 2006-11-30 13:03:26,765 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory] ManagedConnection createManagedConnection(Subject, ConnectionRequestInfo) 2006-11-30 13:03:26,765 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] GenericManagedConnection(ManagedConnectionFactory) 2006-11-30 13:03:26,765 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] cleanup() 2006-11-30 13:03:26,765 DEBUG [fi.logiasoftware.jca.handlers.FTPProtocolHandler] connect(GenericConnectionRequestInfo) 2006-11-30 13:03:26,765 DEBUG [fi.logiasoftware.jca.handlers.FTPProtocolHandler] Connecting to FTP server: wbs.software.logia.fi 21 2006-11-30 13:03:26,780 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] setConnection(AbstractProtocolHandler) 2006-11-30 13:03:26,780 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] addConnectionEventListener(ConnectionEventListener) 2006-11-30 13:03:26,780 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] supplying new ManagedConnection: org.jboss.resource.connectionmanager.NoTxConnectionManager$NoTxConnectionEventListener@1fa8988[state=NORMAL mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@15b44d6 handles=0 lastUse=1164884606780 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@18faa02 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@e26d2e] 2006-11-30 13:03:26,780 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Got connection from pool org.jboss.resource.connectionmanager.NoTxConnectionManager$NoTxConnectionEventListener@1fa8988[state=NORMAL mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@15b44d6 handles=0 lastUse=1164884606780 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@18faa02 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@e26d2e] [InUse/Available/Max]: [3/17/20] 2006-11-30 13:03:26,780 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] Object getConnection(Subject, ConnectionRequestInfo) 2006-11-30 13:03:26,780 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] GenericResourceImpl(AbstractProtocolHandler, GenericManagedConnection) 2006-11-30 13:03:26,780 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] Returning XMPPResource=fi.logiasoftware.jca.adapter.GenericResourceImpl@1044daf 2006-11-30 13:03:26,780 TRACE [org.jboss.resource.connectionmanager.CachedConnectionManager] registering connection from org.jboss.resource.connectionmanager.NoTxConnectionManager@b65a68, connection : fi.logiasoftware.jca.adapter.GenericResourceImpl@1044daf, key: null 2006-11-30 13:03:26,780 INFO [STDOUT] 3-----------Testbean4 ID : 1 user : jmo : 2006-11-30 13:03:46,780 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] AbstractProtocolHandler getHandler() 2006-11-30 13:03:46,780 INFO [STDOUT] Suljetaan TestBean4 resource 2006-11-30 13:03:46,780 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] close() 2006-11-30 13:03:46,780 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] About to close resource fi.logiasoftware.jca.adapter.GenericResourceImpl@1044daf using mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@15b44d6 2006-11-30 13:03:46,780 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] close(GenericResourceImpl) 2006-11-30 13:03:46,780 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] Object getAssociatedObject() 2006-11-30 13:03:46,780 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@15b44d6 closing=fi.logiasoftware.jca.adapter.GenericResourceImpl@1044daf impl.associatedObject=fi.logiasoftware.jca.adapter.GenericManagedConnection@15b44d6 2006-11-30 13:03:46,780 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] connectionClosed(ConnectionEvent) 2006-11-30 13:03:46,780 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] notifyConnectionEvent(ConnectionEvent) 2006-11-30 13:03:46,780 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] CONNECTION CLOSED 2006-11-30 13:03:46,780 TRACE [org.jboss.resource.connectionmanager.CachedConnectionManager] unregistering connection from org.jboss.resource.connectionmanager.NoTxConnectionManager@b65a68, object: fi.logiasoftware.jca.adapter.GenericResourceImpl@1044daf, key: null 2006-11-30 13:03:46,780 TRACE [org.jboss.resource.connectionmanager.NoTxConnectionManager] unregisterConnection: 0 handles left 2006-11-30 13:03:46,780 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] putting ManagedConnection back into pool kill=false cl=org.jboss.resource.connectionmanager.NoTxConnectionManager$NoTxConnectionEventListener@1fa8988[state=NORMAL mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@15b44d6 handles=0 lastUse=1164884606780 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@18faa02 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@e26d2e] 2006-11-30 13:03:46,780 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] cleanup() 2006-11-30 13:03:46,780 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] invalidate() 2006-11-30 13:03:46,780 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] setValid(boolean) 2006-11-30 13:03:46,780 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Returning connection to pool org.jboss.resource.connectionmanager.NoTxConnectionManager$NoTxConnectionEventListener@1fa8988[state=NORMAL mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@15b44d6 handles=0 lastUse=1164884626780 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@18faa02 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@e26d2e] [InUse/Available/Max]: [2/18/20] 2006-11-30 13:03:46,780 TRACE [org.jboss.tm.TxManager] tx timeout is now: 300s 2006-11-30 13:04:06,795 INFO [STDOUT] Suljetaan TestBean2 resource 2006-11-30 13:04:06,795 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] close() 2006-11-30 13:04:06,795 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] About to close resource fi.logiasoftware.jca.adapter.GenericResourceImpl@1156508 using mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@ab58d 2006-11-30 13:04:06,795 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] close(GenericResourceImpl) 2006-11-30 13:04:06,811 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] Object getAssociatedObject() 2006-11-30 13:04:06,811 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@ab58d closing=fi.logiasoftware.jca.adapter.GenericResourceImpl@1156508 impl.associatedObject=fi.logiasoftware.jca.adapter.GenericManagedConnection@ab58d 2006-11-30 13:04:06,811 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] connectionClosed(ConnectionEvent) 2006-11-30 13:04:06,811 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] notifyConnectionEvent(ConnectionEvent) 2006-11-30 13:04:06,811 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] CONNECTION CLOSED 2006-11-30 13:04:06,811 TRACE [org.jboss.resource.connectionmanager.CachedConnectionManager] unregistering connection from org.jboss.resource.connectionmanager.NoTxConnectionManager@b65a68, object: fi.logiasoftware.jca.adapter.GenericResourceImpl@1156508, key: null 2006-11-30 13:04:06,811 TRACE [org.jboss.resource.connectionmanager.NoTxConnectionManager] unregisterConnection: 0 handles left 2006-11-30 13:04:06,811 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] putting ManagedConnection back into pool kill=false cl=org.jboss.resource.connectionmanager.NoTxConnectionManager$NoTxConnectionEventListener@18e862c[state=NORMAL mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@ab58d handles=0 lastUse=1164884596749 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@18faa02 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@e26d2e] 2006-11-30 13:04:06,811 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] cleanup() 2006-11-30 13:04:06,811 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] invalidate() 2006-11-30 13:04:06,811 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] setValid(boolean) 2006-11-30 13:04:06,811 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Returning connection to pool org.jboss.resource.connectionmanager.NoTxConnectionManager$NoTxConnectionEventListener@18e862c[state=NORMAL mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@ab58d handles=0 lastUse=1164884646811 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@18faa02 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@e26d2e] [InUse/Available/Max]: [1/19/20] 2006-11-30 13:04:06,811 TRACE [org.jboss.tm.TxManager] tx timeout is now: 300s 2006-11-30 13:04:06,811 INFO [STDOUT] TestBean3.test kutsuttu : jmo 2006-11-30 13:04:06,811 DEBUG [fi.logiasoftware.jca.adapter.GenericConnectionFactoryImpl] GenericResource getConnection(GenericConnectionRequestInfo) 2006-11-30 13:04:06,811 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory] GManagedConnectionFactory.hashCode() 2006-11-30 13:04:06,811 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory] GManagedConnectionFactory.equals( fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory@4b29cf ) 2006-11-30 13:04:06,811 TRACE [org.jboss.resource.connectionmanager.NoTxConnectionManager] subject: null 2006-11-30 13:04:06,811 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory] MATCHMANAGEDCONNECTIONS ManagedConnection matchManagedConnections(Set, Subject, ConnectionRequestInfo) 2006-11-30 13:04:06,811 INFO [fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory] connections: 1 2006-11-30 13:04:06,811 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] AbstractProtocolHandler getConnection() 2006-11-30 13:04:06,811 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory] Matching 3 with 2 2006-11-30 13:04:06,811 INFO [fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory] Ei match.. 2006-11-30 13:04:06,811 WARN [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Destroying connection that could not be successfully matched: org.jboss.resource.connectionmanager.NoTxConnectionManager$NoTxConnectionEventListener@18e862c[state=NORMAL mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@ab58d handles=0 lastUse=1164884646811 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@18faa02 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@e26d2e] 2006-11-30 13:04:06,811 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] destroy() 2006-11-30 13:04:06,811 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] closing fi.logiasoftware.jca.handlers.FTPProtocolHandler@825459 for fi.logiasoftware.jca.adapter.GenericManagedConnection@ab58d 2006-11-30 13:04:06,811 DEBUG [fi.logiasoftware.jca.handlers.FTPProtocolHandler] disconnect() 2006-11-30 13:04:06,811 DEBUG [fi.logiasoftware.jca.handlers.FTPProtocolHandler] boolean isConnected() 2006-11-30 13:04:06,811 INFO [fi.logiasoftware.jca.handlers.FTPProtocolHandler] this.isConnected?? : true 2006-11-30 13:04:06,811 INFO [STDOUT] Disconnect connected : true 2006-11-30 13:04:06,811 DEBUG [fi.logiasoftware.jca.handlers.FTPProtocolHandler] Disconnecting from FTP server: wbs.software.logia.fi 21 2006-11-30 13:04:06,811 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory] MATCHMANAGEDCONNECTIONS ManagedConnection matchManagedConnections(Set, Subject, ConnectionRequestInfo) 2006-11-30 13:04:06,826 INFO [fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory] connections: 1 2006-11-30 13:04:06,826 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] AbstractProtocolHandler getConnection() 2006-11-30 13:04:06,826 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory] Matching 3 with 1 2006-11-30 13:04:06,826 INFO [fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory] Ei match.. 2006-11-30 13:04:06,826 WARN [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Destroying connection that could not be successfully matched: org.jboss.resource.connectionmanager.NoTxConnectionManager$NoTxConnectionEventListener@1fa8988[state=NORMAL mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@15b44d6 handles=0 lastUse=1164884626780 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@18faa02 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@e26d2e] 2006-11-30 13:04:06,826 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] destroy() 2006-11-30 13:04:06,826 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] closing fi.logiasoftware.jca.handlers.FTPProtocolHandler@6fb3d6 for fi.logiasoftware.jca.adapter.GenericManagedConnection@15b44d6 2006-11-30 13:04:06,826 DEBUG [fi.logiasoftware.jca.handlers.FTPProtocolHandler] disconnect() 2006-11-30 13:04:06,826 DEBUG [fi.logiasoftware.jca.handlers.FTPProtocolHandler] boolean isConnected() 2006-11-30 13:04:06,826 INFO [fi.logiasoftware.jca.handlers.FTPProtocolHandler] this.isConnected?? : true 2006-11-30 13:04:06,826 INFO [STDOUT] Disconnect connected : true 2006-11-30 13:04:06,826 DEBUG [fi.logiasoftware.jca.handlers.FTPProtocolHandler] Disconnecting from FTP server: wbs.software.logia.fi 21 2006-11-30 13:04:06,826 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnectionFactory] ManagedConnection createManagedConnection(Subject, ConnectionRequestInfo) 2006-11-30 13:04:06,826 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] GenericManagedConnection(ManagedConnectionFactory) 2006-11-30 13:04:06,826 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] cleanup() 2006-11-30 13:04:06,826 DEBUG [fi.logiasoftware.jca.handlers.FTPProtocolHandler] connect(GenericConnectionRequestInfo) 2006-11-30 13:04:06,826 DEBUG [fi.logiasoftware.jca.handlers.FTPProtocolHandler] Connecting to FTP server: wbs.software.logia.fi 21 2006-11-30 13:04:06,842 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] setConnection(AbstractProtocolHandler) 2006-11-30 13:04:06,842 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] addConnectionEventListener(ConnectionEventListener) 2006-11-30 13:04:06,842 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] supplying new ManagedConnection: org.jboss.resource.connectionmanager.NoTxConnectionManager$NoTxConnectionEventListener@187a8e0[state=NORMAL mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@1602bbc handles=0 lastUse=1164884646842 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@18faa02 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@e26d2e] 2006-11-30 13:04:06,842 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Got connection from pool org.jboss.resource.connectionmanager.NoTxConnectionManager$NoTxConnectionEventListener@187a8e0[state=NORMAL mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@1602bbc handles=0 lastUse=1164884646842 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@18faa02 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@e26d2e] [InUse/Available/Max]: [2/18/20] 2006-11-30 13:04:06,842 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] Object getConnection(Subject, ConnectionRequestInfo) 2006-11-30 13:04:06,842 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] GenericResourceImpl(AbstractProtocolHandler, GenericManagedConnection) 2006-11-30 13:04:06,842 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] Returning XMPPResource=fi.logiasoftware.jca.adapter.GenericResourceImpl@d75cf7 2006-11-30 13:04:06,842 TRACE [org.jboss.resource.connectionmanager.CachedConnectionManager] registering connection from org.jboss.resource.connectionmanager.NoTxConnectionManager@b65a68, connection : fi.logiasoftware.jca.adapter.GenericResourceImpl@d75cf7, key: null 2006-11-30 13:04:06,842 INFO [STDOUT] 4----------TestBean3 ID : 3 user : jmo : 2006-11-30 13:04:26,841 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] AbstractProtocolHandler getHandler() 2006-11-30 13:04:26,841 INFO [STDOUT] Suljetaan TestBean3 resource 2006-11-30 13:04:26,841 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] close() 2006-11-30 13:04:26,841 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] About to close resource fi.logiasoftware.jca.adapter.GenericResourceImpl@d75cf7 using mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@1602bbc 2006-11-30 13:04:26,841 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] close(GenericResourceImpl) 2006-11-30 13:04:26,841 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] Object getAssociatedObject() 2006-11-30 13:04:26,841 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@1602bbc closing=fi.logiasoftware.jca.adapter.GenericResourceImpl@d75cf7 impl.associatedObject=fi.logiasoftware.jca.adapter.GenericManagedConnection@1602bbc 2006-11-30 13:04:26,841 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] connectionClosed(ConnectionEvent) 2006-11-30 13:04:26,841 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] notifyConnectionEvent(ConnectionEvent) 2006-11-30 13:04:26,841 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] CONNECTION CLOSED 2006-11-30 13:04:26,841 TRACE [org.jboss.resource.connectionmanager.CachedConnectionManager] unregistering connection from org.jboss.resource.connectionmanager.NoTxConnectionManager@b65a68, object: fi.logiasoftware.jca.adapter.GenericResourceImpl@d75cf7, key: null 2006-11-30 13:04:26,841 TRACE [org.jboss.resource.connectionmanager.NoTxConnectionManager] unregisterConnection: 0 handles left 2006-11-30 13:04:26,841 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] putting ManagedConnection back into pool kill=false cl=org.jboss.resource.connectionmanager.NoTxConnectionManager$NoTxConnectionEventListener@187a8e0[state=NORMAL mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@1602bbc handles=0 lastUse=1164884646842 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@18faa02 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@e26d2e] 2006-11-30 13:04:26,841 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] cleanup() 2006-11-30 13:04:26,841 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] invalidate() 2006-11-30 13:04:26,841 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] setValid(boolean) 2006-11-30 13:04:26,841 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Returning connection to pool org.jboss.resource.connectionmanager.NoTxConnectionManager$NoTxConnectionEventListener@187a8e0[state=NORMAL mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@1602bbc handles=0 lastUse=1164884666841 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@18faa02 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@e26d2e] [InUse/Available/Max]: [1/19/20] 2006-11-30 13:04:26,841 TRACE [org.jboss.tm.TxManager] tx timeout is now: 300s 2006-11-30 13:04:46,856 INFO [STDOUT] Suljetaan TestBean resource 2006-11-30 13:04:46,856 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] close() 2006-11-30 13:04:46,856 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] About to close resource fi.logiasoftware.jca.adapter.GenericResourceImpl@1e5052b using mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@df88d2 2006-11-30 13:04:46,856 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] close(GenericResourceImpl) 2006-11-30 13:04:46,856 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] Object getAssociatedObject() 2006-11-30 13:04:46,856 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@df88d2 closing=fi.logiasoftware.jca.adapter.GenericResourceImpl@1e5052b impl.associatedObject=fi.logiasoftware.jca.adapter.GenericManagedConnection@df88d2 2006-11-30 13:04:46,856 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] connectionClosed(ConnectionEvent) 2006-11-30 13:04:46,856 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] notifyConnectionEvent(ConnectionEvent) 2006-11-30 13:04:46,856 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] CONNECTION CLOSED 2006-11-30 13:04:46,856 TRACE [org.jboss.resource.connectionmanager.CachedConnectionManager] unregistering connection from org.jboss.resource.connectionmanager.NoTxConnectionManager@b65a68, object: fi.logiasoftware.jca.adapter.GenericResourceImpl@1e5052b, key: null 2006-11-30 13:04:46,856 TRACE [org.jboss.resource.connectionmanager.NoTxConnectionManager] unregisterConnection: 0 handles left 2006-11-30 13:04:46,856 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] putting ManagedConnection back into pool kill=false cl=org.jboss.resource.connectionmanager.NoTxConnectionManager$NoTxConnectionEventListener@b41541[state=NORMAL mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@df88d2 handles=0 lastUse=1164884576437 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@18faa02 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@e26d2e] 2006-11-30 13:04:46,856 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] cleanup() 2006-11-30 13:04:46,856 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] invalidate() 2006-11-30 13:04:46,856 DEBUG [fi.logiasoftware.jca.adapter.GenericResourceImpl] setValid(boolean) 2006-11-30 13:04:46,856 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Returning connection to pool org.jboss.resource.connectionmanager.NoTxConnectionManager$NoTxConnectionEventListener@b41541[state=NORMAL mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@df88d2 handles=0 lastUse=1164884686856 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@18faa02 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@e26d2e] [InUse/Available/Max]: [0/20/20] 2006-11-30 13:04:46,856 TRACE [org.jboss.tm.TransactionImpl] Committing, tx=TransactionImpl:XidImpl[FormatId=257, GlobalId=ws-sam/14, BranchQual=, localId=14], status=STATUS_ACTIVE 2006-11-30 13:04:46,856 TRACE [org.jboss.tm.TransactionImpl] Before completion done, tx=TransactionImpl:XidImpl[FormatId=257, GlobalId=ws-sam/14, BranchQual=, localId=14], status=STATUS_ACTIVE 2006-11-30 13:04:46,856 TRACE [org.jboss.tm.TransactionImpl] Zero phase commit TransactionImpl:XidImpl[FormatId=257, GlobalId=ws-sam/14, BranchQual=, localId=14]: No resources. 2006-11-30 13:04:46,856 TRACE [org.jboss.tm.TransactionImpl] Committed OK, tx=TransactionImpl:XidImpl[FormatId=257, GlobalId=ws-sam/14, BranchQual=, localId=14] 2006-11-30 13:04:46,856 TRACE [org.jboss.tm.TxManager] commited tx: TransactionImpl:XidImpl[FormatId=257, GlobalId=ws-sam/14, BranchQual=, localId=14] 2006-11-30 13:04:46,856 TRACE [org.jboss.tm.TxManager] tx timeout is now: 300s 2006-11-30 13:04:46,935 DEBUG [org.jboss.remoting.transport.socket.ServerThread] begin thread wait 2006-11-30 13:10:26,348 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000 2006-11-30 13:17:56,345 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000 2006-11-30 13:25:26,353 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000 2006-11-30 13:25:26,353 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Destroying timedout connection org.jboss.resource.connectionmanager.NoTxConnectionManager$NoTxConnectionEventListener@187a8e0[state=NORMAL mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@1602bbc handles=0 lastUse=1164884666841 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@18faa02 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@e26d2e] 2006-11-30 13:25:26,353 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] destroy() 2006-11-30 13:25:26,353 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] closing fi.logiasoftware.jca.handlers.FTPProtocolHandler@d79c75 for fi.logiasoftware.jca.adapter.GenericManagedConnection@1602bbc 2006-11-30 13:25:26,353 DEBUG [fi.logiasoftware.jca.handlers.FTPProtocolHandler] disconnect() 2006-11-30 13:25:26,353 DEBUG [fi.logiasoftware.jca.handlers.FTPProtocolHandler] boolean isConnected() 2006-11-30 13:25:26,353 INFO [fi.logiasoftware.jca.handlers.FTPProtocolHandler] this.isConnected?? : true 2006-11-30 13:25:26,353 INFO [STDOUT] Disconnect connected : true 2006-11-30 13:25:26,353 DEBUG [fi.logiasoftware.jca.handlers.FTPProtocolHandler] Disconnecting from FTP server: wbs.software.logia.fi 21 2006-11-30 13:25:26,353 WARN [fi.logiasoftware.jca.handlers.FTPProtocolHandler] IOException while disconnecting from FTP server: wbs.software.logia.fi 21 Reason : Software caused connection abort: recv failed 2006-11-30 13:25:26,353 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Destroying timedout connection org.jboss.resource.connectionmanager.NoTxConnectionManager$NoTxConnectionEventListener@b41541[state=NORMAL mc=fi.logiasoftware.jca.adapter.GenericManagedConnection@df88d2 handles=0 lastUse=1164884686856 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@18faa02 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@e26d2e] 2006-11-30 13:25:26,353 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] destroy() 2006-11-30 13:25:26,353 DEBUG [fi.logiasoftware.jca.adapter.GenericManagedConnection] closing fi.logiasoftware.jca.handlers.FTPProtocolHandler@160e8a2 for fi.logiasoftware.jca.adapter.GenericManagedConnection@df88d2 2006-11-30 13:25:26,353 DEBUG [fi.logiasoftware.jca.handlers.FTPProtocolHandler] disconnect() 2006-11-30 13:25:26,353 DEBUG [fi.logiasoftware.jca.handlers.FTPProtocolHandler] boolean isConnected() 2006-11-30 13:25:26,353 INFO [fi.logiasoftware.jca.handlers.FTPProtocolHandler] this.isConnected?? : true 2006-11-30 13:25:26,353 INFO [STDOUT] Disconnect connected : true 2006-11-30 13:25:26,353 DEBUG [fi.logiasoftware.jca.handlers.FTPProtocolHandler] Disconnecting from FTP server: wbs.software.logia.fi 21 2006-11-30 13:25:26,353 WARN [fi.logiasoftware.jca.handlers.FTPProtocolHandler] IOException while disconnecting from FTP server: wbs.software.logia.fi 21 Reason : Software caused connection abort: recv failed
Thanks!
Br,
Sami Männistö