Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

APPARENT DEADLOCK Creating emergency threads for unassigned pending tasks

I am using mysql with mybatis and I am greeting this error on our live server

com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@6538f8f2 
-- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!

I don't understand why this error is coming is this because of my C3P0 setting? My C3P0 settings are like this

----start Updated-----

below is my spring-servlet.xml configuration

I updated datasource bean as

<bean id="datasource" class="com.mchange.v2.c3p0.ComboPooledDataSource"
destroy-method="close" p:driverClass="com.mysql.jdbc.Driver"
p:jdbcUrl="jdbc:mysql://localhost/jdb" p:user="root" p:password="root" 
p:acquireIncrement="10" 
p:idleConnectionTestPeriod="60"
p:maxPoolSize="100" 
    p:maxStatements="0" 
    p:minPoolSize="10" 
    p:initialPoolSize="10"
    p:statementCacheNumDeferredCloseThreads="1" />
   <!-- Declare a transaction manager -->

<bean id="transactionManager"
class="org.springframework.jdbc.datasource.DataSourceTransactionManager"
p:dataSource-ref="datasource" />


<bean id="sqlSessionFactory" class="org.mybatis.spring.SqlSessionFactoryBean">
    <property name="dataSource" ref="datasource" />
</bean>

<!-- scan for mappers and will automatically scan the whole classpath for xmls -->
<bean class="org.mybatis.spring.mapper.MapperScannerConfigurer">
    <property name="sqlSessionFactory" ref="sqlSessionFactory" />
    <property name="basePackage" value="com.mycom.myproject.db.mybatis.dao" />
</bean>  

and from my Dao class I call mapper method like

 myDao.updateRecords()

This is my service class method

@Override
public List<UserDetailedBean> selectAllUsersDetail(long groupId, List<Long> ids) {

    List<UserDetailedBean> usersDetailList = null;

    try {
        usersDetailList = userDao.selectAllUsersDetail(groupId, ids);
    } catch (Exception e) {
        e.printStackTrace();
    }

    return usersDetailList;
}

In Dao class I just inject the mapper.

@Resource
private UserMapper userMapper;

@Override
public List<UserDetailedBean> selectAllUsersDetail(long groupId, List<Long> ids) {
    return userMapper.selectAllUsersDetail(groupId,ids);
}

---end updated------

please let me know if any other information is required.

This is the complete stack trace

[ WARN] 2013-01-08 20:13:39       com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@70497e11 -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!
[ WARN] 2013-01-08 20:13:39 com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@70497e11 -- APPARENT DEADLOCK!!! Complete Status: 
 Managed Threads: 3
 Active Threads: 3
 Active Tasks: 
     com.mchange.v2.resourcepool.BasicResourcePool$AsyncTestIdleResourceTask@2e81b8c5 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0)
     com.mchange.v2.resourcepool.BasicResourcePool$AsyncTestIdleResourceTask@4689a55d (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2)
     com.mchange.v2.resourcepool.BasicResourcePool$AsyncTestIdleResourceTask@76c7a0d8 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1)
 Pending Tasks: 
     com.mchange.v2.resourcepool.BasicResourcePool$AsyncTestIdleResourceTask@2c1101d4
     com.mchange.v2.resourcepool.BasicResourcePool$AsyncTestIdleResourceTask@108f1be6
     com.mchange.v2.resourcepool.BasicResourcePool$AsyncTestIdleResourceTask@2370a188
     com.mchange.v2.resourcepool.BasicResourcePool$AsyncTestIdleResourceTask@377cf9e5
     com.mchange.v2.resourcepool.BasicResourcePool$AsyncTestIdleResourceTask@6dfa45d8
     com.mchange.v2.resourcepool.BasicResourcePool$AsyncTestIdleResourceTask@49ffa050
     com.mchange.v2.resourcepool.BasicResourcePool$AsyncTestIdleResourceTask@2d760a24
    Pool thread stack traces:
 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)
     com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:114)
     com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:161)
     com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:189)
     com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2549)
     com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3002)
     com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2991)
     com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3532)
     com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2002)
     com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2163)
     com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2618)
     com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2568)
     com.mysql.jdbc.StatementImpl.executeQuery(StatementImpl.java:1557)
     com.mysql.jdbc.DatabaseMetaData$9.forEach(DatabaseMetaData.java:4984)
     com.mysql.jdbc.IterateBlock.doForAll(IterateBlock.java:51)
     com.mysql.jdbc.DatabaseMetaData.getTables(DatabaseMetaData.java:4962)
     com.mchange.v2.c3p0.impl.DefaultConnectionTester.activeCheckConnectionNoQuery(DefaultConnectionTester.java:185)
     com.mchange.v2.c3p0.impl.DefaultConnectionTester.activeCheckConnection(DefaultConnectionTester.java:62)
     com.mchange.v2.c3p0.AbstractConnectionTester.activeCheckConnection(AbstractConnectionTester.java:67)
     com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.testPooledConnection(C3P0PooledConnectionPool.java:368)
     com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.refurbishIdleResource(C3P0PooledConnectionPool.java:310)
     com.mchange.v2.resourcepool.BasicResourcePool$AsyncTestIdleResourceTask.run(BasicResourcePool.java:1999)
     com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)
 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)
     com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:114)
     com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:161)
     com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:189)
     com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2549)
     com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3002)
     com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2991)
     com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3532)
     com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2002)
     com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2163)
     com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2618)
     com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2568)
     com.mysql.jdbc.StatementImpl.executeQuery(StatementImpl.java:1557)
     com.mysql.jdbc.DatabaseMetaData$9.forEach(DatabaseMetaData.java:4984)
     com.mysql.jdbc.IterateBlock.doForAll(IterateBlock.java:51)
     com.mysql.jdbc.DatabaseMetaData.getTables(DatabaseMetaData.java:4962)
     com.mchange.v2.c3p0.impl.DefaultConnectionTester.activeCheckConnectionNoQuery(DefaultConnectionTester.java:185)
     com.mchange.v2.c3p0.impl.DefaultConnectionTester.activeCheckConnection(DefaultConnectionTester.java:62)
     com.mchange.v2.c3p0.AbstractConnectionTester.activeCheckConnection(AbstractConnectionTester.java:67)
     com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.testPooledConnection(C3P0PooledConnectionPool.java:368)
     com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.refurbishIdleResource(C3P0PooledConnectionPool.java:310)
     com.mchange.v2.resourcepool.BasicResourcePool$AsyncTestIdleResourceTask.run(BasicResourcePool.java:1999)
     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)
     com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:114)
     com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:161)
     com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:189)
     com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2549)
     com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3002)
     com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2991)
     com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3532)
     com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2002)
     com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2163)
     com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2618)
     com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2568)
     com.mysql.jdbc.StatementImpl.executeQuery(StatementImpl.java:1557)
     com.mysql.jdbc.DatabaseMetaData$9.forEach(DatabaseMetaData.java:4984)
     com.mysql.jdbc.IterateBlock.doForAll(IterateBlock.java:51)
     com.mysql.jdbc.DatabaseMetaData.getTables(DatabaseMetaData.java:4962)
     com.mchange.v2.c3p0.impl.DefaultConnectionTester.activeCheckConnectionNoQuery(DefaultConnectionTester.java:185)
     com.mchange.v2.c3p0.impl.DefaultConnectionTester.activeCheckConnection(DefaultConnectionTester.java:62)
     com.mchange.v2.c3p0.AbstractConnectionTester.activeCheckConnection(AbstractConnectionTester.java:67)
     com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.testPooledConnection(C3P0PooledConnectionPool.java:368)
     com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.refurbishIdleResource(C3P0PooledConnectionPool.java:310)
     com.mchange.v2.resourcepool.BasicResourcePool$AsyncTestIdleResourceTask.run(BasicResourcePool.java:1999)
     com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)

---Updated----

when I added p:statementCacheNumDeferredCloseThreads="1" to datasouce bean I am getting the below error

     Error creating bean with name 'sqlSessionFactory' defined in ServletContext resource [/WEB-INF/spring-servlet.xml]: 
     Cannot resolve reference to bean 'datasource' while setting bean property 'dataSource'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'datasource' defined in ServletContext resource [/WEB-INF/spring-servlet.xml]: 
   Error setting property values; nested exception is org.springframework.beans.NotWritablePropertyException: Invalid property 'statementCacheNumDeferredCloseThreads' of bean class [com.mchange.v2.c3p0.ComboPooledDataSource]: 
   Bean property 'statementCacheNumDeferredCloseThreads' is not writable or has an invalid setter method. Does the parameter type of the setter match the return type of the getter?
like image 920
Harry Avatar asked Feb 06 '13 13:02

Harry


3 Answers

From http://www.mchange.com/projects/c3p0/#other_ds_configuration

numHelperThreads and maxAdministrativeTaskTime help to configure the behavior of DataSource thread pools. By default, each DataSource has only three associated helper threads. If performance seems to drag under heavy load, or if you observe via JMX or direct inspection of a PooledDataSource, that the number of "pending tasks" is usually greater than zero, try increasing numHelperThreads. maxAdministrativeTaskTime may be useful for users experiencing tasks that hang indefinitely and "APPARENT DEADLOCK" messages. (See Appendix A for more.)

maxAdministrativeTaskTime Default: 0 Seconds before c3p0's thread pool will try to interrupt an apparently hung task. Rarely useful. Many of c3p0's functions are not performed by client threads, but asynchronously by an internal thread pool. c3p0's asynchrony enhances client performance directly, and minimizes the length of time that critical locks are held by ensuring that slow jdbc operations are performed in non-lock-holding threads. If, however, some of these tasks "hang", that is they neither succeed nor fail with an Exception for a prolonged period of time, c3p0's thread pool can become exhausted and administrative tasks backed up. If the tasks are simply slow, the best way to resolve the problem is to increase the number of threads, via numHelperThreads. But if tasks sometimes hang indefinitely, you can use this parameter to force a call to the task thread's interrupt() method if a task exceeds a set time limit. [c3p0 will eventually recover from hung tasks anyway by signalling an "APPARENT DEADLOCK" (you'll see it as a warning in the logs), replacing the thread pool task threads, and interrupt()ing the original threads. But letting the pool go into APPARENT DEADLOCK and then recover means that for some periods, c3p0's performance will be impaired. So if you're seeing these messages, increasing numHelperThreads and setting maxAdministrativeTaskTime might help. maxAdministrativeTaskTime should be large enough that any resonable attempt to acquire a Connection from the database, to test a Connection, or two destroy a Connection, would be expected to succeed or fail within the time set. Zero (the default) means tasks are never interrupted, which is the best and safest policy under most circumstances. If tasks are just slow, allocate more threads. If tasks are hanging forever, try to figure out why, and maybe setting maxAdministrativeTaskTime can help in the meantime.

The default is 3 for numHelperThreads , increase this to 8-10 

setting maxAdministrativeTaskTime will help 
like image 71
Manish Singh Avatar answered Nov 11 '22 13:11

Manish Singh


Please review next steps to fix problem:

  1. Increase p:maxStatements in ComboPooledDataSource.

  2. Set p:maxStatements to 0. For example in Firebird this hack works ComboPooledDataSource.

  3. Be sure you close SqlSession in your application. Give more attention to intensively executing database operation. In my version of mySql JDBC driver: mysql-connector-java 5.1.8 connections are closed automatically when object is garbage collected. So in your case connections shouldn't leak if you are not use database intensively. Nevertheless you must be sure you are close myBatis SqlSession which wrap jdbc connection to DB.

  4. Also accordingly JDBC3 Connection and Statement Pooling you can try to set statementCacheNumDeferredCloseThreads to 1 in c3p0 configuration.

like image 40
Taky Avatar answered Nov 11 '22 13:11

Taky


In my case too little memory for the application was the cause. The DB used was either H2 or SQLite (both are in use in this app).

The first symptom was these WARN log lines as reported above:

12006925 [C3P0PooledConnectionPoolManager[identityToken->2rvy8f9szmpczp1k2dm1g|33af2d37]-AdminTaskTimer] WARN  com.mchange.v2.async.ThreadPoolAsynchronousRunner  - com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@6d3a9c65 -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!
12016284 [C3P0PooledConnectionPoolManager[identityToken->2rvy8f9szmpczp1k2dm1g|3d98d1b]-AdminTaskTimer] WARN  com.mchange.v2.async.ThreadPoolAsynchronousRunner  - com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@44565f94 -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!
12051847 [C3P0PooledConnectionPoolManager[identityToken->2rvy8f9szmpczp1k2dm1g|5703a6aa]-AdminTaskTimer] WARN  com.mchange.v2.async.ThreadPoolAsynchronousRunner  - com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@c9f37e2 -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!
12085128 [C3P0PooledConnectionPoolManager[identityToken->2rvy8f9szmpczp1k2dm1g|4e50d42b]-AdminTaskTimer] WARN  com.mchange.v2.async.ThreadPoolAsynchronousRunner  - com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@6f1927b7 -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!
12085128 [C3P0PooledConnectionPoolManager[identityToken->2rvy8f9szmpczp1k2dm1g|78fa7f84]-AdminTaskTimer] WARN  com.mchange.v2.async.ThreadPoolAsynchronousRunner  - com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@22c22b50 -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!
12172644 [C3P0PooledConnectionPoolManager[identityToken->2rvy8f9szmpczp1k2dm1g|e8e88fa]-AdminTaskTimer] WARN  com.mchange.v2.async.ThreadPoolAsynchronousRunner  - com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@745a644f -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!

Followed by exceptions after a very long time, including the revealing:

Caused by: java.lang.OutOfMemoryError: GC overhead limit exceeded

The problem was reproducible. Giving the app more memory (-Xmx8G) fixed it.

like image 21
Gonfi den Tschal Avatar answered Nov 11 '22 15:11

Gonfi den Tschal