Hello

Using Hibernate 3.2.1 / c3p0 0.9.1-pre9 we're getting occasional APPARENT DEADLOCK messages :

What does that exactly mean ?

2007-06-27 17:37:18,861 [Timer-1] WARN com.mchange.v2.async.ThreadPoolAsynchronousRunner - com.mchange.v2.async.ThreadPoolAsynchronousRunner$Deadl
ockDetector@323993b6 -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!
2007-06-27 17:37:18,876 [Timer-1] WARN com.mchange.v2.async.ThreadPoolAsynchronousRunner - com.mchange.v2.async.ThreadPoolAsynchronousRunner$Deadl
ockDetector@323993b6 -- APPARENT DEADLOCK!!! Complete Status:
Managed Threads: 3
Active Threads: 3
Active Tasks:
com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@4227a2f6 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolTh
read-#2)
com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@383be668 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolTh
read-#0)
com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@6493d2af (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolTh
read-#1)
Pending Tasks:
com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@24ed12bf
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@4869cc89
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@19f35b83
com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@37fd02c4
Pool thread stack traces:
Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2,5,main]
oracle.jdbc.driver.OracleStatement.close(OracleStatement.java:1340)
com.mchange.v1.db.sql.StatementUtils.attemptClose(StatementUtils.java:41)
com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask.run(GooGooStatementCache.java:404)
com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)
Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0,5,main]
oracle.jdbc.driver.OracleStatement.close(OracleStatement.java:1340)
com.mchange.v1.db.sql.StatementUtils.attemptClose(StatementUtils.java:41)
com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask.run(GooGooStatementCache.java:404)
com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)
Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1,5,main]
oracle.jdbc.driver.OracleStatement.close(OracleStatement.java:1340)
com.mchange.v1.db.sql.StatementUtils.attemptClose(StatementUtils.java:41)
com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask.run(GooGooStatementCache.java:404)
com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)


....


2007-06-27 17:38:18,909 [Timer-1] WARN com.mchange.v2.async.ThreadPoolAsynchronousRunner - Task com.mchange.v2.c3p0.stmt.GooGooStatementCache$1Sta
tementCloseTask@4227a2f6 (in deadlocked PoolThread) failed to complete in maximum time 60000ms. Trying interrupt().
2007-06-27 17:38:18,909 [Timer-1] WARN com.mchange.v2.async.ThreadPoolAsynchronousRunner - Task com.mchange.v2.c3p0.stmt.GooGooStatementCache$1Sta
tementCloseTask@383be668 (in deadlocked PoolThread) failed to complete in maximum time 60000ms. Trying interrupt().
2007-06-27 17:38:18,909 [Timer-1] WARN com.mchange.v2.async.ThreadPoolAsynchronousRunner - Task com.mchange.v2.c3p0.stmt.GooGooStatementCache$1Sta
tementCloseTask@6493d2af (in deadlocked PoolThread) failed to complete in maximum time 60000ms. Trying interrupt().
2007-06-27 17:38:28,918 [Timer-1] WARN com.mchange.v2.async.ThreadPoolAsynchronousRunner - com.mchange.v2.async.ThreadPoolAsynchronousRunner$Deadl
ockDetector@323993b6 -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!
2007-06-27 17:38:28,926 [Timer-1] WARN com.mchange.v2.async.ThreadPoolAsynchronousRunner - com.mchange.v2.async.ThreadPoolAsynchronousRunner$Deadl
ockDetector@323993b6 -- APPARENT DEADLOCK!!! Complete Status:
Managed Threads: 3
Active Threads: 3




Thanks for your insights

Alain

You can find information about this here:

http://www.mchange.com/projects/c3p0/in ... perThreads
http://www.mchange.com/projects/c3p0/in ... veTaskTime

Usually its a slow or hanging database server.

Hello,

I had or I'm having the same problem. But I've just noticed that I'm using an mysql 3.x jdbc driver with an 5.x mysql database :-) . So I guess that's my problem. I'm testing this now.

I think this kind of error is mostly something like:
- DB problems
- connection problems
- bad drivers,
-.....

Not somethings to look for in your java code

best regards,
Christof

ps: don't forget to rate

Hi Ids
I have similar deadlocks :(
See my post here with detailed description:
http://forum.hibernate.org/viewtopic.php?p=2386237

btw:
Have you found a solution or a reson of this deadlocks?

Regards!
Adam

Ok I am using c3p0-0.9.1.2.jar. Previously I am also having APPARENT DEADLOCK messages every now and then.

For my case, besides this deadlock, I also encountered a memory leak in my application.

So therefore, I do a heap dump and analyze my memory usage. In the memory analysis, PreparedStatement were occupying large part of my memory usage.

After some trial and error, I had finally found out if you set maxStatementsPerConnection to be less than the number of PreparedStatement opened during a lifetime of a connection, the PreparedStatement will be cached indefinitely, causing a memory leak and then in turn the APPARENT DEADLOCK.

For example,

conn = connPool.getConnection()

p1 = conn.preparedStatement();
p2 = conn.preparedStatement();

conn.close()


if connPool maxStatementsPerConnection is 1, then the memory leak will occur. To resolve, set it to greater or equal to 2

Hi notorand

Many thanks for you reply.
I will definitely try to run your scenario and I will try to recreate this issue (APPARENT DEADLOCK).

btw:
Your application which you use to recreate this problem was single-threaded or multithreaded?

btw II:
Which database have you use to recreate this error?

Kind regards,
Adam Woźniak

We were able to solve our application's APPARENT DEADLOCK problems by analyzing stack traces. A good idea is to set up a script to trigger stack trace dumping when APPARENT DEADLOCK appears in the log file.

There's a nasty mechanism where a single long-running Oracle query can block other c3p0-managed connections from preparing statements.

A single long-running query will hold the synchronization lock on the OracleConnection it is using.

If OracleStatements have to be evicted from the c3p0 statement cache a c3p0 background thread will try to call OracleStatement.close. OracleStatement holds a reference to the original statement it was created with and will try to obtain lock on it. This will block, if the long running query is using the same connection.

If there's a lot of churn on the statement cache this will happen more often and once in a while all the c3p0 background threads may be blocked by this mechanism.

C3P0 uses background threads to prepare statements (see http://www.java2s.com/Open-Source/Java- ... e.java.htm line 540).

When all the background threads are stuck waiting for access to the single connection no statements will be prepared and all Hibernate operatations will be blocked like so: