公司一個新項目上線,處於試運行階段,這個項目雖然是外網可訪問的,故部署在了DMZ區,但試運行階段只給了公司內少部分員工地址和帳號(其中包括一些領導),故訪問量很小,但項目仍是挺重要的。
試運行階段中,項目應用日誌中不按期會報異常,尤爲是在剛上午剛開始使用時,還有空閒一段時間後再次使用時,具體異常以下:html
ERROR [com.alibaba.druid.util.JdbcUtils] - close connection error
java.sql.SQLRecoverableException: IO Error: Broken pipe
at oracle.jdbc.driver.T4CConnection.logoff(T4CConnection.java:556)
at oracle.jdbc.driver.PhysicalConnection.close(PhysicalConnection.java:3984)
at com.alibaba.druid.filter.FilterChainImpl.connection_close(FilterChainImpl.java:167)
at com.alibaba.druid.filter.stat.StatFilter.connection_close(StatFilter.java:254)
at com.alibaba.druid.filter.FilterChainImpl.connection_close(FilterChainImpl.java:163)
at com.alibaba.druid.proxy.jdbc.ConnectionProxyImpl.close(ConnectionProxyImpl.java:115)
at com.alibaba.druid.util.JdbcUtils.close(JdbcUtils.java:79)
at com.alibaba.druid.pool.DruidDataSource.discardConnection(DruidDataSource.java:965)
at com.alibaba.druid.pool.DruidDataSource.getConnectionDirect(DruidDataSource.java:932)
at com.alibaba.druid.filter.FilterChainImpl.dataSource_connect(FilterChainImpl.java:4534)
at com.alibaba.druid.filter.stat.StatFilter.dataSource_getConnection(StatFilter.java:661)
at com.alibaba.druid.filter.FilterChainImpl.dataSource_connect(FilterChainImpl.java:4530)
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:884)
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:876)
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:92)
at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:205)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:373)
at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:420)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:257)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:95)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:644)
at xxx.xx.modules.deposit.api.service.DepositApiService$$EnhancerBySpringCGLIB$$59c8f6e2.doRecharge() java
at xxx.xx.modules.deposit.FundDepositController.rechargeConfirm(FundDepositController.java:125)
......Caused by: java.net.SocketException: Broken pipe
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
at java.net.SocketOutputStream.write(SocketOutputStream.java:159)
at oracle.net.ns.DataPacket.send(DataPacket.java:210)
at oracle.net.ns.NetOutputStream.flush(NetOutputStream.java:230)
at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:312)
at oracle.net.ns.NetInputStream.read(NetInputStream.java:260)
at oracle.net.ns.NetInputStream.read(NetInputStream.java:185)
at oracle.net.ns.NetInputStream.read(NetInputStream.java:102)
at oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:124)
at oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:80)
at oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1137)
at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:290)
at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:192)
at oracle.jdbc.driver.T4C7Ocommoncall.doOLOGOFF(T4C7Ocommoncall.java:61)
at oracle.jdbc.driver.T4CConnection.logoff(T4CConnection.java:543)
... 69 morespring
從異常信息能夠看出,問題是發生在Druid數據庫鏈接池在關閉物理數據庫鏈接時,報了 SocketException: Broken pipe,但爲何在使用時Druid會關閉數據庫鏈接,關閉數據鏈接又爲何會報SocketException呢?這個異常到底對系統有多大的影響呢?下面一步步分析。sql
項目中使用是的Druid鏈接數據庫,可爲何在系統空閒一段時間後再使用,會嘗試關閉數據庫鏈接,並且關閉的時候還拋了 java.net.SocketException: Broken pipe 呢?
從異常堆棧信息,或者翻看Druid源碼能夠知道,異常是發生在從數據庫鏈接池中獲取鏈接,用於後續數據庫操做時,在執行到DruidDataSource.getConnectionDirect(maxWaitMillis)方法
時,有以下邏輯:數據庫
public DruidPooledConnection getConnectionDirect(long maxWaitMillis) throws SQLException { //循環 for (;;) { //maxWaitMillis時間內從鏈接池獲取一個鏈接 DruidPooledConnection poolalbeConnection = getConnectionInternal(maxWaitMillis); //testOnBorrow爲true,即從池中獲取鏈接後須要檢查鏈接 if (isTestOnBorrow()) { boolean validate = testConnectionInternal(poolalbeConnection.getConnection()); if (!validate) { if (LOG.isDebugEnabled()) { LOG.debug("skip not validate connection."); } Connection realConnection = poolalbeConnection.getConnection(); discardConnection(realConnection); continue; } } else { Connection realConnection = poolalbeConnection.getConnection(); //若是鏈接已經關閉,再從池中獲取一個 if (realConnection.isClosed()) { discardConnection(null); // 傳入null,避免重複關閉 continue; } //testWhileIdle爲true,即空閒後須要檢查鏈接 if (isTestWhileIdle()) { //鏈接空閒時間(當前時間 - 上次ActiveTime) long idleMillis = System.currentTimeMillis() - poolalbeConnection.getConnectionHolder().getLastActiveTimeMillis(); //鏈接空閒時間 > timeBetweenEvictionRunsMillis,檢查鏈接 if (idleMillis >= this.getTimeBetweenEvictionRunsMillis()) { boolean validate = testConnectionInternal(poolalbeConnection.getConnection()); //鏈接檢查失敗,打印log,丟棄鏈接,再獲取一個鏈接 if (!validate) { if (LOG.isDebugEnabled()) { LOG.debug("skip not validate connection."); } discardConnection(realConnection); continue; } } } } //若是開啓了鏈接超時回收 if (isRemoveAbandoned()) { StackTraceElement[] stackTrace = Thread.currentThread().getStackTrace(); poolalbeConnection.setConnectStackTrace(stackTrace); poolalbeConnection.setConnectedTimeNano(); //設置當前時間爲ConnectedTime poolalbeConnection.setTraceEnable(true); synchronized (activeConnections) { activeConnections.put(poolalbeConnection, PRESENT); //將鏈接放入activeConnections Map } } if (!this.isDefaultAutoCommit()) { poolalbeConnection.setAutoCommit(false); } return poolalbeConnection; } }
簡單來講,在從Druid獲取數據庫鏈接時,能夠進行test,這段代碼中包含testOnBorrow
(借出時檢查)和testWhileIdle
(空閒時檢查)的邏輯,此項目在配置文件中編程
testOnBorrow = false
testWhileIdle = true
timeBetweenEvictionRunsMillis = 60000(60s)api
故只會在鏈接空閒60s後再次使用時進行檢測,其實就是執行一個SQL,而在執行SQL時若是失敗了,就會調用JdbcUtils.close(realConnection)
關閉鏈接,在關閉這個鏈接時拋了SocketException異常,但其實這個異常倒不會對但願獲取Connection執行SQL查詢的程序形成太大影響,由於JdbcUtils.close()方法中捕獲了這個異常,打印log,並無上拋服務器
public static void close(Connection x) { if (x == null) { return; } try { x.close(); } catch (Exception e) { LOG.debug("close connection error", e); } }
那麼java.net.SocketException: Broken pipe是什麼意思呢?
其實就是與數據庫創建的tcp鏈接由於某些緣由斷開了,而致使了「管道破裂」。通常數據庫鏈接池會與數據庫保持長鏈接,在須要的時候省去創建鏈接的過程,直接使用,而爲何這些空閒的鏈接會被斷開呢?被誰斷開了?網絡
一開始百思不得其解,想着是由於Oracle數據庫主動斷開了鏈接嗎?由於某些緣由,好比從服務器到數據庫的鏈接太多?明顯不是,這個項目還在試運行階段,用的人很少,且觀察Druid的鏈接池監控,通常創建的鏈接也就幾個
後來和同事討論的過程當中得知別的項目組也發生過相似的狀況,而他們和這個項目的共同之處就在於服務都是在DMZ區,外網可訪問,而數據庫在內網,須要經過防火牆才能訪問到數據庫。因而去找負責維護網絡、防火牆的同事瞭解,原來防火牆有一個TCP超時時間,目前設置的爲半小時,其意義是,對於經過防火牆的全部TCP鏈接,若是在半小時內沒有任何活動,就會被防火牆拆除,這樣就會致使鏈接中斷。在拆除鏈接時,也不會向鏈接的兩端發送任何數據來通知鏈接已經拆除。
這下數據庫鏈接斷開的緣由找到了,那麼這就是一個應用與數據庫在不一樣的網絡中,鏈接須要通過防火牆的場景中會遇到的一個典型問題,怎麼可以使應用和數據庫之間即便比較空閒也可以保持必定數量的長鏈接,是亟待解決的。oracle
數據庫會話正在執行耗時長的SQL
切斷鏈接以前,鏈接對應的Oracle會話正在執行一個耗時特別長的SQL,好比存儲過程而在此過程當中沒有任何數據輸出到客戶端,這樣當SQL執行完成以後,向客戶端返回結果時,若是TCP鏈接已經被防火牆中斷,這時候顯然會出現錯誤,鏈接中斷,那麼會話也就會中斷。可是客戶端還不知道,會一直處於等待服務器返回結果的狀態。
若是客戶端沒有針對這種執行耗時長的SQL的鏈接回收機制,那麼客戶端這個鏈接將一直處於等待狀態,若是客戶端不斷執行這種耗時長SQL,那麼客戶端堆積的等待鏈接將愈來愈多。
Druid鏈接池的removeAbandoned
相關配置以及邏輯,就是爲了解決這種鏈接回收設置的。
數據庫會話空閒
切斷鏈接以前,Oracle會話一直處於空閒狀態,在防火牆中斷以後,客戶端向Oracle服務器提交SQL時,因爲TCP鏈接已經中斷,這時客戶端偵測到鏈接中斷,那麼客戶端就會報ORA-03113/ORA-03114這類錯誤,而後會話中斷。可是在Oracle服務器端,會話一直在處於等待客戶端消息的狀態。
而對於Druid這種有testOnBorrow、testWhileIdle的檢測機制,且檢測失敗能夠從新創建鏈接的鏈接池,空閒的被防火牆切斷的鏈接在後續會被不斷重建,而在數據庫服務器端,則鏈接愈來愈多,即會話數愈來愈多,甚至最終超過了數據爲最大鏈接數。
這是一個臨時解決方法,好比將防火牆的鏈接超時時間調整爲8小時,這樣能夠儘可能避免空閒鏈接的切斷,但沒法徹底避免,由於沒法預計鏈接會被空閒多久,若是你的系統不是總有人訪問的話,那麼鏈接早晚會由於空閒而被切斷,致使一些不可預計的問題,而調大超時時間只是緩解而已
tcp的keepalive,其實就是用來保持tcp鏈接的,其原理簡單說就是若是一個TCP鏈接在指定的時間內沒有任何活動,會發送一個探測包到鏈接的對端,檢測鏈接的對端是否仍然存在,若是對端必定時間內仍沒有對探測的響應,會再次發送探測包,發送幾回後,仍然沒有響應,就認爲鏈接已經失效,關閉本地鏈接。
tcp keepalive並非默認開啓的,在開發程序時能夠設置tcp keepalive爲true,這樣tcp鏈接在必定時間內沒有任何數據報文傳輸則啓動探測,這個時間通常是操做系統規定,Linux系統中能夠經過設置net.ipv4.tcp_keepalive_time
來修改,默認是7200秒,即2小時。固然在編程時也能夠設置這個時間用於當前socket,可是Java的Socket API中好像只有設置keepalive=true,並無法設置tcp_keepalive_time
當設置了tcp keepalive以後,只要tcp探測包發送的時間小於防火牆的鏈接超時時間,防火牆就會檢查到鏈接中仍然有數據傳輸,就不會斷開這個鏈接。
使用JDBC建立的數據庫tcp鏈接是沒有設置keepalive的,這點能夠經過Linux的netstat或ss命令在數據庫客戶端(即應用端)驗證
使用命令netstat -ano 或 ss -ano,其中參數o都是顯示timer計時器,timer計時器在鏈接創建狀態下能夠對鏈接保活計時
netstat命令對沒有開啓keepalive的tcp鏈接顯示爲:off (0.00/0/0)
ss命令對沒有keepalive的tcp鏈接,不會顯示timer計時器
Oracle提供了相似tcp keepalive的機制,也就是DCD(Dead Conneciton Detection)。在$ORACLE_HOME/network/admin/sqlnet.ora文件中增長以下一行:
sqlnet.expire_time=NNN
這裏NNN爲分鐘數,Oracle數據庫會在會話IDLE時間超過這個指定的時間時,檢測這個會話的對端(即客戶端)是否還有效。避免客戶端因爲異常退出,致使會話一直存在。
一樣的若是DCD的時間比防火牆切斷空閒鏈接的時間短,鏈接也能夠一直保持
以上幾種方法要麼是利用tcp鏈接keepalive特性,要麼是採用數據庫端的空閒鏈接檢測,咱們的程序中也能夠主動作這種心跳檢測
Druid數據庫鏈接池從1.0.28開始,添加了druid.keepAlive屬性,默認關閉
打開druid.keepAlive以後,當鏈接池空閒時,池中的minIdle數量之內的鏈接,空閒時間超過minEvictableIdleTimeMillis,則會執行keepAlive操做,即執行druid.validationQuery指定的查詢SQL,通常爲select * from dual,只要minEvictableIdleTimeMillis設置的小於防火牆切斷鏈接時間,就能夠保證當鏈接空閒時自動作保活檢測,不會被防火牆切斷