博客
关于我
强烈建议你试试无所不能的chatGPT,快点击我
记一次异常排查过程:druid连接池抛出DataSourceDisableException
阅读量:6651 次
发布时间:2019-06-25

本文共 4549 字,大约阅读时间需要 15 分钟。

  hot3.png

先交待下项目背景,项目中有个功能是从mysql中获取数据库信息来创建数据库连接,用的连接池是druid,jar包版本是1.0.9。

1. 异常的发生

最近项目中出现了一个神奇的异常:

读取MySQL数据错误: jdbc:mysql://61.160.xxx.xxx:3306/xxx?characterEncoding=utf-8&autoReconnect=false&connectTimeout=15000&socketTimeout=60000, taskId=xxxxx, message: null

这个发生在数据库操作时,神奇之处在于:

  1. 异常偶尔会发生,同一时间的连接,有的会成功,而有的会报异常;
  2. 异常信息为null。

2. 异常抛出位置

抛出异常的代码如下:

@Overrideprotected Result
doImportData() { String url = getJdbcUrl(); String host = getHost(); int port = getPort(); String username = getUsername(); String password = getPassword(); Connection con = null; DataSource dataSource = null; try { long t1 = System.currentTimeMillis(); dataSource = DataSourceProvider.getDataSource(host, port, username, password, url, MAX_POOL_SIZE, MIN_POOL_SIZE, INITIAL_POOL_SZIE); con = dataSource.getConnection(); long getConnectionCostTime = System.currentTimeMillis() - t1; logger.info("taskId=" + task.getTaskId() + ",getConnection()=" + getConnectionCostTime + "ms"); ··· } catch (SQLException e) { logger.error("读取MySQL数据错误: " + url + ", taskId=" + task.getTaskId() + ", message: " + e.getMessage()); ··· } finally { if (con != null) { try { con.close(); } catch (SQLException e) { // ignore } } } return result;}

3. 异常分析与推断

3.1 从异常信息来看,可以得出如下判断:

  1. 异常是由SQLException捕获到的,因此代码运行到了try代码块;
  2. 异常的message是null,很容易联想到抛出的是NullPointerException,但SQLException捕获不到NPE,因此不会是NPE;
  3. 从运行日志排查,没有运行到代码 logger.info("taskId=" + task.getTaskId() + ",getConnection()=" + getConnectionCostTime + "ms");

3.2 从以上信息来排除,发现可疑问代码只有三行了:

long t1 = System.currentTimeMillis();dataSource = DataSourceProvider.getDataSource(host, port, username, 		password, url, MAX_POOL_SIZE, MIN_POOL_SIZE, INITIAL_POOL_SZIE);con = dataSource.getConnection();

3.3 再看看方法的具体实现,发现异常的抛出是在

con = dataSource.getConnection();// 项目中用的是druid连接池// com.alibaba.druid.pool.DruidDataSourcepublic DruidPooledConnection getConnection() throws SQLException

在方法里往下找下去,没找到什么有用的信息,终于还是放弃了...

4.峰回跳转-打印异常堆栈信息

项目中的异常还在报,好想假装异常没发生...嗯,还是继续排查吧。

接下来,刚好碰上项目发布,果断修改了打印异常信息的方式,这次直接打出异常堆栈而不仅仅是message了:

logger.error("读取MySQL数据错误: " + url + ", taskId=" + task.getTaskId() 		+ ", message: " + ExceptionUtils.getStackTrace(e));

ExceptionUtils是apache commmons包提供的类,封装了异常相关的操作方法。

等待着,等待着,异常信息终于来了:

[游戏数据采集异常]读取MySQL数据错误: jdbc:mysql://61.160.xxx.xxx:3306/xxx?characterEncoding=utf-8&autoReconnect=false&connectTimeout=15000&socketTimeout=60000, taskId=xxxxxx, message: com.alibaba.druid.pool.DataSourceDisableException    at com.alibaba.druid.pool.DruidDataSource.pollLast(DruidDataSource.java:1482)    at com.alibaba.druid.pool.DruidDataSource.getConnectionInternal(DruidDataSource.java:1074)    at com.alibaba.druid.pool.DruidDataSource.getConnectionDirect(DruidDataSource.java:941)    at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:921)    at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:911)    at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:98)	···

5.异常排查

从异常堆栈信息来看,报错的异常是DataSourceDisableException,代码是DruidDataSource.java的1482行。

5.1 DataSourceDisableException异常:

首先来认识下DataSourceDisableException异常:

public class DataSourceDisableException extends SQLException

这个类继承了SQLException,所以代码中能catch到。

5.2 异常相关代码

再看看异常抛出的的位置:

if (!enable) {	connectErrorCount.incrementAndGet();	throw new DataSourceDisableException();}

发现两个问题:

  1. if块里的代码执行了,说明enable为false了,只需找到导致enable为false的地方就可以查到异常原因了;
  2. 抛出异常时,没有指定任何的异常信息,如new DataSourceDisableException('出现异常了'),这就导致了异常信息是null。

情况已经很明显了,接下来只要找到导致enable为false的位置就行了。

通过搜索得知,enable初始化时为true,对外暴露了setEnable(boolean)方法:

public void setEnable(boolean enable) {	···	this.enable = enable;	···}

同时在close()方法中明确地将enable设置成了false:

public void close() {	···	enable = false;	···}

5.3 得出结论

进一步排查,发现setEnable()方法没有地方调用,而close()方法有地访问在调用。对照代码逻辑,得出的结论如下:

代码里有这样一个操作:数据库连接时,以host、port为key,从缓存中获取dataSource,若username、password与连接里的不一致时,就会关闭获取到的dataSource,并以新的username、password创建新的dataSource.但是,当同一个host、port有多个账号跟密码时,这种操作会有问题,原因是多线程情况下,关闭的dataSource可以会被其他线程获取到。

5.4 问题的解决

知道了问题的所在,解决办法就很简单了:保证dataSource只能被一个线程获取,这里用的缓存数据结构是ConcurrentHashMap,获取数据源时,用的是操作是get()方法,这里只要将操作改成remove(),并且使用完之后,再将dataSourceput()方法返还就可以了。

6.反思

这个异常困扰了我两天,原因与解决方法并不复杂,难点在于异常信息。对于异常信息为null的情况,实在无人下午,只能对着代码干瞪眼。本次排查的转机出现在异常堆栈信息的打印,详细的异常信息有助于问题的快速解决。

7.总结

写了这么多,总结如下:

  1. 吐槽下ali大厂,异常信息竟然不写。
  2. 实际开发中,异常信息应尽量简洁明了,不能啥都不写,更不能故意制造混乱。只有异常发生了,才懂异常信息的可贵。
  3. 异常堆栈信息最好还是要打出来的,不然项目一复杂、调用一多,短短的一句异常信息,可能看不出是在哪里抛出来的,不利于排查。

转载于:https://my.oschina.net/funcy/blog/1933131

你可能感兴趣的文章
Stani's Python Editor下载
查看>>
[译]Javascript:Harmony(ECMAScript规范)制定流程
查看>>
每天一个linux命令(36):diff 命令
查看>>
2012第50周五
查看>>
一个简单的算法_应该是最笨的写法了
查看>>
20120622第二天_面向对象\02面向对象
查看>>
[翻译].NET框架中的缓存
查看>>
Microsoft Visual Studio 2010 正式版下载[含旗舰版序列号](中、英文版)
查看>>
轻快的VIM(四):修改
查看>>
心惊胆战的多屏图片切换
查看>>
office excel读写类NPOI
查看>>
技术支持经验总结
查看>>
正则教程
查看>>
如何使用Exchange Web Service获取日历(包含循环会议)
查看>>
Oracle二三事之 EBS升级
查看>>
C# DEV XtraGrid
查看>>
【SAS NOTES】data set if
查看>>
关于C#的Process的内存相关属性解读
查看>>
Android 编程下快捷图标的创建
查看>>
C++ GUI Qt4 自学笔记——Qt qmake命令
查看>>