[jira] [Created] (IO-647) Race condition in the GenericObjectPool in removeAbandoned functionality

["Daniel Dudzika (Jira)" <ji...@apache.org>]

Daniel Dudzika created IO-647:
---------------------------------

             Summary: Race condition in the GenericObjectPool in removeAbandoned functionality
                 Key: IO-647
                 URL: https://issues.apache.org/jira/browse/IO-647
             Project: Commons IO
          Issue Type: Bug
    Affects Versions: 2.1
            Reporter: Daniel Dudzika


Hello,

today I found out a potential issue around GenericObjectPool and removing "abandoned" objects functionality. 
During the accident one of our customers faced with database outage. 
After this our product become unreachable.  This state was caused by two threads.
1st "survived" the outage and still possessing the connection it operates on the database,
2nd one was forced to remove "abandoned" objects. 
This situation cause that 2nd thread was waiting for 1st one until this 1st thread end his database operation. 
More context can be found in the stack traces attached below.
{code:java}
"1st thread" #434 daemon prio=5 os_prio=0 tid=0x00007f9e7746f000 nid=0x9680 runnable [0x00007f9d29c70000]"1st thread" #434 daemon prio=5 os_prio=0 tid=0x00007f9e7746f000 nid=0x9680 runnable [0x00007f9d29c70000]   java.lang.Thread.State: RUNNABLE at sun.nio.ch.FileDispatcherImpl.read0(Native Method) at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39) at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223) at sun.nio.ch.IOUtil.read(IOUtil.java:197) at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:380) - locked <0x00007fa23958bc48> (a java.lang.Object) at oracle.net.nt.TimeoutSocketChannel.read(TimeoutSocketChannel.java:144) at oracle.net.ns.NIOHeader.readHeaderBuffer(NIOHeader.java:82) at oracle.net.ns.NIOPacket.readFromSocketChannel(NIOPacket.java:139) at oracle.net.ns.NIOPacket.readFromSocketChannel(NIOPacket.java:101) at oracle.net.ns.NIONSDataChannel.readDataFromSocketChannel(NIONSDataChannel.java:80) at oracle.jdbc.driver.T4CMAREngineNIO.prepareForReading(T4CMAREngineNIO.java:102) at oracle.jdbc.driver.T4CMAREngineNIO.getNBytes(T4CMAREngineNIO.java:679) at oracle.jdbc.driver.T4CMAREngineNIO.unmarshalNBytes(T4CMAREngineNIO.java:651) at oracle.jdbc.driver.DynamicByteArray.unmarshalBuffer(DynamicByteArray.java:334) at oracle.jdbc.driver.DynamicByteArray.unmarshalCLR(DynamicByteArray.java:226) at oracle.jdbc.driver.T4CNumberAccessor.unmarshalBytes(T4CNumberAccessor.java:191) at oracle.jdbc.driver.T4CNumberAccessor.unmarshalOneRow(T4CNumberAccessor.java:173) at oracle.jdbc.driver.T4CTTIrxd.unmarshal(T4CTTIrxd.java:1526) at oracle.jdbc.driver.T4CTTIrxd.unmarshal(T4CTTIrxd.java:1289) at oracle.jdbc.driver.T4C8Oall.readRXD(T4C8Oall.java:850) at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:543) at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:252) at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:612) at oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:226) at oracle.jdbc.driver.T4CPreparedStatement.fetch(T4CPreparedStatement.java:1023) at oracle.jdbc.driver.OracleStatement.fetchMoreRows(OracleStatement.java:3353) at oracle.jdbc.driver.InsensitiveScrollableResultSet.fetchMoreRows(InsensitiveScrollableResultSet.java:736) at oracle.jdbc.driver.InsensitiveScrollableResultSet.absoluteInternal(InsensitiveScrollableResultSet.java:692) at oracle.jdbc.driver.InsensitiveScrollableResultSet.next(InsensitiveScrollableResultSet.java:406) - locked <0x00007fa23958e580> (a oracle.jdbc.driver.T4CConnection) at org.apache.commons.dbcp2.DelegatingResultSet.next(DelegatingResultSet.java:191) at org.apache.commons.dbcp2.DelegatingResultSet.next(DelegatingResultSet.java:191)
{code}
{code:java}
"2nd thread" #376448 daemon prio=5 os_prio=0 tid=0x00007f9e581db000 nid=0x1239 waiting for monitor entry [0x00007f9a75ff2000]"2nd thread" #376448 daemon prio=5 os_prio=0 tid=0x00007f9e581db000 nid=0x1239 waiting for monitor entry [0x00007f9a75ff2000]   java.lang.Thread.State: BLOCKED (on object monitor) at oracle.jdbc.driver.InsensitiveScrollableResultSet.close(InsensitiveScrollableResultSet.java:190) - waiting to lock <0x00007fa23958e580> (a oracle.jdbc.driver.T4CConnection) at org.apache.commons.dbcp2.DelegatingResultSet.close(DelegatingResultSet.java:170) at org.apache.commons.dbcp2.DelegatingStatement.close(DelegatingStatement.java:150) at org.apache.commons.dbcp2.DelegatingConnection.passivate(DelegatingConnection.java:631) at org.apache.commons.dbcp2.PoolableConnection.passivate(PoolableConnection.java:127) at org.apache.commons.dbcp2.DelegatingConnection.closeInternal(DelegatingConnection.java:232) at org.apache.commons.dbcp2.PoolableConnection.reallyClose(PoolableConnection.java:243) at org.apache.commons.dbcp2.PoolableConnectionFactory.destroyObject(PoolableConnectionFactory.java:334) at org.apache.commons.pool2.impl.GenericObjectPool.destroy(GenericObjectPool.java:890) at org.apache.commons.pool2.impl.GenericObjectPool.invalidateObject(GenericObjectPool.java:649) - locked <0x00007fa2651f85f8> (a org.apache.commons.pool2.impl.DefaultPooledObject) at org.apache.commons.pool2.impl.GenericObjectPool.removeAbandoned(GenericObjectPool.java:1022) at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:418) at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:363) at org.apache.commons.dbcp2.PoolingDataSource.getConnection(PoolingDataSource.java:134) at org.apache.commons.dbcp2.BasicDataSource.getConnection(BasicDataSource.java:1533)
{code}
Cheers,
Daniel Dudziak
Atlassian Developer



--
This message was sent by Atlassian Jira
(v8.3.4#803005)