簡(jiǎn)書 Trust_FreeDom
轉(zhuǎn)載請(qǐng)注明原創(chuàng)出處一死,謝謝!
問題描述
公司一個(gè)新項(xiàng)目上線傻唾,處于試運(yùn)行階段投慈,這個(gè)項(xiàng)目雖然是外網(wǎng)可訪問的,故部署在了DMZ區(qū)冠骄,但試運(yùn)行階段只給了公司內(nèi)少部分員工地址和賬號(hào)(其中包括一些領(lǐng)導(dǎo))伪煤,故訪問量很小,但項(xiàng)目還是挺重要的凛辣。
試運(yùn)行階段中抱既,項(xiàng)目應(yīng)用日志中不定期會(huì)報(bào)異常,尤其是在剛上午剛開始使用時(shí)扁誓,還有空閑一段時(shí)間后再次使用時(shí)防泵,具體異常如下:
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(<generated>)
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 more
從異常信息可以看出,問題是發(fā)生在Druid數(shù)據(jù)庫連接池在關(guān)閉物理數(shù)據(jù)庫連接時(shí)蝗敢,報(bào)了SocketException: Broken pipe捷泞,但為什么在使用時(shí)Druid會(huì)關(guān)閉數(shù)據(jù)庫連接,關(guān)閉數(shù)據(jù)連接又為什么會(huì)報(bào)SocketException呢寿谴?這個(gè)異常到底對(duì)系統(tǒng)有多大的影響呢锁右?下面一步步分析。
問題逐步分析
1讶泰、java.net.SocketException: Broken pipe異常是怎么產(chǎn)生的咏瑟?有什么影響?
項(xiàng)目中使用是的Druid連接數(shù)據(jù)庫痪署,可為什么在系統(tǒng)空閑一段時(shí)間后再使用码泞,會(huì)嘗試關(guān)閉數(shù)據(jù)庫連接,而且關(guān)閉的時(shí)候還拋了 java.net.SocketException: Broken pipe 呢狼犯?
從異常堆棧信息余寥,或者翻看Druid源碼可以知道领铐,異常是發(fā)生在從數(shù)據(jù)庫連接池中獲取連接,用于后續(xù)數(shù)據(jù)庫操作時(shí)劈狐,在執(zhí)行到DruidDataSource.getConnectionDirect(maxWaitMillis)方法
時(shí)罐孝,有如下邏輯:
public DruidPooledConnection getConnectionDirect(long maxWaitMillis) throws SQLException {
//循環(huán)
for (;;) {
//maxWaitMillis時(shí)間內(nèi)從連接池獲取一個(gè)連接
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();
//如果連接已經(jīng)關(guān)閉肥缔,再從池中獲取一個(gè)
if (realConnection.isClosed()) {
discardConnection(null); // 傳入null,避免重復(fù)關(guān)閉
continue;
}
//testWhileIdle為true汹来,即空閑后需要檢查連接
if (isTestWhileIdle()) {
//連接空閑時(shí)間(當(dāng)前時(shí)間 - 上次ActiveTime)
long idleMillis = System.currentTimeMillis()
- poolalbeConnection.getConnectionHolder().getLastActiveTimeMillis();
//連接空閑時(shí)間 > timeBetweenEvictionRunsMillis续膳,檢查連接
if (idleMillis >= this.getTimeBetweenEvictionRunsMillis()) {
boolean validate = testConnectionInternal(poolalbeConnection.getConnection());
//連接檢查失敗,打印log收班,丟棄連接坟岔,再獲取一個(gè)連接
if (!validate) {
if (LOG.isDebugEnabled()) {
LOG.debug("skip not validate connection.");
}
discardConnection(realConnection);
continue;
}
}
}
}
//如果開啟了連接超時(shí)回收
if (isRemoveAbandoned()) {
StackTraceElement[] stackTrace = Thread.currentThread().getStackTrace();
poolalbeConnection.setConnectStackTrace(stackTrace);
poolalbeConnection.setConnectedTimeNano(); //設(shè)置當(dāng)前時(shí)間為ConnectedTime
poolalbeConnection.setTraceEnable(true);
synchronized (activeConnections) {
activeConnections.put(poolalbeConnection, PRESENT); //將連接放入activeConnections Map
}
}
if (!this.isDefaultAutoCommit()) {
poolalbeConnection.setAutoCommit(false);
}
return poolalbeConnection;
}
}
簡(jiǎn)單來說,在從Druid獲取數(shù)據(jù)庫連接時(shí)摔桦,可以進(jìn)行test社付,這段代碼中包含testOnBorrow
(借出時(shí)檢查)和testWhileIdle
(空閑時(shí)檢查)的邏輯,此項(xiàng)目在配置文件中
testOnBorrow = false
testWhileIdle = true
timeBetweenEvictionRunsMillis = 60000(60s)
故只會(huì)在連接空閑60s后再次使用時(shí)進(jìn)行檢測(cè)邻耕,其實(shí)就是執(zhí)行一個(gè)SQL鸥咖,而在執(zhí)行SQL時(shí)如果失敗了,就會(huì)調(diào)用JdbcUtils.close(realConnection)
關(guān)閉連接兄世,在關(guān)閉這個(gè)連接時(shí)拋了SocketException異常啼辣,但其實(shí)這個(gè)異常倒不會(huì)對(duì)希望獲取Connection執(zhí)行SQL查詢的程序造成太大影響,因?yàn)镴dbcUtils.close()方法中捕獲了這個(gè)異常御滩,打印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是什么意思呢?
其實(shí)就是與數(shù)據(jù)庫建立的tcp連接因?yàn)槟承┰驍嚅_了削解,而導(dǎo)致了“管道破裂”富弦。一般數(shù)據(jù)庫連接池會(huì)與數(shù)據(jù)庫保持長(zhǎng)連接,在需要的時(shí)候省去建立連接的過程氛驮,直接使用舆声,而為什么這些空閑的連接會(huì)被斷開呢?被誰斷開了柳爽?
2媳握、為什么數(shù)據(jù)庫TCP連接會(huì)被斷開?
一開始百思不得其解磷脯,想著是因?yàn)镺racle數(shù)據(jù)庫主動(dòng)斷開了連接嗎蛾找?因?yàn)槟承┰颍热鐝姆?wù)器到數(shù)據(jù)庫的連接太多赵誓?明顯不是打毛,這個(gè)項(xiàng)目還在試運(yùn)行階段柿赊,用的人不多,且觀察Druid的連接池監(jiān)控幻枉,一般建立的連接也就幾個(gè)
后來和同事討論的過程中得知?jiǎng)e的項(xiàng)目組也發(fā)生過類似的情況碰声,而他們和這個(gè)項(xiàng)目的共同之處就在于服務(wù)都是在DMZ區(qū),外網(wǎng)可訪問熬甫,而數(shù)據(jù)庫在內(nèi)網(wǎng)胰挑,需要通過防火墻才能訪問到數(shù)據(jù)庫。于是去找負(fù)責(zé)維護(hù)網(wǎng)絡(luò)椿肩、防火墻的同事了解瞻颂,原來防火墻有一個(gè)TCP超時(shí)時(shí)間,目前設(shè)置的為半小時(shí)郑象,其意義是贡这,對(duì)于通過防火墻的所有TCP連接,如果在半小時(shí)內(nèi)沒有任何活動(dòng)厂榛,就會(huì)被防火墻拆除盖矫,這樣就會(huì)導(dǎo)致連接中斷。在拆除連接時(shí)击奶,也不會(huì)向連接的兩端發(fā)送任何數(shù)據(jù)來通知連接已經(jīng)拆除辈双。
這下數(shù)據(jù)庫連接斷開的原因找到了,那么這就是一個(gè)應(yīng)用與數(shù)據(jù)庫在不同的網(wǎng)絡(luò)中正歼,連接需要經(jīng)過防火墻的場(chǎng)景中會(huì)遇到的一個(gè)典型問題辐马,怎么能夠使應(yīng)用和數(shù)據(jù)庫之間即使比較空閑也能夠保持一定數(shù)量的長(zhǎng)連接,是亟待解決的局义。
3喜爷、防火墻切斷數(shù)據(jù)庫連接會(huì)造成的影響
數(shù)據(jù)庫會(huì)話正在執(zhí)行耗時(shí)長(zhǎng)的SQL
切斷連接之前,連接對(duì)應(yīng)的Oracle會(huì)話正在執(zhí)行一個(gè)耗時(shí)特別長(zhǎng)的SQL萄唇,比如存儲(chǔ)過程而在此過程中沒有任何數(shù)據(jù)輸出到客戶端檩帐,這樣當(dāng)SQL執(zhí)行完成之后,向客戶端返回結(jié)果時(shí)另萤,如果TCP連接已經(jīng)被防火墻中斷湃密,這時(shí)候顯然會(huì)出現(xiàn)錯(cuò)誤,連接中斷四敞,那么會(huì)話也就會(huì)中斷泛源。但是客戶端還不知道,會(huì)一直處于等待服務(wù)器返回結(jié)果的狀態(tài)忿危。
如果客戶端沒有針對(duì)這種執(zhí)行耗時(shí)長(zhǎng)的SQL的連接回收機(jī)制达箍,那么客戶端這個(gè)連接將一直處于等待狀態(tài),如果客戶端不斷執(zhí)行這種耗時(shí)長(zhǎng)SQL铺厨,那么客戶端堆積的等待連接將越來越多缎玫。
Druid連接池的removeAbandoned
相關(guān)配置以及邏輯硬纤,就是為了解決這種連接回收設(shè)置的。
數(shù)據(jù)庫會(huì)話空閑
切斷連接之前赃磨,Oracle會(huì)話一直處于空閑狀態(tài)筝家,在防火墻中斷之后,客戶端向Oracle服務(wù)器提交SQL時(shí)邻辉,由于TCP連接已經(jīng)中斷溪王,這時(shí)客戶端偵測(cè)到連接中斷,那么客戶端就會(huì)報(bào)ORA-03113/ORA-03114這類錯(cuò)誤恩沛,然后會(huì)話中斷在扰。但是在Oracle服務(wù)器端缕减,會(huì)話一直在處于等待客戶端消息的狀態(tài)雷客。
而對(duì)于Druid這種有testOnBorrow、testWhileIdle的檢測(cè)機(jī)制桥狡,且檢測(cè)失敗可以重新建立連接的連接池搅裙,空閑的被防火墻切斷的連接在后續(xù)會(huì)被不斷重建,而在數(shù)據(jù)庫服務(wù)器端裹芝,則連接越來越多部逮,即會(huì)話數(shù)越來越多,甚至最終超過了數(shù)據(jù)為最大連接數(shù)嫂易。
解決方法
1兄朋、調(diào)大防火墻的連接切斷時(shí)長(zhǎng)
這是一個(gè)臨時(shí)解決方法,比如將防火墻的連接超時(shí)時(shí)間調(diào)整為8小時(shí)怜械,這樣可以盡量避免空閑連接的切斷颅和,但無法完全避免,因?yàn)闊o法預(yù)計(jì)連接會(huì)被空閑多久缕允,如果你的系統(tǒng)不是總有人訪問的話峡扩,那么連接遲早會(huì)因?yàn)榭臻e而被切斷,導(dǎo)致一些不可預(yù)計(jì)的問題障本,而調(diào)大超時(shí)時(shí)間只是緩解而已
2教届、tcp keepalive功能
tcp的keepalive钞翔,其實(shí)就是用來保持tcp連接的丹拯,其原理簡(jiǎn)單說就是如果一個(gè)TCP連接在指定的時(shí)間內(nèi)沒有任何活動(dòng),會(huì)發(fā)送一個(gè)探測(cè)包到連接的對(duì)端速警,檢測(cè)連接的對(duì)端是否仍然存在粪糙,如果對(duì)端一定時(shí)間內(nèi)仍沒有對(duì)探測(cè)的響應(yīng)强霎,會(huì)再次發(fā)送探測(cè)包,發(fā)送幾次后猜旬,仍然沒有響應(yīng)脆栋,就認(rèn)為連接已經(jīng)失效倦卖,關(guān)閉本地連接。
tcp keepalive并不是默認(rèn)開啟的椿争,在開發(fā)程序時(shí)可以設(shè)置tcp keepalive為true怕膛,這樣tcp連接在一定時(shí)間內(nèi)沒有任何數(shù)據(jù)報(bào)文傳輸則啟動(dòng)探測(cè),這個(gè)時(shí)間一般是操作系統(tǒng)規(guī)定秦踪,Linux系統(tǒng)中可以通過設(shè)置net.ipv4.tcp_keepalive_time
來修改褐捻,默認(rèn)是7200秒,即2小時(shí)椅邓。當(dāng)然在編程時(shí)也可以設(shè)置這個(gè)時(shí)間用于當(dāng)前socket柠逞,但是Java的Socket API中好像只有設(shè)置keepalive=true,并沒法設(shè)置tcp_keepalive_time
當(dāng)設(shè)置了tcp keepalive之后景馁,只要tcp探測(cè)包發(fā)送的時(shí)間小于防火墻的連接超時(shí)時(shí)間板壮,防火墻就會(huì)檢查到連接中仍然有數(shù)據(jù)傳輸,就不會(huì)斷開這個(gè)連接合住。
使用JDBC創(chuàng)建的數(shù)據(jù)庫tcp連接是沒有設(shè)置keepalive的绰精,這點(diǎn)可以通過Linux的netstat或ss命令在數(shù)據(jù)庫客戶端(即應(yīng)用端)驗(yàn)證
使用命令netstat -ano 或 ss -ano,其中參數(shù)o都是顯示timer計(jì)時(shí)器透葛,timer計(jì)時(shí)器在連接建立狀態(tài)下可以對(duì)連接北渴梗活計(jì)時(shí)
netstat命令對(duì)沒有開啟keepalive的tcp連接顯示為:off (0.00/0/0)
ss命令對(duì)沒有keepalive的tcp連接,不會(huì)顯示timer計(jì)時(shí)器
3僚害、Oracle數(shù)據(jù)庫的DCD
Oracle提供了類似tcp keepalive的機(jī)制硫椰,也就是DCD(Dead Conneciton Detection)。在$ORACLE_HOME/network/admin/sqlnet.ora文件中增加如下一行:
sqlnet.expire_time=NNN
這里NNN為分鐘數(shù)萨蚕,Oracle數(shù)據(jù)庫會(huì)在會(huì)話IDLE時(shí)間超過這個(gè)指定的時(shí)間時(shí)靶草,檢測(cè)這個(gè)會(huì)話的對(duì)端(即客戶端)是否還有效。避免客戶端由于異常退出门岔,導(dǎo)致會(huì)話一直存在爱致。
同樣的如果DCD的時(shí)間比防火墻切斷空閑連接的時(shí)間短,連接也可以一直保持
4寒随、程序不定時(shí)執(zhí)行查詢
以上幾種方法要么是利用tcp連接keepalive特性糠悯,要么是采用數(shù)據(jù)庫端的空閑連接檢測(cè),我們的程序中也可以主動(dòng)做這種心跳檢測(cè)
Druid數(shù)據(jù)庫連接池從1.0.28開始妻往,添加了druid.keepAlive屬性互艾,默認(rèn)關(guān)閉
打開druid.keepAlive之后,當(dāng)連接池空閑時(shí)讯泣,池中的minIdle數(shù)量以內(nèi)的連接纫普,空閑時(shí)間超過minEvictableIdleTimeMillis,則會(huì)執(zhí)行keepAlive操作,即執(zhí)行druid.validationQuery指定的查詢SQL昨稼,一般為select * from dual节视,只要minEvictableIdleTimeMillis設(shè)置的小于防火墻切斷連接時(shí)間,就可以保證當(dāng)連接空閑時(shí)自動(dòng)做奔偎ǎ活檢測(cè)寻行,不會(huì)被防火墻切斷