druid连接池引起的线程blocked
一、前言
? 最近在捣鼓演示应用的时候发现一个druid连接池引起的线程blocked问题。先声明下,这个问题是druid 1.1.23版本之前的一个bug,并不是说druid存在明显的性能问题。
? github上其实已经有相关的issue:https://github.com/alibaba/dr...;也可以关注下druid各版本的release信息:https://github.com/alibaba/dr...。
文章图片
? 而我在发现这个问题的时候并不知道这其实是个已经修复了的bug,因此记录了一些分析过程的线索,今天主要分享下问题排查的思路。
二、Let‘s Go
(一)严重的Thread Blocked
? 事情起源于准备客户演示环境时的一轮压测(验证环境)。在压测过程中,发现有一个访问数据库的接口响应时间异常的高,虽然故意做了循环查库【一次http请求,10次MySQL查询】的操作,但是对于只是进行简单查询的SQL来说,接口的响应时间显得很不正常。
- 首先检查了下应用服务的资源使用情况,一切正常;
- 检查jvm运行情况。在热点方法【方法消耗CPU资源的情况】中,看到zip压缩相关的方法始终在消耗CPU资源时排在首位:把方法调用链展开,发现是类加载引起的;【可以肯定,应用哪里肯定有问题】
文章图片
- 线程dump,检查线程都在干什么,并看看类加载相关完整的线程栈。在thread dump中发现了大问题,97%的业务线程都处于blocked状态:
文章图片
- 分析线程dump,寻找blocked的主要原因。发现就是类加载操作导致的大量线程blocked。而类加载操作竟然是druid相关的方法导致的(后面会提到,其实连接检测导致的);
文章图片
initialSize: 5
minIdle: 5
maxIdle: 5
maxActive: 5
maxWait: 60000
timeBetweenEvictionRunsMillis: 60000
minEvictableIdleTimeMillis: 300000
validationQuery: SELECT 1 FROM DUAL
poolPreparedStatements: true
testWhileIdle: true
// 获取连接时检测
testOnBorrow: true
// 归还连接时检测
testOnReturn: true
#配置监控统计拦截的filters,去掉后监控界面sql无法统计,'wall'用于防火墙
filters: stat,wall,slf4j
maxPoolPreparedStatementPerConnectionSize: 20
useGlobalDataSourceStat: true
connectionProperties: druid.stat.mergeSql=true;
druid.stat.slowSqlMillis=1000
? 可以看到,这边把连接检测的配置都加上,也就是在获取连接,归还连接,以及连接空闲阶段都会进行连接检测。【考虑到性能影响:一般不开启
testOnReturn
和testOnReturn
,而使用testWhileIdle
配合timeBetweenEvictionRunsMillis
进行空闲连接检测】? 接下来,简单分析下druid的部分源码,以及druid 1.1.23版本之前的bug的相关源码。
或者可以直接跳转至下面 getLastPacketReceivedTimeMs章节,直接切入正题;
(二)连接检测部分源码
1. getConnectionDirect - 连接检测入口 ? 调用
getConnection()
获取连接后,最终会调用com.alibaba.druid.pool.DruidDataSource#getConnectionDirect
方法。在getConnectionDirect
方法中,就会判断是否走连接检测的逻辑,下面是主要源码(篇幅原因其他分支逻辑细节去掉了,可自行阅读):public DruidPooledConnection getConnectionDirect(long maxWaitMillis) throws SQLException {
int notFullTimeoutRetryCnt = 0;
for (;
;
) {
// DruidPooledConnection封装了物理连接对象
DruidPooledConnection poolableConnection;
try {
// 这是连接检测的核心代码所在
poolableConnection = getConnectionInternal(maxWaitMillis);
} catch (GetConnectionTimeoutException ex) {
if (notFullTimeoutRetryCnt <= this.notFullTimeoutRetryCount && !isFull()) {
notFullTimeoutRetryCnt++;
if (LOG.isWarnEnabled()) {
LOG.warn("get connection timeout retry : " + notFullTimeoutRetryCnt);
}
continue;
}
throw ex;
}
// 是否开启了获取连接时检测(按照上面的配置,首先会进入这段代码)
if (testOnBorrow) {
boolean validate = testConnectionInternal(poolableConnection.holder, poolableConnection.conn);
if (!validate) {
if (LOG.isDebugEnabled()) {
LOG.debug("skip not validate connection.");
}discardConnection(poolableConnection.holder);
continue;
}
} else {
if (poolableConnection.conn.isClosed()) {
discardConnection(poolableConnection.holder);
// 传入null,避免重复关闭
continue;
}
// 是否开启了空闲检测,会根据空闲时间,判断是否进行连接检测
if (testWhileIdle) {
// ......
}
}
// 是否开启了removeAbandoned参数(不推荐开启,会获取线程栈信息)
if (removeAbandoned) {
// ......
}if (!this.defaultAutoCommit) {
poolableConnection.setAutoCommit(false);
}return poolableConnection;
}
}
2. testConnectionInternal - 连接检测核心代码 ?
com.alibaba.druid.pool.DruidAbstractDataSource#testConnectionInternal
是连接检测的核心代码。开启了testOnReturn
和testOnReturn
后,核心的连接测试逻辑都在这。两个关键方法:
validConnectionChecker.isValidConnection()
,实际上调用的是com.alibaba.druid.pool.vendor.MySqlValidConnectionChecker#isValidConnection()
。主要做两件事:1、先发送ping信息给mysql服务器,检测tcp连接可用性;2、执行validationQuery配置的SQL查询语句;
MySqlUtils.getLastPacketReceivedTimeMs()
,用于获取连接的空闲时间。这个方法也是今天thread blocked的元凶;
protected boolean testConnectionInternal(DruidConnectionHolder holder, Connection conn) {
// ......其他
try {
if (validConnectionChecker != null) {
// isValidConnection真正做检测的方法,会做两件事
// 1. 先发送ping信息给mysql服务器,检测tcp连接可用性;
// 2. 执行validationQuery配置的SQL查询语句;
boolean valid = validConnectionChecker.isValidConnection(conn, validationQuery, validationQueryTimeout);
long currentTimeMillis = System.currentTimeMillis();
if (holder != null) {
holder.lastValidTimeMillis = currentTimeMillis;
holder.lastExecTimeMillis = currentTimeMillis;
}
// 如果是mysql数据库,且通过了连接测试,就进入下面的代码
if (valid && isMySql) { // unexcepted branch
// 1.1.23之前的bug所在
long lastPacketReceivedTimeMs = MySqlUtils.getLastPacketReceivedTimeMs(conn);
if (lastPacketReceivedTimeMs > 0) {
long mysqlIdleMillis = currentTimeMillis - lastPacketReceivedTimeMs;
if (lastPacketReceivedTimeMs > 0 //
&& mysqlIdleMillis >= timeBetweenEvictionRunsMillis) {
discardConnection(holder);
String errorMsg = "discard long time none received connection. "
+ ", jdbcUrl : " + jdbcUrl
+ ", version : " + VERSION.getVersionNumber()
+ ", lastPacketReceivedIdleMillis : " + mysqlIdleMillis;
LOG.warn(errorMsg);
return false;
}
}
}
if (valid && onFatalError) {
lock.lock();
try {
if (onFatalError) {
onFatalError = false;
}
} finally {
lock.unlock();
}
}
return valid;
}
// ......其他
}
}
3. getLastPacketReceivedTimeMs - 线程阻塞的元凶,bug所在 ? com.alibaba.druid.util.MySqlUtils#getLastPacketReceivedTimeMs
- 1.1.23版本之前的实现
/**
* druid 1.1.23版本之前的源码实现
*/
public static long getLastPacketReceivedTimeMs(Connection conn) throws SQLException {
// 第一次执行这段代码,class_connectionImpl是初始值null,因此会进入if逻辑
if (class_connectionImpl == null && !class_connectionImpl_Error) {
try {
// 写死mysql-connector-java 5的类
// 因此使用6+版本的驱动,会存在ClassNotFound的问题。
class_connectionImpl = Utils.loadClass("com.mysql.jdbc.MySQLConnection");
} catch (Throwable error){
class_connectionImpl_Error = true;
}
}
}
- 修复后的代码实现
新增了对mysql-connector-java 6的支持;
/**
* druid 1.1.23版本及之后的源码实现
* @param conn :如果配置了自定义Filter,传入的conn就是ConnectionProxyImpl类型,否则就是ConnectionImpl类型
*/
public static long getLastPacketReceivedTimeMs(Connection conn) throws SQLException {
// 如果配置了自定义Filter,这边class_connectionImpl就是null
if (class_connectionImpl == null && !class_connectionImpl_Error) {
try {
// 加载mysql连接类
class_connectionImpl = Utils.loadClass("com.mysql.jdbc.MySQLConnection");
if (class_connectionImpl == null) {
class_connectionImpl = Utils.loadClass("com.mysql.cj.MysqlConnection");
if (class_connectionImpl != null) {
mysqlJdbcVersion6 = true;
}
}
} catch (Throwable error) {
class_connectionImpl_Error = true;
}
}
.....
}
? 发现没有,其实主要问题是MySQL驱动包版本的问题,druid 1.1.23之前的版本是写死的
mysql-connector-java 5
的类名,如果工程中配置了com.mysql.cj.*
相关的包,就会导致一系列的问题:loadClass
是同步方法,多线程下导致线程阻塞;
- Spring Boot动态类加载的时候最终会调用其自定义类加载器
LaunchedURLClassLoader
,在加载过程中会遍历BOOT-INF/lib/ 下所有的 jar 包 以及 BOOT-INF/classes/下的字节码文件;【jar方式部署】
- 解析内部jar时,会进行解压缩操作;
com.mysql.cj.*
相关的包不存在,因此每次连接测试都会重复以上操作;
推荐阅读
- 笔记|数据库连接池
- 深度学习|计算机机器视觉原理之全连接神经网络1
- 单片机|L298N 驱动电机与单片机的线路连接图
- 单片机|L298N、电机、单片机的线路连接
- win10 Telnet服务器 解决telnet正在连接127.0.0.1...无法打开到主机的连接 在端口 23: 连接失败
- 关于golang监听rabbitmq消息队列任务断线自动重连接的问题
- golang监听rabbitmq消息队列任务断线自动重连接
- java学习之JVM运行时常量池理解
- Android|手机网络连接类型判断 2/3/4G网络 WiFi和无网络 工具类
- 最佳实践丨三种典型场景下的云上虚拟IDC(私有池)选购指南