Uploaded image for project: 'Mule'
  1. Mule
  2. MULE-14605

Deadlock when two JDBC connections are created concurrently before the DriverManager classloading takes place

    XMLWordPrintable

Details

    • S3
    • Production Defect

    Description

      Although this issue was originally reproduced with an scatter gather where the paths had db operations that point to different vendors (MSSQL and MySQL in the customer scenario), it could take place in any other scenario where two JDBC connections from different vendors are generated concurrently.

      The deadlock only occurs if the DriverManager classloading haven't taken place.

      Steps of the deadlock:
      1) To create the VendorA JDBC connection, the org.enhydra.jdbc.standard.StandardDataSource instantiates its driver class.
      2) As the DriverManager classloading hasn't taken place yet, it occurs when the driver class register itself.
      3) As part of its static initialization, the DriverManager loads all the JDBC Drivers defined through the SPI mechanism. In this loading, the DriverManager treats to instantiate the Vendor B driver class.

      Simulataneously the first steps occurs for generating the Vendor B JDBC Connection. As the creation of this second connection also depends on the DriverManager classloading (that is being triggered by the VendorA connection generation) it remains blocked waiting for its resolution.
      On the hand, the DriverManager blocks trying to instantiate the DriverClass, whose static initialization is blocked for the cause explained in the previous paragraph.

      Notes:

      1. I haven't looked at the JDK code, but for some reason, this issue doesn't take place if two or more JDBC connections of the same vendor are generated concurrently.
      2. Exists a SO post that exposes the same deadlock scenario.
      3. I have not found any issues reported to Oracle about this case so we should create one to ensure this can be fixed in next JDK versions.

      Verification of the deadlock and proposed solution
      I have verified the cause of the issue, removing the SPI defined in the driver jars.
      The proposed solution is to guarantee the DriverManager classloading occurs before any attempt to create a JDBC Connection calling any irrelevant method of its API from our ConnectionFactory.

      Deadlock Stacktrace Case 1. 

      Stacktrace Thread 1

      "[scatter-gather-hangs].ScatterGatherWorkManager.02" #89 daemon prio=5 os_prio=0 tid=0x00007fa4c40e0000 nid=0x5892 in Object.wait() [0x00007fa494634000]
         java.lang.Thread.State: RUNNABLE
      	at com.microsoft.sqlserver.jdbc.SQLServerDriver.<clinit>(SQLServerDriver.java:427)
      	at java.lang.Class.forName0(Native Method)
      	at java.lang.Class.forName(Class.java:264)
      	at org.enhydra.jdbc.standard.StandardDataSource.getConnection(StandardDataSource.java:167)
      	- locked <0x00000000dd2658c8> (a org.enhydra.jdbc.standard.StandardDataSource)
      	at org.enhydra.jdbc.standard.StandardDataSource.getConnection(StandardDataSource.java:144)
      	- locked <0x00000000dd2658c8> (a org.enhydra.jdbc.standard.StandardDataSource)
      	at org.mule.module.db.internal.domain.connection.SimpleConnectionFactory.doCreateConnection(SimpleConnectionFactory.java:30)
      	at org.mule.module.db.internal.domain.connection.AbstractConnectionFactory.create(AbstractConnectionFactory.java:23)
      	at org.mule.module.db.internal.domain.connection.TransactionalDbConnectionFactory.createDataSourceConnection(TransactionalDbConnectionFactory.java:84)
      	at org.mule.module.db.internal.domain.connection.TransactionalDbConnectionFactory.createConnection(TransactionalDbConnectionFactory.java:53)
      

      Stacktrace Thread 2

      "[scatter-gather-hangs].ScatterGatherWorkManager.01" #88 daemon prio=5 os_prio=0 tid=0x00007fa4c40df800 nid=0x5891 in Object.wait() [0x00007fa4cf8e2000]
         java.lang.Thread.State: RUNNABLE
      	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
      	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
      	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
      	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
      	at java.lang.Class.newInstance(Class.java:442)
      	at java.util.ServiceLoader$LazyIterator.nextService(ServiceLoader.java:380)
      	at java.util.ServiceLoader$LazyIterator.next(ServiceLoader.java:404)
      	at java.util.ServiceLoader$1.next(ServiceLoader.java:480)
      	at java.sql.DriverManager$2.run(DriverManager.java:603)
      	at java.sql.DriverManager$2.run(DriverManager.java:583)
      	at java.security.AccessController.doPrivileged(Native Method)
      	at java.sql.DriverManager.loadInitialDrivers(DriverManager.java:583)
      	at java.sql.DriverManager.<clinit>(DriverManager.java:101)
      	at com.mysql.jdbc.Driver.<clinit>(Driver.java:49)
      	at java.lang.Class.forName0(Native Method)
      	at java.lang.Class.forName(Class.java:264)
      	at org.enhydra.jdbc.standard.StandardDataSource.getConnection(StandardDataSource.java:167)
      	- locked <0x00000000dcf9b118> (a org.enhydra.jdbc.standard.StandardDataSource)
      	at org.enhydra.jdbc.standard.StandardDataSource.getConnection(StandardDataSource.java:144)
      	- locked <0x00000000dcf9b118> (a org.enhydra.jdbc.standard.StandardDataSource)
      	at org.mule.module.db.internal.domain.connection.SimpleConnectionFactory.doCreateConnection(SimpleConnectionFactory.java:30)
      	at org.mule.module.db.internal.domain.connection.AbstractConnectionFactory.create(AbstractConnectionFactory.java:23)
      	at org.mule.module.db.internal.domain.connection.TransactionalDbConnectionFactory.createDataSourceConnection(TransactionalDbConnectionFactory.java:84)
      	at org.mule.module.db.internal.domain.connection.TransactionalDbConnectionFactory.createConnection(TransactionalDbConnectionFactory.java:53)
      

      Deadlock Stacktrace Case 2.

      Stacktrace Thread 1

      "[scatter-gather-hangs].ScatterGatherWorkManager.02" #89 daemon prio=5 os_prio=0 tid=0x00007f856c0e7800 nid=0x51b6 in Object.wait() [0x00007f8535a58000]
         java.lang.Thread.State: RUNNABLE
      	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
      	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
      	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
      	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
      	at java.lang.Class.newInstance(Class.java:442)
      	at java.util.ServiceLoader$LazyIterator.nextService(ServiceLoader.java:380)
      	at java.util.ServiceLoader$LazyIterator.next(ServiceLoader.java:404)
      	at java.util.ServiceLoader$1.next(ServiceLoader.java:480)
      	at java.sql.DriverManager$2.run(DriverManager.java:603)
      	at java.sql.DriverManager$2.run(DriverManager.java:583)
      	at java.security.AccessController.doPrivileged(Native Method)
      	at java.sql.DriverManager.loadInitialDrivers(DriverManager.java:583)
      	at java.sql.DriverManager.<clinit>(DriverManager.java:101)
      	at com.microsoft.sqlserver.jdbc.SQLServerDriver.<clinit>(SQLServerDriver.java:427)
      	at java.lang.Class.forName0(Native Method)
      	at java.lang.Class.forName(Class.java:264)
      	at org.enhydra.jdbc.standard.StandardDataSource.getConnection(StandardDataSource.java:167)
      	- locked <0x00000000d9ce9a10> (a org.enhydra.jdbc.standard.StandardDataSource)
      	at org.enhydra.jdbc.standard.StandardDataSource.getConnection(StandardDataSource.java:144)
      	- locked <0x00000000d9ce9a10> (a org.enhydra.jdbc.standard.StandardDataSource)
      	at org.mule.module.db.internal.domain.connection.SimpleConnectionFactory.doCreateConnection(SimpleConnectionFactory.java:30)
      	at org.mule.module.db.internal.domain.connection.AbstractConnectionFactory.create(AbstractConnectionFactory.java:23)
      	at org.mule.module.db.internal.domain.connection.TransactionalDbConnectionFactory.createDataSourceConnection(TransactionalDbConnectionFactory.java:84)
      	at org.mule.module.db.internal.domain.connection.TransactionalDbConnectionFactory.createConnection(TransactionalDbConnectionFactory.java:53)
      

      Stacktrace Thread 2

      "[scatter-gather-hangs].ScatterGatherWorkManager.01" #88 daemon prio=5 os_prio=0 tid=0x00007f856c0e9800 nid=0x51b5 in Object.wait() [0x00007f85a8e62000]
         java.lang.Thread.State: RUNNABLE
      	at com.mysql.jdbc.Driver.<clinit>(Driver.java:49)
      	at java.lang.Class.forName0(Native Method)
      	at java.lang.Class.forName(Class.java:264)
      	at org.enhydra.jdbc.standard.StandardDataSource.getConnection(StandardDataSource.java:167)
      	- locked <0x00000000d9ce2708> (a org.enhydra.jdbc.standard.StandardDataSource)
      	at org.enhydra.jdbc.standard.StandardDataSource.getConnection(StandardDataSource.java:144)
      	- locked <0x00000000d9ce2708> (a org.enhydra.jdbc.standard.StandardDataSource)
      	at org.mule.module.db.internal.domain.connection.SimpleConnectionFactory.doCreateConnection(SimpleConnectionFactory.java:30)
      	at org.mule.module.db.internal.domain.connection.AbstractConnectionFactory.create(AbstractConnectionFactory.java:23)
      	at org.mule.module.db.internal.domain.connection.TransactionalDbConnectionFactory.createDataSourceConnection(TransactionalDbConnectionFactory.java:84)
      	at org.mule.module.db.internal.domain.connection.TransactionalDbConnectionFactory.createConnection(TransactionalDbConnectionFactory.java:53)
      

      Attachments

        Activity

          People

            facundo.velazquez facundo.velazquez
            facundo.velazquez facundo.velazquez
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: