态度决定一切

0%

记一次生产异常问题排查过程

账号中心异常日志问题排查

今天上午发现调用账号中心接口异常,于是立马去线上查看日志发现了大量的异常信息,异常日志如下:

1
Error querying database.  Cause: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

于是上网查了下相关文章,给出如下解释

MySQL默认连接存活时长为28800秒,即8小时。如果在wait_timeout期间内,数据库连接(java.sql.Connection)一直处于等待状态,MySQL就将该连接关闭。此时,数据库连接池仍然合法地持有该连接,当用该连接来进行数据库操作时,就报上述错误。

查了下线上账号中心库的 wait_timeout时间为259200s=3天

确实从异常日志文件也能看到异常信息:

1
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: The last packet successfully received from the server was 1,536,593,656 milliseconds ago.  The last packet sent successfully to the server was 1,536,593,656 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.

从日志文件看出有些数据库操作正常的,有些查询是异常的,所有猜测大概是数据库连接池中部分链接其实已经断开。

其中异常日志也给出了原因和响应的解决办法:

1
or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.

方法一:
即使用autoReconnect=true来避免面这个这个问题,但是查了下配置文件中发现已经配置了此参数

1
xxxauth.datasource.url=jdbc:mysql://xxxxx?useUnicode=true&characterEncoding=UTF-8&autoReconnect=true&rewriteBatchedStatements=TRUE&useSSL=false

既然已经配置了那为什么还有这个问题,于是查了想相关文档
autoReconnect=true这个参数对 mysql5以上的版本不生效,现在公司 mysql 使用的都是5.6版本,所以这个方法不行。

方法二:
将数据库 wait_timeout调大,但是就算调大可能链接空闲等待的时间还是会超出等待时间还是不能解决实际问题。

方法三:
数据库连接池配置:testOnBorrow、testOnReturn、testWhileIdle属性,意义分别是取得、返回对象和空闲时,是否进行对象有效性检查,默认都是False关闭状态。只要都设置为True,并提供validationQuery语句即可保证数据库连接始终有效。
检查了下账号中心相关配置

账号中心是有配置但是为啥还是有这个问题?
于是 debug 了下DataSourceConfig这个类加载过程发现这么些个配置文件竟然只加载了前四项
有图有真相

xxxauth.datasource.tomcat开头的都解析不了咯。
继续看,发现如下代码

系统会在家 prefix + “.” + reflaxName的的配置信息,而这里的prefix是在类注解是这样的

1
@ConfigurationProperties(prefix = "xxxauth.datasource")

所以只会加载xxxauth.datasource.test-on-borrow这样的配置加载不到xxxauth.datasource.tomcat.test-on-borrow类似这样的配置。

将配置文件修改

1
2
3
4
5
6
7
8
9
10
11
xxxauth.datasource.driver-class-name=com.mysql.jdbc.Driver
xxxauth.datasource.test-on-borrow=true
xxxauth.datasource.test-while-idle=true
xxxauth.datasource.max-active=30
xxxauth.datasource.test-on-return=true
xxxauth.datasource.test-on-connect=true
xxxauth.datasource.initial-size=10
xxxauth.datasource.min-idle=10
xxxauth.datasource.validation-query=SELECT 1
xxxauth.datasource.validation-interval=5000
xxxauth.datasource.log-validation-errors=true

再次 debug 发现 这些配置以及加载到了