问题背景
在项目启动时出现大量
c.a.d.pool.DruidAbstractDataSource: discard long time none received connection.
明显是Druid管理的数据库连接由于太长时间没有收到数据库发来的数据,把连接给回收掉了,这导致服务在启动时由于要重复创建连接让服务启动时间延长。
定位原因
根据错误信息,找到Druid源码
com.alibaba.druid.pool.DruidAbstractDataSource#testConnectionInternal(com.alibaba.druid.pool.DruidConnectionHolder, java.sql.Connection)
- if (validConnectionChecker != null) {
- // 验证连接的有效性 mysql下实际调用代码在下面那块
- boolean valid = validConnectionChecker.isValidConnection(conn, validationQuery, validationQueryTimeout);
- long currentTimeMillis = System.currentTimeMillis();
- if (holder != null) {
- holder.lastValidTimeMillis = currentTimeMillis;
- holder.lastExecTimeMillis = currentTimeMillis;
- }
- if (valid && isMySql) { // unexcepted branch
- 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;
- }
- }
- }
- // ... 省略
- }
- // com.alibaba.druid.pool.vendor.MySqlValidConnectionChecker#isValidConnection
- public boolean isValidConnection(Connection conn, String validateQuery, int validationQueryTimeout) throws Exception {
- if (conn.isClosed()) {
- return false;
- }
- if (usePingMethod) {
- // 以ping的方式检测连接的有效性
- if (conn instanceof DruidPooledConnection) {
- conn = ((DruidPooledConnection) conn).getConnection();
- }
- if (conn instanceof ConnectionProxy) {
- conn = ((ConnectionProxy) conn).getRawObject();
- }
- if (clazz.isAssignableFrom(conn.getClass())) {
- if (validationQueryTimeout <= 0) {
- validationQueryTimeout = DEFAULT_VALIDATION_QUERY_TIMEOUT;
- }
- try {
- ping.invoke(conn, true, validationQueryTimeout * 1000);
- } catch (InvocationTargetException e) {
- Throwable cause = e.getCause();
- if (cause instanceof SQLException) {
- throw (SQLException) cause;
- }
- throw e;
- }
- return true;
- }
- }
- String query = validateQuery;
- if (validateQuery == null || validateQuery.isEmpty()) {
- // 以 sql SELECT 1 的方式验证连接有效性
- query = DEFAULT_VALIDATION_QUERY;
- }
- Statement stmt = null;
- ResultSet rs = null;
- try {
- stmt = conn.createStatement();
- if (validationQueryTimeout > 0) {
- stmt.setQueryTimeout(validationQueryTimeout);
- }
- rs = stmt.executeQuery(query);
- return true;
- } finally {
- JdbcUtils.close(rs);
- JdbcUtils.close(stmt);
- }
- }
- }
复制代码 这是调用 testConnectionInternal方法的上层.

可以看到,由于我们开启了testOnBorrow 开关,以是数据库连接会在申请乐成后,立即进行一次测试,然后根据数据库连接的最后一次心跳时间,判断是否闲置过长要丢弃掉该数据库连接。
该开关主要在从连接池获取时立即查抄连接的有效性。
而不开启testOnBorrow则会在保持连接过程中不断查抄连接的闲置环境,对闲置过长的连接回收。
com.alibaba.druid.util.MySqlUtils#getLastPacketReceivedTimeMs 这个方法会返回连接最后一次收到消息的时间.
- // 以mysql6的 com.mysql.cj.jdbc.ConnectionImpl 为栗子
- // getLastPacketReceivedTimeMs 方法中获取链接时间的实际方法
- public long getIdleFor() {
- return this.lastQueryFinishedTime == 0 ? 0 : System.currentTimeMillis() - this.lastQueryFinishedTime;
- }
- // com.mysql.cj.NativeSession#execSQL
- public <T extends Resultset> T execSQL(Query callingQuery, String query, int maxRows, NativePacketPayload packet, boolean streamResults,
- ProtocolEntityFactory<T, NativePacketPayload> resultSetFactory, ColumnDefinition cachedMetadata, boolean isBatch) {
- long queryStartTime = this.gatherPerfMetrics.getValue() ? System.currentTimeMillis() : 0;
- int endOfQueryPacketPosition = packet != null ? packet.getPosition() : 0;
- this.lastQueryFinishedTime = 0; // we're busy!
- if (this.autoReconnect.getValue() && (getServerSession().isAutoCommit() || this.autoReconnectForPools.getValue()) && this.needsPing && !isBatch) {
- try {
- ping(false, 0);
- this.needsPing = false;
- } catch (Exception Ex) {
- invokeReconnectListeners();
- }
- }
- try {
- return packet == null
- ? ((NativeProtocol) this.protocol).sendQueryString(callingQuery, query, this.characterEncoding.getValue(), maxRows, streamResults,
- cachedMetadata, resultSetFactory)
- : ((NativeProtocol) this.protocol).sendQueryPacket(callingQuery, packet, maxRows, streamResults, cachedMetadata, resultSetFactory);
- } catch (CJException sqlE) {
- if (getPropertySet().getBooleanProperty(PropertyKey.dumpQueriesOnException).getValue()) {
- String extractedSql = NativePacketPayload.extractSqlFromPacket(query, packet, endOfQueryPacketPosition,
- getPropertySet().getIntegerProperty(PropertyKey.maxQuerySizeToLog).getValue());
- StringBuilder messageBuf = new StringBuilder(extractedSql.length() + 32);
- messageBuf.append("\n\nQuery being executed when exception was thrown:\n");
- messageBuf.append(extractedSql);
- messageBuf.append("\n\n");
- sqlE.appendMessage(messageBuf.toString());
- }
- if ((this.autoReconnect.getValue())) {
- if (sqlE instanceof CJCommunicationsException) {
- // IO may be dirty or damaged beyond repair, force close it.
- this.protocol.getSocketConnection().forceClose();
- }
- this.needsPing = true;
- } else if (sqlE instanceof CJCommunicationsException) {
- invokeCleanupListeners(sqlE);
- }
- throw sqlE;
- } catch (Throwable ex) {
- if (this.autoReconnect.getValue()) {
- if (ex instanceof IOException) {
- // IO may be dirty or damaged beyond repair, force close it.
- this.protocol.getSocketConnection().forceClose();
- } else if (ex instanceof IOException) {
- invokeCleanupListeners(ex);
- }
- this.needsPing = true;
- }
- throw ExceptionFactory.createException(ex.getMessage(), ex, this.exceptionInterceptor);
- } finally {
- // 需要开启数据库连接的jdbc参数 maintainTimeStats=true
- if (this.maintainTimeStats.getValue()) {
- // 连接的最后查询时间被更新
- this.lastQueryFinishedTime = System.currentTimeMillis();
- }
- if (this.gatherPerfMetrics.getValue()) {
- ((NativeProtocol) this.protocol).getMetricsHolder().registerQueryExecutionTime(System.currentTimeMillis() - queryStartTime);
- }
- }
- }
复制代码 办理
通过源码分析,就大抵清楚问题的原因。
druid会从数据库获取一批连接持有在当地,以便快速利用。
为了查抄连接的可用(如连接超时被数据库回收了,网络非常等),以是当开启testOnBorrow开关后,会在客户端从druid获取连接时进行闲置连接查抄。
而闲置查抄时比较连接当前时间与最后一次执行sql的时间的差值。
我们的服务在启动时没有进行数据查询,而且连接保活维持是通过ping的方式,以是当启动时间超过之前设置的15s后,再利用最开始池化的数据库借入连接时检测不外而抛出文章开头的非常信息。
我们可以通过调大闲置连接剔除时间和保活时间,让连接闲置能够撑过服务启动的无数据查询时间。
此外,假如服务的活泼环境很低,也就是执行sql的频率很低,可以设置环境变量druid.mysql.usePingMethod为false,让druid以执行SELECT 1sql的方式来保活连接,如此就会顺带刷新getLastPacketReceivedTimeMs属性。
- // com.alibaba.druid.pool.vendor.MySqlValidConnectionChecker#configFromProperties
- public void configFromProperties(Properties properties) {
- if (properties == null) {
- return;
- }
- String property = properties.getProperty("druid.mysql.usePingMethod");
- if ("true".equals(property)) {
- setUsePingMethod(true);
- } else if ("false".equals(property)) {
- setUsePingMethod(false);
- }
- }
复制代码 当然通过源码尚有其他方式,可以自行发现。
- spring:
- datasource:
- druid:
- # 让底层的jdbc维护连接的状态的时间
- url: jdck:mysql://xxx?maintainTimeStats=true
- # 连接闲置剔除时间
- time-between-eviction-runs-millis: 300000
- # 必须大于 time-between-eviction-runs-millis 时间
- keep-alive-between-time-millis: 450000
复制代码- // 启动代码添加系统属性
- // 或者通过 -Ddruid.mysql.usePingMethod=false 的命令参数
- // 或者通过环境变量
- public static void main(String[] args) {
- Properties properties = System.getProperties();
- // 用 select 1 替换 ping 来检测连接保活
- properties.setProperty("druid.mysql.usePingMethod", "false");
- SpringApplication.run(App.class, args);
- }
复制代码 免责声明:如果侵犯了您的权益,请联系站长,我们会及时删除侵权内容,谢谢合作!更多信息从访问主页:qidao123.com:ToB企服之家,中国第一个企服评测及商务社交产业平台。 |