C3P0 apparent deadlock when the threads are all empty?
Asked Answered
D

11

30

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);
Dade answered 16/9, 2010 at 21:9 Comment(2)
were you able to resolve your issue? (I know it's been a very long time)Stoop
@Ittai: no, but it eventually went away. No clue what exactly fixed it :-(Dade
P
16

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)
Planography answered 12/8, 2013 at 16:58 Comment(5)
What a kicker! I was getting this error after some major architectural changes and so I thought I'd screwed it. Where the real reason was related to your answer - because I couldn't get through the firewall to the database server!Cessation
Had the same issue now. Again because of the firewall rule. @Cessation thanks for the lead.Carolyn
100% spot on for me, aws security group.Stinkpot
@Cessation - you should post your comment as an answer - you saved me hours of not so fun debugging - thanks!Hickox
@Cessation I am facing the same issue .Once the issue is logged , it keeps on getting logged continously , the application response gets unpredictable .We are on aws , what corrective steps can be taken in this scenariosFoote
N
8

This sounds like you have already acquired a connection from the pool and do not return it in time.

C3P0 determines "apparent deadlocks" when a connection is acquired but not returned to the pool within the deadlock detection timeout.

If you move the connection acquisition closer to the "action" and immediately return it to the pool after the database work is done, this message will disappear.

Neurology answered 16/9, 2010 at 23:21 Comment(7)
The documentation says that setMaxAdministrativeTime defaults to 0 (i.e. forever). Additionally, why should I have to return a connection to a pool in any fixed time limit? I've checked it out; it ought to be mine for as long as I need it... and even if not, that's not a deadlock!Dade
You are right, that's why the WARNING says APPARENT deadlock. And by the way, you use a connection pool so you do not need to keep the connection while you do not use itNeurology
Sure, but the place in question could be in a long-running transaction; during which you cannot release it.Dade
That should not cause the problem, in my experience C3P0 checks whether the connection is actively used. I'm not used to using C3P0 directly, I use it with Hibernate - but in this scenario, long transactions are never a problem, but idling connections cause the warning you are receiving.Neurology
Just saw your edit to the question. The timeout you hit is set by "ds.setMaxIdleTime(900)"Neurology
@Thomas Weber: The documentation says: "maxIdleTime: Seconds a Connection can remain pooled but unused before being discarded." Therefore it shouldn't affect this at all?Dade
Hi Steven, my mistake - should have read. Just to understand your problem a little better: when are you getting these messages? Right after startup or after the application has been running for some hours? Do you use "idleConnectionTestPeriod" to check whether any of the pooled connections have been dropped by the database server?Neurology
A
4

This will sort out your problem

ds.setMaxStatements(1000);
ds.setMaxStatementsPerConnection(100); (the maximum number of prepared statments your system can execute on a single connection)

check out : https://forum.hibernate.org/viewtopic.php?t=947246&highlight=apparent+deadlock+c3p0

Remember to close your statements after you are done with them !!

Autochthonous answered 31/3, 2011 at 9:10 Comment(0)
C
4

My comment on answer https://mcmap.net/q/476744/-c3p0-apparent-deadlock-when-the-threads-are-all-empty received enough up-votes to suggest it should be an answer.

I received this error because I couldn't get through the firewall to the database server. Check to see if that is your problem.

Cessation answered 14/8, 2018 at 1:59 Comment(0)
S
1

@eebbesen, I got the same error as you did. I am running Tomcat version 9.0.6. I have hibernate core ver 5.2.10, hibernate c3p0 ver 3.6.3 in my maven project. Mine was not an authentication error, but rather due to me having previously changed the name of my computer. This did not have an immediate effect on tomcat, but upon a restart of my machine, when I tried to bring up tomcat again via eclipse (Oxygen 2), I could no longer start eclipse due exactly to the issue you raised.

I googled this and I found this link, which tipped me off to the issue:

https://community.oracle.com/thread/339825

where it says:

First see if OracleServiceXE and OracleXETNSListener services are running. Replace 127.0.0.1 in the url, with the IP or the name of your machine. It must match the host declared in the tnsnames.ora file.

Later it mentions where to find this tnsnames.ora file, and for me it was here:

C:\oraclexe\app\oracle\product\11.2.0\server\network\ADMIN

Looking at this tnsnames.ora file, I saw this:

XE =
  (DESCRIPTION =
    (ADDRESS = (PROTOCOL = TCP)(HOST = MyMachineName-7)(PORT = 1521))
    (CONNECT_DATA =
      (SERVER = DEDICATED)
      (SERVICE_NAME = XE)
    )
  )

But I had recently renamed my machine to MyMachineName-5. I changed the 7 to a 5 and saved the file. I checked the "listener.ora" file in this directory, and it had the same issue:

LISTENER =
  (DESCRIPTION_LIST =
    (DESCRIPTION =
      (ADDRESS = (PROTOCOL = IPC)(KEY = EXTPROC1))
      (ADDRESS = (PROTOCOL = TCP)(HOST = MyMachineName-7)(PORT = 1521))
    )
  )

I changed the 7 to a 5 and saved the file.

Then I opened Task Manager, clicked the "Services" tab, and looked at the "Oracle" services. I did a restart on: OracleXETNSListener, OracleXEClrAgent, OracleServiceXE. I went to restart tomcat in eclipse again, and this time there was now problem.

Appendix:

I also googled this:

https://community.oracle.com/thread/2267906

This lead me to try:

1) Turned off the firewall in Windows Defender (already turned off mcaffee firewall)

2) Started sqlplus to make sure that I could log in with the credentials I was using in my hibernate file: hibernate.cfg.xml

C:\oraclexe\app\oracle\product\11.2.0\server\bin\sqlplus.exe

3) Started the desktop shortcut to Oracle Database 11g

This failed for me even after I fixed the machine name issue though, something I still have to look into.

4) Using dbVisualizer, I tried making a connection to Oracle. This only worked after I resolved the .ora file machine name issue: double click the connection and click the "ping server" button.

Scuppernong answered 30/9, 2018 at 16:7 Comment(0)
F
0

I had the same (was unable to detect) problem solved by correctly closing Statement and Resultset instances (somehow left unclosed):

String SQL = "SELECT 1";
try {
    con = DriverManager.getConnection(host, userName, userPassword);
    stmt = con.prepareStatement(SQL, ResultSet.TYPE_SCROLL_INSENSITIVE, ResultSet.CONCUR_UPDATABLE);
    try {
        rs = stmt.executeQuery(SQL);
        try {
            rs.next();
            // ...
        } finally {
            rs.close();
        }
    } finally {
        stmt.close();
    }
} catch (SQLException ex) {
    Logger.getLogger(MyClass.class.getName()).log(Level.SEVERE, null, ex);
}
Felizio answered 8/5, 2013 at 16:22 Comment(0)
S
0

I've had the same problem but the cause was a bit hard to spot as it was caused by some simultaneous resources trying to acquire a connection at the same time.

As you can read if the pool had not been initialized the code provided to init it by calling a setup function.

public Connection getConnection() throws SQLException {
    if (mCPDS == null) {
        setupPool();
    }

    return mCPDS.getConnection();
}

The problem was that many resources were trying to acquire the connection at the beginning of the program so more than one were instantiating the pool causing your problem after a while.

The solution was just to declare the method synchronized to keep out other resources while one has called the method and it's still inside instantiating the pool for instance.

public synchronized Connection getConnection() throws SQLException {
    if (mCPDS == null) {
        setupPool();
    }

    return mCPDS.getConnection();
}

This may be a design error for not using a singleton but fixes the problem lacking some performance.

Scevo answered 28/10, 2015 at 17:10 Comment(0)
K
0

We ran into this problem and solved it by adding this to the C3P0 config:

<property name="statementCacheNumDeferredCloseThreads" value="1"/>

as per: this from the C3P0 doc

Kermie answered 3/3, 2016 at 17:46 Comment(0)
E
0

Hi my friend just to comment, I had the same case. I just configured my spring-hibernate eclipse project and showed up the same exception, it should be noted that my project still does not have any query.

I resolved that issue with below steps:

1) Clean project : Project--> Clean... 2) Build project : Project--> Build Project

I hope it works for you.

Ervinervine answered 26/2, 2018 at 4:34 Comment(0)
W
0

I've just had the same problem suddenly: after noticing that the deadlock was present only when launching my application in debug mode (I'm using IntelliJ) and it was fine when running with normal run, I started to dig it.

I finally figured out that a breakpoint was blocking the connection: I don't know why Intellij didn't "listen" that the application was passing through that breakpoint, but was hanged somewhere cause of a breakpoint, and this was causing appartent deadlock

After removing all breakpoints in my project, everything started smooth again.

Hope this helps someone

Wadley answered 20/9, 2018 at 7:34 Comment(0)
A
-1

Similar problem was encountered on glassfish4 server while deploying the application. Turned out it was a database configuration issue. Just make sure your database connectivity configurations are proper, verify that the hostname provided in the configuration allows the connection to database. Try connecting to the database manually with the configured username and the hostname/domain. If required, allow the db user to connect from the required domain. Rebuild the application with correct db configurations and then deploy it.

Atul answered 1/4, 2017 at 6:44 Comment(0)

© 2022 - 2024 — McMap. All rights reserved.