redis 의 부적 절 한 사용 으로 인 한 카드 사 bug 의 과정 분석

먼저 문제 현상 을 말씀 드 리 겠 습 니 다.내부 네트워크 Sandbox 환경 API 는 1 주일 동안 응용 카드 가 죽 고 모든 api 가 응답 하지 않 습 니 다.
처음에 환경 응답 이 느리다 고 불평 할 때 우 리 는 응용 프로그램 을 다시 시작 하고 응용 프로그램 이 정상 으로 돌아 와 서 처리 하지 않 았 다.그러나 그 후에 문제 가 발생 하 는 빈도 가 점점 잦 아 지면 서 동료 들 이 불평 하기 시 작 했 고 코드 에 문제 가 있 을 것 같 아서 검 사 를 시작 했다.
먼저 개 발 된 로 컬 id 에 문제 가 발견 되 지 않 았 습 니 다.카드 가 죽 었 을 때 데이터 베 이 스 를 사용 하고 redis 가 정상 적 이 며 특별한 오류 로그 가 없습니다.샌 드 박스 환경 기계 문제 라 고 의심 하기 시작 했다.(테스트 환경 자체 가 바삭바삭 하 다!!)
그래서 ssh 는 서버 에 올 라 다음 명령 을 수행 합 니 다.
top

이때 기계 가 그런대로 정상 인 것 을 발 견 했 지만,마음 은 여전히😖，그래서 jvm 스 택 정 보 를 보 려 고 합 니 다.
먼저 문 제 를 보고 자원 을 비교적 소모 하 는 스 레 드 를 응용 하 다.
집행

상대 적 으로 자원 을 소모 하 는 세 개의 스 레 드 를 찾 습 니 다.
jstack 메모리 보기
jstack 12798|grep 12799 의 16 진법 31ff

아무 문제 도 알 아 채 지 못 하고 상하 10 줄 도 보고 집행 하 다.

일부 스 레 드 가 lock 상태 에 있 는 것 을 보 았 습 니 다.그러나 업무 관련 코드 가 나타 나 지 않 아 무시 했다.이 럴 때 는 두서 가 없다.한 번 생각 하 다.이번에 렉 걸 린 기 계 를 포기 하기 로 했 어 요.
사고 현장 을 보호 하기 위해 먼저 문제 프로 세 스 의 모든 메모 리 를 덤 프 한 다음 debug 모드 에서 테스트 환경 응용 을 다시 시작 합 니 다.문 제 를 다시 표시 할 때 원 격 debug 문제 기 계 를 직접 사용 합 니 다.
다음 날 문제 가 재현 되자 운영 nginx 리 트 윗 에 이 문제 응용 프로그램 을 제거 하고 원 격 debug tomcat 를 사용 하 라 고 알 렸 습 니 다.
스스로 인 터 페 이 스 를 찾 았 습 니 다.인터페이스 입구 에 정지점 이 있 었 습 니 다.비극 이 시작 되 었 고 아무 일 도 일어나 지 않 았 습 니 다!API 가 서비스 응답 을 기다 리 고 정지점 에 들 어가 지 않 았 습 니 다.이때 약간 어리둥절 하고 냉정 해 졌 습 니 다.입구 앞 에 있 는 op 에서 정지점 을 내 렸 고 debug 를 한 번 더 했 습 니 다.이번 에는 정지점 에 들 어 갔 습 니 다.f8 N 번 후에 redis 명령 을 수행 할 때 카드 주 를 발 견 했 습 니 다.계속 따라 가세 요.마지막 으로 제 디 스 의 한 곳 에서 문 제 를 발 견 했 습 니 다.

/**
 * Returns a Jedis instance to be used as a Redis connection. The instance can be newly created or retrieved from a
 * pool.
 * 
 * @return Jedis instance ready for wrapping into a {@link RedisConnection}.
 */
protected Jedis fetchJedisConnector() {
   try {
      if (usePool && pool != null) {
         return pool.getResource();
      }
      Jedis jedis = new Jedis(getShardInfo());
      // force initialization (see Jedis issue #82)
      jedis.connect();
      return jedis;
   } catch (Exception ex) {
      throw new RedisConnectionFailureException("Cannot get Jedis connection", ex);
   }
}

위 pool.getResource()후 스 레 드 시작 wait

public T getResource() {
  try {
    return internalPool.borrowObject();
  } catch (Exception e) {
    throw new JedisConnectionException("Could not get a resource from the pool", e);
  }
}

return internalPool.borrowObject(); 이 코드 는 임대 코드 일 거 예요.이어서...

public T borrowObject(long borrowMaxWaitMillis) throws Exception {
    this.assertOpen();
    AbandonedConfig ac = this.abandonedConfig;
    if (ac != null && ac.getRemoveAbandonedOnBorrow() && this.getNumIdle() < 2 && this.getNumActive() > this.getMaxTotal() - 3) {
        this.removeAbandoned(ac);
    }

    PooledObject<T> p = null;
    boolean blockWhenExhausted = this.getBlockWhenExhausted();
    long waitTime = 0L;

    while(p == null) {
        boolean create = false;
        if (blockWhenExhausted) {
            p = (PooledObject)this.idleObjects.pollFirst();
            if (p == null) {
                create = true;
                p = this.create();
            }

            if (p == null) {
                if (borrowMaxWaitMillis < 0L) {
                    p = (PooledObject)this.idleObjects.takeFirst();
                } else {
                    waitTime = System.currentTimeMillis();
                    p = (PooledObject)this.idleObjects.pollFirst(borrowMaxWaitMillis, TimeUnit.MILLISECONDS);
                    waitTime = System.currentTimeMillis() - waitTime;
                }
            }

            if (p == null) {
                throw new NoSuchElementException("Timeout waiting for idle object");
            }

그 중 에 코드 가 있어 요.

if (p == null) {
    if (borrowMaxWaitMillis < 0L) {
        p = (PooledObject)this.idleObjects.takeFirst();
    } else {
        waitTime = System.currentTimeMillis();
        p = (PooledObject)this.idleObjects.pollFirst(borrowMaxWaitMillis, TimeUnit.MILLISECONDS);
        waitTime = System.currentTimeMillis() - waitTime;
    }
}

borrow MaxWait Millis<0 은 계속 실 행 됩 니 다.그리고 계속 순환 합 니 다. 이 값 이 설정 되 어 있 지 않 은 지 의심 하기 시작 합 니 다.
redis pool 설정 을 찾 았 습 니 다.MaxWait Millis 가 설정 되 어 있 지 않 은 것 을 발 견 했 습 니 다.설정 후 else 코드 도 Exception 으로 문 제 를 해결 할 수 없습니다.
계속 F8 

public E takeFirst() throws InterruptedException {
    this.lock.lock();

    Object var2;
    try {
        Object x;
        while((x = this.unlinkFirst()) == null) {
            this.notEmpty.await();
        }

        var2 = x;
    } finally {
        this.lock.unlock();
    }

    return var2;
}

여기에 와 서 lock 글 자 를 발견 하고 모든 요청 api 가 차단 되 었 다 고 의심 하기 시작 했다.
그래서 다시 ssh 서버 설치 arthas ,(Arthas 알 리 바 바 가 오픈 한 자바 진단 도구 입 니 다)
thread 명령 실행 

http-nio 의 스 레 드 waiting 상 태 를 많이 발 견 했 습 니 다.http-nio-8083-exec-이 스 레 드 는 http 에서 요청 한 tomcat 스 레 드 입 니 다.
임의의 스 레 드 를 찾 아 메모리 더 미 를 봅 니 다.

thread -428

이것 은 api 가 계속 빙빙 돌 고 있 는 문제 임 을 확인 할 수 있 습 니 다.바로 이 redis 가 연결 코드 를 가 져 와 서 생 긴 것 입 니 다.
이 메모리 코드 해독  모든 스 레 드 가 기다 리 고 있 습 니 다. @53e 5504 e 이 대상 은 자 물 쇠 를 방출 합 니 다.그래서 jstack 는 전체 국면 에서 53e 5504 e 를 찾 았 지만 이 대상 이 있 는 스 레 드 를 찾 지 못 했다.
이로부터.문제 의 원인 은 redis 연결 이 가 져 온 문제 임 이 확실 합 니 다.그런데 어떤 이유 로 연결 이 안 되 는 지 아직 확실 하지 않 아 요.
arthas 의 thread-b(thread-b 를 다시 실행 하여 현재 다른 스 레 드 를 막 고 있 는 스 레 드 를 찾 습 니 다)

결과 가 없다.여 기 는 생각 과 달리 차단 스 레 드 를 찾 을 수 있 을 것 입 니 다.그래서 이 명령 을 내 린 문 서 를 보 니 다음 말 이 있 습 니 다.

좋아,우 리 는 마침 후자 야...
다시 한 번 생각 을 정리 하 다.이번 redis pool 설정 을 수정 하면 연결 시간 초과 설정 을 2s 로 설정 한 다음 문제 가 다시 복 원 될 때 응용 프로그램 이 마지막 으로 정상 적 인 시간 에 무엇 을 했 는 지 관찰 합 니 다.
설정 추가

JedisConnectionFactory jedisConnectionFactory = new JedisConnectionFactory();
.......
JedisPoolConfig config = new JedisPoolConfig();
config.setMaxWaitMillis(2000);
.......
jedisConnectionFactory.afterPropertiesSet();

서비스 재 개,대기...
또 하루 지나 다시
ssh 서버,tomcat accesslog 검사,대량의 api 요청 500,
org.springframework.data.redis.RedisConnectionFailureException: Cannot get Jedis connection; nested exception is redis.clients.jedis.exceptions.JedisConnectionException: Could not get a resource fr
om the pool
    at org.springframework.data.redis.connection.jedis.JedisConnectionFactory.fetchJedisConnector(JedisConnectionFactory.java:140)
    at org.springframework.data.redis.connection.jedis.JedisConnectionFactory.getConnection(JedisConnectionFactory.java:229)
    at org.springframework.data.redis.connection.jedis.JedisConnectionFactory.getConnection(JedisConnectionFactory.java:57)
    at org.springframework.data.redis.core.RedisConnectionUtils.doGetConnection(RedisConnectionUtils.java:128)
    at org.springframework.data.redis.core.RedisConnectionUtils.getConnection(RedisConnectionUtils.java:91)
    at org.springframework.data.redis.core.RedisConnectionUtils.getConnection(RedisConnectionUtils.java:78)
    at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:177)
    at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:152)
    at org.springframework.data.redis.core.AbstractOperations.execute(AbstractOperations.java:85)
    at org.springframework.data.redis.core.DefaultHashOperations.get(DefaultHashOperations.java:48)
원천 을 찾 아 처음으로 500 곳 이 나 타 났 다.
다음 코드 발견

.......
Cursor c = stringRedisTemplate.getConnectionFactory().getConnection().scan(options);
while (c.hasNext()) {
.....,,
   }

이 코드 를 분석 하면 string RedisTemplate.getConnection Factory().getConnection()은 pool 의 redisConnection 을 가 져 온 후 후속 작업 을 하지 않 았 습 니 다.즉,이때 redis 연결 풀 에 있 는 링크 가 임대 되 었 을 때 풀 리 거나 링크 풀 에 반환 되 지 않 았 습 니 다.비록 업무 가 처리 되 었 지만 redisConnection 은 이미 비어 있 습 니 다.하지만 pool 의 redisConnection 상 태 는 아직 idle 상태 로 돌아 가지 않 았 습 니 다.

정상

이 문 제 는 이미 찾 았 다.
총화:spring stringRedisTemplate 는 redis 의 일반적인 작업 을 패키지 로 했 지만 Scan SetNx 와 같은 명령 은 지원 되 지 않 습 니 다.이 때 는 jedis Connection 을 받 아 특별한 Commands 를 진행 해 야 합 니 다.
쓰다 string RedisTemplate.getConnection Factory().getConnection()은 추천 되 지 않 습 니 다.
우 리 는 사용 할 수 있다.

stringRedisTemplate.execute(new RedisCallback<Cursor>() {

     @Override
     public Cursor doInRedis(RedisConnection connection) throws DataAccessException {
         
       return connection.scan(options);
     }
   });

수행 하 러 왔 습 니 다.
또는 connection 을 사용 한 후 사용 합 니 다.

RedisConnectionUtils.releaseConnection(conn, factory);

연결 을 해제 합 니 다.
또한,redis 에서 도 keys 명령 을 사용 하 는 것 을 권장 하지 않 습 니 다.redis pool 의 설정 은 합 리 적 으로 맞 춰 야 합 니 다.그렇지 않 으 면 문제 가 발생 하지 않 고 오류 로그 가 없 으 며 오류 가 없 으 며 위치 추적 이 상당히 어렵 습 니 다.
 여기 서 redis 의 부적 절 한 사용 으로 인해 카드 가 죽 는 bug 를 분석 하 는 과정 에 관 한 글 을 소개 합 니 다.더 많은 관련 redis 로 인해 카드 가 죽 는 내용 은 우리 의 이전 글 을 검색 하거나 아래 의 관련 글 을 계속 조회 하 시기 바 랍 니 다.앞으로 많은 응원 바 랍 니 다!