今天发现consul上的A服务处于failed状态,幸运的是服务部署了两份,以预防单点故障,做负载均衡,连忙查看http://ip:port/health输出,内容如下:
{
"status": "DOWN",
"diskSpace": {
"status": "UP",
"total":888888,
"free":666666,
"threshold":123456
},
"redis": {
"status": "UP",
"version": "2.x.x"
},
"db": {
"status": "DOWN",
"aDbDataSource": {
"status": "UP",
"database": "MySQL",
"hello": 1
},
"bDbDataSource": {
"status": "UP",
"database": "MySQL",
"hello": 1
},
"cDbDataSource": {
"status": "DOWN",
"error": "org.springframework.dao.DataAccessResourceFailureException: ConnectionCallback; SQL []; No operations allowed after connection closed.; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed."
}
}
由于是多数据源配置,consul只要检测到一个数据源连接有问题,就会标记该应用服务为failed状态,这比较严格,或许可以做改造,但有一定道理,因此,暂不做改动,直接从根子上找原因:
No operations allowed after connection closed。
这个异常是偶发的,过个几天发生一次,但其他服务没发生过这类问题,服务的多数据源的配置方式也是一样的。这类bug很难一下子调试解决,我遍历了相关代码和配置,感觉需要从数据源的配置入手。
原来的多个数据源配置很简单:
db.aDbDataSource.type=org.apache.commons.dbcp.BasicDataSource
db.aDbDataSource.driver-class-name=com.mysql.jdbc.Driver
db.aDbDataSource.url=jdbc:mysql://ip:port/aDb
db.aDbDataSource.username=drjava
db.aDbDataSource.password=123456
db.bDbDataSource.type=org.apache.commons.dbcp.BasicDataSource
db.bDbDataSource.driver-class-name=com.mysql.jdbc.Driver
db.bDbDataSource.url=jdbc:mysql://ip:port/bDb
db.bDbDataSource.username=drjava
db.bDbDataSource.password=123456
db.cDbDataSource.type=org.apache.commons.dbcp.BasicDataSource
db.cDbDataSource.driver-class-name=com.mysql.jdbc.Driver
db.cDbDataSource.url=jdbc:mysql://ip:port/cDb
db.cDbDataSource.username=drjava
db.cDbDataSource.password=123456
数据库连接池用的是dbcp,从官网上可知,连接池还有很多配置参数:
http://commons.apache.org/proper/commons-dbcp/configuration.html
到底是哪些参数的缺失,导致了“No operations allowed after connection closed”错误呢?
首先这是一个无法重现的错误,无法重现的错误,通常是一个初始化问题,或者是与时间有关问题,这让人联想到了经典的mysql8小时重连问题: 当一个连接的空闲时间超过8小时后,MySQL 就会断开该连接,而dbcp 连接池则以为该被断开的连接依然有效。如果此时客户端向dbcp连接池请求连接,连接池就会把已经失效的连接返回给客户端,客户端在使用该失效连接的时候即抛出异常。
解决这个问题,涉及到以下参数:
参数 | 默认值 | 描述 |
---|---|---|
validationQuery | SQL查询 | 用来验证从连接池取出的连接,在将连接返回给调用者之前.如果指定,则查询必须是一个SQL SELECT并且必须返回至少一行记录 |
testWhileIdle | false | 指明连接是否被空闲连接回收器(如果有)进行检验.如果检测失败,则连接将被从池中去除. |
timeBetweenEvictionRunsMillis | -1 | 在空闲连接回收器线程运行期间休眠的时间值,以毫秒为单位. 如果设置为非正数,则不运行空闲连接回收器线程 |
默认空闲连接回收器是不运行的,因此参数重新设置如下:
db.aDbDataSource.type=org.apache.commons.dbcp.BasicDataSource
db.aDbDataSource.driver-class-name=com.mysql.jdbc.Driver
db.aDbDataSource.url=jdbc:mysql://ip:port/aDb
db.aDbDataSource.username=drjava
db.aDbDataSource.password=123456
db.aDbDataSource.validation-query=SELECT 1
db.aDbDataSource.test-while-idle=true
db.aDbDataSource.time-between-eviction-runs-millis=15000
db.bDbDataSource.type=org.apache.commons.dbcp.BasicDataSource
db.bDbDataSource.driver-class-name=com.mysql.jdbc.Driver
db.bDbDataSource.url=jdbc:mysql://ip:port/bDb
db.bDbDataSource.username=drjava
db.bDbDataSource.password=123456
db.bDbDataSource.validation-query=SELECT 1
db.bDbDataSource.test-while-idle=true
db.bDbDataSource.time-between-eviction-runs-millis=15000
db.cDbDataSource.type=org.apache.commons.dbcp.BasicDataSource
db.cDbDataSource.driver-class-name=com.mysql.jdbc.Driver
db.cDbDataSource.url=jdbc:mysql://ip:port/cDb
db.cDbDataSource.username=drjava
db.cDbDataSource.password=123456
db.cDbDataSource.validation-query=SELECT 1
db.cDbDataSource.test-while-idle=true
db.cDbDataSource.time-between-eviction-runs-millis=15000
由于第三方框架和组件导致的系统级偶发问题,除非对底层有比较全面深入的了解并能快速定位相关代码和问题,否则就需要对这种尝试性的解决bug方案的效果进行长期监控观察,有时候,某个bug不是因为一个缺陷引入的,而是多个缺陷同时引入,你解决了一个点不代表问题就彻底解决了。
还有一些问题从代码层就可以直接发现,但总少不了寻寻觅觅的过程,比如曾经碰到过一个拦截器失效问题。和其他服务一样,相关的注解都已经放在相应的方法上了,从相似服务B的代码形状上比较,没有发现什么问题,由于拦截器注解信息是在启动的时候被读取使用的,因此,需要了解框架底层原理,观察启动过程来判断在添加拦截器的过程中缺失了什么,失效问题是可重现问题,因此它比前面那个问题更容易发现缺陷。
找到添加拦截器的代码,直接发现原来父类的方法拦截器注册方法被overwrite了,git中show history,发现确实有该项变动:
@Override
public void addInterceptors(Registry registry) {
registry.addInterceptor(new BInterceptor());
}
此时,BInterceptor是添加了,但原来AInterceptor的添加方法却没有执行,直接修复如下:
@Override
public void addInterceptors(Registry registry) {
super.addInterceptors(registry);
registry.addInterceptor(new BInterceptor());
}
众里寻她千百度,那bug却在灯火阑珊处,或许bug才是程序员最费心费力的情人,有时候变幻莫测,有时候直接而致命,对此,我们该如何调试应对呢?
1、首先,不要慌,java开发多年以来,我还从未碰到过解决不了的bug,而且bug是必须解决的,特别是线上严重bug,连夜通宵也要搞定,这时候,沉着冷静应对很重要。
2、调试过程中最难的是寻找bug的过程,它很可能是一次烧脑的迷宫游戏。要走出迷宫,你不能凭着猜测乱走一通,需要标记点什么,这就是日志的作用,最好在测试上线前把日志打全,这样在测试或上线的时候就能根据日志定位到相关问题,如果没有相关日志记录或者记录不全,这你就要搜集相关数据,让bug在测试环境重现。bug被记录或可重现是调试工作成功的第一步,试想前面那两个例子,如果没有那行No operations allowed after connection closed,或者拦截器时而有效,时而失效,那调试工作将会难上十倍不止。
3、根据日志记录,阅读相关代码,假设问题最有可能发生的原因,据此进行修正,再测试判断假设是否正确,一般一个有能力的java程序员,他设立的假设十有八九都是事实,如果在验证时问题依然出现,这很有可能是个有多重缺陷引入的bug。在不断验证的过程中,缩小测试范围,一定能找出问题所在。
4、有空多阅读框架源码,了解底层原理,自己写的业务代码bug在手,就像走迷宫有了大略的地图,而像上面那个连接关闭问题,涉及到第三方的代码和原理,如果自身不熟悉,需要验证的次数可能就会多一些。所以平时多了解常用组件的原理和源码还是很有帮助的。