nested exception is com.alibaba.druid.pool.GetConnectionTimeoutException: wait millis 60000, active

admin 管理员组

文章数量: 887021

nested exception is com.alibaba.druid.pool.GetConnectionTimeoutException: wait millis 60000, active

os: ubuntu 16.03
db: postgresql 9.6.8

应用连接数据库报错

2019-07-29 08:40:51,445 946379015 [http-node1] ERROR BaseController  [xxxxxxxxxxxxxxxxxxxxxxxxxxxxxx] - got a Exception
org.mybatis.spring.MyBatisSystemException: nested exception is org.apache.ibatis.exceptions.PersistenceException:Caused by: org.springframework.jdbc.CannotGetJdbcConnectionException: Could not get JDBC Connection; nested exception is com.alibaba.druid.pool.GetConnectionTimeoutException: wait millis 60000, active 0, maxActive 20, creating 1at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:80)at org.mybatis.spring.transaction.SpringManagedTransaction.openConnection(SpringManagedTransaction.java:82)at org.mybatis.spring.transaction.SpringManagedTransaction.getConnection(SpringManagedTransaction.java:68)at org.apache.ibatis.executor.BaseExecutor.getConnection(BaseExecutor.java:336)at org.apache.ibatis.executor.SimpleExecutor.prepareStatement(SimpleExecutor.java:84)at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:62)at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:324)at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:156)at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:109)at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:83)at sun.reflect.GeneratedMethodAccessor277.invoke(Unknown Source)at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)at java.lang.reflect.Method.invoke(Method.java:498)at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:63)at com.sun.proxy.$Proxy220.query(Unknown Source)at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:148)... 91 common frames omitted
Caused by: com.alibaba.druid.pool.GetConnectionTimeoutException: wait millis 60000, active 0, maxActive 20, creating 1at com.alibaba.druid.pool.DruidDataSource.getConnectionInternal(DruidDataSource.java:1510)at com.alibaba.druid.pool.DruidDataSource.getConnectionDirect(DruidDataSource.java:1255)at com.alibaba.druid.filter.FilterChainImpl.dataSource_connect(FilterChainImpl.java:5007)at com.alibaba.druid.filter.logging.LogFilter.dataSource_getConnection(LogFilter.java:876)at com.alibaba.druid.filter.FilterChainImpl.dataSource_connect(FilterChainImpl.java:5003)at com.alibaba.druid.filter.stat.StatFilter.dataSource_getConnection(StatFilter.java:680)at com.alibaba.druid.filter.FilterChainImpl.dataSource_connect(FilterChainImpl.java:5003)at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1233)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)... 106 common frames omitted
Caused by: org.postgresql.util.PSQLException: FATAL: the database system is shutting downat org.postgresql.core.v3.ConnectionFactoryImpl.doAuthentication(ConnectionFactoryImpl.java:443)at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:217)at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:51)at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:215)at org.postgresql.Driver.makeConnection(Driver.java:404)at org.postgresql.Driver.connect(Driver.java:272)at com.alibaba.druid.filter.FilterChainImpl.connection_connect(FilterChainImpl.java:156)at com.alibaba.druid.filter.FilterAdapter.connection_connect(FilterAdapter.java:786)at com.alibaba.druid.filter.FilterEventAdapter.connection_connect(FilterEventAdapter.java:38)at com.alibaba.druid.filter.FilterChainImpl.connection_connect(FilterChainImpl.java:150)at com.alibaba.druid.filter.stat.StatFilter.connection_connect(StatFilter.java:218)at com.alibaba.druid.filter.FilterChainImpl.connection_connect(FilterChainImpl.java:150)at com.alibaba.druid.pool.DruidAbstractDataSource.createPhysicalConnection(DruidAbstractDataSource.java:1560)at com.alibaba.druid.pool.DruidAbstractDataSource.createPhysicalConnection(DruidAbstractDataSource.java:1623)at com.alibaba.druid.pool.DruidDataSource$CreateConnectionThread.run(DruidDataSource.java:2468)

开发重启了应用,是能够正常创建到数据库的连接.

排查

应用使用的 jdbc 是 postgresql-9.4.1212.jre7.jar ,下载源码 postgresql-jdbc-9.4.1212.src.tar.gz
查看 ConnectionFactoryImpl.java
doAuthentication 方法

		  case 'E':// An error occurred, so pass the error message to the// user.//// The most common one to be thrown here is:// "User authentication failed"//int l_elen = pgStream.receiveInteger4();if (l_elen > 30000) {// if the error length is > than 30000 we assume this is really a v2 protocol// server, so trigger fallback.throw new UnsupportedProtocolException();}ServerErrorMessage errorMsg =new ServerErrorMessage(pgStream.receiveErrorString(l_elen - 4), logger.getLogLevel());if (logger.logDebug()) {logger.debug(" <=BE ErrorMessage(" + errorMsg + ")");}throw new PSQLException(errorMsg);

openConnectionImpl 方法

        // Do authentication (until AuthenticationOk).doAuthentication(newStream, hostSpec.getHost(), user, info, logger);

没有分析出有用的信息.

困惑的是: 连接池在 creating 时居然提示 FATAL: the database system is shutting down,但事实上 postgresql 正常运行,没有任何问题.
否则也不会重启就正常了.

参考:
.html

本文标签： nested exception is comalibabadruidpoolGetConnectionTimeoutException wait millis 60000 active