背景
數(shù)據(jù)源初始化后,獲取Oracle的連接進行查詢操作,相隔 半個小時 左右,再次對同一數(shù)據(jù)庫進行查詢操作。
問題
第二次查詢的時候,就會出現(xiàn)如下一些異常情況
2019-06-05 14:17:58.247 [CorePoolHandler-thread-6] ERROR [LOGID:] com.alibaba.druid.pool.DruidDataSource - discard connection
java.sql.SQLRecoverableException: IO 錯誤: Socket read timed out
at oracle.jdbc.driver.T4CPreparedStatement.fetch(T4CPreparedStatement.java:1031) ~[ojdbc6-12.1.0.1-atlassian-hosted.jar:12.1.0.1.0]
at oracle.jdbc.driver.OracleStatement.fetchMoreRows(OracleStatement.java:3590) ~[ojdbc6-12.1.0.1-atlassian-hosted.jar:12.1.0.1.0]
at oracle.jdbc.driver.InsensitiveScrollableResultSet.fetchMoreRows(InsensitiveScrollableResultSet.java:937) ~[ojdbc6-12.1.0.1-atlassian-hosted.jar:12.1.0.1.0]
at oracle.jdbc.driver.InsensitiveScrollableResultSet.absoluteInternal(InsensitiveScrollableResultSet.java:901) ~[ojdbc6-12.1.0.1-atlassian-hosted.jar:12.1.0.1.0]
at oracle.jdbc.driver.InsensitiveScrollableResultSet.next(InsensitiveScrollableResultSet.java:572) ~[ojdbc6-12.1.0.1-atlassian-hosted.jar:12.1.0.1.0]
at com.alibaba.druid.filter.FilterChainImpl.resultSet_next(FilterChainImpl.java:917) ~[druid-1.1.10.jar:1.1.10]
at com.alibaba.druid.filter.FilterAdapter.resultSet_next(FilterAdapter.java:1907) ~[druid-1.1.10.jar:1.1.10]
at com.alibaba.druid.filter.FilterChainImpl.resultSet_next(FilterChainImpl.java:913) ~[druid-1.1.10.jar:1.1.10]
2019-06-05 14:22:32.714 [Druid-ConnectionPool-Destroy-1030806200] ERROR [LOGID:] com.alibaba.druid.util.JdbcUtils - close connection error
java.sql.SQLRecoverableException: IO 錯誤: Socket read timed out
at oracle.jdbc.driver.T4CConnection.logoff(T4CConnection.java:770) ~[ojdbc6-12.1.0.1-atlassian-hosted.jar:12.1.0.1.0]
at oracle.jdbc.driver.PhysicalConnection.close(PhysicalConnection.java:4581) ~[ojdbc6-12.1.0.1-atlassian-hosted.jar:12.1.0.1.0]
at com.alibaba.druid.filter.FilterChainImpl.connection_close(FilterChainImpl.java:186) ~[druid-1.1.10.jar:1.1.10]
at com.alibaba.druid.filter.stat.StatFilter.connection_close(StatFilter.java:261) ~[druid-1.1.10.jar:1.1.10]
at com.alibaba.druid.filter.FilterChainImpl.connection_close(FilterChainImpl.java:181) ~[druid-1.1.10.jar:1.1.10]
at com.alibaba.druid.proxy.jdbc.ConnectionProxyImpl.close(ConnectionProxyImpl.java:115) ~[druid-1.1.10.jar:1.1.10]
at com.alibaba.druid.util.JdbcUtils.close(JdbcUtils.java:73) [druid-1.1.10.jar:1.1.10]
at com.alibaba.druid.pool.DruidDataSource.shrink(DruidDataSource.java:2797) [druid-1.1.10.jar:1.1.10]
at com.alibaba.druid.pool.DruidDataSource$DestroyTask.run(DruidDataSource.java:2562) [druid-1.1.10.jar:1.1.10]
at com.alibaba.druid.pool.DruidDataSource$DestroyConnectionThread.run(DruidDataSource.java:2549) [druid-1.1.10.jar:1.1.10]
2019-06-17 18:11:18.995 [task-scheduler-5] ERROR [LOGID:] com.alibaba.druid.util.JdbcUtils - close statement error
java.sql.SQLRecoverableException: 關(guān)閉的連接
at oracle.jdbc.driver.PhysicalConnection.needLine(PhysicalConnection.java:6291) ~[ojdbc6-12.1.0.1-atlassian-hosted.jar:12.1.0.1.0]
at oracle.jdbc.driver.OracleStatement.closeOrCache(OracleStatement.java:1364) ~[ojdbc6-12.1.0.1-atlassian-hosted.jar:12.1.0.1.0]
at oracle.jdbc.driver.OracleStatement.close(OracleStatement.java:1343) ~[ojdbc6-12.1.0.1-atlassian-hosted.jar:12.1.0.1.0]
at oracle.jdbc.driver.OracleStatementWrapper.close(OracleStatementWrapper.java:100) ~[ojdbc6-12.1.0.1-atlassian-hosted.jar:12.1.0.1.0]
at com.alibaba.druid.util.JdbcUtils.close(JdbcUtils.java:84) [druid-1.1.10.jar:1.1.10]
at com.alibaba.druid.pool.vendor.OracleValidConnectionChecker.isValidConnection(OracleValidConnectionChecker.java:88) [druid-1.1.10.jar:1.1.10]
at com.alibaba.druid.pool.DruidAbstractDataSource.testConnectionInternal(DruidAbstractDataSource.java:1400) [druid-1.1.10.jar:1.1.10]
at com.alibaba.druid.pool.DruidDataSource.getConnectionDirect(DruidDataSource.java:1299) [druid-1.1.10.jar:1.1.10]
at com.alibaba.druid.filter.FilterChainImpl.dataSource_connect(FilterChainImpl.java:5007) [druid-1.1.10.jar:1.1.10]
at com.alibaba.druid.filter.stat.StatFilter.dataSource_getConnection(StatFilter.java:680) [druid-1.1.10.jar:1.1.10]
at com.alibaba.druid.filter.FilterChainImpl.dataSource_connect(FilterChainImpl.java:5003) [druid-1.1.10.jar:1.1.10]
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1233) [druid-1.1.10.jar:1.1.10]
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1225) [druid-1.1.10.jar:1.1.10]
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:90) [druid-1.1.10.jar:1.1.10]
at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:111) [spring-jdbc-4.3.14.RELEASE.jar:4.3.14.RELEASE]
排查原因過程
一開始以為是查詢的數(shù)據(jù)量太大（7.9W+），于是網(wǎng)上查了druid對Oracle數(shù)據(jù)庫的讀超時時間相關(guān)的設(shè)置,配置如下,設(shè)置后發(fā)現(xiàn)仍舊是socket read timeout，繼續(xù)增大socket read timeout的值，雖然“socket read timeout”沒有出現(xiàn)了，但是“關(guān)閉的連接”字樣冒了出來。
spring.datasource.traffic.connectionProperties=oracle.net.CONNECT_TIMEOUT=6000;oracle.jdbc.ReadTimeout=180000
查看出錯日志，跟蹤方法棧，發(fā)現(xiàn)是獲取連接時執(zhí)行了testConnectionInternal()方法，繼續(xù)跟蹤方法棧發(fā)現(xiàn)是執(zhí)行數(shù)據(jù)源配置中的validationQuery語句時，拋出了異常。但這個是測試連接是否可用的方法，不會影響下一步對數(shù)據(jù)庫的操作，因為druid數(shù)據(jù)源會創(chuàng)建新的一條數(shù)據(jù)庫連接。
但是！打印異常的logger明明是debug，這XX為什么要以error的形式寫進日志里?。?！如果沒有仔細(xì)看上下文的代碼，能把人糾結(jié)個好幾天!!!文章來源：http://www.zghlxwxcb.cn/news/detail-853535.html
public static void close(Statement x) {
if (x == null) {
return;
}
try {
x.close();
} catch (Exception e) {
LOG.debug("close statement error", e);
}
}
總結(jié)
查看出錯日志檢查問題的時候，不能只看拋出錯誤最近的那幾行代碼，一定要看過整體的方法棧，知道運行的流程，再仔細(xì)看拋出異常的代碼，看看該行代碼執(zhí)行的前后邏輯。文章來源地址http://www.zghlxwxcb.cn/news/detail-853535.html
到了這里，關(guān)于關(guān)于使用druid數(shù)據(jù)源連接Oracle導(dǎo)致的SQLRecoverableException（socket read timeout,關(guān)閉的連接等）的文章就介紹完了。如果您還想了解更多內(nèi)容，請在右上角搜索TOY模板網(wǎng)以前的文章或繼續(xù)瀏覽下面的相關(guān)文章，希望大家以后多多支持TOY模板網(wǎng)！
