How to trace and prevent the deadlock appeared in c3po which is running in seperate processes?

Question

I have a very simple computation which produces letter matrices finds probably all the words in the matrix. The letters in the word are adjacent cells.

   for (int i = 0; i < 500; i++) {
        System.out.println(i);
        Matrix matrix = new Matrix(4);
        matrix.scanWordsRandomly(9);
        matrix.printMatrix();
        System.out.println(matrix.getSollSize());
        matrix.write_to_db();
    }

Here is the persisting code.

public void write_to_db() {
    Session session = null;
    try {
        session = HibernateUtil.getSessionFactory().openSession();
        session.beginTransaction();
        Matrixtr onematrixtr = new Matrixtr();
        onematrixtr.setDimension(dimension);
        onematrixtr.setMatrixstr(this.toString());
        onematrixtr.setSolsize(getSollSize());
        session.save(onematrixtr);
        for (Map.Entry<Kelimetr, List<Cell>> sollution : sollutions.entrySet()) {
            Kelimetr kelimetr = sollution.getKey();
            List<Cell> solpath = sollution.getValue();
            Solstr onesol = new Solstr();
            onesol.setKelimetr(kelimetr);
            onesol.setMatrixtr(onematrixtr);
            onesol.setSoltext(solpath.toString().replace("[", "").replace("]", "").replace("true", "").replace("false", ""));
            session.save(onesol);
        }

        session.getTransaction().commit();
        session.close();

    }
    catch (HibernateException he) {
        System.out.println("DB Error : " + he.getMessage());
        session.close();
    } 
    catch (Exception ex) {
        System.out.println("General Error : " + ex.getMessage());
    }
}

Here is the hibernate configuration file.

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE hibernate-configuration PUBLIC "-//Hibernate/Hibernate Configuration DTD 3.0//EN" "http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd">
<hibernate-configuration>
  <session-factory>
    <property name="hibernate.dialect">org.hibernate.dialect.MySQLDialect</property>
    <property name="hibernate.connection.driver_class">com.mysql.jdbc.Driver</property>
    <property name="hibernate.connection.url">jdbc:mysql://localhost:3306/kelimegame_db_dev?autoReconnect=true&amp;useUnicode=true&amp;characterEncoding=UTF-8</property>
    <property name="hibernate.connection.username">root</property>
    <property name="hibernate.connection.password">!.Wlu9RrCA</property>
    <property name="hibernate.show_sql">false</property>
    <property name="hibernate.query.factory_class">org.hibernate.hql.classic.ClassicQueryTranslatorFactory</property>
    <property name="hibernate.format_sql">false</property>
    <!-- Use the C3P0 connection pool provider -->
    <property name="hibernate.c3p0.acquire_increment">50</property>
    <property name="hibernate.c3p0.min_size">10</property>
    <property name="hibernate.c3p0.max_size">100</property>
    <property name="hibernate.c3p0.timeout">300</property>
    <property name="hibernate.c3p0.max_statements">5</property>
    <property name="hibernate.c3p0.idle_test_period">3000</property>
    <mapping resource="kelimegame/entity/Progress.hbm.xml"/>
    <mapping resource="kelimegame/entity/Solstr.hbm.xml"/>
    <mapping resource="kelimegame/entity/Kelimetr.hbm.xml"/>
    <mapping resource="kelimegame/entity/User.hbm.xml"/>
    <mapping resource="kelimegame/entity/Achievement.hbm.xml"/>
    <mapping resource="kelimegame/entity/Matrixtr.hbm.xml"/>
  </session-factory>
</hibernate-configuration>

After finding all possible solutions I persist the matrix and the solutions using hibernate. I am also using c3pO library. I am not spawning any thread. All the work is being done in a very simple iterative way. But I am running the jar in separate processes. From different terminals I am executing this :

java -jar NewDB.jar

I got a deadlock as follows :

Apr 25, 2013 8:38:05 PM com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector run
WARNING: com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@7f0c09f9 -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!
Apr 25, 2013 9:08:23 PM com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector run
WARNING: com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@7f0c09f9 -- APPARENT DEADLOCK!!! Complete Status: 
    Managed Threads: 3
    Active Threads: 3
    Active Tasks: 
        com.mchange.v2.resourcepool.BasicResourcePool$1DestroyResourceTask@2933f261
            on thread: C3P0PooledConnectionPoolManager[identityToken->z8kfsx8uibeyqevbbapc|4045cf35]-HelperThread-#1
        com.mchange.v2.resourcepool.BasicResourcePool$1DestroyResourceTask@116dd369
            on thread: C3P0PooledConnectionPoolManager[identityToken->z8kfsx8uibeyqevbbapc|4045cf35]-HelperThread-#0
        com.mchange.v2.resourcepool.BasicResourcePool$1DestroyResourceTask@41529b6f
            on thread: C3P0PooledConnectionPoolManager[identityToken->z8kfsx8uibeyqevbbapc|4045cf35]-HelperThread-#2
    Pending Tasks: 
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@165ab5ea
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@1d5d211d
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@4d2905fa
Pool thread stack traces:
    Thread[C3P0PooledConnectionPoolManager[identityToken->z8kfsx8uibeyqevbbapc|4045cf35]-HelperThread-#1,5,main]
        com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:662)
    Thread[C3P0PooledConnectionPoolManager[identityToken->z8kfsx8uibeyqevbbapc|4045cf35]-HelperThread-#0,5,main]
        com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:662)
    Thread[C3P0PooledConnectionPoolManager[identityToken->z8kfsx8uibeyqevbbapc|4045cf35]-HelperThread-#2,5,main]
        com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:662)


Apr 25, 2013 9:41:29 PM com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector run
WARNING: com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@7f0c09f9 -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!
Apr 25, 2013 9:55:18 PM com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector run
WARNING: com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@7f0c09f9 -- APPARENT DEADLOCK!!! Complete Status: 
    Managed Threads: 3
    Active Threads: 3
    Active Tasks: 
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@5a337b7d
            on thread: C3P0PooledConnectionPoolManager[identityToken->z8kfsx8uibeyqevbbapc|4045cf35]-HelperThread-#0
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@69f079ce
            on thread: C3P0PooledConnectionPoolManager[identityToken->z8kfsx8uibeyqevbbapc|4045cf35]-HelperThread-#1
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@2accf9b8
            on thread: C3P0PooledConnectionPoolManager[identityToken->z8kfsx8uibeyqevbbapc|4045cf35]-HelperThread-#2
    Pending Tasks: 
        com.mchange.v2.resourcepool.BasicResourcePool$1DestroyResourceTask@771eb4fb
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@fc07d6
        com.mchange.v2.resourcepool.BasicResourcePool$1DestroyResourceTask@2266731b
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@740f0341
        com.mchange.v2.resourcepool.BasicResourcePool$1DestroyResourceTask@59edbee
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@78e924
        com.mchange.v2.resourcepool.BasicResourcePool$1DestroyResourceTask@2123aba
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@7acd8a65
Pool thread stack traces:
    Thread[C3P0PooledConnectionPoolManager[identityToken->z8kfsx8uibeyqevbbapc|4045cf35]-HelperThread-#0,5,main]
        java.text.NumberFormat.getInstance(NumberFormat.java:769)
        java.text.NumberFormat.getInstance(NumberFormat.java:393)
        java.text.MessageFormat.subformat(MessageFormat.java:1262)
        java.text.MessageFormat.format(MessageFormat.java:860)
        java.text.Format.format(Format.java:157)
        java.text.MessageFormat.format(MessageFormat.java:836)
        com.mysql.jdbc.Messages.getString(Messages.java:106)
        com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2552)
        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.checkErrorPacket(MysqlIO.java:943)
        com.mysql.jdbc.MysqlIO.secureAuth411(MysqlIO.java:4113)
        com.mysql.jdbc.MysqlIO.doHandshake(MysqlIO.java:1308)
        com.mysql.jdbc.ConnectionImpl.coreConnect(ConnectionImpl.java:2336)
        com.mysql.jdbc.ConnectionImpl.connectWithRetries(ConnectionImpl.java:2176)
        com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2158)
        com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:792)
        com.mysql.jdbc.JDBC4Connection.<init>(JDBC4Connection.java:47)
        sun.reflect.GeneratedConstructorAccessor7.newInstance(Unknown Source)
        sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        java.lang.reflect.Constructor.newInstance(Constructor.java:525)
        com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
        com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:381)
        com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:305)
        com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:134)
        com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:183)
        com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:172)
        com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:188)Killed
caglar@ubuntu:~/NetBeansProjects/NewDB/dist$ 

My question is as follows :

1. Can this deadlock in c3po happen since I am running the program in separate processes?
2. Should I use one process and multiple threads inside of this process?
3. How can I trace this deadlock understand the cause of it? Is there a way to trace multiple JVMs causing deadlocks?

Answer 1

this is an interesting one.

you've published two distinct APPARENT DEADLOCKS. the first one is being caused by c3p0 attempting to close() Connections, and those close() operations are neither succeeding nor failing with an Exception in a timely manner. the second APPARENT DEADLOCK shows problems with Connection acquisition: c3p0 is attempting to acquire new Connections, and those attempts are neither succeeding nor failing with an Exception in a timely manner. the fact that very different operations are freezing suggests that it might be a more general problem with your dbms locking up under the stress of what you are doing or somesuch. it should be no problem to run multiple processes against your database, but you need to stay cognizant of limits.

there are a few interesting things about your configuration:

1) hibernate.c3p0.max_statements=5 is a very bad idea, on almost any pool and particularly on pools this large. you've got up to 100 Connections, and you're only allowing a total of 5 Statements to be cached between all of them. this might stress both the pool and the DBMS, as you will constantly be churning through PreparedStatements and the statement cache does a lot of bookkeeping about that. you may have meant that to be 5 cached statements per connection, but that's not what you have configured. you have set a global maximum for your pool. maybe try hibernate.c3p0.maxStatementsPerConnection=5 instead? or set max_statements to zero to turn statement caching off, at least until you resolve your deadlock. see http://www.mchange.com/projects/c3p0/#configuring_statement_pooling

2) if you are running your computation in multiple processes rather than multiple Threads, do you really need each process to hold 50 - 100 Connections? things may well be freezing up simply because you are stressing the dbms with too many Connections outstanding as each of your multiple processes acquire lots of resource-heavy Connections. you don't need more Connections in any process than you might have client Threads running concurrently within that process. i'd set hibernate.c3p0.acquire_increment and probably hibernate.c3p0.max_size to much smaller values.

3) if you really do need all those Connections running simultaneously, you can reduce the vulnerability of your pools to deadlock by increasing the config parameter numHelperThreads to some value greater than its default of 3. you probably want numHelperThreads to be something like twice the number of cores available on your machine. given that you are running multiple processes though, you might find that you are saturating your CPU, and that is freezing things up. so watch for that.

basically, try updating your configuration so that you are using resources -- file handles, network connections, CPU -- as efficiently as possible and so that you are not unnecessarily stressing the pool / statement cache / dbms more than you need to be.

if these suggestions don't resolve the problem, please post the fill config of your pools. c3p0 dumps its config at INFO level on pool initialization.

good luck!