본문 바로가기
트러블슈팅과 고민/트러블슈팅

레디스 파이프라인으로 인한 Netty 태스크 큐 병목 식별 및 해결 후 Spring Data Redis 기여

by 정재익 2026. 3. 9.

목차

 

1. 서론

    1.1 오류발생

    1.2 상황종합

    1.3 결과요약

2. 원인 탐색

    2.1 FD, Redis 커넥션, 메모리, 로그, 실행시간 분석    

    2.2 커넥션 풀이 없는 경우 파이프라인의 동작

    2.3 Redis가 수신한 커넥션과 현재 커넥션 수의 괴리

    2.4 레터스의 첫 응답 마지막 응답 시간 비교 - 병목 시간 식별

    2.5 Lettuce의 커넥션 해제 로직 - Netty 이벤트루프 호출

    2.6 Redis CPU

    2.7 Unable to connect to Redis 발생 이유
    2.8 Pipeline contained one or more invalid commands 발생 이유

    2.9 재테스트 - Netty 병목 식별
    2.10 문제 해결 - 커넥션 풀 설정으로 요청마다 파이프라인의 독립 커넥션 생성 및 파괴로 인한 Netty이벤트루프 병목 제거 

3. 테스트 시나리오

    3.1 게시글 목록 조회 테스트 시나리오

    3.2 캐시 수정 상황 테스트 시나리오

4. 테스트 결과

    4.1 게시글 목록 조회 테스트 결과

    4.2 캐시 수정 상황 테스트 결과

5. 캐시 구조 변경

6. 변경한 캐시 테스트 결과

    6.1 게시글 목록 조회 테스트 결과

    6.2 캐시 수정 상황 테스트 결과

7. 스프링 데이터 레디스 기여 및 3.5.11까지 백포팅

 

1. 서론

1.1 오류발생

Redis의 연결 오류는 게시글 조회에서 발생하였습니다.

첫 페이지를 캐시로 활용하는데 리스트를 큐로 사용하여 글 ID를 삽입하고 각 글의 상세 내용을 별도의 Hash에 담았습니다.

 

실험을 위해 부하테스트를 실행했을 때 아래와 같은 오류가 발생했습니다.

ERROR j.b.i.exception.GlobalExceptionHandler - Exception occurred: 
타입 = RedisConnectionFailureException, 메시지 = Unable to connect to Redis, 

org.springframework.data.redis.connection.lettuce.LettuceConnectionFactory$ExceptionTranslatingConnectionProvider.translateException
(LettuceConnectionFactory.java:1858) -> org.springframework.data.redis.
connection.lettuce.LettuceConnectionFactory$ExceptionTranslatingConnectionProvider
.getConnection(LettuceConnectionFactory.java:1789) -> org.springframework.data.redis.
connection.lettuce.LettuceConnection.doGetAsyncDedicatedConnection(LettuceConnection.java:964)
첫 페이지 캐시 조회 실패: Unable to connect to Redis
첫 페이지 캐시 삽입 실패: Redis command timed out
첫 페이지 캐시 삽입 실패: Redis command timed out
첫 페이지 캐시 조회 실패: Pipeline contained one or more invalid commands
첫 페이지 캐시 조회 실패: Pipeline contained one or more invalid commands
첫 페이지 캐시 조회 실패: Pipeline contained one or more invalid commands
첫 페이지 캐시 조회 실패: Pipeline contained one or more invalid commands

발생한 오류는

1. Unable to connent to Redis : 레디스에 연결할 수 없다.

2. Redis command timed out : 타임아웃 초과

3. Pipeline contained one or more invalid commands : 파이프라인이 잘못된 명령어를 가지고 있다.


아래는 부하테스트의 과정입니다. 오류가 발생한 것은 부하가 심하지 않은 초반이었습니다.

summary +     61 in 00:00:10 =    6.3/s Avg:    64 Min:    16 Max:   528 Err:     0 (0.00%) Active: 58 Started: 58 Finished: 0
summary +   1288 in 00:00:30 =   43.1/s Avg:    13 Min:     7 Max:    82 Err:     0 (0.00%) Active: 258 Started: 258 Finished: 0
summary =   1349 in 00:00:40 =   34.1/s Avg:    15 Min:     7 Max:   528 Err:     0 (0.00%)
summary +   2900 in 00:00:30 =   96.7/s Avg:    10 Min:     6 Max:    82 Err:     0 (0.00%) Active: 458 Started: 458 Finished: 0
summary =   4249 in 00:01:10 =   61.1/s Avg:    12 Min:     6 Max:   528 Err:     0 (0.00%)
summary +   4301 in 00:00:30 =  143.4/s Avg:    58 Min:     5 Max:  1452 Err:    29 (0.67%) Active: 658 Started: 658 Finished: 0
summary =   8550 in 00:01:40 =   85.9/s Avg:    35 Min:     5 Max:  1452 Err:    29 (0.34%)
[lettuce-eventExecutorLoop-1-1] INFO  i.l.core.protocol.ConnectionWatchdog - Reconnecting, last destination was redis/172.19.0.2:6379
[lettuce-eventExecutorLoop-1-3] INFO  i.l.core.protocol.ConnectionWatchdog - Reconnecting, last destination was redis/172.19.0.2:6379
[lettuce-eventExecutorLoop-1-4] INFO  i.l.core.protocol.ConnectionWatchdog - Reconnecting, last destination was redis/172.19.0.2:6379
[lettuce-eventExecutorLoop-1-2] INFO  i.l.core.protocol.ConnectionWatchdog - Reconnecting, last destination was redis/172.19.0.2:6379
[lettuce-nioEventLoop-4-6] INFO  i.l.core.protocol.ReconnectionHandler - Reconnected to redis/<unresolved>:6379
[lettuce-eventExecutorLoop-1-6] INFO  i.l.core.protocol.ConnectionWatchdog - Reconnecting, last destination was redis/172.19.0.2:6379
[lettuce-nioEventLoop-4-5] INFO  i.l.core.protocol.ReconnectionHandler - Reconnected to redis/<unresolved>:6379
[lettuce-eventExecutorLoop-1-3] INFO  i.l.core.protocol.ConnectionWatchdog - Reconnecting, last destination was redis/172.19.0.2:6379
[http-nio-8080-exec-8] WARN  i.l.core.protocol.ConnectionWatchdog - Cannot reconnect to [redis/<unresolved>:6379]: java.util.concurrent.CancellationException

 
로그에서 레디스 커넥션 수립을 재시도 한 것을 발견했습니다.

현재 저는 레디스 클라이언트로 Lettuce를 사용하고 있습니다.

lettuce-eventExecutorLoop는 와치독을 통해 레디스 커넥션 상태 변화를 감지합니다. 커넥션을 재 연결하라는 명령을 내립니다.
lettuce-nioEventLoop스레드는 Lettuce의 네트워크 I/O 전담 스레드입니다. 여기서 재 연결을 시도하고 있습니다.

 

무엇인가 커넥션이 끊어졌다는 것을 의미합니다.

 

1.2 상황 종합

적은 부하에도 Redis 타임아웃 초과 : 현재 레디스의 타임아웃은 150ms 입니다 이 값을 500ms로 늘려도 빈도만 줄었지 결국 타임아웃이 발생했습니다. 그리고 부하가 적은 상황임에도 타임아웃이 발생했습니다. 부하가 높으면 응답의 지연이 생길 수 있지만 초당 100건의 요청으로 응답 지연이 발생하지는 않습니다

 

정상 로직이지만 파이프라인에 잘못된 명령어 포함 예외 발생 : 파이프라인에 잘못된 명령어는 없습니다. 첫 페이지 캐시를 조회하거나 글을 작성하면 캐시를 갱신하는등의 로직입니다. 정말 잘못된 명령이 있었다면 테스트 시작 직후에 해당 예외가 발생했을겁니다. 후에 발견했지만 잘못된 명령어가 아님에도 파이프라인 실행중 타임아웃이 발생하면 해당 예외가 래핑되어서 나옵니다.

 

Redis 커넥션 연결실패와 재연결 발생 : 모종의 이유로 커넥션 연결이 실패하고 재연결을 시도했습니다.

 

1.3 결과 요약

파이프라인이 요청마다 TCP 연결과 해제를 반복하면서 Netty 이벤트루프에 병목이 발생했고, 이로 인해 Redis 명령이 전달되지 못했습니다.

  1. 부하 테스트 중 초당 수백 건의 파이프라인이 실행되며, 그만큼의 TCP 연결 및 해제 이벤트가 Netty 태스크 큐에 쌓입니다.
  2. 부하가 강해지면서 이벤트루프 스레드가 큐의 적체를 해소하지 못합니다.
  3. 파이프라인의 TCP 연결 시도가 10초간 처리되지 못하여 Unable to connect to Redis가 발생합니다.
  4. 파이프라인이 커넥션을 맺었으나 명령의 응답이 타임아웃 내에 도착하지 않으면, Redis command timed out이 Pipeline contained one or more invalid commands에 래핑되어 발생합니다.

파이프라인을 사용하지 않는 공유 커넥션의 명령도 같은 이벤트루프를 거치므로, 동일하게 Redis command timed out이 발생합니다.

 

커넥션 풀을 설정하여 이를 해결하고 캐시 구조를 바뀌어 테스트한 결과 

  게시판 조회 테스트 / P99 응답시간 캐시 수정 상황 테스트 / P99 응답시간
커넥션 풀 미설정  11,802ms -
List + Hash 3,290ms 13,612ms
List 575ms 4,333ms

 

위와 같은 결과가 도출되어 캐시 구조를 바꾸었습니다.

 

2. 원인 탐색

2.1 FD, Redis 커넥션, 메모리, 로그, 실행시간 분석

레디스의 최대 커넥션 한계는 1만입니다.

 

연결된 커넥션은 최대 50이고 한참 여유있습니다. 블록된 커넥션도 없습니다.

 

거절된 커넥션도 존재하지 않습니다.

즉, 레디스 측의 커넥션 오류는 아닙니다. 그래서 스프링쪽 FD가 문제인가 확인하려 했습니다.

스프링의 FD는 최대가 100만이고 현재 최대 1500입니다. 스프링측의 병목도 아닙니다.

 
아래는 레디스의 로그입니다.

일반적으로 테스트할때는 RDB를 비활성화 하지만 활성화 되어있는 것을 발견했습니다. 다만 이것이 원인은 아닙니다.

1995:C 13 Feb 2026 15:54:01.091 * DB saved on disk
1:M 13 Feb 2026 15:54:01.063 * Background saving started by pid 1995
1:M 13 Feb 2026 15:54:01.062 * 10000 changes in 60 seconds. Saving...
1:M 13 Feb 2026 15:53:00.998 * Background saving terminated with success
1960:C 13 Feb 2026 15:53:00.920 * Fork CoW for RDB: current 0 MB, peak 0 MB, average 0 MB
1960:C 13 Feb 2026 15:53:00.919 * DB saved on disk
1:M 13 Feb 2026 15:53:00.897 * Background saving started by pid 1960
1:M 13 Feb 2026 15:53:00.896 * 10000 changes in 60 seconds. Saving...
1:M 13 Feb 2026 15:51:02.027 * Background saving terminated with success
1891:C 13 Feb 2026 15:51:01.952 * Fork CoW for RDB: current 0 MB, peak 0 MB, average 0 MB
1891:C 13 Feb 2026 15:51:01.950 * DB saved on disk
1:M 13 Feb 2026 15:51:01.926 * Background saving started by pid 1891
1:M 13 Feb 2026 15:51:01.925 * 100 changes in 300 seconds. Saving...

 

레디스의 메모리도 여유롭습니다.

 

레디스의 초당 명령 실행시간은 최대 60ms입니다.

명령 실행시간은 타임아웃인 150ms를 넘지 않았는데도 타임아웃 오류가 발생했습니다.

 

2.2 커넥션 풀이 없는 경우 파이프라인의 동작

https://techblog.woowahan.com/23121/

 

Redis New Connection 증가 이슈 돌아보기 | 우아한형제들 기술블로그

서비스 성능을 높이기 위해 여러 영역에서 캐싱을 활용하고 있습니다. 그중 사용자 맞춤 데이터를 빠르게 제공하기 위해 Redis를 사용하고 있는데요. Redis 관련 지표를 모니터링 하던 중 신규 커

techblog.woowahan.com

 

우아한형제들의 테크 블로그에서 커넥션 풀이 없을 때 파이프라인은 실행 시점에 독립 커넥션을 생성한다는 것을 확인했습니다.
그리고 직접 Spring Data Redis를 확인했습니다.

 

아래는 파이프라인 실행 시 Spring Data Redis에서 커넥션을 수립하는 과정입니다.

@Override
public void openPipeline() { <- 파이프라인 실행 시 진입
    if (!isPipelined) {
       isPipelined = true;
       ppline = new ArrayList<>();
       pipeliningFlushState = this.pipeliningFlushPolicy.newPipeline();
       pipeliningFlushState.onOpen(this.getOrCreateDedicatedConnection()); -> 아래 메서드 진입
    }
}

private StatefulConnection<byte[], byte[]> getOrCreateDedicatedConnection() {
    if (this.asyncDedicatedConnection == null) { <- 기존에 파이프라인 커넥션이 존재하는지 검사하는 방어로직
        this.asyncDedicatedConnection = doGetAsyncDedicatedConnection(); -> 아래 메서드 진입
    }
    return this.asyncDedicatedConnection;
}

protected StatefulConnection<byte[], byte[]> doGetAsyncDedicatedConnection() {
    return getConnectionProvider().getConnection(StatefulConnection.class);
}

default <T extends StatefulConnection<?, ?>> T getConnection(Class<T> connectionType) {
    return LettuceFutureUtils.join(getConnectionAsync(connectionType));
}

 

아래는 getConnectionAsync()의 구현체입니다.

Spring Data Redis에서 Lettuce로 요청을 보내고 있습니다. 

// 커넥션 풀이 있을 때 구현체 
@Override
public <T extends StatefulConnection<?, ?>> T getConnection(Class<T> connectionType) {
    GenericObjectPool<StatefulConnection<?, ?>> pool = pools.computeIfAbsent(connectionType, poolType -> {
        GenericObjectPool<StatefulConnection<?, ?>> newPool = ConnectionPoolSupport
                .createGenericObjectPool(() 
                -> connectionProvider.getConnection(connectionType), poolConfig, false); <- Lettuce에서 커넥션 전달 받음
        try {
            newPool.preparePool();
        } catch (Exception ex) {
            throw new PoolException("Could not prepare the pool", ex);
        }
        return newPool;
    });

    try {
        StatefulConnection<?, ?> connection = pool.borrowObject();
        poolRef.put(connection, pool);
        return connectionType.cast(connection);
    } catch (Exception ex) {
        throw new PoolException("Could not get a resource from the pool", ex);
    }
}

// 커넥션 풀이 없을 때 구현체
@Override
public <T extends StatefulConnection<?, ?>> T getConnection(Class<T> connectionType) {
    if (connectionType.equals(StatefulRedisSentinelConnection.class)) {
        return connectionType.cast(client.connectSentinel());
    }

    if (connectionType.equals(StatefulRedisPubSubConnection.class)) {
        return connectionType.cast(client.connectPubSub(codec));
    }

    if (StatefulConnection.class.isAssignableFrom(connectionType)) { <- 이 곳으로 진입
        return connectionType.cast(readFrom.map(it -> this.masterReplicaConnection(redisURISupplier.get(), it))
                .orElseGet(() -> client.connect(codec))); <- Lettuce에서 새로운 커넥션 수립
    }

    throw new UnsupportedOperationException("Connection type " + connectionType + " not supported");
}

스프링 데이터 레디스에서는 커넥션 풀이 있으면 풀에서 꺼내오고 없으면 새로운 커넥션을 만들어옵니다.

 

아래는 파이프라인의 종료 시 실행되는 로직 입니다.

private void reset() {
    if (this.asyncDedicatedConnection != null) {
        try {
            if (customizedDatabaseIndex()) {
                potentiallySelectDatabase(this.asyncDedicatedConnection, this.defaultDbIndex);
            }
            this.connectionProvider.release(this.asyncDedicatedConnection); <- 실제 커넥션 해제
            this.asyncDedicatedConnection = null;
        } catch (RuntimeException ex) {
            throw convertLettuceAccessException(ex);
        }
    }

    LettuceSubscription subscription = this.subscription;

    if (isAlive(subscription)) {
        subscription.doClose();
    }

    this.subscription = null;
    this.dbIndex = defaultDbIndex;
}

파이프라인을 사용하지 않는 명령은 커넥션 풀이 없어도 미리 만들어 놓은 하나의 공유 커넥션을 활용합니다.

Lettuce는 내부적으로 Netty를 사용합니다. Netty는 논블로킹인 Java Nio를 추상화한 네트워크 프레임워크입니다. 그리고 Redis는 싱글 스레드 기반이라 명령을 순차처리합니다 따라서 애플리케이션의 많은 스레드가 하나의 커넥션을 공유할 수 있습니다.

 

다만 파이프라인을 사용할 때는 행동이 다릅니다. 커넥션 풀이 없으면 파이프라인 실행과 종료 시 커넥션을 수립하고 해제 합니다. 즉, 초당 100건의 요청이 커넥션을 수립하고 파괴하고 있습니다. 이것은 분명 고쳐야 할 문제입니다.

다만, 레디스 클라이언트의 기본값은 1만입니다. 효율은 차치하더라도 커넥션이 연결되어야 합니다.

 

2.3 Redis가 수신한 커넥션과 현재 커넥션 수의 괴리

Redis가 초당 수신한 커넥션 수
현재 Redis에 연결된 커넥션

 

연결된 커넥션은 최대 50 정도에 머물고 있었지만 초당 수신한 연결은 100회이상 발생하고 있습니다. 커넥션의 수명이 극도로 짧다는 뜻입니다. 커넥션 생성 -> 파이프라인 실행 -> 커넥션 파괴가 일어나고 있다는 것 입니다. 
 

2.4 레터스의 첫 응답 수신, 마지막 응답 시간 비교 - 병목 시간 식별

lettuce_command_firstresponse_seconds_max 그래프는 레디스가 첫 응답을 보내기까지의 초당 최대 시간입니다. lettuce_command_completion_seconds_max 그래프는 레디스가 명령이 완전히 완료되기 까지의 초당 최대 시간입니다.

둘 다 600ms 정도입니다. 반면 실제 레디스의 명령 완료 시간은 위에서 초당 60ms정도로 나왔습니다.
 

응답이 도착하기까지 최대 600ms 소모되었고 그 중 Redis의 명령 실행시간은 60ms입니다 540ms의 병목시간을 식별했습니다. 응답의 첫 바이트 도착과 응답완료 시간이 일치하지만 이 상황으로 병목지점을 단정지을 수 없습니다

  • Lettuce는 내부적으로 Netty를 활용합니다.
  • 첫 응답을 기록하는 시점은 이벤트루프가 특정 채널에 대해 복사를 시작하는 시점입니다
  • 데이터의 크기가 많을 때는 작업을 여러번 나누어서 하기 때문에 특정 채널에 대한 병목을 측정할 수 있습니다.

첫 페이지 캐시라 용량이 작아 한 번에 데이터를 가져 올 수 있기 때문에 도착시간과 완료시간은 일치할 수 밖에 없습니다
 

2.5 Lettuce의 커넥션 해제 로직 - Netty 이벤트루프 호출

아래는 Lettuce의 커넥션 해제 로직입니다.

public CompletableFuture<Void> closeAsync() {

    if (debugEnabled) {
        logger.debug("closeAsync()");
    }

    if (CLOSED.get(this) == ST_CLOSED) {
        logger.warn("Connection is already closed");
        return closeFuture;
    }

    if (CLOSED.compareAndSet(this, ST_OPEN, ST_CLOSED)) {

        active = false;
        CompletableFuture<Void> future = channelWriter.closeAsync(); <- Netty 진입

 
현재 이벤트 루프의 스레드 개수는 6개입니다.

조회때마다 파이프라인이 실행되고 커넥션이 생성되고 파이프라인 해제시 커넥션이 파괴되어 TCP 연결을 끊거나 연결하는 이벤트 루프가 바빠졌고 그로인해 파이프라인이 아닌 일반 명령들까지 TCP 연결을 못하게 되었다면 Netty의 태스크 큐가 가득찼을 것 입니다. 하지만 모니터링 설정 누락으로 Netty의 태스크 큐의 측정이 되지 않았습니다. 추론을 끝내고 재 테스트를 할 예정입니다.

 

2.6 레디스 CPU

애플리케이션 측의 Netty 뿐만 아니라 레디스측의 이벤트루프에도 문제가 있을 수 있을 수 있습니다.

레디스의 CPU는 크게 sys와 user 그리고 main과 children으로 나뉩니다.

sys는 커널이 처리한 부분 user는 레디스가 처리한 부분입니다.

main은 메인스레드 children은 fork()된 자식 스레드가 한 일을 뜻합니다.

유저 자식, 메인
시스템 자식, 메인

sys main 스레드는 소켓 read/write를 주로 합니다.

sys children은 디스크 i/o를 담당합니다.

children은 아주 미미한 CPU를 사용했습니다. 메인스레드는 최대 18%를 사용한것을 보아 분명 레디스에도 영향이 있던것을 확인할 수 있습니다. 다만 그것이 병목을 일으킨 것만큼 최대치를 사용한 것은 아닙니다.

 

Redis CPU 사용량은 정상이나, sys_main이 비정상적으로 높습니다.

  • 전체 CPU : 28.1%
    • user_main : 10% (명령어 파싱, 실행)
    • user_children : 0.02% (직렬화, RDB)
    • sys_main : 18% (소켓 I/O)
    • sys_children: 0.1% (시스템 콜)

단일 코어에서 CPU 28%는 오류를 유발할 수준이 아닙니다. 그러나 sys_main이 전체 CPU 사용량의 64%를 차지하는 것은 소켓 I/O에 비정상적인 부하가 걸리고 있다는 신호입니다.


 

2.7  Unable to connect to Redis 발생이유

파이프라인에서 커넥션을 가져올 때 커넥션 연결이 실패하면 아래와 같은 오류가 발생합니다.

protected StatefulConnection<byte[], byte[]> doGetAsyncDedicatedConnection() {
    return getConnectionProvider().getConnection(StatefulConnection.class);
}

@Override
public <T extends StatefulConnection<?, ?>> T getConnection(Class<T> connectionType) {

    try {
        return delegate.getConnection(connectionType);
    } catch (RuntimeException ex) {
        throw translateException(ex);
    }
}
        
private RuntimeException translateException(Throwable cause) {
	return cause instanceof RedisConnectionFailureException connectionFailure ? connectionFailure
    	: new RedisConnectionFailureException("Unable to connect to Redis", cause);
}

 


 

2.8  Pipeline contained one or more invalid commands 발생이유

LettuceConntect클래스의 closePipeline() 메서드

    try {
       boolean done = LettuceFutures.awaitAll(timeout, TimeUnit.MILLISECONDS, futures.toArray(new RedisFuture[0]));
       List<Object> results = new ArrayList<>(futures.size());
       Exception problem = null;

       if (done) {
          for (LettuceResult<?, ?> result : ppline) {
             CompletableFuture<?> resultHolder = result.getResultHolder();
             if (resultHolder.isCompletedExceptionally()) {
                String message;
                if (resultHolder instanceof io.lettuce.core.protocol.RedisCommand<?, ?, ?> rc) {
                   message = rc.getOutput().getError();
                } else {
                   try {
                      resultHolder.get();
                      message = "";
                   } catch (InterruptedException ignore) {
                      message = "";
                   } catch (ExecutionException e) {
                      message = e.getCause().getMessage();
                   }
                }

                Exception exception = new InvalidDataAccessApiUsageException(message);

                // remember only the first error
                if (problem == null) {
                   problem = exception;
                }

                results.add(exception);
             } else if (!result.isStatus()) {

                try {
                   results.add(result.conversionRequired() ? result.convert(result.get()) : result.get());
                } catch (DataAccessException ex) {
                   if (problem == null) {
                      problem = ex;
                   }
                   results.add(ex);
                }
             }
          }
       }

       ppline.clear();

       if (problem != null) {
          throw new RedisPipelineException(problem, results);
       }

       if (done) {
          return results;
       }

       throw new RedisPipelineException(new QueryTimeoutException("Redis command timed out"));
    } catch (Exception ex) {
       throw new RedisPipelineException(ex);
    }
}

 

boolean done = LettuceFutures.awaitAll(timeout, TimeUnit.MILLISECONDS, futures.toArray(new RedisFuture[0]));

에서 반환값이 false면 파이프라인예외에 타임아웃이 래핑되어 발생합니다.

 

awaitAll()메서드를 살펴보면

public static boolean awaitAll(long timeout, TimeUnit unit, Future<?>... futures) {
    return Futures.awaitAll(timeout, unit, futures);
}

public static boolean awaitAll(long timeout, TimeUnit unit, java.util.concurrent.Future<?>... futures) {
    try {
        long nanos = unit.toNanos(timeout);
        long time = System.nanoTime();

        for(java.util.concurrent.Future<?> f : futures) {
            if (timeout <= 0L) {
                f.get();
            } else {
                if (nanos < 0L) {
                    return false;
                }

                f.get(nanos, TimeUnit.NANOSECONDS);
                long now = System.nanoTime();
                nanos -= now - time;
                time = now;
            }
        }

        return true;
    } catch (TimeoutException var14) {
        return false;
    } catch (Exception e) {
        throw Exceptions.fromSynchronization(e);
    }
}

파이프라인의 모든 메서드가 타임아웃내에 이루어져야 한다는 것을 알 수 있습니다.

즉, TCP연결을 맺었지만 타임아웃내에 명령을 실행하지못하면 이 예외가 발생합니다.

 

2.9 재테스트 Netty 병목 식별

MeterRegistry를 이용해 모니터링을 설정하고 제 가설이 맞는지 실제로 테스트하였습니다.

Netty의 남은 작업들이 계속해서 쌓여있는 모습을 볼 수 있습니다.

6개의 이벤트루프에도 작업이 쌓여있습니다.

 

2.10 문제 해결 - 커넥션 풀 설정으로 요청마다 파이프라인의 독립 커넥션 생성 및 파괴로 인한 Netty이벤트루프 병목 제거

해결책은 커넥션풀을 설정하는 것입니다. 커넥션 풀이 있어야 파이프라인의 독립커넥션의 생성을 막을 수 있습니다. 조회가 수십만번일어나는데 그때마다 파이프라인이 시행되어 커넥션의 생성 및 파괴로 인한 Netty이벤트루프의 대한 병목이 문제이기 때문입니다.

implementation 'org.apache.commons:commons-pool2'
spring.data.redis.lettuce.pool.max-active=10
spring.data.redis.lettuce.pool.max-idle=5
spring.data.redis.lettuce.pool.min-idle=2
spring.data.redis.lettuce.pool.max-wait=100ms
spring.data.redis.timeout=30ms


별도의 커넥션 풀 설정으로 해결하였습니다.

이제 테스트로 List + Hash 구조의 성능을 측정하겠습니다.

3. 테스트 시나리오

3.1 게시글 목록 조회 테스트 시나리오

미국의 국립 바이오 기술 정보 센터에서 작성한 소셜 네트워크의 1% 법칙이라는 논문을 살펴 테스트 시나리오를 작성했습니다.
The 1% Rule in Four Digital Health Social Networks: An Observational Study
이 논문에서는 90%가 관찰하고 9%가 드물게 기여하고 1%가 새로운 콘텐츠를 생성한다고 되어있습니다. 
 
그리고 글의 페이지를 조회하는 수치를 찾기 위해 2025년 구글 통계를 확인했습니다.
7 First Page of Google Statistics: A Must Know in 2025
제 서비스는 SNS이기 때문에 되도록 SNS에 따른 통계로 하고 싶었지만 SNS는 대부분 무한 스크롤 형태이기 때문인지 SNS에 관련한 페이지 통계에 대한 자료는 없었습니다. 그래서 2025년 구글 통계로 대신했습니다. 이 논문에서는 사용자의 99%는 첫 페이지만 살펴보며 사용자의 91.5%가 첫 페이지에 머무른다고 하는데 영어로 되어있어 늬앙스의 차이를 알 수 없어 첫페이지를 91.5% ~ 99%로 가정하였습니다. 두번째 페이지를 클릭하는 비율은 0.6% 마지막 페이지를 클릭하는 비율은 1% 미만이라고 말합니다.
 
종합적으로 아래와 같이 테스트 시나리오를 구축했습니다.

행동 비율 부하
게시글 첫 페이지 조회 97.5% 1초에 1회
게시글 중간 페이지 조회 0.5% 195초에 1회
게시글 마지막 페이지 조회 1% 97초에 1회
게시글 작성 1% 97초에 1회

 

테스트 환경 수치
테스트 시간 10분
사용자 그룹 총 4개 그룹
그룹별 최대 사용자 1000명
램프업 10분간 선형증가
피크요청량 1015RPS / 초

 

테스트 환경 (도커 네트워크) 사양 (실제 운영 사양과 유사하게)
스프링 메모리 1GB
레디스 메모리 100MB
기본 / 최대 스레드 풀 40 / 200
기본 / 최대 커넥션 풀 50 / 100

 

데이터 수치
10만 레코드
글 추천 100만 레코드

 

3.2 캐시 수정 상황 테스트 시나리오

캐시가 변동하는 테스트도 만들겠습니다. 댓글 작성 1%, 글 추천 1%, 글 상세 조회를 10%로 추가하여 테스트를 하나 더 진행하겠습니다. 글 상세 조회를 추가한 이유는 이 때 조회수의 상승이 일어납니다.

 

 

4. 테스트 결과

4.1 게시글 목록 조회 테스트 결과

 

커넥션 풀

커넥션 풀은 여유롭습니다.
 

200ms 이내 응답보장은 처리량은 495TPS입니다,
 

레디스 명령어 초당 소요시간

HGETALL이 많이 실행되다 보니 후반에는 1초당 60ms동안 HGETALL이 점유하였습니다.
 

레디스 명령 별 소요시간

단일 HGETALL의 명령은 6us로 즉 0.006ms로 매우 짧은 시간입니다. 다만 매우 자주 많이 일어나서 빈도가 많은 탓입니다.

4.2 캐시 수정 상황 테스트 결과

 

레디스 커넥션은 70까지 사용중입니다. 
 

레디스 메모리

 

레디스 CPU

CPU는 여유롭습니다.
 

레디스 명령어

전체적으로 HGETALL이 많은 시간을 점유하고 있습니다. 오른쪽 그래프에 HGETALL이 1.5초가 넘었다고 되어있는데 왼쪽 그래프에 나타나지 않았던것을 보면 타임아웃에 걸려 실패하고 DB로 폴백했습니다. 아무튼 HGETALL이 가장 중요한 요소임을 알 수 있습니다. 조회시도 직렬화와 역직렬화가 필요없긴하지만 각 HASH에 HGETALL을 보내는 오버헤드가 더 큰 것으로 보입니다.
 

조회수 추천수 댓글수 증가 명령은 빠른모습을 보여줍니다. 이전 경우에는 역직렬화를 해야하다보니 부하 후반에는 SET명령이 100us까지 갔지만 5배정도 빠른 모습입니다.
 

커넥션 풀

LIST단일구조와 달리 전체적인 성능하락으로 커넥션이 아슬하게 병목은 생기지 않았지만 여유로운 모습은 아닙니다.
 

스레드 풀

스레드에도 병목이 보이는 모습입니다.
 

200ms이내 응답가능 처리량은 369TPS입니다.

5. 캐시 구조 변경

LIST post:list
[
  "{ id:1, title:'A', like:10, view:100 }",
  "{ id:2, title:'B', like:5, view:50 }"
]

VS

LIST post:list
[1,2,3,4,5]

HASH post:1
{
  title -> "A"
  like  -> "10"
  view  -> "100"
}

 

현재 캐시에는 댓글 수, 추천 수, 조회 수가 있는데 댓글 수, 추천 수의 변화는 즉시 반영하고 조회수는 라이트백 패턴을 선택했습니다. 레디스에 숫자만 담고 1분마다 디비에 배치삽입하는 것입니다. 이때 그 숫자들을 그대로 캐시에 삽입하면 캐시는 DB를 조회하지 않고도 조회 수를 업데이트 할 수 있습니다.
 
설계를 전환에 대한 고민은 그 방법에 있습니다.

조회 LIST 인덱스에 JSON 저장 LIST에 글ID + HASH에 필드 저장
명령 LRANGE LRANGE + 글 마다 HGETALL
명령 수 1번 21번
시간복잡도 O(20) + 역직렬화 비용 O(220) = O(20) + O(200) 필드 10개
파이프라인 X O
RTT 1회 1회

 

수정 삭제 LIST 인덱스에 JSON 저장 LIST에 글ID + HASH에 필드 저장
명령 LRANGE + LSET or LRAM + RPUSH LPOS + HSET or HDEL + RPUSH
명령 수 3번 3번
시간복잡도 O(22) + 루아스크립트 내부연산 글마다 역직렬화 비용 O(3)
파이프라인 X X
RTT 2회 2회

 

새 글 삽입 LIST 인덱스에 JSON 저장 LIST에 글ID + HASH에 필드 저장
명령 LPUSH + LTRIM LPUSH + LTRIM + HMSET + DEL
명령 수 2번 4번
시간복잡도 O(2) O(13)
파이프라인 X X
RTT 1회 (루아) 1회 (루아)

 
삽입은 LIST 단일 구조가 유리하고 수정 삭제는 LIST + HASH 구조가 유리합니다. 가장 중요한 조회는 LIST단일 구조가 수치상으로는 더 좋지만 역직렬화 비용이 있습니다. 이것을 테스트를 통해 판단해보겠습니다.

 

6. 변경한 캐시 테스트 결과 

6.1 게시글 목록 조회 테스트 결과

 

커넥션은 거의 쓰지 않았습니다.

 

API별 리소스 사용량

 
글 작성, 글 조회 모두 api/post인데 조회는 GET 작성은 POST를 사용합니다. 글 조회의 26만번 글 작성의 2천번 조회의 모두 총합한 SQL시간이 49000ms로 조회당 0.2ms이하의 시간을 가집니다.

 

200ms이하 응답가능 처리량은 898/TPS입니다. 170TPS 가량 상승했습니다.
 

 

 

6.2 캐시 수정 상황 테스트 결과

 

레디스 커넥션

커넥션 풀 설정 이후에 커넥션은 약 22개를 사용중입니다.
 

메모리는 여유롭습니다.
 

자주 쓰이는 LRANGE 명령입니다.
 

조회수 댓글수 추천수 추가 명령입니다.
 

커넥션은 여유롭습니다.
 

스레드풀의 병목은 크지 않습니다.
 

응답시간 200ms를 보장하는 처리량은 637/TPS 입니다.

 

7. 스프링 데이터 레디스 기여 

현재 LettuceConnection의 closepipline() 메서드에는 두 가지 문제가 있습니다,

      throw new RedisPipelineException(new QueryTimeoutException("Redis command timed out"));
    } catch (Exception ex) {
       throw new RedisPipelineException(ex);
    }
}

1. 에러가 이중래핑됩니다.

2. 잘못된 명령어가 없음에도 타임아웃시 Pipeline contained one or more invalid commands가 반환됩니다.

 

1번의 경우 예를들어 파이프라인에서 타임아웃이 발생하면 Pipeline contained one or more invalid commands ( Pipeline contained one or more invalid commands (Redis command timed out)이 발생합니다.

 

아래처럼 바꾸었습니다. 

        throw new RedisPipelineException(new QueryTimeoutException("Redis command timed out"));
    } catch (RedisPipelineException ex) {
        throw ex;
    } catch (Exception ex) {
        throw new RedisPipelineException(ex);
    }

RedisPipelineException은 바로 던져 이중 래핑을 방지했습니다. 이제 파이프라인에서 타임아웃 발생 시 Pipeline contained one or more invalid commands (Redis command timed out)이 발생합니다.

 

2번의 경우 잘못된 명령어가 없음에도 Pipeline contained one or more invalid commands이 발생하는 것은 옳지 않습니다. 하지만 RedisPiplineException클래스의 생성자에 Pipeline contained one or more invalid commands가 하드 코딩 되어있어서 바꾸려면 작업 범위가 넓어 메인테이너 분들과 미리 얘기를 해야할 것 같아 PR에 첨언으로 남겨두었습니다.

 

https://github.com/spring-projects/spring-data-redis/pull/3347

 

Fix `RedisPipelineException` double-wrapping in `LettuceConnection.closePipeline()` by JEONGJAEIK · Pull Request #3347 · sprin

Bug Description LettuceConnection.closePipeline() wraps all exceptions in a generic RedisPipelineException with the misleading message "Pipeline contained one or more invalid commands", ...

github.com

 

코멘트가 달렸습니다.

Thank you for your contribution. That's merged, polished, and backported now.

 

확인해보니 스프링 데이터팀의 리더이신 메인테이너분이 코드를 조금 고치고 3.5.11까지 즉시 백포팅을 하여서 현재 쓰시는 분들에게도 즉시 적용되게 하였습니다. 하이버네이트에 기여했을 때와 다르게 보라색으로 머지가 되어있지 않고 클로즈가 되어있었지만 컨트리뷰터화면에는 제가 있네요.

 

다만, 아직 잘못된 예외 메시지는 작업안하신듯합니다. 생성자에 박혀있어서 변화가 큰 작업일 겁니다.