Enabling "Allow only SSL connection" option causes connection problem between SSL-configured Spring application and GC SQL instance

[Hasan Çelik]

Hello,

I have Spring application which is running on Tomcat(7.0.68) at my local machine that uses Google Cloud SQL instance. Also I am using C3P0(0.9.1.2) as a connection pool. You can find a part of the DAOcontext.xml file and CATALINA_OPTS: 

.....
<bean id="dataSource" class="com.mchange.v2.c3p0.ComboPooledDataSource">

            <property name="driverClass" value="com.mysql.jdbc.Driver"/>

            <property name="jdbcUrl" value="jdbc:mysql://sql_instance_ip:3306/table_name?verifyServerCertificate=true&useSSL=true&requireSSL=true&trustCertificateKeyStoreUrl=file:/path/to/trustStore.jks&trustCertificateKeyStorePassword=****&characterEncoding=UTF-8&useUnicode=true&autoReconnect=true&useServerPrepStmts=false&rewriteBatchedStatements=true&failOverReadOnly=false&zeroDateTimeBehavior=convertToNull"/>

            <property name="user" value="***"/>

            <property name="password" value="****"/>

            <property name="acquireIncrement" value="1"/>

            <property name="initialPoolSize" value="1"/>

            <property name="minPoolSize" value="1"/>

            <property name="maxPoolSize" value="5"/>

            <property name="maxIdleTime" value="120"/>

</bean>
.....

CATALINA_OPTS="... -Djavax.net.ssl.keyStore=/path/to/keyStore.jks -Djavax.net.ssl.keyStorePassword=**** ..."

Kodu buraya girin...

These key stores are created from my SQL instance's certificate.

https://cloud.google.com/sql/docs/mysql/configure-ssl-instance 

When I disable "Allow only SSL connection" option from dashboard, my application runs without any DB connection problem. Also when I check connection between my application and SQL instance via WireShark, I see that packets are SSL encrypted. 

When I enable this option, my tomcat application gives these errors:

May 07, 2018 5:02:49 PM com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource getPoolManager

INFO: Initializing c3p0 pool... com.mchange.v2.c3p0.ComboPooledDataSource [ acquireIncrement -> 1, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, dataSourceName -> ****, debugUnreturnedConnectionStackTraces -> false, description -> null, driverClass -> com.mysql.jdbc.Driver, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> ****, idleConnectionTestPeriod -> 0, initialPoolSize -> 1, jdbcUrl -> jdbc:mysql://sql_instance_ip:3306/table_name?verifyServerCertificate=true&useSSL=true&requireSSL=true&trustCertificateKeyStoreUrl=file:/path/to/trustStore.jks&trustCertificateKeyStorePassword=****&characterEncoding=UTF-8&useUnicode=true&autoReconnect=true&useServerPrepStmts=false&rewriteBatchedStatements=true&failOverReadOnly=false&zeroDateTimeBehavior=convertToNull"/, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 120, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 5, maxStatements -> 0, maxStatementsPerConnection -> 0, minPoolSize -> 1, numHelperThreads -> 3, numThreadsAwaitingCheckoutDefaultUser -> 0, preferredTestQuery -> null, properties -> {user=******, password=******}, propertyCycle -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 0, usesTraditionalReflectiveProxies -> false ]

May 07, 2018 5:03:09 PM com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector run

WARNING: com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@274517d0 -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!

May 07, 2018 5:03:09 PM com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector run

WARNING: com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@274517d0 -- APPARENT DEADLOCK!!! Complete Status:

Managed Threads: 3

Active Threads: 3

Active Tasks:

com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@68bff773 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1)

com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@67cb9623 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2)

com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@599d5f2f (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0)

Pending Tasks:

com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@1f0360c0

com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@890083c

Pool thread stack traces:

Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1,5,main]

java.lang.Thread.sleep(Native Method)

com.mysql.jdbc.ConnectionImpl.connectWithRetries(ConnectionImpl.java:2376)

com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2306)

com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:834)

com.mysql.jdbc.JDBC4Connection.<init>(JDBC4Connection.java:47)

sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)

sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)

sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)

java.lang.reflect.Constructor.newInstance(Constructor.java:423)

com.mysql.jdbc.Util.handleNewInstance(Util.java:411)

com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:416)

com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:346)

com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:134)

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-#0,5,main]

java.net.SocketInputStream.socketRead0(Native Method)

java.net.SocketInputStream.socketRead(SocketInputStream.java:116)

java.net.SocketInputStream.read(SocketInputStream.java:171)

java.net.SocketInputStream.read(SocketInputStream.java:141)

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:3116)

com.mysql.jdbc.MysqlIO.readPacket(MysqlIO.java:599)

com.mysql.jdbc.MysqlIO.doHandshake(MysqlIO.java:1086)

com.mysql.jdbc.ConnectionImpl.coreConnect(ConnectionImpl.java:2483)

com.mysql.jdbc.ConnectionImpl.connectWithRetries(ConnectionImpl.java:2324)

com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2306)

com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:834)

com.mysql.jdbc.JDBC4Connection.<init>(JDBC4Connection.java:47)

sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)

sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)

sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)

java.lang.reflect.Constructor.newInstance(Constructor.java:423)

com.mysql.jdbc.Util.handleNewInstance(Util.java:411)

com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:416)

com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:346)

com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:134)

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.Thread.sleep(Native Method)

com.mysql.jdbc.ConnectionImpl.connectWithRetries(ConnectionImpl.java:2376)

com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2306)

com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:834)

com.mysql.jdbc.JDBC4Connection.<init>(JDBC4Connection.java:47)

sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)

sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)

sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)

java.lang.reflect.Constructor.newInstance(Constructor.java:423)

com.mysql.jdbc.Util.handleNewInstance(Util.java:411)

com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:416)

com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:346)

com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:134)

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)

May 07, 2018 5:04:09 PM com.mchange.v2.async.ThreadPoolAsynchronousRunner processReplacedThreads

WARNING: Task com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@68bff773 (in deadlocked PoolThread) failed to complete in maximum time 60000ms. Trying interrupt().

May 07, 2018 5:04:09 PM com.mchange.v2.async.ThreadPoolAsynchronousRunner processReplacedThreads

WARNING: Task com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@599d5f2f (in deadlocked PoolThread) failed to complete in maximum time 60000ms. Trying interrupt().

May 07, 2018 5:04:09 PM com.mchange.v2.async.ThreadPoolAsynchronousRunner processReplacedThreads

These error logs are not specific to this issue but they are similar to those I got when my application are not able to connect DB. Do you have any idea or advice about this issue? Is there anyone who use similar setup and encountered this problem?

Any kind of help and suggestion is highly appreciated! 

Thanks in advance.

[Kenworth (Google Cloud Platform)]

A thread like this is off-topic for Google Groups, and should be posted to StackOverflow. This forum isn't meant for specific 1-on-1 technical issues, but for general discussion of the platform and its services. With StackOverflow, which we also monitor, you'll be in touch with a much larger user-base of people who are going to help you, and in a format which is designed for that purpose. Check out our community support page for the list of tags we monitor.

[Hasan Çelik]

Point taken, https://stackoverflow.com/questions/50229789/ for anybody searching the internet after a similar problem.

7 Mayıs 2018 Pazartesi 22:23:32 UTC+3 tarihinde Kenworth (Google Cloud Platform) yazdı: