1. 问题缘起
有一个web服务应用一直在稳定运行，直到最近一个月，陆续三次在晚上出现了JedisConnectionException的异常，服务集群几乎在同一时间段都报同一错误，无法正常运行，重启后一切正常。
redis.clients.jedis.exceptions.JedisConnectionException: Could not get a resource from the pool
at redis.clients.util.Pool.getResource(Pool.java:50)
at redis.clients.jedis.JedisPool.getResource(JedisPool.java:86)
…
Caused by: java.util.NoSuchElementException: Timeout waiting for idle object
at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:449)
2. 现场处理和初步调查结论
- JedisConnectionException异常所报告的问题是，无法正常获取连接，通过查看redis连接池配置（maxTotal=200）和当时的并发流量（并发数小于5），没有发现不对和特别的地方。
- 通过netstat查看网络TCP连接，redis连接数也不多（小于20），正常连接中，在redis服务器端可以观察到有连接正在陆续正常地新建和关闭，网络没有问题。
- 查看zabbix和pinpoint监控，主站应用的CPU使用率有升高，不过在正常范围内，但响应时间有飙高（长达6秒），预计是获取redis连接阻塞的原因（在redis客户端设置阻塞时间为6秒）。
- 为了能够保证主站恢复使用，调查一段时间后，决定重启应用，然后检查所有服务，一切恢复正常使用。
3. 调查方向
根据现象，确定如下几个调查方向，
- 查看redis的访问代码实现，是否有redis连接泄漏？并尝试是否可以本地开发环境重现同样问题。
- 查看线上配置，是否配置不正确或者未加载的情况？
- 查看网络原因，是否由于因为防火墙导致单机连接有限制？
- 查看iptables
- 使用tcpdump查看TCP流量
- 查看主站应用的请求访问日志和运行日志，查看异常前后有无特别的请求访问？
- 请求访问日志 localhost_access_log.2018-12-28
- 运行日志 catalina.out-20181228
4. 定位问题
通过查看代码时，发现有段代码在获取redis连接后，没有在方法退出时执行close()方法，
public void leakRedisConn() {
Jedis jedis = null;
try {
jedis = jedisPool.getResource();
jedis.ping();
} catch (Exception ignored) {
} finally {
// 没有归还redis连接到空闲资源池
// if (jedis != null) jedis.close();
}
}
查看服务集群的请求访问日志和运行日志，发现在JedisConnectionException异常出现前，都有对该方法的调用，印证此方法和异常的出现有强关联性，因此上述方法应该就是异常发生的罪魁祸首。
该方法在获取连接后，并没有执行close()方法，使得redis连接无法回收到空闲资源池，每一次调用，都会泄漏一个连接，直到整个连接池队列达到上限，从而出现异常。具体原因见对JedisPool的代码分析。
5. 异常出现的原因和JedisPool代码分析
通过分析JedisPool的实现代码，可以看到里面有两个内部对象allObjects和idleObjects，一个是保存着所有连接对象，一个是保存着所有空闲连接对象，
public class JedisPool extends Pool<Jedis> {
protected GenericObjectPool<T> internalPool;
}
// JedisPool里通过GenericObjectPool维护着所创建的连接池对象，实现Jedis连接的创建、获取和回收，
class GenericObjectPool{
private final Map<T, PooledObject<T>> allObjects; // 保存着所有连接对象，上限通过maxTotal控制
private final LinkedBlockingDeque<PooledObject<T>> idleObjects; // 保存着所有空闲连接对象，上限通过maxIdle控制
}
每次创建时，新建的连接会放入allObjects列表中，在close()方法调用时，空闲的连接会存放入idleObjects，以待后续重复利用。
方法jedisPool.getResource()会先尝试从空闲队列中获取连接，若获取不到，则尝试新建一个连接。一旦获取到的连接没有执行close()方法，则无法被回收到空闲队列，于是每一次方法调用，allObjects连接池中会增加一个，一旦数量超过maxTotal，则不再允许创建，请见下面的代码，
class GenericObjectPool{
public T borrowObject(long borrowMaxWaitMillis) throws Exception {
...
boolean create;
p = (PooledObject)this.idleObjects.pollFirst();
if(p == null) {
p = this.create();
if(p != null) {
create = true;
}
}
...
}
private PooledObject<T> create() throws Exception {
int localMaxTotal = this.getMaxTotal();
long newCreateCount = this.createCount.incrementAndGet();
// 当创建的个数大于maxTotal时，则不再允许创建，直接返回null
if((localMaxTotal <= -1 || newCreateCount <= (long)localMaxTotal) && newCreateCount <= 2147483647L) {
PooledObject p;
try {
p = this.factory.makeObject();
} catch (Exception var6) {
}
...
return p;
} else {
this.createCount.decrementAndGet();
return null;
}
}
}
注意的是，泄漏的连接在redis服务器端在超时后会被关闭，但在客户端则一直占着位置不会被释放，从而报JedisConnectionException异常，直到重启。
5. 后记
对这个JedisConnectionException的异常泄漏问题解决后，后来想了想，还有两个事情可以总结下，以待未来改进。
5.1 保留问题第一现场
在发生问题时，可以通过如下jmap命令保存下Java内存快照，保留第一现场，这样能够为后续查看发生问题，分析JedisPool对象的内部数据提供方便。
jmap -dump:format=b,file=jmap.dump <pid>
下图是通过Eclipse的MemoryAnalyzer工具分析的JedisPool对象，
若当时有上面的内存快照，可以看到minIdle/maxIdle的配置情况，也可以看到createCount的变量值，这样会更加容易发现redis泄漏问题。
5.2 一颗老鼠屎，坏了一锅粥
对于Jedis连接池这种全局有限资源，必须严控管理，规范使用，不然一个地方出现泄漏，就会导致整个应用崩溃，本案例是一个活生生的例子。
