记一次mysql线上问题排查

xindoo

发布于 2021-01-22 11:45:07

9870

发布于 2021-01-22 11:45:07

　　背景是这样的，我们有个系统每天都会调起多个定时任务，首先quartz每分钟会调起一次检查时间的任务，如果发现时间到达设定的任务执行时间，java代码会向数据库里写入一条记录，然后有另外一个系统就会根据这条记录执行相应的任务，有天有同事反馈说有条定时任务没执行。。　　后来排查发现，这条定时任务从5月多开始，偶尔才执行一次，不执行的时候都是这条记录写不到库里，将这条定时任务执行时间调后之后就可以正常执行了，但是又有另外一条定时任务不执行了……啊啊啊这是什么鬼bug。峰回路转，我在日志里发现了这样一条记录。

### Error querying database.  Cause: org.apache.ibatis.transaction.TransactionException: Error configuring AutoCommit.  Your driver may not support getAutoCommit() or setAutoCommit(). Requested setting: false.  Cause: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: The last packet successfully received from the server was 40,655,368 milliseconds ago.  The last packet sent successfully to the server was 40,655,368 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.
### The error may exist in xxxx/dao/MybatisDBOperation.java (best guess)
### The error may involve xxx.dao.MybatisDBOperation.getTemplateIdById
### The error occurred while executing a query
### Cause: org.apache.ibatis.transaction.TransactionException: Error configuring AutoCommit.  Your driver may not support getAutoCommit() or setAutoCommit(). Requested setting: false.  Cause: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: The last packet successfully received from the server was 40,655,368 milliseconds ago.  The last packet sent successfully to the server was 40,655,368 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.

　　原来是第一次写库会写失败，google这段报错，发现网上有人说mysql端会释放超过一段时间的空闲链接，默认8小时。如果你拿着已经被mysql释放的链接去读写库，肯定会失败。联系我司dba后发现，如果java端连接池没管理好，确实会出现这个问题。而且这样可以完美解释为啥有时候第一次写库会成功，我看了下第一条定时任务成功那几天，都是有人在20点后操作过系统（我定时任务4点开始执行），这样connection刚好没有超时，可以接着用。　　问题的原因找到了，其实就是我用了mybatis，mybatis自己维护了一个连接池，但是没对连接池里的链接有效性做校验。

解决方案一

　　把mysql段的超时时间设大，从默认的8小时设置到24小时。因为我们的系统至少每天都会有读写mysql的操作，24小时肯定能覆盖的一个完整的读写库周期。但其实这种方法治标不治本。

解决方案二

　　写个定时任务定期读一次数据库，保证mybatis维护的connection都是有效的，这是一个很low的方案，但确实有效啊。

解决方案三

　　更方案二差不多，都是定时查库，但是不是写定时任务，而是又mybatis自己定时去查。所以需要在mybatis配置里加上以下几行配置

//开启mybatis的poolping功能
<property name="poolPingEnabled" value="true"/>
//select 1其实是定期执行的sql
<property name="poolPingQuery" value="select 1"/>
//表示无数据库操作3600000ms（1h）执行一次poolping
<property name="poolPingConnectionsNotUsedFor" value="3600000"/>

　　看了下同事c3p0配置，发现c3p0中有周期性对连接池中链接有效性做校验的功能，对mybatis不是特别了解，不知道mybatis有没有类似的功能（估计肯定会有）。