I have posted a small part of a log below from which I would really appreciate if someone can decode the following:
- List item
- Managed Threads
- Active Threads
- Active Tasks
- Pending Tasks
- Pool thread stack traces
I have the following C3PO configuration:
JavaScript
x
c3p0.minPoolSize=10c3p0.maxPoolSize=40c3p0.acquireIncrement=5c3p0.maxIdleTime=1800c3p0.maxStatements=50c3p0.idleConnectionTestPeriod=180This is the Log:
JavaScript
09-02@12:28:43 WARN ThreadPoolAsynchronousRunner [Timer-0] - com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@700ec336 -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!09-02@12:28:43 WARN ThreadPoolAsynchronousRunner [Timer-0] - com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@700ec336 -- APPARENT DEADLOCK!!! Complete Status: Managed Threads: 3 Active Threads: 3 Active Tasks: com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@34ac7f2c (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1) com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@28d13cb8 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0) com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@40e968f7 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2) Pending Tasks: com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@1bea516c com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@348797c5 com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@31fd2174 com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@619f604f com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@266c149b com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@1bcdfd2 com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@170a54e2 com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@274acd3f com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@1fe8f740 com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@77c09b1d com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@607ca57 com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@697518d8 com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@6b242ff com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@214c76c8 com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@230a558c com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@7b766c4c com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@1bc030e7 com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@66ca9bec com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@7fc2d7ac com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@50dd9ebb com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@5e03077 com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@418dd7a4 com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@4748719b com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@651a9bac com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@35e26d0f com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@24660f6c com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@287e8e1f com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@ca4a9fe com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@e94692e com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@3185527c com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@27ea644a com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@d5e4abf com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@297d4874 com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@601fccf3 com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@47c896d2 com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@4225d9cf com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@42fec6f6 com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@64b862d6 com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@5610343 com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@241d2677 com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@75c86126 com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@36624233 com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@6ce83e29 com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@3492d9b com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@39511ccc com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@7c39b279 com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@2ff465a6 com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@563d8de2 com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@632e1ca9 com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@685bce1d com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@63390771 com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@3517be9bPool thread stack traces: Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0,5,main] com.mysql.jdbc.StatementImpl.close(StatementImpl.java:575) 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-#2,5,main] com.mysql.jdbc.StatementImpl.close(StatementImpl.java:575) 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] com.mysql.jdbc.StatementImpl.close(StatementImpl.java:575) 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)Some information on the apparent deadlock would be appreciated.
Advertisement
Answer
The thread pool contains 3 threads. (“Managed Threads”). All 3 of them are “active”, trying to complete a task. (“Active Threads”), there are no dormant threads ready to take on work. The tasks are listed. They are all cached-statement close tasks.
An APPARENT DEADLOCK is triggered when all tasks in thread pool have remained the same for a long period of time. c3p0 (the thread pool library beneath it really) eventually assumes, if no task has managed to complete in the pool, that the pool is deadlocked. The library interrupt()s and then discards those Threads, and replaces them with new ones so that other tasks (you have a long task backlog, “Pending Tasks”) can try to run.
In your case, the issue is a well-known one. Some JDBC drivers’ Statement.close() operation may deadlock if their parent Connection is in use. For these (formally out-of-spec) drivers, c3p0 implements a cautious Statement close strategy, in which Statement destruction is tasked asynchronously and only performed when the parent Connection is known not to be in use.
TL; DR: set statementCacheNumDeferredCloseThreads to one.
JavaScript
c3p0.statementCacheNumDeferredCloseThreads=1