Commons Dbcp
  1. Commons Dbcp
  2. DBCP-272

Contention for DriverManager when initializing multiple datasources

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 1.2.2
    • Fix Version/s: 1.3
    • Labels:
      None
    • Environment:

      Java HotSpot(TM) 64-Bit Server VM (1.6.0-b105 mixed mode) on Linux

      Description

      This issue has been discussed in the commons user's mailing list between myself, Simon Kitching and Phil Steitz.

      In summary:

      I have a webapp deployed in tomcat containing 3 pooled datasources which are managed by Spring. The webapp starts up OK and is immediately hit by a load of a few hundred requests a second. It seems to handle a few hundred request and then just locks up entirely and stops responding entirely. Attached is a stack trace obtained by doing kill -3 when in this state. After discussion on the mailing list I changed the datasources to be non-lazy initialised in spring but the issue still occurs.

      Simon Kitching said:
      "The first thread is trying to initialise a postgresql driver and register it with DriverManager. The driver registration is being triggered from a static initialiser block on the postgresql driver class, so is executing from within the Class.forName method (and therefore the postgresql driver Class object is locked by this thread).

      The second thread is trying to initialise a mysql driver and register it with DriverManager. Again, the driver registration is being triggered from a static initialiser block on the mysql driver class, so the mysql driver Class object is locked by this thread).

      But in both cases, the DriverManager needs to be initialised before anything can be registered. The first thread appears to have run first, triggering the initialisation process, and the second thread is blocked waiting for initialisation of DriverManager to complete before it registers the mysql driver.

      <snip/>

      Possibly dbcp should call DriverManager.getDrivers() internally on startup to avoid this race... "

      1. catalina.out.stuck2
        918 kB
        Adrian Woodhead

        Activity

        Hide
        Adrian Woodhead added a comment - - edited

        This is the thread dump obtained by doing a "kill -3" on the tomcat process when in the stuck state soon after startup.

        Show
        Adrian Woodhead added a comment - - edited This is the thread dump obtained by doing a "kill -3" on the tomcat process when in the stuck state soon after startup.
        Hide
        Adrian Woodhead added a comment -

        Interestingly, we tried to replace the DBCP connection pool with c3p0. We did not mark the datasources as lazy-init in spring. c3p0 exhibited very similar behaviour to dbcp, what is does better is that it actually detects the deadlock itself and outputs some useful information related to this It seems it also blocks in DirverManager.registerDriver and in doing the Class.forName step:

        [2008-07-09 17:31:24] WARN (com.mchange.v2.async.ThreadPoolAsynchronousRunner:608) - com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@2cec4462 – APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!
        [2008-07-09 17:31:24] WARN (com.mchange.v2.async.ThreadPoolAsynchronousRunner:624) - com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@2cec4462 – APPARENT DEADLOCK!!! Complete Status:
        Managed Threads: 3
        Active Threads: 3
        Active Tasks:
        com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@21bf4c80 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0)
        com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@163778cf (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1)
        com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@13dc696e (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2)
        Pending Tasks:
        com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@6b8dbef1
        com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@26f2f761
        com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@194f1541
        com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@16fc6b62
        com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@15edfab8
        com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@3ae75147
        com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@28892a87
        com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@454719db
        com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@3ef29c65
        com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@29f9cb2c
        Pool thread stack traces:
        Threadcom.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0,5,main
        java.sql.DriverManager.registerDriver(DriverManager.java:280)
        com.mysql.jdbc.Driver.<clinit>(Driver.java:62)
        java.lang.Class.forName0(Native Method)
        java.lang.Class.forName(Class.java:169)
        com.mchange.v2.c3p0.DriverManagerDataSource.ensureDriverLoaded(DriverManagerDataSource.java:100)
        com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:132)
        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)
        Threadcom.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1,5,main
        java.lang.Class.forName0(Native Method)
        java.lang.Class.forName(Class.java:169)
        com.mchange.v2.c3p0.DriverManagerDataSource.ensureDriverLoaded(DriverManagerDataSource.java:100)
        com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:132)
        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)
        Threadcom.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2,5,main
        java.lang.Class.forName0(Native Method)
        java.lang.Class.forName(Class.java:169)
        com.mchange.v2.c3p0.DriverManagerDataSource.ensureDriverLoaded(DriverManagerDataSource.java:100)
        com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:132)
        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)

        Show
        Adrian Woodhead added a comment - Interestingly, we tried to replace the DBCP connection pool with c3p0. We did not mark the datasources as lazy-init in spring. c3p0 exhibited very similar behaviour to dbcp, what is does better is that it actually detects the deadlock itself and outputs some useful information related to this It seems it also blocks in DirverManager.registerDriver and in doing the Class.forName step: [2008-07-09 17:31:24] WARN (com.mchange.v2.async.ThreadPoolAsynchronousRunner:608) - com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@2cec4462 – APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks! [2008-07-09 17:31:24] WARN (com.mchange.v2.async.ThreadPoolAsynchronousRunner:624) - com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@2cec4462 – APPARENT DEADLOCK!!! Complete Status: Managed Threads: 3 Active Threads: 3 Active Tasks: com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@21bf4c80 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0) com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@163778cf (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1) com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@13dc696e (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2) Pending Tasks: com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@6b8dbef1 com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@26f2f761 com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@194f1541 com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@16fc6b62 com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@15edfab8 com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@3ae75147 com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@28892a87 com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@454719db com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@3ef29c65 com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@29f9cb2c Pool thread stack traces: Thread com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0,5,main java.sql.DriverManager.registerDriver(DriverManager.java:280) com.mysql.jdbc.Driver.<clinit>(Driver.java:62) java.lang.Class.forName0(Native Method) java.lang.Class.forName(Class.java:169) com.mchange.v2.c3p0.DriverManagerDataSource.ensureDriverLoaded(DriverManagerDataSource.java:100) com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:132) 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.lang.Class.forName0(Native Method) java.lang.Class.forName(Class.java:169) com.mchange.v2.c3p0.DriverManagerDataSource.ensureDriverLoaded(DriverManagerDataSource.java:100) com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:132) 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-#2,5,main java.lang.Class.forName0(Native Method) java.lang.Class.forName(Class.java:169) com.mchange.v2.c3p0.DriverManagerDataSource.ensureDriverLoaded(DriverManagerDataSource.java:100) com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:132) 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)
        Hide
        Mark Thomas added a comment -

        We can never truly fix this since the way drivers are expected to register with the DriverManager is asking for a deadlock to occur in multi-thread environments. Yuck.

        What we can do is attempt to prevent this in environments where only DBCP is used. I have applied a patch that calls DriverManager.getDrivers() to force initialisation before we ever do anything that might use Class.forName() to load (and register) a JDBC driver. This should prevent this deadlock occurring. Any feedback from testing in your environment would be appreciated.

        Show
        Mark Thomas added a comment - We can never truly fix this since the way drivers are expected to register with the DriverManager is asking for a deadlock to occur in multi-thread environments. Yuck. What we can do is attempt to prevent this in environments where only DBCP is used. I have applied a patch that calls DriverManager.getDrivers() to force initialisation before we ever do anything that might use Class.forName() to load (and register) a JDBC driver. This should prevent this deadlock occurring. Any feedback from testing in your environment would be appreciated.

          People

          • Assignee:
            Unassigned
            Reporter:
            Adrian Woodhead
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development