Redis pipelining 을 통한 알림 서비스 개선기

나르·2023년 12월 24일

Spring redis

NoSQL

목록 보기

4/4

`1. 발단`

기존의 알림 서비스는 아래와 같이 구성되어 있었습니다.

각 서비스 서버에서 알림이 필요한 이벤트가 발생하면 알림 서버로 요청을 보냄
알림 서비스는 레디스에서 유저의 알림 설정 정보를 조회해옴
알림 타입별(광고/결제/소셜..) 설정이 ON 인 유저만 필터링
메세지 및 링크 생성 등의 처리 후 푸시 서버로 발송 요청

기존에도 소셜 알림의 경우 한번에 1000+명의 유저에게 발송이 필요했지만, 큰 이슈 없이 동작했기 때문에 발견되지 않았습니다.

그런데 이벤트 기간동안 몇 십만명에게 푸시를 발송해야하는 요구사항이 있었고, response time 이 7초까지 지연되며 개선의 필요성이 화두에 올랐습니다.

2. 원인 파악

로그와 핀포인트를 통해 확인한 결과, 성능 저하의 원인이 되는 부분은 명확했습니다.
유저의 알림 설정 정보를 가져오는 부분에서 1건씩 조회를 하다보니 매번 커넥션 생성-커넥션 종료 하는 부분에서 많은 시간을 소요하고 있었습니다.


public List<Long> getNotificationEnabled(List<Long> memberList,
                                                  Integer notificationNo) {
  		...                                               
		return memberList.stream()
                  .map(this::findById)  // 한 건씩 조회
                  .filter(it -> it.doSomething())
                  .map(Notification::getMemberNo)
                  .toList();
}  

public Optional<Notification> findById(Long memberNo) {
        return Optional.of(hashOperations.entries(memberNo))
                       .filter(Predicate.not(Map::isEmpty))
                       .map(Notification::of);
}

스트림의 특징 중 하나인 지연 실행(lazy evaluation) 때문입니다.
스트림은 파이프라인의 최종 연산이 수행될 때까지 중간 연산들이 실행되지 않고, 각 멤버에 대한 Redis 조회가 stream().map() 내부에서 개별적으로 이루어졌기 때문에 findById 메서드가 매번 호출되어 Redis 연결이 생성되고 종료되는 문제가 발생했습니다.

해결 방법으로는 두 가지 정도를 고민했는데, 하나는 인자를 리스트로 받는 쿼리를 통해 다건조회를 하는 것이고 다른 하나는 커넥션을 생성해서 조회하는 것이었습니다.

하지만 일반 StringRedisTemplate 에서는 mget을 통해 쉽게 멀티 키 조회가 가능했으나, 현재 서비스는 hash 형식으로 데이터를 저장하고 있었고, HashOperation 에서는 멀티 키 조회를 지원하지 않고 있습니다.

개선

Redis 는 기본적으로 Request/Response 프로토콜을 사용하며, 하나의 요청에 대한 응답을 받은 후에 다음 요청을 처리합니다. 이는 Round-Trip Time (RTT)을 증가시켜 전체 응답 시간에 영향을 미칠 수 있습니다.

이를 해결하기 위한 방법으로 Redis 와 Spring Data Redis 공식문서 에서 Pipelining에 대한 내용을 확인할 수 있었습니다.

조회를 하는 부분의 코드를 아래와 같이 pipeline 처리를 했고, 성능 테스트 결과 10000 건 조회에 걸리는 시간이 약 1/100 수준으로 줄어든 것을 확인할 수 있었습니다.

@SuppressWarnings("unchecked")
private Map<Long, Notification> getMemberNotificationMap(List<Long> memberNos) {
    return hash.getOperations().executePipelined(new SessionCallback<>() {
                   @Override
                   public <K, V> Object execute(RedisOperations<K, V> operations) throws DataAccessException {
                       HashOperations<K, Object, Object> hashOperations = operations.opsForHash();
                       memberNos.forEach(memberNo -> hashOperations.entries((K) getKey(memberNo)));
                       return null;
                   }
               })
               .stream()
               .map(it -> (Map<String, String>) it)
               .filter(Predicate.not(Map::isEmpty))
               .map(Notification::of)
               .collect(Collectors.toMap(Notification::getMemberNo, Function.identity()));
}

추가로 알림 이벤트 API를 비동기처리도 해봤는데... 이건 서버가 요청을 못버티고 터져버려서 파이프라이닝만 추가하고 작업을 마무리했습니다😂

사실 Lettuce 를 사용하고 있어서 non-blocking으로 요청이 전부 처리가 될 줄 알았는데 이번에 로그를 확인하니 응답이 오고 나서야 다음 커넥션을 생성하는 것을 발견했습니다.
무엇이 문제인지, 제가 생각하는 동작 방식이 틀린 것인지 확인해 볼 필요성을 느꼈습니다.🤔
검증 없이 막연하게 기술을 사용하는 모습에 또 반성하게 되는 요즘입니다...

2024.10 추가
놀라운 사실. 완전히 잘못 파악한 글이었습니다.

stream 연산 로직은 아무 관련이 없고 그냥 lettuce 를 잘못 이해해서 생긴 일이었습니다.
lettuce의 "하나의 커넥션을 공유한다" 와 파이프라이닝은 다른건데 이상하게 생각을 했었네요.

기존처럼 stream 을 돌며 조회를 했을 때의 로그는 아래와 같습니다.

[           main] [] i.lettuce.core.protocol.DefaultEndpoint  : [channel=0x36802467, /10.5.26.83:63897 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x1] write() writeAndFlush command AsyncCommand [type=HGETALL, output=MapOutput [output={}, error='null'], commandType=io.lettuce.core.protocol.Command]
[ueEventLoop-7-1] [] i.lettuce.core.protocol.CommandHandler   : [channel=0x36802467, /10.5.26.83:63897 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x1, chid=0x1] write(ctx, AsyncCommand [type=HGETALL, output=MapOutput [output={}, error='null'], commandType=io.lettuce.core.protocol.Command], promise)
[ueEventLoop-7-1] [] i.lettuce.core.protocol.CommandEncoder   : [channel=0x36802467, /10.5.26.83:63897 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379] writing command AsyncCommand [type=HGETALL, output=MapOutput [output={}, error='null'], commandType=io.lettuce.core.protocol.Command]
[           main] [] i.lettuce.core.protocol.DefaultEndpoint  : [channel=0x36802467, /10.5.26.83:63897 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x1] write() done
[ueEventLoop-7-1] [] i.lettuce.core.protocol.CommandHandler   : [channel=0x36802467, /10.5.26.83:63897 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x1, chid=0x1] Received: 4 bytes, 1 commands in the stack
[ueEventLoop-7-1] [] i.lettuce.core.protocol.CommandHandler   : [channel=0x36802467, /10.5.26.83:63897 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x1, chid=0x1] Stack contains: 1 commands
[ueEventLoop-7-1] [] i.l.core.protocol.RedisStateMachine      : Decode done, empty stack: true
[ueEventLoop-7-1] [] i.lettuce.core.protocol.CommandHandler   : [channel=0x36802467, /10.5.26.83:63897 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x1, chid=0x1] Completing command LatencyMeteredCommand [type=HGETALL, output=MapOutput [output={}, error='null'], commandType=io.lettuce.core.protocol.AsyncCommand]
[           main] [] io.lettuce.core.RedisChannelHandler      : dispatching command AsyncCommand [type=HGETALL, output=MapOutput [output={}, error='null'], commandType=io.lettuce.core.protocol.Command]
[           main] [] i.lettuce.core.protocol.DefaultEndpoint  : [channel=0x36802467, /10.5.26.83:63897 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x1] write() writeAndFlush command AsyncCommand [type=HGETALL, output=MapOutput [output={}, error='null'], commandType=io.lettuce.core.protocol.Command]
[           main] [] i.lettuce.core.protocol.DefaultEndpoint  : [channel=0x36802467, /10.5.26.83:63897 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x1] write() done
[ueEventLoop-7-1] [] i.lettuce.core.protocol.CommandHandler   : [channel=0x36802467, /10.5.26.83:63897 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x1, chid=0x1] write(ctx, AsyncCommand [type=HGETALL, output=MapOutput [output={}, error='null'], commandType=io.lettuce.core.protocol.Command], promise)
[ueEventLoop-7-1] [] i.lettuce.core.protocol.CommandEncoder   : [channel=0x36802467, /10.5.26.83:63897 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379] writing command AsyncCommand [type=HGETALL, output=MapOutput [output={}, error='null'], commandType=io.lettuce.core.protocol.Command]
[ueEventLoop-7-1] [] i.lettuce.core.protocol.CommandHandler   : [channel=0x36802467, /10.5.26.83:63897 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x1, chid=0x1] Received: 4 bytes, 1 commands in the stack
[ueEventLoop-7-1] [] i.lettuce.core.protocol.CommandHandler   : [channel=0x36802467, /10.5.26.83:63897 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x1, chid=0x1] Stack contains: 1 commands
[ueEventLoop-7-1] [] i.l.core.protocol.RedisStateMachine      : Decode done, empty stack: true
[ueEventLoop-7-1] [] i.lettuce.core.protocol.CommandHandler   : [channel=0x36802467, /10.5.26.83:63897 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x1, chid=0x1] Completing command LatencyMeteredCommand [type=HGETALL, output=MapOutput [output={}, error='null'], commandType=io.lettuce.core.protocol.AsyncCommand]

모든 명령이 동일 channel을 통해 전달되는 것을 확인할 수 있습니다.
다만 명령의 응답까지 오고 나서야 다음 요청을 보낼 수 있습니다. 때문에 실행 시간은 상당히 오래 걸립니다.
(5000건 기준 3분 이상)

아래는 파이프라이닝을 적용했을 때의 로그입니다.
응답을 기다리지 않고 명령을 모두 전송한 후, 응답이 돌아오는대로 받는 것을 확인할 수 있습니다.

[ueEventLoop-7-2] [] i.lettuce.core.protocol.CommandHandler   : [channel=0xd82a51ff, /10.5.26.83:63934 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x2, chid=0x2] Completing command LatencyMeteredCommand [type=HGETALL, output=MapOutput [output={}, error='null'], commandType=io.lettuce.core.protocol.AsyncCommand]
[ueEventLoop-7-2] [] i.lettuce.core.protocol.CommandHandler   : [channel=0xd82a51ff, /10.5.26.83:63934 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x2, chid=0x2] Stack contains: 1015 commands
[ueEventLoop-7-2] [] i.l.core.protocol.RedisStateMachine      : Decode done, empty stack: true
[ueEventLoop-7-2] [] i.lettuce.core.protocol.CommandHandler   : [channel=0xd82a51ff, /10.5.26.83:63934 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x2, chid=0x2] Completing command LatencyMeteredCommand [type=HGETALL, output=MapOutput [output={}, error='null'], commandType=io.lettuce.core.protocol.AsyncCommand]
[ueEventLoop-7-2] [] i.lettuce.core.protocol.CommandHandler   : [channel=0xd82a51ff, /10.5.26.83:63934 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x2, chid=0x2] Stack contains: 1014 commands
[ueEventLoop-7-2] [] i.l.core.protocol.RedisStateMachine      : Decode done, empty stack: true

....

[           main] [] i.lettuce.core.protocol.DefaultEndpoint  : [channel=0x7f871210, /10.5.26.83:64032 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x2] write() writeAndFlush command AsyncCommand [type=HGETALL, output=MapOutput [output={}, error='null'], commandType=io.lettuce.core.protocol.Command]
[ueEventLoop-7-2] [] i.lettuce.core.protocol.CommandEncoder   : [channel=0x7f871210, /10.5.26.83:64032 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379] writing command AsyncCommand [type=HGETALL, output=MapOutput [output={}, error='null'], commandType=io.lettuce.core.protocol.Command]
[           main] [] i.lettuce.core.protocol.DefaultEndpoint  : [channel=0x7f871210, /10.5.26.83:64032 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x2] write() done
[ueEventLoop-7-2] [] i.lettuce.core.protocol.CommandHandler   : [channel=0x7f871210, /10.5.26.83:64032 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x2, chid=0x2] write(ctx, AsyncCommand [type=HGETALL, output=MapOutput [output={}, error='null'], commandType=io.lettuce.core.protocol.Command], promise)
[           main] [] io.lettuce.core.RedisChannelHandler      : dispatching command AsyncCommand [type=HGETALL, output=MapOutput [output={}, error='null'], commandType=io.lettuce.core.protocol.Command]
[           main] [] i.lettuce.core.protocol.DefaultEndpoint  : [channel=0x7f871210, /10.5.26.83:64032 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x2] write() writeAndFlush command AsyncCommand [type=HGETALL, output=MapOutput [output={}, error='null'], commandType=io.lettuce.core.protocol.Command]
[ueEventLoop-7-2] [] i.lettuce.core.protocol.CommandEncoder   : [channel=0x7f871210, /10.5.26.83:64032 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379] writing command AsyncCommand [type=HGETALL, output=MapOutput [output={}, error='null'], commandType=io.lettuce.core.protocol.Command]
[           main] [] i.lettuce.core.protocol.DefaultEndpoint  : [channel=0x7f871210, /10.5.26.83:64032 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x2] write() done
[ueEventLoop-7-2] [] i.lettuce.core.protocol.CommandHandler   : [channel=0x7f871210, /10.5.26.83:64032 -> qa2-official-ch.wfamrx.ng.0001.apne1.cache.amazonaws.com/10.250.73.252:6379, epid=0x2, chid=0x2] write(ctx, AsyncCommand [type=HGETALL, output=MapOutput [output={}, error='null'], commandType=io.lettuce.core.protocol.Command], promise)
[           main] [] io.lettuce.core.RedisChannelHandler      : dispatching command AsyncCommand [type=HGETALL, output=MapOutput [output={}, error='null'], commandType=io.lettuce.core.protocol.Command]

Ref.

Redis pipelining
Spring Boot with Redis: Pipeline Operations
Spring Data Redis Pipelining
lettuce.io/pipelining_and_command_flushing

나르

💻 + ☕ = </>

Redis pipelining 을 통한 알림 서비스 개선기

NoSQL

1. 발단

2. 원인 파악

개선

Ref.

0개의 댓글

`1. 발단`