MySQL数据库连接池泄露导致MySQL Server超时关闭连接
前言
最近做项目，发现老项目出现xxx，这个错误其实很简单，出现在MySQL数据库Server端对长时间没有使用的client连接执行清楚处理，因为是druid数据库，且在github也出现这样的issue：The last packet successfully received from the server was 6,011 milliseconds ago. The last packet sent successfully to the server was 6,011 milliseconds ago.，所以怀疑是不是druid配置的问题，毕竟连接池会定时的检查连接，但是实际排查发现不是那么回事，是连接池泄露了，只不过并发不大，表现为{conn-10002} discard错误而已。
准备
按照笔者上次的文章mybatis plus相同Id与xml配置错误时，mybatis plus解决逻辑_mybatis plus xml文件查询id名字相同-CSDN博客
准备数据库，且通过开启root权限
demo
demo简单写一下，实际项目肯定复杂很多
<dependencies>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-web</artifactId>
<version>2.7.17</version>
</dependency>
<dependency>
<groupId>com.alibaba</groupId>
<artifactId>druid-spring-boot-starter</artifactId>
<version>1.2.22</version>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-jdbc</artifactId>
<version>2.7.17</version>
</dependency>
<dependency>
<groupId>org.mybatis.spring.boot</groupId>
<artifactId>mybatis-spring-boot-starter</artifactId>
<version>2.3.2</version>
</dependency>
<dependency>
<groupId>mysql</groupId>
<artifactId>mysql-connector-java</artifactId>
<version>8.0.33</version>
</dependency>
</dependencies>写一个main controller dao
@SpringBootApplication
@MapperScan("org.example.druid.demo.dao")
public class DruidMain {
public static void main(String[] args) {
SpringApplication.run(DruidMain.class, args);
}
}
@RestController
public class DemoController {
@Autowired
private UserDao userDao;
@RequestMapping(value = "/demo", method = RequestMethod.GET)
public String demo(){
int num = userDao.updateUser();
return "{\"update\" : " + num + "}";
}
}
@Mapper
public interface UserDao {
@Update("update User set age = 30 where id = 1")
int updateUser();
}配置文件
spring.datasource.druid.url= jdbc:mysql://127.0.0.1:3306/demo?useUnicode=true&characterEncoding=UTF-8&allowMultiQueries=true&autoReconnect=true&useSSL=false&serverTimezone=Asia/Shanghai
spring.datasource.druid.username= root
spring.datasource.druid.password= 123456i
spring.datasource.druid.driver-class-name= com.mysql.cj.jdbc.Driver
spring.datasource.druid.initialSize=1
spring.datasource.druid.minIdle=1
spring.datasource.druid.maxActive=2
spring.datasource.druid.maxWait=20000
spring.datasource.druid.timeBetweenEvictionRunsMillis=1000
spring.datasource.druid.minEvictableIdleTimeMillis=30000
spring.datasource.druid.validationQuery=SELECT 1
spring.datasource.druid.validationQueryTimeout=1
spring.datasource.druid.testOnBorrow=false
spring.datasource.druid.testOnReturn=false
spring.datasource.druid.testWhileIdle=true
spring.datasource.druid.keepAlive=true
spring.datasource.druid.socketTimeout=6000
spring.datasource.druid.poolPreparedStatements=true访问 http://localhost:8080/demo
这一步实际上没什么问题，但是如果涉及编程式事务，那么可能出现代码逻辑漏洞
@Configuration
public class DemoConfiguration {
@Bean
public PlatformTransactionManager initPlatformTransactionManager(DruidDataSource dataSource) {
return new DataSourceTransactionManager(dataSource);
}
}
@RestController
public class DemoController {
@Autowired
private UserDao userDao;
@Autowired
private PlatformTransactionManager transactionManager;
@RequestMapping(value = "/demo", method = RequestMethod.GET)
public String demo(){
TransactionStatus transactionStatus = transactionManager.getTransaction(new DefaultTransactionDefinition());
int num = 0;
try {
num = userDao.updateUser();
transactionManager.commit(transactionStatus);
} catch (TransactionException e) {
transactionManager.rollback(transactionStatus);
}
return "{\"update\" : " + num + "}";
}
}这样写也没问题，但是，如果我们在事务拿到后，因为一些逻辑return呢
设置MySQL的超时时间
通过临时设置或者永久设置，--来自bing AI搜索
比如我们临时设置1分钟试试，问题复现
排查过程
The last packet successfully received from the server was 6,006 milliseconds ago. The last packet sent successfully to the server was 6,006 milliseconds ago.
2025-02-24 22:44:02.967 ERROR 2485 --- [nio-8080-exec-1] c.a.druid.pool.DruidPooledStatement : CommunicationsException, druid version 1.2.22, jdbcUrl : jdbc:mysql://127.0.0.1:3306/demo?useUnicode=true&characterEncoding=UTF-8&allowMultiQueries=true&autoReconnect=true&useSSL=false&serverTimezone=Asia/Shanghai, testWhileIdle true, idle millis 6017, minIdle 1, poolingCount 0, timeBetweenEvictionRunsMillis 1000, lastValidIdleMillis 6017, driver com.mysql.cj.jdbc.Driver, exceptionSorter com.alibaba.druid.pool.vendor.MySqlExceptionSorter
2025-02-24 22:44:02.972 ERROR 2485 --- [nio-8080-exec-1] com.alibaba.druid.pool.DruidDataSource : {conn-10002} discard
com.mysql.cj.jdbc.exceptions.CommunicationsException: Communications link failure
The last packet successfully received from the server was 6,011 milliseconds ago. The last packet sent successfully to the server was 6,011 milliseconds ago.
at com.mysql.cj.jdbc.exceptions.SQLError.createCommunicationsException(SQLError.java:175) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:64) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.jdbc.ClientPreparedStatement.executeInternal(ClientPreparedStatement.java:916) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.jdbc.ClientPreparedStatement.execute(ClientPreparedStatement.java:354) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.alibaba.druid.pool.DruidPooledPreparedStatement.execute(DruidPooledPreparedStatement.java:483) ~[druid-1.2.22.jar:na]
at org.apache.ibatis.executor.statement.PreparedStatementHandler.update(PreparedStatementHandler.java:48) [mybatis-3.5.14.jar:3.5.14]
at org.apache.ibatis.executor.statement.RoutingStatementHandler.update(RoutingStatementHandler.java:75) [mybatis-3.5.14.jar:3.5.14]
at org.apache.ibatis.executor.SimpleExecutor.doUpdate(SimpleExecutor.java:50) [mybatis-3.5.14.jar:3.5.14]
at org.apache.ibatis.executor.BaseExecutor.update(BaseExecutor.java:117) [mybatis-3.5.14.jar:3.5.14]
at org.apache.ibatis.executor.CachingExecutor.update(CachingExecutor.java:76) [mybatis-3.5.14.jar:3.5.14]
at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:197) [mybatis-3.5.14.jar:3.5.14]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_431]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_431]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_431]
at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_431]
at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:425) [mybatis-spring-2.1.2.jar:2.1.2]
at com.sun.proxy.$Proxy56.update(Unknown Source) [na:na]
at org.mybatis.spring.SqlSessionTemplate.update(SqlSessionTemplate.java:288) [mybatis-spring-2.1.2.jar:2.1.2]
at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:67) [mybatis-3.5.14.jar:3.5.14]
at org.apache.ibatis.binding.MapperProxy$PlainMethodInvoker.invoke(MapperProxy.java:141) [mybatis-3.5.14.jar:3.5.14]
at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:86) [mybatis-3.5.14.jar:3.5.14]
at com.sun.proxy.$Proxy59.updateUser(Unknown Source) [na:na]
at org.example.druid.demo.controller.DemoController.demo(DemoController.java:27) [classes/:na]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_431]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_431]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_431]
at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_431]
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205) [spring-web-5.3.30.jar:5.3.30]
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:150) [spring-web-5.3.30.jar:5.3.30]
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:117) [spring-webmvc-5.3.30.jar:5.3.30]
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:895) [spring-webmvc-5.3.30.jar:5.3.30]
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:808) [spring-webmvc-5.3.30.jar:5.3.30]
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) [spring-webmvc-5.3.30.jar:5.3.30]
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1072) [spring-webmvc-5.3.30.jar:5.3.30]
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:965) [spring-webmvc-5.3.30.jar:5.3.30]
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) [spring-webmvc-5.3.30.jar:5.3.30]
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898) [spring-webmvc-5.3.30.jar:5.3.30]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:529) [tomcat-embed-core-9.0.82.jar:4.0.FR]
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) [spring-webmvc-5.3.30.jar:5.3.30]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:623) [tomcat-embed-core-9.0.82.jar:4.0.FR]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:209) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:51) [tomcat-embed-websocket-9.0.82.jar:9.0.82]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) [spring-web-5.3.30.jar:5.3.30]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117) [spring-web-5.3.30.jar:5.3.30]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) [spring-web-5.3.30.jar:5.3.30]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117) [spring-web-5.3.30.jar:5.3.30]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) [spring-web-5.3.30.jar:5.3.30]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117) [spring-web-5.3.30.jar:5.3.30]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:168) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:90) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:481) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:130) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:93) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:390) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:63) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:928) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1794) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659) [tomcat-embed-core-9.0.82.jar:9.0.82]
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-embed-core-9.0.82.jar:9.0.82]
at java.lang.Thread.run(Thread.java:750) [na:1.8.0_431]
Caused by: com.mysql.cj.exceptions.CJCommunicationsException: Communications link failure
The last packet successfully received from the server was 6,011 milliseconds ago. The last packet sent successfully to the server was 6,011 milliseconds ago.
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[na:1.8.0_431]
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[na:1.8.0_431]
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:1.8.0_431]
at java.lang.reflect.Constructor.newInstance(Constructor.java:423) ~[na:1.8.0_431]
at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:62) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:105) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:150) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.exceptions.ExceptionFactory.createCommunicationsException(ExceptionFactory.java:166) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.protocol.a.NativeProtocol.readMessage(NativeProtocol.java:582) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.protocol.a.NativeProtocol.checkErrorMessage(NativeProtocol.java:762) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.protocol.a.NativeProtocol.sendCommand(NativeProtocol.java:701) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.protocol.a.NativeProtocol.sendQueryPacket(NativeProtocol.java:1052) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.NativeSession.execSQL(NativeSession.java:657) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.jdbc.ClientPreparedStatement.executeInternal(ClientPreparedStatement.java:893) ~[mysql-connector-j-8.0.33.jar:8.0.33]
... 70 common frames omitted
Caused by: java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method) ~[na:1.8.0_431]
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) ~[na:1.8.0_431]
at java.net.SocketInputStream.read(SocketInputStream.java:171) ~[na:1.8.0_431]
at java.net.SocketInputStream.read(SocketInputStream.java:141) ~[na:1.8.0_431]
at com.mysql.cj.protocol.ReadAheadInputStream.fill(ReadAheadInputStream.java:107) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.protocol.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:150) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.protocol.ReadAheadInputStream.read(ReadAheadInputStream.java:180) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at java.io.FilterInputStream.read(FilterInputStream.java:133) ~[na:1.8.0_431]
at com.mysql.cj.protocol.FullReadInputStream.readFully(FullReadInputStream.java:64) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.protocol.a.SimplePacketReader.readHeaderLocal(SimplePacketReader.java:81) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.protocol.a.SimplePacketReader.readHeader(SimplePacketReader.java:63) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.protocol.a.SimplePacketReader.readHeader(SimplePacketReader.java:45) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.protocol.a.TimeTrackingPacketReader.readHeader(TimeTrackingPacketReader.java:52) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.protocol.a.TimeTrackingPacketReader.readHeader(TimeTrackingPacketReader.java:41) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.protocol.a.MultiPacketReader.readHeader(MultiPacketReader.java:54) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.protocol.a.MultiPacketReader.readHeader(MultiPacketReader.java:44) ~[mysql-connector-j-8.0.33.jar:8.0.33]
at com.mysql.cj.protocol.a.NativeProtocol.readMessage(NativeProtocol.java:576) ~[mysql-connector-j-8.0.33.jar:8.0.33]
... 75 common frames omitted
这个问题在github也有类似的情况，但是不一定是笔者遇到的问题：https://github.com/alibaba/druid/issues/5963
对于连接泄露可以配置泄露连接强制回收，但是这个仅在排查问题使用
removeAbandoned: true
removeAbandonedTimeoutMillis: 30000 #(以毫秒数为单位)
logAbandoned: true貌似有用，但是实际情况是占用数据库连接的线程并不一定是问题的代码逻辑，我这里仅仅写了一个controller，刚好对应上
所以排查还需要另外的思路。
解决方法
开启连接池连接的状态日志，这里以druid为例
spring.datasource.druid.filters=stat,wall,slf4j logging.level.com.alibaba.druid=TRACE
可以看到事务并没提交，连接关闭不了
当然笔者使用的MySQL版本低了点，还有缓存，再高一些版本的MySQL就删除了，毕竟命中效率比较低，还是吞吐量比较重要，还增加了查询重写插件
可以看到根本关闭不了连接，这个时候就需要安装报错的连接id搜索，相同连接ID报错前的最后一次数据库操作很可能就是出问题的连接操作，同时业务日志打印也非常重要，否则极难判断
然后判断id为10002的 正常业务是做了什么，就可以找到问题了，我这里示例Demo偷懒了，应该用另一个controller来验证
找到问题就好处理有问题的代码了。
总结
我们在写代码时，尽量还是使用框架封装的逻辑，比如连接池，比如Spring声明式事务，可以避免编程式事务在写代码时的逻辑漏洞，因为在没触发的时候很难出现，测试很多时候不充分。实际上一起写jdbc的时候还很少出现这个问题，因为那个时候会非常注意连接的回收，事务的提交逻辑，但是Spring自动管理后，这个就很少注意了，因为注解声明式事务太方便了，只有特殊时候才会自己管理事务。
另外这个问题具备隐蔽性，因为报错是MySQL驱动连接MySQL Server报超时未使用关闭连接，但是此处示例的根源却是编程式事务导致连接池泄露。