java.sql.SQLRecoverableException: IO 错误: Socket closed

   今天weblogic的alllog日志报了很多socket closed的错误。

### Cause: org.hibernate.exception.JDBCConnectionException: IO 错误: Socket closed

at com.gg.corm.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:23) ~[gg-top-corm-3.1.2-20141209.jar:na]
at com.gg.corm.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:104) ~[gg-top-corm-3.1.2-20141209.jar:na]
at com.gg.corm.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:95) ~[gg-top-corm-3.1.2-20141209.jar:na]
at com.gg.corm.session.defaults.DefaultSqlSession.selectOne(DefaultSqlSession.java:59) ~[gg-top-corm-3.1.2-20141209.jar:na]
at com.gg.sproc.core.base.dao.MyBatisDAO$6.execute(MyBatisDAO.java:241) ~[sproc-core-1.3.1-20141225.jar:1.3.1-20141225]
at org.hibernate.jdbc.WorkExecutor.executeWork(WorkExecutor.java:54) ~[com.gg.top.thirdparty-hibernate-core-4.1.9.Final.jar:4.1.9.Final]
at org.hibernate.internal.SessionImpl$2.accept(SessionImpl.java:1936) ~[com.gg.top.thirdparty-hibernate-core-4.1.9.Final.jar:4.1.9.Final]
at org.hibernate.internal.SessionImpl$2.accept(SessionImpl.java:1933) ~[com.gg.top.thirdparty-hibernate-core-4.1.9.Final.jar:4.1.9.Final]
at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.coordinateWork(JdbcCoordinatorImpl.java:211) ~[com.gg.top.thirdparty-hibernate-core-4.1.9.Final.jar:4.1.9.Final]
at org.hibernate.internal.SessionImpl.doWork(SessionImpl.java:1954) ~[com.gg.top.thirdparty-hibernate-core-4.1.9.Final.jar:4.1.9.Final]
at org.hibernate.internal.SessionImpl.doWork(SessionImpl.java:1940) ~[com.gg.top.thirdparty-hibernate-core-4.1.9.Final.jar:4.1.9.Final]
at com.gg.sproc.core.base.dao.MyBatisDAO.getObject(MyBatisDAO.java:236) ~[sproc-core-1.3.1-20141225.jar:1.3.1-20141225]
... 75 common frames omitted
Caused by: org.hibernate.exception.JDBCConnectionException: IO 错误: Socket closed
at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:131) ~[com.gg.top.thirdparty-hibernate-core-4.1.9.Final.jar:4.1.9.Final]
at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:49) ~[com.gg.top.thirdparty-hibernate-core-4.1.9.Final.jar:4.1.9.Final]
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:125) ~[com.gg.top.thirdparty-hibernate-core-4.1.9.Final.jar:4.1.9.Final]
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:110) ~[com.gg.top.thirdparty-hibernate-core-4.1.9.Final.jar:4.1.9.Final]
at org.hibernate.engine.jdbc.internal.proxy.AbstractStatementProxyHandler.continueInvocation(AbstractStatementProxyHandler.java:129) ~[com.gg.top.thirdparty-hibernate-core-4.1.9.Final.jar:4.1.9.Final]
at org.hibernate.engine.jdbc.internal.proxy.AbstractProxyHandler.invoke(AbstractProxyHandler.java:81) ~[com.gg.top.thirdparty-hibernate-core-4.1.9.Final.jar:4.1.9.Final]
at com.sun.proxy.$Proxy250.execute(Unknown Source) ~[na:na]
at com.gg.corm.executor.statement.PreparedStatementHandler.query(PreparedStatementHandler.java:56) ~[gg-top-corm-3.1.2-20141209.jar:na]
at com.gg.corm.executor.statement.RoutingStatementHandler.query(RoutingStatementHandler.java:70) ~[gg-top-corm-3.1.2-20141209.jar:na]
at sun.reflect.GeneratedMethodAccessor197.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_40]
at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_40]
at com.gg.corm.plugin.Plugin.invoke(Plugin.java:59) ~[gg-top-corm-3.1.2-20141209.jar:na]
at com.sun.proxy.$Proxy234.query(Unknown Source) ~[na:na]
at com.gg.corm.executor.SimpleExecutor.doQuery(SimpleExecutor.java:69) ~[gg-top-corm-3.1.2-20141209.jar:na]
at com.gg.corm.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:267) ~[gg-top-corm-3.1.2-20141209.jar:na]
at com.gg.corm.executor.BaseExecutor.query(BaseExecutor.java:141) ~[gg-top-corm-3.1.2-20141209.jar:na]
at com.gg.corm.executor.CachingExecutor.query(CachingExecutor.java:105) ~[gg-top-corm-3.1.2-20141209.jar:na]
at com.gg.corm.executor.CachingExecutor.query(CachingExecutor.java:81) ~[gg-top-corm-3.1.2-20141209.jar:na]
at com.gg.corm.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:101) ~[gg-top-corm-3.1.2-20141209.jar:na]
... 85 common frames omitted
Caused by: java.sql.SQLRecoverableException: IO 错误: Socket closed
at oracle.jdbc.driver.T4CPreparedStatement.executeForDescribe(T4CPreparedStatement.java:897) ~[ojdbc6.jar:11.2.0.3.0]
at oracle.jdbc.driver.OracleStatement.executeMaybeDescribe(OracleStatement.java:1167) ~[ojdbc6.jar:11.2.0.3.0]
at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1289) ~[ojdbc6.jar:11.2.0.3.0]
at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3594) ~[ojdbc6.jar:11.2.0.3.0]
at oracle.jdbc.driver.OraclePreparedStatement.execute(OraclePreparedStatement.java:3695) ~[ojdbc6.jar:11.2.0.3.0]
at oracle.jdbc.driver.OraclePreparedStatementWrapper.execute(OraclePreparedStatementWrapper.java:1378) ~[ojdbc6.jar:11.2.0.3.0]
at weblogic.jdbc.wrapper.PreparedStatement.execute(PreparedStatement.java:101) ~[weblogic.server.merged.jar:12.1.2.0.0]
at sun.reflect.GeneratedMethodAccessor695.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_40]
at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_40]
at org.hibernate.engine.jdbc.internal.proxy.AbstractStatementProxyHandler.continueInvocation(AbstractStatementProxyHandler.java:122) ~[com.gg.top.thirdparty-hibernate-core-4.1.9.Final.jar:4.1.9.Final]
... 100 common frames omitted
Caused by: java.net.SocketException: Socket closed
at java.net.SocketInputStream.socketRead0(Native Method) ~[na:1.7.0_40]
at java.net.SocketInputStream.read(SocketInputStream.java:152) ~[na:1.7.0_40]
at java.net.SocketInputStream.read(SocketInputStream.java:122) ~[na:1.7.0_40]
at oracle.net.ns.Packet.receive(Packet.java:300) ~[ojdbc6.jar:11.2.0.3.0]
at oracle.net.ns.DataPacket.receive(DataPacket.java:106) ~[ojdbc6.jar:11.2.0.3.0]
at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:315) ~[ojdbc6.jar:11.2.0.3.0]
at oracle.net.ns.NetInputStream.read(NetInputStream.java:260) ~[ojdbc6.jar:11.2.0.3.0]
at oracle.net.ns.NetInputStream.read(NetInputStream.java:185) ~[ojdbc6.jar:11.2.0.3.0]
at oracle.net.ns.NetInputStream.read(NetInputStream.java:102) ~[ojdbc6.jar:11.2.0.3.0]
at oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:124) ~[ojdbc6.jar:11.2.0.3.0]
at oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:80) ~[ojdbc6.jar:11.2.0.3.0]
at oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1137) ~[ojdbc6.jar:11.2.0.3.0]
at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:290) ~[ojdbc6.jar:11.2.0.3.0]
at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:192) ~[ojdbc6.jar:11.2.0.3.0]
at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:531) ~[ojdbc6.jar:11.2.0.3.0]
at oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:207) ~[ojdbc6.jar:11.2.0.3.0]
at oracle.jdbc.driver.T4CPreparedStatement.executeForDescribe(T4CPreparedStatement.java:884) ~[ojdbc6.jar:11.2.0.3.0]

... 110 common frames omitted

再检查server日志，发现在alllog中报socket closed错误的时段：

####<2015-1-5 上午11时37分22秒 CST> <Info> <JDBC> <scgg15140> <appServer> <[ACTIVE] ExecuteThread: '3' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1420429042060> <BEA-001128> <Connection for pool "ggDataSource" has been closed.> 
####<2015-1-5 上午11时38分32秒 CST> <Info> <JDBC> <scgg15140> <appServer> <[ACTIVE] ExecuteThread: '3' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1420429112057> <BEA-001128> <Connection for pool "ggDataSource" has been closed.> 
####<2015-1-5 上午11时38分52秒 CST> <Info> <JDBC> <scgg15140> <appServer> <[ACTIVE] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1420429132057> <BEA-001128> <Connection for pool "ggDataSource" has been closed.> 
####<2015-1-5 上午11时51分32秒 CST> <Info> <JDBC> <scgg15140> <appServer> <[ACTIVE] ExecuteThread: '13' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1420429892057> <BEA-001128> <Connection for pool "ggDataSource" has been closed.> 

连接池关闭，连接池为甚关闭呢？在此时间段只有一条SQL报错，为什么不是大规模的报错呢？

与一名开发人员反馈，说每次都可以出现，于是找他重现。在16点到17点重现了，但在17点到18点又重现不了，我无意识的看了两个时段的AWR报告，发现有报错时段的SQL执行时37s，没有报错时段的SQL执行是2s。

我怀疑与非活动连接超时这个参数有关系，于是找了一个功能为120s的，做了个测试：

非活动连接超时	等待多少秒后报错
1	20s
5	16s
10	40s
15	不报错，等待120s后功能出来了
30	同上
50	同上

总结：治标的调大非活动连接超时这个参数，治本的方法是调优SQL。

A leaked connection is a connection that was not properly returned to the connection pool in the data source. To automatically recover leaked connections, you can specify a value for Inactive Connection Timeouton the JDBC Data Source: Configuration: Connection Pool page in the Administration Console. When you set a value for Inactive Connection Timeout, WebLogic Server forcibly returns a connection to the data source when there is no activity on a reserved connection for the number of seconds that you specify. When set to 0 (the default value), this feature is turned off.