2020/07/25일 Redis로 인해 블로그가 접속되지 않는 문제가 발생하였고 해당 내용에 대해 정리한 글입니다.

장애발생 일시

2020/07/25 19:10 ~ 20:00

현상

Redis에서 Snapshot 저장 실패로 인하여 redis write 기능이 중단 되어 세션을 정상적으로 저장하지 못하여 블로그가 일시 중단 됨.

조치내용

• 19:10 장애발생 확인
• 19:25 오류 원인 파악
• 19:30 Redis 재기동(일시 정상화)
• 19:50 Redis 설정 적용 및 Snapshot 저장공간 권한 적용
• 20:00 Redis 재기동(완전 정상화)

장애내용

Redis가 일정 시간에 따라 Snapshot을 저장하는데 Snapshot을 저장하는 위치에 권한이 없어 저장되지 못하였고 Redis는 스냅샷이 저장되지 않았을 때 관련 데이터를 잃어버릴 가능성이 크기 때문에 오류를 발생하여 이를 사전에 알리게 되는데, 그로 인해 서비스가 중단 됨.

19시10분경 블로그 접근 중 서버 장애 여부를 확인하였고 오류 메시지를 통해 Redis 서버에서 발생한 문제임을 확인 함.
이후 Redis에서 Snapshot을 저장하지 못해 발생한 문제임을 확인하고 재기동을 통해 일시적으로 정상화를 하였음.

일시 정상화 이후 추가적으로 근본적인 해결방법을 파악하였고 Redis의 설정 및 Snapshot을 저장하는 공간의 쓰기 권한을 추가하여 문제를 해결하였음.

이후 추가적인 재기동을 통해 완전 복구 됨.

발생 오류

HTTP 상태 500 – 내부 서버 오류
타입 예외 보고

메시지 Error in execution; nested exception is io.lettuce.core.RedisCommandExecutionException: MISCONF Redis is configured to save RDB snapshots, but it is currently not able to persist on disk. Commands that may modify the data set are disabled, because this instance is configured to report errors during writes if RDB snapshotting fails (stop-writes-on-bgsave-error option). Please check the Redis logs for details about the RDB error.
설명 서버가, 해당 요청을 충족시키지 못하게 하는 예기치 않은 조건을 맞닥뜨렸습니다.

예외
org.springframework.data.redis.RedisSystemException: Error in execution; nested exception is io.lettuce.core.RedisCommandExecutionException: MISCONF Redis is configured to save RDB snapshots, but it is currently not able to persist on disk. Commands that may modify the data set are disabled, because this instance is configured to report errors during writes if RDB snapshotting fails (stop-writes-on-bgsave-error option). Please check the Redis logs for details about the RDB error.
org.springframework.data.redis.connection.lettuce.LettuceExceptionConverter.convert(LettuceExceptionConverter.java:54)
org.springframework.data.redis.connection.lettuce.LettuceExceptionConverter.convert(LettuceExceptionConverter.java:52)
org.springframework.data.redis.connection.lettuce.LettuceExceptionConverter.convert(LettuceExceptionConverter.java:41)
org.springframework.data.redis.PassThroughExceptionTranslationStrategy.translate(PassThroughExceptionTranslationStrategy.java:44)
org.springframework.data.redis.FallbackExceptionTranslationStrategy.translate(FallbackExceptionTranslationStrategy.java:42)
org.springframework.data.redis.connection.lettuce.LettuceConnection.convertLettuceAccessException(LettuceConnection.java:269)
org.springframework.data.redis.connection.lettuce.LettuceHashCommands.convertLettuceAccessException(LettuceHashCommands.java:471)
org.springframework.data.redis.connection.lettuce.LettuceHashCommands.hMSet(LettuceHashCommands.java:347)
org.springframework.data.redis.connection.DefaultedRedisConnection.hMSet(DefaultedRedisConnection.java:1095)
org.springframework.data.redis.core.DefaultHashOperations.lambda$putAll$7(DefaultHashOperations.java:151)
org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:228)
org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:188)
org.springframework.data.redis.core.AbstractOperations.execute(AbstractOperations.java:96)
org.springframework.data.redis.core.DefaultHashOperations.putAll(DefaultHashOperations.java:150)
org.springframework.data.redis.core.DefaultBoundHashOperations.putAll(DefaultBoundHashOperations.java:147)
org.springframework.session.data.redis.RedisIndexedSessionRepository$RedisSession.saveDelta(RedisIndexedSessionRepository.java:795)
org.springframework.session.data.redis.RedisIndexedSessionRepository$RedisSession.save(RedisIndexedSessionRepository.java:783)
org.springframework.session.data.redis.RedisIndexedSessionRepository$RedisSession.access$000(RedisIndexedSessionRepository.java:670)
org.springframework.session.data.redis.RedisIndexedSessionRepository.save(RedisIndexedSessionRepository.java:398)
org.springframework.session.data.redis.RedisIndexedSessionRepository.save(RedisIndexedSessionRepository.java:249)
org.springframework.session.web.http.SessionRepositoryFilter$SessionRepositoryRequestWrapper.commitSession(SessionRepositoryFilter.java:225)
org.springframework.session.web.http.SessionRepositoryFilter$SessionRepositoryRequestWrapper.access$100(SessionRepositoryFilter.java:192)
org.springframework.session.web.http.SessionRepositoryFilter.doFilterInternal(SessionRepositoryFilter.java:144)
org.springframework.session.web.http.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:82)
org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:358)
org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:271)
org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)

근본 원인 (root cause)
io.lettuce.core.RedisCommandExecutionException: MISCONF Redis is configured to save RDB snapshots, but it is currently not able to persist on disk. Commands that may modify the data set are disabled, because this instance is configured to report errors during writes if RDB snapshotting fails (stop-writes-on-bgsave-error option). Please check the Redis logs for details about the RDB error.
io.lettuce.core.ExceptionFactory.createExecutionException(ExceptionFactory.java:135)
io.lettuce.core.ExceptionFactory.createExecutionException(ExceptionFactory.java:108)
io.lettuce.core.protocol.AsyncCommand.completeResult(AsyncCommand.java:120)
io.lettuce.core.protocol.AsyncCommand.complete(AsyncCommand.java:111)
io.lettuce.core.protocol.CommandHandler.complete(CommandHandler.java:654)
io.lettuce.core.protocol.CommandHandler.decode(CommandHandler.java:614)
io.lettuce.core.protocol.CommandHandler.channelRead(CommandHandler.java:565)
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:377)
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363)
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:355)
io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:377)
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363)
io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163)
io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:714)
io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:650)
io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:576)
io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493)
io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
java.lang.Thread.run(Thread.java:748)

비고
근본 원인(root cause)의 풀 스택 트레이스를, 서버 로그들에서 확인할 수 있습니다.

Apache Tomcat/8.5.53

Redis log

Redis의 로그에는 "Failed opening the RDB file dump.rdb (in server root dir /data) for saving: Permission denied"라는 오류메시지가 남아있었습니다. (위 이미지는 이후에 다시 현상을 재현하여 찍었습니다.)

조치사항

기존 Docker Redis의 경우 기본 환경설정 파일을 지정하는 부분이 없어서 기본값으로 처리되고 있었음.
docker-compose 실행 시 command를 통해 redis-server [config file path]를 입력하여 커스텀 설정 값을 처리하도록 변경하였음.

# docker-compose ver 3.8

redis:
    image: redis:latest
    container_name: redis
    command: redis-server /usr/local/etc/redis/redis.conf
    ports:
        - "6379:6379"
    volumes:
        - /etc/localtime:/etc/localtime:ro
        - /home/kurien/services/redis/redis.conf:/usr/local/etc/redis/redis.conf
        - /home/kurien/services/redis/backup:/usr//local/etc/redis/backup

redis.conf 파일 내 "dir ./data" 설정을 "dir /usr/local/etc/redis/backup" 으로 변경
연결된 volumes 중 /home/kurien/services/redis/backup 폴더의 읽기, 쓰기, 실행 권한 추가

이슈 확인 중 설정의 stop-writes-on-bgsave-error 옵션을 yes에서 no로 변경하게 되면 오류가 발생하더라도 레디스가 쓰기 금지 되지 않고 정상적으로 작동된다고 합니다.

# By default Redis will stop accepting writes if RDB snapshots are enabled
# (at least one save point) and the latest background save failed.
# This will make the user aware (in a hard way) that data is not persisting                                                                                                                     # on disk properly, otherwise chances are that no one will notice and some
# disaster will happen.
#
# If the background saving process will start working again Redis will
# automatically allow writes again.
#
# However if you have setup your proper monitoring of the Redis server
# and persistence, you may want

하지만 해당 사항은 근본적인 해결책은 아니며, Redis에서는 Snapshot 저장이 안되는 경우 중요 정보를 잃어버릴 가능성이 높고, 별도의 모니터링이 없으면 해당 오류를 발견하기 어려우므로 오류를 발생하게 하는 것을 권장하고 있습니다.

저도 아직 모니터링 환경은 구축하지 않았기 때문에 Redis의 권장사항에 따라 오류 발생 시 쓰기 금지되도록 처리해둔 상태입니다.

향후대책

• 시스템 모니터링 서버를 제작하여 문제발생 시 바로 확인이 가능하도록 시스템 구성 필요.
• Redis의 설정에 대한 추가적인 학습 필요.