XWM执行JDBC定时查询报Socket closed异常问题咨询

每日调度运行的定时任务代码此前长期运行正常，首次触发SQL异常。项目所有数据库连接均由XWM框架托管，无手动编写连接关闭逻辑，异常触发时提示Socket closed。

log.info("*************inicio getFactsBajaRelsNoCerradas****************");

JSONArray facts = new JSONArray();

String query = "select nrelac, imprel, fact032, pfj032, no032, ap1032, ap2032, noc032 "
                + "from fiatc.sdt040 left join fiatc.gactb032 on cprof = fact032 "
                + "where scerrada = :relCerrada and sit032 = :sitFacturador ";

Map where = new HashMap<>();
where.put("relCerrada", Constants.NO);
where.put("sitFacturador", Constants.ESTAT_BAIXA);

Map in = JDBCUtil.jdbcExecuteQuery(Constants.CONNEXIO_SALUD, query, where);

Map out = XWM.execute(Constants.JDBC, Constants.EXECUTE_QUERY, in);

List<Map> valuesList = (List<Map>) out.get(Constants.VALUES);

for(Map mapValues : valuesList)
{
    JSONObject facturador = new JSONObject();
    facturador.put(Constants.NRELAC, mapValues.get(Constants.NRELAC).toString().trim());
    facturador.put(Constants.IMPREL, mapValues.get(Constants.IMPREL).toString().trim());
    facturador.put(Constants.FACT032, mapValues.get(Constants.FACT032).toString().trim());
    facturador.put(Constants.PFJ032, mapValues.get(Constants.PFJ032).toString().trim());
    facturador.put(Constants.NO032, mapValues.get(Constants.NO032) != null ? mapValues.get(Constants.NO032).toString().trim() : "");
    facturador.put(Constants.AP1032, mapValues.get(Constants.AP1032) != null ? mapValues.get(Constants.AP1032).toString().trim() : "");
    facturador.put(Constants.AP2032, mapValues.get(Constants.AP2032) != null ? mapValues.get(Constants.AP2032).toString().trim() : "");
    facturador.put(Constants.NOC032, mapValues.get(Constants.NOC032) != null ? mapValues.get(Constants.NOC032).toString().trim() : "");
    facts.put(facturador);
}

异常在以下代码行抛出：

Map out = XWM.execute(Constants.JDBC, Constants.EXECUTE_QUERY, in);

2022-07-06 07:00:27,262 [] INFO [es.fiatc.xwm.jdbc.ExecuteQuery.executeQuery]- Executing query: select nrelac, imprel, fact032, pfj032, no032, ap1032, ap2032, noc032 from fiatc.sdt040 left join fiatc.gactb032 on cprof = fact032 where scerrada = ? and sit032 = ? 
2022-07-06 07:00:27,278 [] INFO [es.fiatc.xwm.jdbc.ExecuteQuery.executeQuery]- With params: [N, BA]
2022-07-06 07:01:30,020 [] ERROR [es.fiatc.xwm.jdbc.ExecuteQuery.execute]- 
com.microsoft.sqlserver.jdbc.SQLServerException: Socket closed
    at com.microsoft.sqlserver.jdbc.SQLServerConnection.terminate(SQLServerConnection.java:2435) ~[mssql-jdbc-6.2.2.jre8.jar:?]
    at com.microsoft.sqlserver.jdbc.TDSChannel.read(IOBuffer.java:1991) ~[mssql-jdbc-6.2.2.jre8.jar:?]
    at com.microsoft.sqlserver.jdbc.TDSReader.readPacket(IOBuffer.java:6310) ~[mssql-jdbc-6.2.2.jre8.jar:?]
    at com.microsoft.sqlserver.jdbc.TDSCommand.startResponse(IOBuffer.java:7545) ~[mssql-jdbc-6.2.2.jre8.jar:?]
    at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.doExecutePreparedStatement(SQLServerPreparedStatement.java:465) ~[mssql-jdbc-6.2.2.jre8.jar:?]
    at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement$PrepStmtExecCmd.doExecute(SQLServerPreparedStatement.java:409) ~[mssql-jdbc-6.2.2.jre8.jar:?]
    at com.microsoft.sqlserver.jdbc.TDSCommand.execute(IOBuffer.java:7151) ~[mssql-jdbc-6.2.2.jre8.jar:?]
    at com.microsoft.sqlserver.jdbc.SQLServerConnection.executeCommand(SQLServerConnection.java:2478) ~[mssql-jdbc-6.2.2.jre8.jar:?]
    at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeCommand(SQLServerStatement.java:219) ~[mssql-jdbc-6.2.2.jre8.jar:?]
    at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeStatement(SQLServerStatement.java:199) ~[mssql-jdbc-6.2.2.jre8.jar:?]
    at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.executeQuery(SQLServerPreparedStatement.java:331) ~[mssql-jdbc-6.2.2.jre8.jar:?]
    at org.apache.tomcat.dbcp.dbcp2.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:121) ~[tomcat-dbcp.jar:9.0.63]
    at org.apache.tomcat.dbcp.dbcp2.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:121) ~[tomcat-dbcp.jar:9.0.63]
    at es.fiatc.xwm.jdbc.ExecuteQuery.executeQuery(ExecuteQuery.java:83) ~[965bfc6983ba2d05e4f861434399d06b8091c0c4.1631203556828/:?]
    at es.fiatc.xwm.jdbc.ExecuteQuery.execute(ExecuteQuery.java:39) ~[965bfc6983ba2d05e4f861434399d06b8091c0c4.1631203556828/:?]
    at es.fiatc.xwm.jdbc.ExecuteQuery.execute(ExecuteQuery.java:53) [965bfc6983ba2d05e4f861434399d06b8091c0c4.1631203556828/:?]
    at es.fiatc.xwm.mod.props.DefaultModule.execute(DefaultModule.java:100) [general-7.0.4.jar:?]
    at es.fiatc.xwm.XWM.execute(XWM.java:148) [general-7.0.4.jar:?]
    at es.fiatc.sld_facturadors.db.FacturadorsDB.getFactsBajaRelsNoCerradas(FacturadorsDB.java:996) [5e123940-6ba6-4fb5-a913-9044a66ae3ef/:?]
    at es.fiatc.sld_facturadors.dao.CercaDAO.getFactsBajaRelsNoCerradas(CercaDAO.java:69) [5e123940-6ba6-4fb5-a913-9044a66ae3ef/:?]
    at es.fiatc.sld_facturadors.actions.scheduler.FactsBajaRelsNoCerradasAction.execute(FactsBajaRelsNoCerradasAction.java:50) [5e123940-6ba6-4fb5-a913-9044a66ae3ef/:?]
    at es.fiatc.xwm.mod.props.DefaultModule.execute(DefaultModule.java:100) [general-7.0.4.jar:?]
    at es.fiatc.xwm.XWM.execute(XWM.java:148) [general-7.0.4.jar:?]
    at es.fiatc.launcher.xwm.XWMJob.execute(XWMJob.java:33) [62b55c76-b327-4cf5-b4a6-1ac84589f545/:?]
    at es.fiatc.launcher.ExecutionJob.run(ExecutionJob.java:38) [62b55c76-b327-4cf5-b4a6-1ac84589f545/:?]
    at java.lang.Thread.run(Thread.java:748) [?:1.8.0_271]
Caused by: java.net.SocketException: Socket closed
    at java.net.SocketInputStream.socketRead0(Native Method) ~[?:1.8.0_271]
    at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) ~[?:1.8.0_271]
    at java.net.SocketInputStream.read(SocketInputStream.java:171) ~[?:1.8.0_271]
    at java.net.SocketInputStream.read(SocketInputStream.java:141) ~[?:1.8.0_271]
    at com.microsoft.sqlserver.jdbc.TDSChannel.read(IOBuffer.java:1981) ~[mssql-jdbc-6.2.2.jre8.jar:?]
    ... 24 more

从日志时间差可以看到，查询发起时间为07:00:27，异常抛出时间为07:01:30，间隔约63秒，按优先级从高到低排查：

• 连接池僵死连接问题：项目使用Tomcat DBCP2作为连接池，定时任务每日仅执行一次，连接池中的连接会存在长时间空闲的情况。若SQL Server侧、中间网络防火墙配置了空闲连接超时，会主动断开长时间无流量的TCP连接，若连接池未配置连接有效性校验，会把已经被对端关闭的僵死连接分配给业务代码，执行SQL时就会抛出Socket closed异常。
  对应修复：调整DBCP2连接池配置
  • 配置validationQuery = "SELECT 1"作为连接校验语句
  • 开启testOnBorrow = true，从连接池获取连接时先做轻量有效性校验，自动剔除失效连接
  • 配置timeBetweenEvictionRunsMillis = 30000，每30秒扫描一次空闲连接；配置minEvictableIdleTimeMillis，值比数据库/防火墙的空闲超时时间短1-2分钟，提前清理长期空闲的连接。
• SQL执行超时问题：先手动在数据库执行带相同参数[N, BA]的查询，确认执行时长是否超过1分钟。若执行耗时过长，检查执行计划是否存在全表扫描、关联字段cprof、过滤字段scerrada/sit032是否缺失索引，同时确认任务执行时间窗口内两个关联表是否存在长事务、锁表情况，导致查询被阻塞超时，连接被数据库强制断开。
• JDBC驱动版本缺陷：当前使用的mssql-jdbc-6.2.2.jre8存在已知的空闲连接复用场景下偶发Socket closed的bug，可升级到6.4.x及以上的稳定版本修复。
• 偶发网络波动：确认异常发生时间窗口是否存在数据库主从切换、网络设备割接、防火墙规则重载等运维操作，如果是单次偶发异常，可给定时任务的数据库查询逻辑增加2-3次重试，每次重试间隔3-5秒，避免单次网络波动导致任务整体失败。

内容的提问来源于stack exchange，提问作者Grismak