连接 com.mysql.cj.jdbc.ConnectionImpl@ee48bb3 因 SQLSTATE(08S01)、ErrorCode(0) 标记为损坏

Posted 2023-02-26

【中文标题】连接 com.mysql.cj.jdbc.ConnectionImpl@ee48bb3 因 SQLSTATE(08S01)、ErrorCode(0) 标记为损坏

【英文标题】：Connection com.mysql.cj.jdbc.ConnectionImpl@ee48bb3 marked as broken because of SQLSTATE(08S01), ErrorCode(0)

【发布时间】：2021-11-22 10:19:38

【问题描述】：

我正在寻找相关的问题，但并不完全相似，因此发布了这个问题 说明：此警告（SQLSTATE（08S01），ErrorCode（0））间歇性地出现，此后在springboot java代码中出现异常，同时从使用springboot jparepository的数据库中获取（选择查询）记录概念。

下面是WARN的异常跟踪

com.zaxxer.hikari.pool.ProxyConnection:::ProxyConnection.java:::checkException:::182:::HikariPool-1 - Connection com.mysql.cj.jdbc.ConnectionImpl@ee48bb3 marked as broken because of SQLSTATE(08S01), ErrorCode(0)
com.mysql.cj.jdbc.exceptions.CommunicationsException: The last packet successfully received from the server was 949,021 milliseconds ago. The last packet sent successfully to the server was 949,022 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
at com.mysql.cj.jdbc.exceptions.SQLError.createCommunicationsException(SQLError.java:174)
at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:64)
at com.mysql.cj.jdbc.ConnectionImpl.setReadOnlyInternal(ConnectionImpl.java:2161)
at com.mysql.cj.jdbc.ConnectionImpl.setReadOnly(ConnectionImpl.java:2145)
at com.zaxxer.hikari.pool.ProxyConnection.setReadOnly(ProxyConnection.java:423)
at com.zaxxer.hikari.pool.HikariProxyConnection.setReadOnly(HikariProxyConnection.ja

在上述 WARN 之后，服务代码由于使用 springboot jparepository 的以下异常而失败

:::D3931305D3A84D82AACF29594A0432C8::::::Monitor:::com.zaxxer.hikari.pool.ProxyLeakTask:::ProxyLeakTask.java:::cancel:::91:::Previously reported leaked connection com.mysql.cj.jdbc.ConnectionImpl@ee48bb3 on thread http-nio-9090-exec-69 was returned to the pool (unleaked)
2021-09-07 **21:39:52,100:::ERROR:::D3931305D3A84D82AACF29594A0432C8:::saveRunConfigurations:::388:::Could not open JPA EntityManager for transaction; nested exception is org.hibernate.TransactionException: JDBC begin transaction failed:
org.springframework.transaction.CannotCreateTransactionException: Could not open JPA EntityManager for transaction; nested exception is org.hibernate.TransactionException: JDBC begin transaction failed:**
at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:448)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.startTransaction(AbstractPlatformTransactionManager.java:400)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:373)
at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:572)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:360)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:118)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:139)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
.
.

下面是 mysql db 的 HikariCp 配置和超时值

spring.datasource.hikari.maximumPoolSize=150
spring.datasource.hikari.minimumIdle=20
spring.datasource.hikari.idleTimeout=600000
spring.datasource.hikari.connectionTimeout=900000
spring.datasource.hikari.maxLifetime=1000000
spring.datasource.hikari.validationTimeout=30000
spring.datasource.hikari.connectionTestQuery=SELECT 1
spring.datasource.hikari.leakDetectionThreshold=90000

---

 MySQL [(none)]> SHOW GLOBAL VARIABLES LIKE "%wait%";
+---------------------------------------------------+----------+
| Variable_name | Value |
+---------------------------------------------------+----------+
| innodb_fatal_semaphore_wait_threshold | 600 |
| innodb_lock_wait_timeout | 50 |
| innodb_spin_wait_delay | 6 |
| lock_wait_timeout | 31536000 |
| performance_schema_events_waits_history_long_size | 10000 |
| performance_schema_events_waits_history_size | 10 |
| shutdown_wait_connection_timeout | 500 |
| thread_pool_batch_wait_timeout | 10000 |
| wait_timeout | 180 |


MySQL [(none)]> SHOW VARIABLES LIKE "%timeout%";
+----------------------------------+----------+
| Variable_name | Value |
+----------------------------------+----------+
| connect_timeout | 10 |
| delayed_insert_timeout | 300 |
| have_statement_timeout | YES |
| innodb_flush_log_at_timeout | 1 |
| innodb_lock_wait_timeout | 50 |
| innodb_rollback_on_timeout | OFF |
| interactive_timeout | 28800 |
| lock_wait_timeout | 31536000 |
| net_read_timeout | 120 |
| net_write_timeout | 240 |
| rpl_stop_slave_timeout | 31536000 |
| shutdown_wait_connection_timeout | 500 |
| slave_net_timeout | 60 |
| tcp_linger_timeout | 10 |
| thread_pool_batch_wait_timeout | 10000 |\
| wait_timeout | 28800 | 

由于问题出在 PROD env 上，所以我必须在 Lower env 上重现该问题才能找到准确的 RCA 因此

尝试使用相同的配置，但仍然无法在较低的环境中重现 起初我认为这是由于 wait_timeout 的值较低，因此尝试将 wait_timeout 增加到 28800 仍然没有重现 尝试在较低的环境中增加 Mysql 的负载 可能是由于防火墙限制或其他原因，但我不知道要检查什么 尝试降低 spring.datasource.hikari.maxLifetime=100000 的值

这将有助于找到此问题的确切原因以及如何重现此问题的建议

【参考方案1】：

似乎您在服务器上配置了某种空闲连接超时。您应该能够通过将连接池配置为每 X 秒执行一次连接验证查询来解决这个问题。查看文档，看起来 keepaliveTime 是您应该设置的设置，例如300000（5 分钟，毫秒）：https://github.com/brettwooldridge/HikariCP