The last packet successfully received from the server was XXX milliseconds ago 问题排查

快来打我* 2023-01-24 04:30 554阅读 0赞

# 1.起因： #

在半夜执行的定时任务偶现The last packet successfully received from the server was 1,373,532 milliseconds ago问题，导致部分sql没有执行。

# 2.排查： #

2.1 查看日志：

DruidDataSource:discard connection com.mysql.cj.jdbc.exceptions.CommunicationsException: 
    Communications link failure The last packet successfully received from the server was 1,373,532 milliseconds ago. 
    The last packet sent successfully to the server was 1,373,554 milliseconds ago.

查了下，这个错误是链接失败，即druid当前使用的连接池中的线程时无效连接，mysql服务端已经把这个连接给断了，但是druid这边不知道，继续使用就报错了。

对于这个问题，看到很多帖子都说去设置mysql服务器的wait\_timeout（另外说一下wait\_timeout表示通过非交互连接，例如jdbc，interactive\_timeout表示交互式连接，通过mysql客户端连接数据库是交互式连接，通过jdbc连接数据库是非交互式连接），但是这个参数是设置空闲连接保持连接状态的最大秒数，例如：

![14430142-e1535ed5e89e0f3c.png][]

mysql监控

这里如果wait\_timeout设置为2355，那么这个sleep状态的链接再过一秒，就会被mysql客户端给断掉，所以一般druid设置的检查时间都会比这个时间短：（druid配置minEvictableIdleTimeMillis：连接保持空闲而不被驱逐的最小时间-毫秒）  
另外也会有validationQuery: SELECT 'x'，testWhileIdle: true这样的设置，用于检测链接是否有效；但是druid检查有效性有两种方法，一种是 `this.ping.invoke(conn, true, validationQueryTimeout * 1000);`用ping的方法，这样配置的validationQuery: SELECT 'x'就不会执行，所以可以在客户端启动参数加上  
`-Ddruid.mysql.usePingMethod=false`，就可以用配置的方法去验证有效性。

**但是！**我配置了以后该偶现的还是偶现，我决定看看mybatis的日志：  
logback.xml配置：

// 仅XxxxDao类输出debug日志
        <logger name="com.xxxx.xxxx.xxx.dao.XxxxDao" level="debug" additivity="false">
            <appender-ref ref="STDOUT" />
        </logger>

以下是执行日志:

[DEBUG] 2021-07-01 01:08:53.262 [Thread-3069] queryDispatch:==> Preparing: SELECT  xxxxxx like concat(?,'%')
    2021-07-01 01:08:58.826
    [DEBUG] 2021-07-01 01:08:53.262 [Thread-3069] queryDispatch:==> Parameters: XXXX(String)

这里可以比较清楚的看到准备的sql和参数，并且发送去了mysql，但是半天后返回了上述的报错，这几条日志都是同一个线程，并且这个方法用到所有的sql的连接池应该都是一个，在准备sql的日志前都有这么一句：  
`SpringManagedTransaction:JDBC Connection [com.alibaba.druid.proxy.jdbc.ConnectionProxyImpl@5c21e27f] will not be managed by Spring`  
@5c21e27f应该就是持有同一个连接的代理。

有成功时候：sql跑了30多分钟；也有提交了语句，20分钟后直接报错的，这让我觉得应该不是因为服务端设置了语句执行最大时间的设置，去看了下果然没限制时间：  
`max_execution_time 0`

因为我是半夜1：00执行，我看到这个时间有好多定时任务开始执行，就在想会不会是数据库压力的关系，看到一篇文章：

connect_timeout在获取连接阶段（authenticate）起作用，
    
    interactive_timeout和wait_timeout在连接空闲阶段（sleep）起作用，
    
    net_read_timeout和net_write_timeout在连接繁忙阶段（query）起作用。

net\_read\_timeout / net\_write\_timeout 这个参数只对TCP/IP链接有效，分别是数据库等待接收客户端发送网络包和发送网络包给客户端的超时时间，这是在Activity状态下的线程才有效的参数  
结合来看，此问题应该是在mysql返回给客户端的时候超时，然后导致连接被断。

## 现在通过更换了定时任务的执行时间，错峰执行解决了这个问题。 ##

参考:  
[https://blog.csdn.net/jiadajing267/article/details/79516989][https_blog.csdn.net_jiadajing267_article_details_79516989]  
[https://blog.csdn.net/qq\_37637196/article/details/106053558][https_blog.csdn.net_qq_37637196_article_details_106053558]

[14430142-e1535ed5e89e0f3c.png]: /images/20221119/1f62549a3fa74ead803ffd2a4e7457f5.png
[https_blog.csdn.net_jiadajing267_article_details_79516989]: https://links.jianshu.com/go?to=https%3A%2F%2Fblog.csdn.net%2Fjiadajing267%2Farticle%2Fdetails%2F79516989
[https_blog.csdn.net_qq_37637196_article_details_106053558]: https://links.jianshu.com/go?to=https%3A%2F%2Fblog.csdn.net%2Fqq_37637196%2Farticle%2Fdetails%2F106053558

发表评论取消回复

表情：

评论列表（有 0 条评论，554人围观）

还没有评论，来说两句吧...

相关阅读

相关 The last packet successfully received from the server was xxx milliseconds ago. The last packet sen

问题： Java项目启动，mysql 配置报错 The last packet successfully received from the server was 304 m

﹏ヽ暗。殇╰゛Y/ 2024年03月16日 12:30/ 0 赞/ 61 阅读

相关解决 ‘The last packet successfully received from the server was xxx milliseconds ago‘ 问题

`springboot` \+ `druid` \+ `mysql` 在查询某些比较耗时的sql会报错 com.mysql.cj.jdbc.exceptions.Co

左手的ㄟ右手/ 2023年10月10日 17:42/ 0 赞/ 151 阅读

相关 The last packet successfully received from the server was XXX milliseconds ago 问题排查

1.起因：在半夜执行的定时任务偶现The last packet successfully received from the server was 1,373,532

快来打我*/ 2023年01月24日 04:30/ 0 赞/ 555 阅读

相关 mysql连接池报错:The last packet successfully received from the server was XXXXX milliseconds ago

具体报错信息 > 0:Communications link failure The last packet successfully received > from

喜欢ヅ旅行/ 2022年12月27日 11:25/ 0 赞/ 442 阅读

相关 The last packet successfully received from the server was 4,758 milliseconds ago

The last packet successfully received from the server was 4,758 milliseconds ago. The l

太过爱你忘了你带给我的痛/ 2022年09月15日 12:51/ 0 赞/ 7 阅读

相关 The last packet successfully received from the server was 1,547,682,071 milliseconds ago. The last

MySQL 经常出现这样的错误： org.springframework.dao.DataAccessResourceFailureException: Prepar

客官°小女子只卖身不卖艺/ 2022年09月11日 06:10/ 0 赞/ 132 阅读

相关【异常】The last packet successfully received from the server was 179 milliseconds ago.

问题系统中功能批量插入，当数据量大了之后这个插入不进去了，报出异常如下 Caused by: com.mysql.jdbc.exceptions.jd

不念不忘少年蓝@/ 2022年05月30日 11:18/ 0 赞/ 594 阅读

相关 The last packet sent successfully to the server was 0 milliseconds ago.

最初百度出的大神的经验，先记录一下。但是我重启了下计算机就好使了，怕以后在遇到万一重启不好使呢，先记录一下大神经验：出现异常”The last packet sent su

我会带着你远行/ 2022年04月23日 07:36/ 0 赞/ 127 阅读

相关 The last packet successfully received from the server was 8,268,658 milliseconds ago

最近做一个小应用，启动后刚开始访问时报错，但是多点几次就好了，就没在意。应用里面有定时，分别是上午10点，11点和12点各执行一次。奇怪的是10点的定时执行的时候会报下面的错误

偏执的太偏执、/ 2022年04月03日 10:00/ 0 赞/ 474 阅读

相关连接数据库报错：The last packet successfully received from the server was 67 milliseconds ago.

今天在阿里云上安装了一个mysql数据库，然后将本地代码的连接地址直接换成阿里云的地址，没想带连接报错： ![20190416092148366.png][] 报错信息：

系统管理员/ 2021年09月18日 23:38/ 0 赞/ 286 阅读