flink实时任务因jedis连接池导致的任务阻塞问题

问题现象

有个flink实时任务，读kafka和redis，中间有复杂的逻辑处理过程，最终结果写redis。flink实时任务运行一段时间后阻塞了，有时是几个小时后，有时是一两天后。

任务看起来正常是正常的，但kafka消费已经停止，checkpoint也失败。看日志，当问题出现后，kafka一直WARN，提示如下

Marking the coordinator xxxxxx dead.
Marking the coordinator xxxxxx dead.
Marking the coordinator xxxxxx dead.

……

任务看起来正常运行，但不再消费kafka，checkpoint失败，除此之外，cpu、mem、io、日志，均看不出异常；集群节点登陆需要申请权限，比较麻烦。

原因分析

步骤1

刚开始以为是kafka消费的问题，导致了任务阻塞。于是寻找解决办法，发现也有部分人遇到类似的问题，但办法不管用。

后面了解到kafka集群版本之前是0.9，最近升级到了2.2.0，建议更新了kafka客户端版本。升级到2.2.0客户端版本后，没有"Marking the coordinator xxx dead."的日志了，但任务还是在运行一段时间后回挂起，问题还没有解决。

步骤2

由于没有权限登陆集群节点，只能通过flink ui，观察cpu、mem、io正常，查看job manager和task manager日志，也没有发现异常。

每次任务阻塞后查看checkpoint，都是失败。刚开始以为checkpoint间隔5秒太短，于是一直往上调整到10分钟，还是照样挂。

有次checkpoint刚挂不久，发现checkpoint挂在sink redis了，其他操作都是几到几十毫秒。那大概原因找到了，写redis有问题。

同时通过最近几次任务挂起后的观察，sink redis数量好像都是在1608，资源申请的是8核cpu、单核内存4G，配置文件prod.sink.redis.maxPools=200，(200+1)*8=1608，看起来有联系？

将prod.sink.redis.maxPools设置为1或者10，问题很快就复现了，可以基本确定，问题发生在sink redis操作了。

步骤3

分析代码，因为写redis需要设置key有效时间，所以没有用原生的flink-redis-connector，而是用了flink-redis-connector+jedis，基于二者做了稍显复杂的封装，用于读写redis三种集群模式：主从复制、哨兵模式、集群模式。

最终发现，setex实现方法有问题，使用完连接后，并没有释放资源。

基本代码逻辑如下：

    @Override
    public String setex(String key, int seconds, String value) {
        String res = null;
        Jedis jedis = null;
        try {
            jedis = getInstance();
            res = jedis.setex(key, seconds, value);
        } catch (Exception e) {
            logger.error("Cannot get Redis message with command GET to key {} error message {}", key, e.getMessage());
            throw e;
        }

        return res;
    }

使用后应该释放资源，正确姿势如下：

    @Override
    public String setex(String key, int seconds, String value) {
        String res = null;
        Jedis jedis = null;
        try {
            jedis = getInstance();
            res = jedis.setex(key, seconds, value);
        } catch (Exception e) {
            logger.error("Cannot get Redis message with command GET to key {} error message {}", key, e.getMessage());
            throw e;
        } finally {
            releaseInstance(jedis);
        }

        return res;
    }

上面优化对于并发的场景，还是有问题。提供另外一个版本，可以解决上面并发问题：

    @Override
    public String setex(String key, int seconds, String value) {
        String res = null;
        try (Jedis jedis = getInstance()) {
            res = jedis.setex(key, seconds, value);
        } catch (Exception e) {
            logger.error("Cannot get Redis message with command GET to key {} error message {}", key, e.getMessage());
        }

        return res;
    }

但是，为啥没有抛异常，没有error或者warn日志？ 

深层分析

明明是jedis连接池不够了，为什么不报错，为什么日志没有error、warn等任何有效信息？是flink集群设置问题，还是其他原因？带着这些问题，继续寻找深层原因。

先看看获取jedis连接的主体代码逻辑

public static RedisContainerInterface build(FlinkJedisPoolConfig flinkJedisPoolConfig) {
    logger.info("flinkJedisPoolConfig:" + flinkJedisPoolConfig.toString());
    Preconditions.checkNotNull(flinkJedisPoolConfig);

    GenericObjectPoolConfig genericObjectPoolConfig = new GenericObjectPoolConfig();
    genericObjectPoolConfig.setMaxIdle(flinkJedisPoolConfig.getMaxIdle());
    genericObjectPoolConfig.setMinIdle(flinkJedisPoolConfig.getMinIdle());
    genericObjectPoolConfig.setMaxTotal(flinkJedisPoolConfig.getMaxTotal());

    JedisPool jedisPool = new JedisPool(genericObjectPoolConfig,
            flinkJedisPoolConfig.getHost(),
            flinkJedisPoolConfig.getPort(),
            flinkJedisPoolConfig.getConnectionTimeout(),
            flinkJedisPoolConfig.getPassword(),
            flinkJedisPoolConfig.getDatabase());

    return new RedisContainerImpl(jedisPool);
}

public RedisContainerImpl(JedisPool jedisPool) {
    Preconditions.checkNotNull(jedisPool, "JedisPool can not be null");
    this.jedisPool = jedisPool;
}

private Jedis getInstance() {
    return jedisPool.getResource();
}

再看看jedis中关于GenericObjectPoolConfig及父类的定义，重点跟连接池有关的部分

public class JedisPoolConfig extends GenericObjectPoolConfig {
  public JedisPoolConfig() {
    // defaults to make your life with connection pool easier :)
    setTestWhileIdle(true);
    setMinEvictableIdleTimeMillis(60000);
    setTimeBetweenEvictionRunsMillis(30000);
    setNumTestsPerEvictionRun(-1);
  }
}

public class GenericObjectPoolConfig<T> extends BaseObjectPoolConfig<T> {
    ……
}

public abstract class BaseObjectPoolConfig<T> extends BaseObject implements Cloneable {

    public static final boolean DEFAULT_BLOCK_WHEN_EXHAUSTED = true;
    public static final long DEFAULT_MAX_WAIT_MILLIS = -1L;


    private boolean blockWhenExhausted = DEFAULT_BLOCK_WHEN_EXHAUSTED;
    private long maxWaitMillis = DEFAULT_MAX_WAIT_MILLIS;

    public boolean getBlockWhenExhausted() {
        return blockWhenExhausted;
    }

    public void setBlockWhenExhausted(final boolean blockWhenExhausted) {
        this.blockWhenExhausted = blockWhenExhausted;
    }

    public void setMaxWaitMillis(final long maxWaitMillis) {
        this.maxWaitMillis = maxWaitMillis;
    }

    public long getMaxWaitMillis() {
        return maxWaitMillis;
    }
    ……
}

看上面代码，BaseObjectPoolConfig类中有两个关键属性：

blockWhenExhausted：如果超时就抛异常,小于零:阻塞不确定的时间, 默认-1。

maxWaitMillis：获取连接时的最大等待毫秒数(如果设置为阻塞时)。

所以，如果要在获取不到连接时抛出异常，需要修改前面的代码，有两种方法：

一是blockWhenExhausted设置为false，即不阻塞，如下

public static RedisContainerInterface build(FlinkJedisPoolConfig flinkJedisPoolConfig) {
    logger.info("flinkJedisPoolConfig:" + flinkJedisPoolConfig.toString());
    Preconditions.checkNotNull(flinkJedisPoolConfig);

    GenericObjectPoolConfig genericObjectPoolConfig = new GenericObjectPoolConfig();
    genericObjectPoolConfig.setMaxIdle(flinkJedisPoolConfig.getMaxIdle());
    genericObjectPoolConfig.setMinIdle(flinkJedisPoolConfig.getMinIdle());
    genericObjectPoolConfig.setMaxTotal(flinkJedisPoolConfig.getMaxTotal());
    genericObjectPoolConfig.setBlockWhenExhausted(false);

    JedisPool jedisPool = new JedisPool(genericObjectPoolConfig,
            flinkJedisPoolConfig.getHost(),
            flinkJedisPoolConfig.getPort(),
            flinkJedisPoolConfig.getConnectionTimeout(),
            flinkJedisPoolConfig.getPassword(),
            flinkJedisPoolConfig.getDatabase());

    return new RedisContainerImpl(jedisPool);
}

二是blockWhenExhausted设置为true，且将maxWaitMillis设置一个超时时间，如下

public static RedisContainerInterface build(FlinkJedisPoolConfig flinkJedisPoolConfig) {
    logger.info("flinkJedisPoolConfig:" + flinkJedisPoolConfig.toString());
    Preconditions.checkNotNull(flinkJedisPoolConfig);

    GenericObjectPoolConfig genericObjectPoolConfig = new GenericObjectPoolConfig();
    genericObjectPoolConfig.setMaxIdle(flinkJedisPoolConfig.getMaxIdle());
    genericObjectPoolConfig.setMinIdle(flinkJedisPoolConfig.getMinIdle());
    genericObjectPoolConfig.setMaxTotal(flinkJedisPoolConfig.getMaxTotal());
    genericObjectPoolConfig.setBlockWhenExhausted(true);
    genericObjectPoolConfig.setMaxWaitMillis(2000);

    JedisPool jedisPool = new JedisPool(genericObjectPoolConfig,
            flinkJedisPoolConfig.getHost(),
            flinkJedisPoolConfig.getPort(),
            flinkJedisPoolConfig.getConnectionTimeout(),
            flinkJedisPoolConfig.getPassword(),
            flinkJedisPoolConfig.getDatabase());

    return new RedisContainerImpl(jedisPool);
}

问题总结

1. kafka之所以有上面的报错，是因为任务已经阻塞了，导致kafka客户端与集群之间通信出问题了。kafka的warn日志只是问题导致的现象，并不是导致问题的原因。尽量保持kafka客户端和集群之间的版本一致，避免一些不必要的麻烦。

2. 问题的根本原因是写redis时，扩展实现了setex方法，但没有释放资源。测试和上线前期，尽量不要将资源设置太大，比如jedis资源池，如果测试环境设置成1，正式环境先设置成10，加上压测，其实问题很快就复现了。

3. jedis连接池资源不够但不抛异常没有日志，导致任务一直阻塞，造成问题分析没那么直观。建议BaseObjectPoolConfig的BlockWhenExhausted默认设置为false，并将MaxWaitMillis设置一个默认超时时间。