首页
学习
活动
专区
工具
TVP
发布
社区首页 >专栏 >众里寻她千百度,蓦然回首,那bug却在灯火阑珊处

众里寻她千百度,蓦然回首,那bug却在灯火阑珊处

作者头像
java达人
发布2018-01-31 12:36:12
1.2K0
发布2018-01-31 12:36:12
举报
文章被收录于专栏:java达人java达人

今天发现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在手,就像走迷宫有了大略的地图,而像上面那个连接关闭问题,涉及到第三方的代码和原理,如果自身不熟悉,需要验证的次数可能就会多一些。所以平时多了解常用组件的原理和源码还是很有帮助的。

本文参与 腾讯云自媒体分享计划,分享自微信公众号。
原始发表:2017-11-26,如有侵权请联系 cloudcommunity@tencent.com 删除

本文分享自 java达人 微信公众号,前往查看

如有侵权,请联系 cloudcommunity@tencent.com 删除。

本文参与 腾讯云自媒体分享计划  ,欢迎热爱写作的你一起参与!

评论
登录后参与评论
0 条评论
热度
最新
推荐阅读
相关产品与服务
云数据库 MySQL
腾讯云数据库 MySQL(TencentDB for MySQL)为用户提供安全可靠,性能卓越、易于维护的企业级云数据库服务。其具备6大企业级特性,包括企业级定制内核、企业级高可用、企业级高可靠、企业级安全、企业级扩展以及企业级智能运维。通过使用腾讯云数据库 MySQL,可实现分钟级别的数据库部署、弹性扩展以及全自动化的运维管理,不仅经济实惠,而且稳定可靠,易于运维。
领券
问题归档专栏文章快讯文章归档关键词归档开发者手册归档开发者手册 Section 归档