Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

C3P0 apparent deadlock when the threads are all empty?

I'm using C3P0 as a connection pool in Tomcat, and I'm seeing very worrying errors:

2010-09-16 13:25:00,160 [Timer-0] WARN  com.mchange.v2.async.ThreadPoolAsynchronousRunner  - com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@43502400 -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks! 2010-09-16 13:25:01,407 [Timer-0] WARN  com.mchange.v2.async.ThreadPoolAsynchronousRunner  - com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@43502400 -- APPARENT DEADLOCK!!! Complete Status:   Managed Threads: 10   Active Threads: 0   Active Tasks:   Pending Tasks:     com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@6e4151a7   Pool thread stack traces:   Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#6,5,main]     java.lang.Object.wait(Native Method)     com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:534)   Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2,5,main]     java.lang.Object.wait(Native Method)     com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:534)   Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1,5,main]     java.lang.Object.wait(Native Method)     com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:534)   Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0,5,main]     java.lang.Object.wait(Native Method)     com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:534)   Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#5,5,main]     java.lang.Object.wait(Native Method)     com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:534)   Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#4,5,main]     java.lang.Object.wait(Native Method)  ... many more, exact same stack trace 

Line 534 is:

 while (true) {    Runnable myTask;    synchronized ( ThreadPoolAsynchronousRunner.this ) {      while ( !should_stop && pendingTasks.size() == 0 )        ThreadPoolAsynchronousRunner.this.wait( POLL_FOR_STOP_INTERVAL ); // <- here      if (should_stop) ... 

It looks very much like all the threads are idle. They're waiting for work. 0 active threads, and only 1 task to complete. Any clues on what's going wrong?

Here's the configuration:

ds.setUser(userName); ds.setPassword(password); ds.setMaxPoolSize(16); ds.setMaxConnectionAge(1800); ds.setAcquireRetryAttempts(4); ds.setMaxIdleTime(900); ds.setNumHelperThreads(10); ds.setCheckoutTimeout(1000); 
like image 592
Steven Schlansker Avatar asked Sep 16 '10 21:09

Steven Schlansker


1 Answers

I just experienced a similar issue against an Oracle database, but in my case Managed Thread and Active Thread counts were the same.

    Managed Threads: 3     Active Threads: 3 

For me it was actually an authentication error but appeared as the APPARENT DEADLOCK error because of the way I was doing login auditing.

    2013-08-12 11:29:04,910 [Timer-4] WARN  com.mchange.v2.async.ThreadPoolAsynchronousRunner: com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@34996454 -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!     2013-08-12 11:29:04,914 [Timer-4] WARN  com.mchange.v2.async.ThreadPoolAsynchronousRunner: com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@34996454 -- APPARENT DEADLOCK!!! Complete Status:              Managed Threads: 3             Active Threads: 3             Active Tasks:                      com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@6730b844 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2)                     com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@2f91ad49 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0)                     com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@507ac05 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1)             Pending Tasks:                      com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@3aae7ed7     Pool thread stack traces:             Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2,5,main]                     java.net.SocketInputStream.socketRead0(Native Method)                     java.net.SocketInputStream.read(SocketInputStream.java:150)                     java.net.SocketInputStream.read(SocketInputStream.java:121)                     oracle.net.ns.Packet.receive(Packet.java:300)                     oracle.net.ns.DataPacket.receive(DataPacket.java:106)                     oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:315)                     oracle.net.ns.NetInputStream.read(NetInputStream.java:260)                     oracle.net.ns.NetInputStream.read(NetInputStream.java:185)                     oracle.net.ns.NetInputStream.read(NetInputStream.java:102)                     oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:124)                     oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:80)                     oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1137)                     oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:290)                     oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:192)                     oracle.jdbc.driver.T4CTTIoauthenticate.doOAUTH(T4CTTIoauthenticate.java:380)                     oracle.jdbc.driver.T4CTTIoauthenticate.doOAUTH(T4CTTIoauthenticate.java:760)                     oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:401)                     oracle.jdbc.driver.PhysicalConnection.<init>(PhysicalConnection.java:546)                     oracle.jdbc.driver.T4CConnection.<init>(T4CConnection.java:236)                     oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:32)                     oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:521)                     com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:134)                     com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:182)                     com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:171)                     com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:137)                     com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1014)                     com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32)                     com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1810)                     com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)             Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0,5,main]                     java.net.SocketInputStream.socketRead0(Native Method)                     java.net.SocketInputStream.read(SocketInputStream.java:150)                     java.net.SocketInputStream.read(SocketInputStream.java:121)                     oracle.net.ns.Packet.receive(Packet.java:300)                     oracle.net.ns.DataPacket.receive(DataPacket.java:106)                     oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:315)                     oracle.net.ns.NetInputStream.read(NetInputStream.java:260)                     oracle.net.ns.NetInputStream.read(NetInputStream.java:185)                     oracle.net.ns.NetInputStream.read(NetInputStream.java:102)                     oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:124)                     oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:80)                     oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1137)                     oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:290)                     oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:192)                     oracle.jdbc.driver.T4CTTIoauthenticate.doOAUTH(T4CTTIoauthenticate.java:380)                     oracle.jdbc.driver.T4CTTIoauthenticate.doOAUTH(T4CTTIoauthenticate.java:760)                     oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:401)                     oracle.jdbc.driver.PhysicalConnection.<init>(PhysicalConnection.java:546)                     oracle.jdbc.driver.T4CConnection.<init>(T4CConnection.java:236)                     oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:32)                     oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:521)                     com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:134)                     com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:182)                     com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:171)                     com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:137)                     com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1014)                     com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32)                     com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1810)                     com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)             Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1,5,main]                     java.net.SocketInputStream.socketRead0(Native Method)                     java.net.SocketInputStream.read(SocketInputStream.java:150)                     java.net.SocketInputStream.read(SocketInputStream.java:121)                     oracle.net.ns.Packet.receive(Packet.java:300)                     oracle.net.ns.DataPacket.receive(DataPacket.java:106)                     oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:315)                     oracle.net.ns.NetInputStream.read(NetInputStream.java:260)                     oracle.net.ns.NetInputStream.read(NetInputStream.java:185)                     oracle.net.ns.NetInputStream.read(NetInputStream.java:102)                     oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:124)                     oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:80)                     oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1137)                     oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:290)                     oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:192)                     oracle.jdbc.driver.T4CTTIoauthenticate.doOAUTH(T4CTTIoauthenticate.java:380)                     oracle.jdbc.driver.T4CTTIoauthenticate.doOAUTH(T4CTTIoauthenticate.java:760)                     oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:401)                     oracle.jdbc.driver.PhysicalConnection.<init>(PhysicalConnection.java:546)                     oracle.jdbc.driver.T4CConnection.<init>(T4CConnection.java:236)                     oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:32)                     oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:521)                     com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:134)                     com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:182)                     com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:171)                     com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:137)                     com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1014)                     com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32)                     com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1810)                     com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547) 
like image 148
eebbesen Avatar answered Oct 05 '22 16:10

eebbesen