searchusermenu
  • 发布文章
  • 消息中心
点赞
收藏
评论
分享
原创

一次数据源连接问题排查

2023-05-29 01:35:45
300
0

现象

服务内访问数据库超时

分析日志

不断输出如下日志:

2023-05-15 17:50:34.507 ... org.mybatis.spring.MyBatisSystemException: nested exception is org.apache.ibatis.exceptions.PersistenceException: 
### Error querying database.  Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Could not get JDBC Connection; nested exception is com.alibaba.druid.pool.GetConnectionTimeoutException: wait millis 60000, active 10, maxActive 10, creating 0
### The error occurred while executing a query
### Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Could not get JDBC Connection; nested exception is com.alibaba.druid.pool.GetConnectionTimeoutException: wait millis 60000, active 10, maxActive 10, creating 0
    ...
Caused by: com.alibaba.druid.pool.GetConnectionTimeoutException: wait millis 60000, active 10, maxActive 10, creating 0
    at com.alibaba.druid.pool.DruidDataSource.getConnectionInternal(DruidDataSource.java:1512)
    at com.alibaba.druid.pool.DruidDataSource.getConnectionDirect(DruidDataSource.java:1255)
    at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1235)
    at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1225)
    at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:90)
    at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:111)
    at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:77)
    ... 148 common frames omitted    

先重启服务先恢复连接。
然后排查代码,发现连接池中没有可用连接,但是并没有找到连接池创建连接的日志。

直到看见下面一段日志后,数据库访问恢复正常。

2023-05-15 18:21:19.764 [Druid-ConnectionPool-Create-565246475] ERROR c.alibaba.druid.pool.DruidDataSource - [TID:N/A] - create connection SQLException, ..., errorCode 0, state 08S01
com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet sent successfully to the server was 0 milliseconds ago. The driver has not received any packets from the server.
at sun.reflect.GeneratedConstructorAccessor301.newInstance(Unknown Source)

Caused by: java.net.SocketException: Connection reset

    ... 30 common frames omitted

分析关键代码

# com.mysql.jdbc.ConnectionImpl#createNewIO

发现此处会对建立连接上锁,建立连接超时了。
进一步分析,发现是连接正常,读取数据超时,即未触发 connectionTimeout,触发了 readTimeout。当 jdbc 未设置 socketTimeout,用到了操作系统的 tcp 超时时间。


结论

数据源配置超时参数:

# 连接超时
connectTimeout=
# 支持重连
autoReconnect=true
# jdbc 不设置,默认采用 操作系统的 tcp 超时时间,/proc/sys/net/ipv4/tcp_keepalive_time
socketTimeout=
0条评论
0 / 1000
朱****斌
10文章数
0粉丝数
朱****斌
10 文章 | 0 粉丝
原创

一次数据源连接问题排查

2023-05-29 01:35:45
300
0

现象

服务内访问数据库超时

分析日志

不断输出如下日志:

2023-05-15 17:50:34.507 ... org.mybatis.spring.MyBatisSystemException: nested exception is org.apache.ibatis.exceptions.PersistenceException: 
### Error querying database.  Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Could not get JDBC Connection; nested exception is com.alibaba.druid.pool.GetConnectionTimeoutException: wait millis 60000, active 10, maxActive 10, creating 0
### The error occurred while executing a query
### Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Could not get JDBC Connection; nested exception is com.alibaba.druid.pool.GetConnectionTimeoutException: wait millis 60000, active 10, maxActive 10, creating 0
    ...
Caused by: com.alibaba.druid.pool.GetConnectionTimeoutException: wait millis 60000, active 10, maxActive 10, creating 0
    at com.alibaba.druid.pool.DruidDataSource.getConnectionInternal(DruidDataSource.java:1512)
    at com.alibaba.druid.pool.DruidDataSource.getConnectionDirect(DruidDataSource.java:1255)
    at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1235)
    at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1225)
    at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:90)
    at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:111)
    at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:77)
    ... 148 common frames omitted    

先重启服务先恢复连接。
然后排查代码,发现连接池中没有可用连接,但是并没有找到连接池创建连接的日志。

直到看见下面一段日志后,数据库访问恢复正常。

2023-05-15 18:21:19.764 [Druid-ConnectionPool-Create-565246475] ERROR c.alibaba.druid.pool.DruidDataSource - [TID:N/A] - create connection SQLException, ..., errorCode 0, state 08S01
com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet sent successfully to the server was 0 milliseconds ago. The driver has not received any packets from the server.
at sun.reflect.GeneratedConstructorAccessor301.newInstance(Unknown Source)

Caused by: java.net.SocketException: Connection reset

    ... 30 common frames omitted

分析关键代码

# com.mysql.jdbc.ConnectionImpl#createNewIO

发现此处会对建立连接上锁,建立连接超时了。
进一步分析,发现是连接正常,读取数据超时,即未触发 connectionTimeout,触发了 readTimeout。当 jdbc 未设置 socketTimeout,用到了操作系统的 tcp 超时时间。


结论

数据源配置超时参数:

# 连接超时
connectTimeout=
# 支持重连
autoReconnect=true
# jdbc 不设置,默认采用 操作系统的 tcp 超时时间,/proc/sys/net/ipv4/tcp_keepalive_time
socketTimeout=
文章来自个人专栏
文章 | 订阅
0条评论
0 / 1000
请输入你的评论
0
0