GetConnectionTimeoutException排查分析

报错

Caused by: com.alibaba.druid.pool.GetConnectionTimeoutException: wait millis 600000, active 3, maxActive 3, creating 0
从字面理解为：
给的3个连接一直未释放，但又有新的请求进来，等待600000后报错GetConnectionTimeoutException。
这个问题曾经遇到过，本次梳理一下记录备查。

环境

1. MyEclipse测试环境
2. jdbc.properties

mysql.jdbc.initialPoolSize=1
mysql.jdbc.minPoolSize=1
mysql.jdbc.maxPoolSize=3
mysql.jdbc.maxWait=600000
mysql.jdbc.timeBetweenEvictionRunsMillis=900000
mysql.jdbc.minEvictableIdleTimeMillis=300000
mysql.jdbc.mysqlValidationQuery=SELECT 1

3. log4j

### local log Console ###
log4j.appender.Console=org.apache.log4j.ConsoleAppender
log4j.appender.Console.Threshold = DEBUG  
log4j.appender.Console.layout=org.apache.log4j.PatternLayout
log4j.appender.Console.layout.ConversionPattern=%d [%t] %-5p [%c] - %m%n 

### local log file ###
log4j.appender.D = org.apache.log4j.DailyRollingFileAppender
log4j.appender.D.Threshold = DEBUG
log4j.appender.D.ImmediateFlush=true
log4j.appender.D.DatePattern='_'yyyy-MM-dd'.log'
log4j.appender.D.File = ${catalina.home}/debug
log4j.appender.D.Append = true
log4j.appender.D.layout = org.apache.log4j.PatternLayout
log4j.appender.D.layout.ConversionPattern = %-d{yyyy-MM-dd HH:mm:ss}  [ %t:%r ] - [ %p ]  %m%n

分析

1. 将mysql.jdbc.maxPoolSize从3修改为5

问题依旧存在

2. 排查是否存在未释放连接的业务

看了下日志打印的SQL，没找到此类隐患，SQL执行耗时基本正常

3. log4j的隐患排查

发送死锁。线程过多。 这个问题你把输出到控制台的日志，不要用debug，改用更高级别的即可。

网友的意见给我启发，将日志级别Threshold调为INFO

验证

将log4j日志级别Threshold调为INFO后再未出现GetConnectionTimeoutException报错。