要約

When using MySQL as your database server and starting Bamboo this fails to start with error message Bamboo bootstrap failed: Your Bamboo instance could not start because health check failed.

環境

Java8u291 or higher

MySQL database server 5.6 or 5.7

診断

1. When checking the atlassian-bamboo.log we can find a stack trace which is generated while Bamboo is trying to acquire a database connection:

   2021-07-02 11:49:10,177 WARN [C3P0PooledConnectionPoolManager[identityToken->1hged5qaiskpfo9gt1gzw|4255fa8c]-HelperThread-#1] [BasicResourcePool] com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@99ff0e5 -- Acquisition Attempt Failed!!! Clearing pending acquires. While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (30). Last acquisition attempt exception: 
   com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Could not create connection to database server. Attempted reconnect 3 times. Giving up.
   	at sun.reflect.GeneratedConstructorAccessor43.newInstance(Unknown Source)
   	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
   	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
   	at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
   	at com.mysql.jdbc.Util.getInstance(Util.java:408)
   	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:919)
   	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:898)
   	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:887)
   	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:861)
   	at com.mysql.jdbc.ConnectionImpl.connectWithRetries(ConnectionImpl.java:2095)
   	at com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2020)
   	at com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:768)
   	at com.mysql.jdbc.JDBC4Connection.<init>(JDBC4Connection.java:47)
   	at sun.reflect.GeneratedConstructorAccessor42.newInstance(Unknown Source)
   	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
   	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
   	at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
   	at com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:385)
   	at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:323)
   	at com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:175)
   	at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:220)
   	at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:206)
   	at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:203)
   	at com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1176)
   	at com.mchange.v2.resourcepool.BasicResourcePool.doAcquireAndDecrementPendingAcquiresWithinLockOnSuccess(BasicResourcePool.java:1163)
   	at com.mchange.v2.resourcepool.BasicResourcePool.access$700(BasicResourcePool.java:44)
   	at com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask.run(BasicResourcePool.java:1908)
   	at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:696)
   Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure
   
   The last packet successfully received from the server was 1 milliseconds ago.  The last packet sent successfully to the server was 1 milliseconds ago.
   	at sun.reflect.GeneratedConstructorAccessor31.newInstance(Unknown Source)
   	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
   	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
   	at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
   	at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:990)
   	at com.mysql.jdbc.ExportControlled.transformSocketToSSLSocket(ExportControlled.java:201)
   	at com.mysql.jdbc.MysqlIO.negotiateSSLConnection(MysqlIO.java:4869)
   	at com.mysql.jdbc.MysqlIO.proceedHandshakeWithPluggableAuthentication(MysqlIO.java:1656)
   	at com.mysql.jdbc.MysqlIO.doHandshake(MysqlIO.java:1217)
   	at com.mysql.jdbc.ConnectionImpl.coreConnect(ConnectionImpl.java:2189)
   	at com.mysql.jdbc.ConnectionImpl.connectWithRetries(ConnectionImpl.java:2036)
   	... 18 more
   Caused by: javax.net.ssl.SSLHandshakeException: No appropriate protocol (protocol is disabled or cipher suites are inappropriate)
   	at sun.security.ssl.HandshakeContext.<init>(HandshakeContext.java:171)
   	at sun.security.ssl.ClientHandshakeContext.<init>(ClientHandshakeContext.java:98)
   	at sun.security.ssl.TransportContext.kickstart(TransportContext.java:220)
   	at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:428)
   	at com.mysql.jdbc.ExportControlled.transformSocketToSSLSocket(ExportControlled.java:186)
   	... 23 more

2. In addition, you may find the following errors in the atlassian-bamboo.log that shows that your database has reached the maximum number of connection errors and a flush at database server level is required.

   2021-07-01 17:24:08,558 WARN [C3P0PooledConnectionPoolManager[identityToken->1hged5qair1xuxebrapzb|4255fa8c]-HelperThread-#1] [BasicResourcePool] com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@4abddc14 -- Acquisition Attempt Failed!!! Clearing pending acquires. While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (30). Last acquisition attempt exception: 
   com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Could not create connection to database server. Attempted reconnect 3 times. Giving up.
   	at sun.reflect.GeneratedConstructorAccessor43.newInstance(Unknown Source)
   	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
   	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
   	at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
   	at com.mysql.jdbc.Util.getInstance(Util.java:408)
   	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:919)
   	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:898)
   	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:887)
   	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:861)
   	at com.mysql.jdbc.ConnectionImpl.connectWithRetries(ConnectionImpl.java:2095)
   	at com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2020)
   	at com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:768)
   	at com.mysql.jdbc.JDBC4Connection.<init>(JDBC4Connection.java:47)
   	at sun.reflect.GeneratedConstructorAccessor39.newInstance(Unknown Source)
   	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
   	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
   	at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
   	at com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:385)
   	at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:323)
   	at com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:175)
   	at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:220)
   	at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:206)
   	at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:203)
   	at com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1176)
   	at com.mchange.v2.resourcepool.BasicResourcePool.doAcquireAndDecrementPendingAcquiresWithinLockOnSuccess(BasicResourcePool.java:1163)
   	at com.mchange.v2.resourcepool.BasicResourcePool.access$700(BasicResourcePool.java:44)
   	at com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask.run(BasicResourcePool.java:1908)
   	at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:696)
   Caused by: java.sql.SQLException: null,  message from server: "Host '192.168.62.30' is blocked because of many connection errors; unblock with 'mysqladmin flush-hosts'"
   	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:965)
   	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:898)
   	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:887)
   	at com.mysql.jdbc.MysqlIO.doHandshake(MysqlIO.java:1031)
   	at com.mysql.jdbc.ConnectionImpl.coreConnect(ConnectionImpl.java:2189)
   	at com.mysql.jdbc.ConnectionImpl.connectWithRetries(ConnectionImpl.java:2036)
   	... 18 more

3. Lastly, and after enabling maximum log verbosity on your MySQL database server the message [Note] Bad handshake is shown on your database error logs.

原因

Since Java version 8 update 291 or higher TLS 1.0 and TLS 1.1 have been disabled by default. See a snippet from the Java 8 update 291 release notes:

• Java™ SE Development Kit 8, Update 291 Release Notes

security-libs/javax.net.ssl
Disable TLS 1.0 and 1.1
TLS 1.0 and 1.1 are versions of the TLS protocol that are no longer considered secure and have been superseded by more secure and modern versions (TLS 1.2 and 1.3).
These versions have now been disabled by default. If you encounter issues, you can, at your own risk, re-enable the versions by removing "TLSv1" and/or "TLSv1.1" from the jdk.tls.disabledAlgorithms security property in the java.security configuration file.

However, for compatibility reasons the default MySQL Connector/J does not enable TLS 1.2 and higher by default. This causes issues with the application connecting to the database as Java does not allow the connector default protocol TLS 1.1. Therefore, one has to enable it explicitly.

See the following note:

For Connector/J 8.0.18 and earlier when connecting to MySQL Community Server 5.6 and 5.7 using the JDBC API: Due to compatibility issues with MySQL Server compiled with yaSSL, Connector/J does not enable connections with TLSv1.2 and higher by default. When connecting to servers that restrict connections to use those higher TLS versions, enable them explicitly by setting the Connector/J connection property enabledTLSProtocols (e.g., set enabledTLSProtocols=TLSv1,TLSv1.1,TLSv1.2).

ソリューション

1. Shutdown Bamboo

2. Connect to your database directly and run the flush hosts command to clear the previous connection errors and unblock the Bamboo host from connecting

3. Modify the <bamboo-home>/bamboo.cfg.xml file, and change the "hibernate.connection.url" and add the following at the end of your URL:

   &enabledTLSProtocols=TLSv1.2

   The database URL should look similarly as this example:

   <property name="hibernate.connection.url">jdbc:mysql://instenv-2161-ae9w.c7uydxwwuprf.eu-west-1.rds.amazonaws.com:3306/atldb?autoReconnect=true&amp;enabledTLSProtocols=TLSv1.2</property>

4. Restart Bamboo