【线上问题】由防火墙导致的数据库空闲连接断开问题

简书 Trust_FreeDom
转载请注明原创出处，谢谢！

问题描述

公司一个新项目上线，处于试运行阶段，这个项目虽然是外网可访问的，故部署在了DMZ区，但试运行阶段只给了公司内少部分员工地址和账号（其中包括一些领导），故访问量很小，但项目还是挺重要的。
试运行阶段中，项目应用日志中不定期会报异常，尤其是在刚上午刚开始使用时，还有空闲一段时间后再次使用时，具体异常如下：

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

从异常信息可以看出，问题是发生在Druid数据库连接池在关闭物理数据库连接时，报了SocketException: Broken pipe，但为什么在使用时Druid会关闭数据库连接，关闭数据连接又为什么会报SocketException呢？这个异常到底对系统有多大的影响呢？下面一步步分析。

问题逐步分析

1、java.net.SocketException: Broken pipe异常是怎么产生的？有什么影响？

项目中使用是的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）

故只会在连接空闲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连接因为某些原因断开了，而导致了“管道破裂”。一般数据库连接池会与数据库保持长连接，在需要的时候省去建立连接的过程，直接使用，而为什么这些空闲的连接会被断开呢？被谁断开了？

2、为什么数据库TCP连接会被断开？

一开始百思不得其解，想着是因为Oracle数据库主动断开了连接吗？因为某些原因，比如从服务器到数据库的连接太多？明显不是，这个项目还在试运行阶段，用的人不多，且观察Druid的连接池监控，一般建立的连接也就几个
后来和同事讨论的过程中得知别的项目组也发生过类似的情况，而他们和这个项目的共同之处就在于服务都是在DMZ区，外网可访问，而数据库在内网，需要通过防火墙才能访问到数据库。于是去找负责维护网络、防火墙的同事了解，原来防火墙有一个TCP超时时间，目前设置的为半小时，其意义是，对于通过防火墙的所有TCP连接，如果在半小时内没有任何活动，就会被防火墙拆除，这样就会导致连接中断。在拆除连接时，也不会向连接的两端发送任何数据来通知连接已经拆除。
这下数据库连接断开的原因找到了，那么这就是一个应用与数据库在不同的网络中，连接需要经过防火墙的场景中会遇到的一个典型问题，怎么能够使应用和数据库之间即使比较空闲也能够保持一定数量的长连接，是亟待解决的。

3、防火墙切断数据库连接会造成的影响

数据库会话正在执行耗时长的SQL
切断连接之前，连接对应的Oracle会话正在执行一个耗时特别长的SQL，比如存储过程而在此过程中没有任何数据输出到客户端，这样当SQL执行完成之后，向客户端返回结果时，如果TCP连接已经被防火墙中断，这时候显然会出现错误，连接中断，那么会话也就会中断。但是客户端还不知道，会一直处于等待服务器返回结果的状态。
如果客户端没有针对这种执行耗时长的SQL的连接回收机制，那么客户端这个连接将一直处于等待状态，如果客户端不断执行这种耗时长SQL，那么客户端堆积的等待连接将越来越多。
Druid连接池的removeAbandoned相关配置以及逻辑，就是为了解决这种连接回收设置的。

数据库会话空闲
切断连接之前，Oracle会话一直处于空闲状态，在防火墙中断之后，客户端向Oracle服务器提交SQL时，由于TCP连接已经中断，这时客户端侦测到连接中断，那么客户端就会报ORA-03113/ORA-03114这类错误，然后会话中断。但是在Oracle服务器端，会话一直在处于等待客户端消息的状态。
而对于Druid这种有testOnBorrow、testWhileIdle的检测机制，且检测失败可以重新建立连接的连接池，空闲的被防火墙切断的连接在后续会被不断重建，而在数据库服务器端，则连接越来越多，即会话数越来越多，甚至最终超过了数据为最大连接数。

解决方法

1、调大防火墙的连接切断时长

这是一个临时解决方法，比如将防火墙的连接超时时间调整为8小时，这样可以尽量避免空闲连接的切断，但无法完全避免，因为无法预计连接会被空闲多久，如果你的系统不是总有人访问的话，那么连接迟早会因为空闲而被切断，导致一些不可预计的问题，而调大超时时间只是缓解而已

2、tcp keepalive功能

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计时器

3、Oracle数据库的DCD

Oracle提供了类似tcp keepalive的机制，也就是DCD（Dead Conneciton Detection）。在$ORACLE_HOME/network/admin/sqlnet.ora文件中增加如下一行：

sqlnet.expire_time=NNN

这里NNN为分钟数，Oracle数据库会在会话IDLE时间超过这个指定的时间时，检测这个会话的对端（即客户端）是否还有效。避免客户端由于异常退出，导致会话一直存在。
同样的如果DCD的时间比防火墙切断空闲连接的时间短，连接也可以一直保持

4、程序不定时执行查询

以上几种方法要么是利用tcp连接keepalive特性，要么是采用数据库端的空闲连接检测，我们的程序中也可以主动做这种心跳检测

Druid数据库连接池从1.0.28开始，添加了druid.keepAlive属性，默认关闭
打开druid.keepAlive之后，当连接池空闲时，池中的minIdle数量以内的连接，空闲时间超过minEvictableIdleTimeMillis，则会执行keepAlive操作，即执行druid.validationQuery指定的查询SQL，一般为select * from dual，只要minEvictableIdleTimeMillis设置的小于防火墙切断连接时间，就可以保证当连接空闲时自动做保活检测，不会被防火墙切断

参考：
Oracle与防火墙
防火墙、DCD与TCP Keep alive

最后编辑于 ：
©著作权归作者所有,转载或内容合作请联系作者
  • 人面猴
    序言：七十年代末，一起剥皮案震惊了整个滨河市，随后出现的几起案子，更是在滨河造成了极大的恐慌，老刑警刘岩，带你破解...
    沈念sama阅读 202,802评论 5赞 476
  • 死咒
    序言：滨河连续发生了三起死亡事件，死亡现场离奇诡异，居然都是意外死亡，警方通过查阅死者的电脑和手机，发现死者居然都...
    沈念sama阅读 85,109评论 2赞 379
  • 救了他两次的神仙让他今天三更去死
    文/潘晓璐 我一进店门，熙熙楼的掌柜王于贵愁眉苦脸地迎上来，“玉大人，你说我怎么就摊上这事。” “怎么了？”我有些...
    开封第一讲书人阅读 149,683评论 0赞 335
  • 道士缉凶录：失踪的卖姜人
    文/不坏的土叔 我叫张陵，是天一观的道长。 经常有香客问我，道长，这世上最难降的妖魔是什么？ 我笑而不...
    开封第一讲书人阅读 54,458评论 1赞 273
  • 港岛之恋（遗憾婚礼）
    正文 为了忘掉前任，我火速办了婚礼，结果婚礼上，老公的妹妹穿的比我还像新娘。我一直安慰自己，他们只是感情好，可当我...
    茶点故事阅读 63,452评论 5赞 364
  • 恶毒庶女顶嫁案：这布局不是一般人想出来的
    文/花漫 我一把揭开白布。 她就那样静静地躺着，像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上，一...
    开封第一讲书人阅读 48,505评论 1赞 281
  • 城市分裂传说
    那天，我揣着相机与录音，去河边找鬼。 笑死，一个胖子当着我的面吹牛，可吹牛的内容都是我干的。 我是一名探鬼主播，决...
    沈念sama阅读 37,901评论 3赞 395
  • 双鸳鸯连环套：你想象不到人心有多黑
    文/苍兰香墨 我猛地睁开眼，长吁一口气：“原来是场噩梦啊……” “哼！你这毒妇竟也来了？” 一声冷哼从身侧响起，我...
    开封第一讲书人阅读 36,550评论 0赞 256
  • 万荣杀人案实录
    序言：老挝万荣一对情侣失踪，失踪者是张志新（化名）和其女友刘颖，没想到半个月后，有当地人在树林里发现了一具尸体，经...
    沈念sama阅读 40,763评论 1赞 296
  • 护林员之死
    正文 独居荒郊野岭守林人离奇死亡，尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,556评论 2赞 319
  • 白月光启示录
    正文 我和宋清朗相恋三年，在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,629评论 1赞 329
  • 活死人
    序言：一个原本活蹦乱跳的男人离奇死亡，死状恐怖，灵堂内的尸体忽然破棺而出，到底是诈尸还是另有隐情，我是刑警宁泽，带...
    沈念sama阅读 33,330评论 4赞 318
  • 日本核电站爆炸内幕
    正文 年R本政府宣布，位于F岛的核电站，受9级特大地震影响，放射性物质发生泄漏。R本人自食恶果不足惜，却给世界环境...
    茶点故事阅读 38,898评论 3赞 307
  • 男人毒药：我在死后第九天来索命
    文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹，春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,897评论 0赞 19
  • 一桩弑父案，背后竟有这般阴谋
    文/苍兰香墨 我抬头看了看天上的太阳。三九已至，却和暖如春，着一层夹袄步出监牢的瞬间，已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,140评论 1赞 259
  • 情欲美人皮
    我被黑心中介骗来泰国打工， 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留，地道东北人。 一个月前我还...
    沈念sama阅读 42,807评论 2赞 349
  • 代替公主和亲
    正文 我出身青楼，却偏偏与公主长得像，于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子，可洞房花烛夜当晚...
    茶点故事阅读 42,339评论 2赞 342

推荐阅读更多精彩内容