一次现网问题定位-Redis连接不断增长

背景

系统原来是使用(HAProxy+Sentinel+redis)做的高可用方案，该方案HAProxy无法感知到主从切换，导致写操作失败。具体可参考之前的文章。
为了解决这个问题，拿掉了HAProxy，然后使用Jedis的Sentinel模式。

# 代码有删减
RedisSentinelConfiguration redisSentinelConfiguration = new RedisSentinelConfiguration(sentinel.getMaster(), sentinelHostAndPorts);
JedisPoolConfig jedisPoolConfig = new JedisPoolConfig();
JedisConnectionFactory jedisConnectionFactory = new JedisConnectionFactory(redisSentinelConfiguration, jedisPoolConfig);
jedisConnectionFactory.afterPropertiesSet();

切换新方案上线后，白天业务高峰期，redis报错:
org.springframework.data.redis.RedisConnectionFailureException: Cannot get Jedis connection; nested exception is redis.clients.jedis.exceptions.JedisConnectionException: open to many files.

定位思路

1.解决open to many files

open to many files一般是超过了系统打开文件数限制。linux一切皆文件，包括网络连接。因此猜测是网络高峰期网络请求太多导致。

解决方法

通过ulimit命令查看当前限制，并通过lsof -p pid查看进程当前已打开文件数。发现系统限制为4096，当前已打开文件数已达到这个限制。
因此先使用ulimit提高这个限制。

结果

当提高系统文件限制数量后，观测打开文件数仍在不断增长。对比以往业务量，这个现象明显有异常，因此分析连接的分布，发现大部分都是redis的连接。

2.定位为什么redis的连接数会不断增长

对比之前版本，本版本只是修改的redis连接方式，运维这边怀疑是哨兵模式本身有问题。个人觉得redis哨兵模式几年前就发布了，要是有BUG，早报到开源社区修复了。之前分析哨兵模式源码时，主从切换jedis会清理连接池，而且redis本身没有事务(具备完整的acid特性，此处表达不够准确)，访问完后就会释放连接，本身不应该有问题。
连接数不断增长有可能的原因应该就2点：
1.redis连接有泄漏，未回收                       --测试环境没有复现问题，此原因存疑。
2.现网就是有这么大访问量，导致redis连接需求有这么高。        --由于系统配置原因，无法使用jstack查看线程堆栈来确认这一点。(因为redis没有事务，执行完查询后，连接直接释放，所以一个线程理论上最多只会持有一个redis连接，所以可以通过线程堆栈来确认)

尝试一：确认redis连接释放是否存在失败的可能

经过源码排查(源码分析见另外一篇文章)，不太有可能。

• 如果释放失败，会抛异常打日志。
• 如上jedis这个包已经在全球现网经受了考验，不太可能有这方面的bug。

尝试二：系统原班开发人员提供了一个疑点

执行multi命令后，未执行exec()方法。

stringRedisTemplate.multi();
stringRedisTemplate.boundHashOps(hkey).put(vkey, vval);
stringRedisTemplate.expireAt(hkey, TimeUtil.startDate(incre));

multi指令是为redis事务准备的，虽然无法进行回退，但是他能保证指令的原子性(redis是单线程的，通过multi包装的指令，redis一次性全部执行完，中间不会插入其他连接发过来的指令)。
为了保证指令的原子性，redis连接肯定是需要被绑定的（执行multi后，当前连接需要跟线程绑定，这样在执行exec前都需要从ThreadLocal去获取同一个连接），不然上面3行代码都是用不同的连接，是无法实现multi指令的。
初步看上述代码嫌疑很大。

结果，验证失败

本地按照现网的模式，写了一个测试代码，并使用redis客户端，通过info clients发现连接数并不如预期会不断增长。

                String prefix = "test";
                for (int i = 0; i < 100; i++) {
                    String key = prefix + String.valueOf(i);
                    new Thread(() -> {
                        while (true) {
                            stringRedisTemplate.multi();
                            stringRedisTemplate.boundHashOps(key).put("a", "vval");
                            stringRedisTemplate.expireAt(key, TimeUtil.startDate(1));
                            try {
                                Thread.sleep(2000);
                            } catch (InterruptedException e) {
                                e.printStackTrace();
                            }
                        }
                    }).start();

                }

通过阅读源码发现，redistemplate只有启用enableTransactionSupport后，才会开启事务功能。
此配置未开启的情况下，即使是执行multi方法，执行完后释放连接的时候，会立即执行exec方法，进行自动提交。
大家可以执行跟踪muti方法的执行，主方法在Redistemplate#execute(RedisCallback action, boolean exposeConnection, boolean pipeline)

	public <T> T execute(RedisCallback<T> action, boolean exposeConnection, boolean pipeline) {
		RedisConnectionFactory factory = getRequiredConnectionFactory();
		RedisConnection conn = null;
		try {

			if (enableTransactionSupport) {
			    # 如果开启事务，会对将Redis连接绑定到线程的上下文，方便后面执行获取到的是同一个连接。
			    # 同时会对RedisConnection进行包装，因为需要拦截close方法，防止连接被回收到连接池
				conn = RedisConnectionUtils.bindConnection(factory, enableTransactionSupport);
			} else {
			    # 走这个分支
				conn = RedisConnectionUtils.getConnection(factory);
			}

			boolean existingConnection = TransactionSynchronizationManager.hasResource(factory);
			T result = action.doInRedis(connToExpose);
			return postProcessResult(result, connToUse, existingConnection);
		} finally {
		    # 执行完命令后，需要释放连接。这就是为啥之前强调一个线程最多只用使用一个redis连接。因为一般的指令执行完后，连接会立即释放
		    # 线程里面的执行都是串行执行的，所以不可能一个线程同时执行2个Redis方法，来持有2条redis连接
			RedisConnectionUtils.releaseConnection(conn, factory, enableTransactionSupport);
		}
	}

到此已经没有办法分析下去了。

尝试三：只能通过dump线程及内存去分析当前线程情况及内存对象。

之前现网jdk的命令执行不成功，因此准备在测试环境捣鼓一下，顺便看看测试环境是不是确实没问题。
准备工作：

1. 使用命令dump内存，jmap -dump:format=b,file=xxx.bin pid
2. 使用visualvm导入内存文件
   通过分析dump文件发现，redis连接确实存在泄漏。
   如图：Redis的连接状态是ALLOCATED，但是除了连接池，却没有其他对象持有它。这个说明之前确实有使用到这个连接，而且使用这个连接的对象已经被回收了。

所以有2个方面的原因：

1. 要么回收连接的时候，抛了异常导致状态没有修改成功。 --貌似不太可能，全球大量使用的库不可能有这种低级错误，而且自身排查源码也没发现什么疑点。
2. 代码中是否用到了某个redis特性，开启了事务，同时未提交事务，导致连接未释放
3. 有地方没有释放资源 --需要全面排查代码

对于第二点，如果开启了事务，会绑定连接到线程上下文的。可以追踪到TransactionSynchronizationManager#resources字段。被绑定的连接都是存在这个里面，因此想通过dump出来的内存，去查找这种对象的信息。遗憾的是，visualvm查找起来太麻烦，遂放弃。

于是找原班人马分析一下用到的redis高阶功能，这样可以快速缩小范围。
根据提供的范围，快速锁定了下面的代码。因为游标类似滑动窗口，一般都会保持与服务端的连接，这样可以实现分批次找服务端查询数据，防止单次查询数据量过大，内存溢出。这里代码又没有显示的关闭游标，泄漏很可能是这里导致。 (ps:要是还不是这个原因，真滴就脑壳疼了，已经快没招了，只能头铁去验证第二点了）

    public Map<String, String> hscan(final String key, int count) {
        ScanOptions scanOptions = ScanOptions.scanOptions().count(count).match("xxxx").build();
        Cursor<Map.Entry<Object, Object>> cursor = stringRedisTemplate.opsForHash().scan(key, scanOptions);

        while (cursor.hasNext()){
            Map.Entry<Object,Object> entry = cursor.next();
            result.put(entry.getKey().toString(),entry.getValue().toString());
        }
        return result;
    }

根据scan方法定位到RedisTemplate的executeWithStickyConnection方法，很惊喜的发现这里没有关闭连接。

	@Override
	public <T extends Closeable> T executeWithStickyConnection(RedisCallback<T> callback) {

		Assert.isTrue(initialized, "template not initialized; call afterPropertiesSet() before using it");
		Assert.notNull(callback, "Callback object must not be null");

		RedisConnectionFactory factory = getRequiredConnectionFactory();

		RedisConnection connection = preProcessConnection(RedisConnectionUtils.doGetConnection(factory, true, false, false),
				false);

		return callback.doInRedis(connection);
	}

理论上上面的分析已经能够解释Redis连接泄漏的问题了，剩的就是本地复现。

答疑

为啥切换之前没有这个问题，切换之前，没有启用连接池。当Curse对象被GC回收后，RedisConection也会被GC被回收，从而释放连接。
切换后，RedisConection除了被Curse持有，还会被连接池持有。Curse回收后，RedisConection仍然在内存中，然后状态还是ALLOCATED无法被复用，这样新连接会不断的被创建，最终达到ulimit的限制。

补充-对“RedisConection也会被GC被回收，从而释放连接”的解释

jvm回收对象的时候，不会自动调用close方法，但是会调用finalize()方法清理资源。
RedisConection本身不占有系统资源，而是其持有的socket占有资源。通过代码跟踪可以看到，RedisConection不显示调用close，gc后也能关闭连接，是因为其持有的socket实现了finalize，并在gc的时候关闭了连接。

Jedis jedis = new Jedis("10.21.22.175",6381);
jedis.connect();

redis.clients.jedis.BinaryJedis#connect

public void connect() {
    this.client.connect();
}

redis.clients.jedis.Connection#connect

    public void connect() {
        if (!this.isConnected()) {
            try {
                this.socket = this.jedisSocketFactory.createSocket();
                this.outputStream = new RedisOutputStream(this.socket.getOutputStream());
                this.inputStream = new RedisInputStream(this.socket.getInputStream());
            }
        }
    }

redis.clients.jedis.DefaultJedisSocketFactory#createSocket

    public Socket createSocket() throws IOException {
        Socket socket = null;

        try {
            socket = new Socket();
            socket.setReuseAddress(true);
            socket.setKeepAlive(true);
            socket.setTcpNoDelay(true);
            socket.setSoLinger(true, 0);
            socket.connect(new InetSocketAddress(this.getHost(), this.getPort()), this.getConnectionTimeout());
            socket.setSoTimeout(this.getSoTimeout());
            # 代码有删减
    }

java.net.Socket#setImpl

    void setImpl() {
        if (factory != null) {
            impl = factory.createSocketImpl();
            checkOldImpl();
        } else {
            # 实际走的是这个分支
            impl = new SocksSocketImpl();
        }
        if (impl != null)
            impl.setSocket(this);
    }

SocksSocketImpl的父类AbstractPlainSocketImpl实现了finalize，并进行了连接关闭
java.net.AbstractPlainSocketImpl#finalize

    protected void finalize() throws IOException {
        close();
    }

测试方法

在java.net.AbstractPlainSocketImpl#finalize方法打一个断点，并观察该代码是否会被执行。

public class DemoApplication {
    public static void main(String[] args) {
        Jedis jedis = new Jedis("xx.xx.xx.xx",6379);
        jedis.connect();
        jedis = null;
        byte[] tmp;
        # 创建大量垃圾，触发gc
        for (int i = 0; i < 10000; i++) {
            tmp = new byte[1024000];
        }
        while (true) {
            ;
        }
    }
}