Spring Boot + Liquibase：通信链路故障

Question

我在所有项目中都使用 Liquibase，我真的很喜欢它处理数据库更新的方式，但最近我遇到了这个问题：

liquibase                                : Successfully acquired change log lock
liquibase                                : Successfully released change log lock
liquibase                                : Could not release lock

liquibase.exception.LockException: liquibase.exception.DatabaseException: liquibase.exception.DatabaseException: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Communications link failure during rollback(). Transaction resolution unknown.
    at liquibase.lockservice.StandardLockService.releaseLock(StandardLockService.java:283) ~[liquibase-core-3.5.5.jar!/:na]
    at liquibase.Liquibase.update(Liquibase.java:218) [liquibase-core-3.5.5.jar!/:na]
    at liquibase.Liquibase.update(Liquibase.java:192) [liquibase-core-3.5.5.jar!/:na]
.
.
.
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Communications link failure during rollback(). Transaction resolution unknown.
.
.
liquibase                                : Failed to restore the auto commit to true
.
.
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 16,913 milliseconds ago.  The last packet sent successfully to the server was 89 milliseconds ago.
.
.
Caused by: java.lang.NullPointerException: null
    at com.mysql.jdbc.MysqlIO.clearInputStream(MysqlIO.java:899) ~[mysql-connector-java-5.1.46.jar!/:5.1.46]
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2477) ~[mysql-connector-java-5.1.46.jar!/:5.1.46]

我的服务器上正在运行 3 个应用程序。其中一个运行了大约2年。第二个运行了两个月，第三个是新的。

它们都是 Spring Boot 应用程序。

当我想更新第二个应用程序的 jar 时开始发生这种情况，我停止了旧的 jar，运行新的 jar，但由于上述错误无法启动它。 然后我运行同一个应用程序的旧 jar，它启动得很好。我尝试停止并重新启动这个旧 jar，有几次我得到了上面的错误，但大多数时候它启动得很好。

我尝试重新启动服务器（所有三个应用程序都作为系统启动的服务启动）但由于同样的错误，它们都没有成功启动。连跑了2年的也没有。我停止了所有其他应用程序并再次尝试使用这个持久的应用程序，它一直失败，直到它启动。

会不会是内存问题？我正在使用具有 1 个核心和 2gb RAM 的 DigitalOcean droplet。

另外，我注意到，当它成功启动时，日志看起来像：

liquibase                                : Successfully acquired change log lock
liquibase                                : Reading from myDataBase.DATABASECHANGELOG
liquibase                                : Successfully released change log lock

注意获取和释放锁之间的语句。我还怀疑在获取锁和读取更改日志之间存在时间问题。但不知道我是否可以增加那个时间或者我该怎么做。

更新

我不知道问题的根源，但是在将 liquibase-core 更新到 v3.7.0 后，所有应用都正常启动了

更新 2

关于之前的更新，我测试的不是问题解决，只是频率降低了。但它已经发生了

重要更新 3

经过一番挖掘，我意识到在发生这种情况的同时，团队正在使用 DB Connection Pool。 application.properties 文件包含以下内容：

spring.datasource.tomcat.initial-size=5
spring.datasource.tomcat.max-wait=20000
spring.datasource.tomcat.max-active=5
spring.datasource.tomcat.max-idle=5
spring.datasource.tomcat.min-idle=5
spring.datasource.tomcat.default-auto-commit=true

遗憾的是，我对 DB Pool 了解不多。但引起我注意的是关于auto-commit 的最后一行。上次弹出此错误。我禁用了所有这些行，应用程序开始正常。我不知道这是否只是巧合。

非常感谢！

更新 4

我又回到了原点......我不知道如何解决这个问题，任何线索都会被欣赏

更新 5

我将 mysql-connector-java 更新到 v8.0.15。我的服务器有 MySQL v5.6.33。我仍然有这个问题，现在我无法重新启动我的应用程序。

经过上述更改，现在异常以：

结束

The last packet successfully received from the server was 10,036 milliseconds ago.  The last packet sent successfully to the server was 10,036 milliseconds ago.
.
.
.
Caused by: java.io.IOException: Socket is closed
    at com.mysql.cj.protocol.AbstractSocketConnection.getMysqlInput(AbstractSocketConnection.java:72) ~[mysql-connector-java-8.0.15.jar!/:8.0.15]
    at com.mysql.cj.protocol.a.NativeProtocol.clearInputStream(NativeProtocol.java:833) ~[mysql-connector-java-8.0.15.jar!/:8.0.15]
    ... 92 common frames omitted

更新 6 - 临时解决方案

我决定在我的项目中禁用 liquibase，方法是在application.properties 中设置liquibase.enabled=false。现在我可以随时启动/停止/重新启动应用程序，没有任何问题。由于我只使用 liquibase 来维护数据库，并且我所做的更改被执行（问题是释放锁时），我将启用 Liquibase 只是为了更新架构，然后禁用它来运行应用程序

更新 7 - 我想我已经解决了

我不停地停止和启动应用程序，每次我都收到Socket is closed 所以我开始思考时间问题......从抛出的异常中我注意到每次它说那：

从服务器成功接收到的最后一个数据包是在 xxxx 毫秒前。

我在几毫秒前得到的最小值是 10.085 并且偶然我有一些相同应用程序的日志，当时这个问题从未弹出。从这些日志语句中，我测量了获取更改日志锁和释放它之间的时间。令我惊讶的是，它大约是 9 秒，而且从未超过此时间。

所以我登录到mysql 控制台并发出：

show variables LIKE '%timeout%';

这给了我定义的超时列表。 connect_timeout 是最小的，设置为 10 秒。一定是这样的。

我用谷歌搜索了如何设置该值。我尝试创建一个文件/etc/my.cnf 并添加到它：

[mysqld]
connect_timeout=20

然后重启mysql：

sudo /etc/init.d/mysql restart

但是当我重新登录到 mysql 控制台时，该值仍然是 10。所以在 mysql 控制台中我发出了另一个命令：

SET GLOBAL connect_timeout=20;

而且值也更新了（不知道重启后会不会持续）

我再次重新启动 mysql 并且...瞧！现在应用程序在启用 liquibase 的情况下正常启动。我很高兴！ :-)

Answer 1

我们使用的是 MySQL 8.0.19。对我来说，这只是一个曾经失败的查询，但 Caused by: java.io.IOException: Socket is closed 除外。

发现对于 MySQL 8.0.19，有一个错误报告与我的类似堆栈跟踪 - https://bugs.mysql.com/bug.php?id=99234

将 MySQL 服务器升级到 8.0.21 后，它开始工作了！没有其他变化。

希望它对那些花费了相当长的时间来处理所选查询无法正常工作并遇到相同错误并尝试了各种其他选项的人们有所帮助。

Answer 2

我不停地停止和启动应用程序，每次我都收到Socket is closed 所以我开始思考时间问题......从抛出的异常中我注意到每次它说那：

从服务器成功接收到的最后一个数据包是在 xxxx 毫秒前。

我在几毫秒前得到的最小值是 10.085 并且偶然我有一些相同应用程序的日志，当时这个问题从未弹出。从这些日志语句中，我测量了获取更改日志锁和释放它之间的时间。令我惊讶的是，它大约是 9 秒，而且从未超过此时间。

所以我登录到 mysql 控制台并发出：

show variables LIKE '%timeout%';

这给了我定义的超时列表。 connect_timeout 是最小的，设置为 10 秒。一定是这样的。

我用谷歌搜索了如何设置该值。我尝试创建一个文件 /etc/my.cnf 并添加到它：

[mysqld]
connect_timeout=20

然后重启mysql：

sudo /etc/init.d/mysql restart

但是当我重新登录到 mysql 控制台时，该值仍然是 10。所以在 mysql 控制台中我发出了另一个命令：

SET GLOBAL connect_timeout=20;

并且该值已更新（我不知道这是否会在服务器完全重启后仍然存在）

我再次重新启动 mysql 并且...瞧！现在应用程序在启用 liquibase 的情况下正常启动。我很高兴！ :-)

Answer 3

你解决了吗？

我有一个类似的问题，并通过强制 Liquibase 以同步模式执行来解决它。 您的 Spring Boot 应用程序是由 jhipster 生成的吗？如果是这样，请查看 DatabaseConfiguration 并从 AsyncSpringLiquibase 更改为 SpringLiquibase