JDBC链接出现超时问题

今日线上突发一个问题，应用假死，不接受http请求，排查日志，发现有大量的 The last packet successfully received from 异常。

首先排查数据库和链接池配置

<bean id="dataSource" class="org.apache.tomcat.jdbc.pool.DataSource"
          destroy-method="close">
        <!-- Connection Info -->
        <property name="driverClassName" value="${jdbc.driver}"/>
        <property name="url" value="${jdbc.url}"/>
        <property name="username" value="${jdbc.username}"/>
        <property name="password" value="${jdbc.password}"/>

        <!-- Connection Pooling Info -->
        <property name="maxActive" value="${jdbc.pool.maxActive}"/>
        <property name="maxIdle" value="${jdbc.pool.maxIdle}"/>
        <property name="defaultAutoCommit" value="true"/>
        <property name="validationQuery" value="${jdbc.validationQuery}"/>
        <property name="testOnBorrow" value="true"/>
        <!-- 连接Idle一个小时后超时 -->
        <property name="timeBetweenEvictionRunsMillis" value="3600000"/>
        <property name="minEvictableIdleTimeMillis" value="3600000"/>
       
    </bean>

对比mysql 配置 的timeout配置

链接池的超时时间远远小于 数据库的wait_timeout ,配置没有问题

wait_timeout wait_timeout 服务器关闭非交互连接之前等待活动的秒数
数据库wait_timeout配置的3600s(1小时)、业务线程闲置状态下和数据库保持的连接存活1个小时后数据库主动断开连接，这个时候有新的数据库操作请求、拿到该连接去执行validationQuery检测连接是否有效，由于数据库已经主动断开连接、执行检测sql就会抛出上面的错误。问题的本质还是druid线程池里没有及时清除无效的数据库连接导致。
但数据库的判断认为的连接超时时间是 timeBetweenEvictionRunsMillis = 3600000 < wait_timeout = 31536000 故问题不在此

排查应用程序

使用arthas监控线程，果不其然，出现了10running的http-nio线程，打开一个查看一下，果然有线程死锁

[arthas@23223]$ thread 167
"http-nio-30030-exec-113" Id=167 RUNNABLE (in native)
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
    at java.net.SocketInputStream.read(SocketInputStream.java:171)
    at java.net.SocketInputStream.read(SocketInputStream.java:141)
    at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:112)
    at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:159)
    at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:187)
    -  locked com.mysql.jdbc.util.ReadAheadInputStream@5c14cebc
    at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3140)
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3597)
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3586)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4131)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2597)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2758)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2820)
    -  locked com.mysql.jdbc.JDBC4Connection@eba881e
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2769)
    at com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:907)
    -  locked com.mysql.jdbc.JDBC4Connection@eba881e
    at com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:791)
    at net.sf.log4jdbc.StatementSpy.execute(StatementSpy.java:842)
    at org.apache.tomcat.jdbc.pool.PooledConnection.validate(PooledConnection.java:455)
    at org.apache.tomcat.jdbc.pool.PooledConnection.validate(PooledConnection.java:395)
    at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:777)
    at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:618)
    at org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:188)
    at org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:128)
    at org.springside.modules.persistence.Hibernates.getJdbcUrlFromDataSource(Hibernates.java:47)
    at org.springside.modules.persistence.Hibernates.getDialect(Hibernates.java:30)
    at cn.infisa.obstetrics.respository.DaoUtils.getDatabaseDialect(DaoUtils.java:130)
    at cn.infisa.obstetrics.respository.DaoUtils.getUrl(DaoUtils.java:151)
    at cn.infisa.obstetrics.respository.DaoUtils.getDataList(DaoUtils.java:174)
    at cn.infisa.obstetrics.respository.hospital.PatientInfoJdbcDao.getTimeline(PatientInfoJdbcDao.java:136)
    at cn.infisa.obstetrics.service.hospital.PatientInfoService.getTimeline(PatientInfoService.java:74)
    at cn.infisa.obstetrics.service.hospital.PatientInfoMenuService.assemPatientTimeline(PatientInfoMenuService.java:375)
    at cn.infisa.obstetrics.web.record.PatientInfoController.getTimeline(PatientInfoController.java:134)
    at sun.reflect.GeneratedMethodAccessor149.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

线程调用过程中，有三把锁，分别位于：

• com.mysql.jdbc.StatementImpl.execute synchronized (locallyScopedConn.getConnectionMutex()) Line:797
• com.mysql.jdbc.ConnectionImpl.execSQL synchronized (getConnectionMutex()) Line:2779
• com.mysql.jdbc.util.ReadAheadInputStream public synchronized int read(byte b[], int off, int len) throws IOException Line 176
  最后锁住在 socketRead0 方法，而socketRead0 是一个native方法，有一个参数表示方法的超时设置-timeout

 private int socketRead(FileDescriptor fd,
                           byte b[], int off, int len,
                           int timeout)
        throws IOException {
        return socketRead0(fd, b, off, len, timeout);
    }
  private native int socketRead0(FileDescriptor fd,
                                   byte b[], int off, int len,
                                   int timeout)
        throws IOException;

什么是 Socket 超时

JDBC 驱动是用 Socket 方式与数据库连接的，应用程序和数据库之间的连接超时并不是由数据库处理的。

当数据库突然宕掉或发生网络错误（设备故障等）时，JDBC 驱动的 Socket 超时的值是必须的。由于 TCP/IP 的结构，Socket 没有办法检测到网络错误，因此应用不能检测到与数据库到连接断开了。如果没有设置 Socket 超时，应用程序会一直等待数据库返回结果。（这个连接也被叫做“死连接”） 为了避免死连接，Socket 必须要设置超时时间。Socket 超时可以通过 JDBC 驱动程序配置。通过设置 Socket 超时，可以防止出现网络错误时一直等待的情况并缩短故障时间。

原因分析

通过这儿明白了，socket链接超时，导致链接池中数据库占满，新线程申请不到链接，故http请求不响应；在socket超时后，释放链接，就会抛出大量的超时(The last packet successfully received from)错误。

解决办法

配置jdbc参数，在一个合理的范围内影响，超时即停止。

jdbc.url=jdbc:log4jdbc:mysql://ip:port/dbname?useUnicode=true&characterEncoding=utf-8&connectTimeout=60000&socketTimeout=60000

参考：

https://blog.csdn.net/jiadajing267/article/details/79516989
https://blog.csdn.net/java1993666/article/details/87889941
深入理解 JDBC 的超时