레디스 장애 회고
2022년 11월 30일 단 한줄의 코드로 인하여 시스템을 정상적으로 이용할 수 없는 상태로 만들어버리는 심각한 결함을 만들었다. 과연 어떤 문제가 발생했고 그 원인은 무엇이었는지 되돌아보며 여러분에게 공유하고자 한다.
일반적인 웹 서비스처럼 실시간으로 많은 사용자와 그리고 각 사용자에 의해 대량의 트래픽이 발생하는 시스템 환경은 아닙니다만 애플리케이션이 스케일 아웃되어 분산화되는 것을 고려하여 세션 클러스터링을 위하여 스프링 세션과 함께 세션 정보를 레디스라는 인메모리 저장소에 연계하도록 스프링 세션 레디스를 사용하고 있었다. 시스템 환경 규모 상 많은 사용자의 세션 데이터가 저장되는 것은 아니므로 1GB 정도의 메모리 사양을 가지는 작은 단일 인스턴스에 레디스를 설치하여 스탠다드-얼론 모드로써 사용하더라도 큰 문제가 없었다. 세션 저장소로써 레디스를 도입하였으나 실제로 사용자에 의해 발생하는 세션 데이터가 많이 저장되지 않을 것이므로 일부 데이터베이스 조회에 대해서 부하를 줄일 수 있도록 자주 변경될 가능성이 없는 일부 데이터를 조회하는 프로시저 호출에 대해서 스프링 캐시를 적용하였다. 그러나, 세션과 캐시 데이터를 포함하여 생각보다 사용되는 메모리는 미비했었기에 세션이나 캐시에 대해 그다지 고민할 필요성은 없었다고 생각된다.
그러나, 어느 시점부터 특정 환경에서 레디스가 설치된 서버의 메모리 사용량이 조금씩 오른다는 모니터링 지표를 전달받았으며 모니터링 지표가 전달되는 과정에서 시간이 많이 흘렀기에 긴급하게 레디스가 설치된 서버의 메모리 사용량이 높으며 애플리케이션 서버의 CPU 부하가 높고 시스템을 정상적으로 이용할 수 없는 상태가 되었다고 보고 받게 되었다.
레디스의 메모리 사용량이 높아진 원인
처음에는 레디스가 설치된 서버의 메모리 사용량이 높아진다는 이야기만 전달받았기에 (이전에 발생한 이력을 토대로) 보안 및 모니터링 목적으로 각 서버에 설치된 백신 프로그램이나 모니터링 에이전트로 인해 메모리 누수가 발생했을 것이라고 의심했으나 레디스 서버에 접속 후 명령어를 수행하는데 버벅거릴 정도로 서버의 여유 메모리가 남아있지 않은 상태가 되어있었으며 레디스가 실시간으로 사용하는 메모리의 사용량이 서버 메모리를 거의 점유하고 있었음을 확인하였다.
레디스가 서버 메모리를 거의 사용한 이유
서버의 메모리 사용량이 엄청나게 높았던 이유는 레디스가 거의 대부분의 메모리를 사용하고 있었기 때문이며 이렇게까지 되어버린 사유에 대해서는 운영적인 측면을 고려하지 않고 인프라 및 서버 환경 구축 시 레디스를 설치하고나서 비밀번호를 제외한 나머지 옵션에 대해서는 기본값으로 구동하였기 때문이다. 사실 상 레디스라는 기술에 대해서 라인이나 카카오와 같은 규모의 조직이 아니라면 기술적인 경험이 부족해서 레디스에서 제공하는 기본값을 사용하는 곳이 많을지도 모르겠다.
아무튼 레디스를 설치하였을때 기본적으로 제공하는 설정 파일에서 레디스가 사용하는 최대 매모리에 대한 제한은 없도록 되어있으며 경고 문구를 통해 세션이나 캐시를 위해서 레디스를 사용하는 경우 최대 메모리 설정을 하는 것이 좋을 수 있다고 안내하고 있다. 레디스가 서버 메모리를 제한없이 사용하게 되면서 서버 상태가 이상해진 것을 경험하고 나서야 해당 옵션이 적용되어 있지 않음을 확인하였고 이에 대해 긴급 잠정 조치가 필요함을 우선 전달하였다.
최대 메모리 설정은 서버 메모리를 너무 많이 사용하게 되어 가상 메모리까지 스왑하여 사용하지 않도록 하기 위한 예방책일 뿐 근본적인 원인에 대해 검토되지 않았고 해결 방법은 아니다. 우선 레디스 서버의 상태를 안정적으로 유지할 수 있도록 최대 메모리를 설정 및 스냅샷된 파일을 삭제하고 레디스를 재시작하였다.
레디스 스냅샷을 통해 데이터 분석
레디스의 최대 메모리 설정 조치를 수행하기 전에 레디스에서 기본값에 의해 자체적으로 저장해두었던 스냅샷(dump.rdb) 파일을 백업한 후 로컬 환경에서 도커 컨테이너를 통해 레디스를 스냅샷 기준으로 구동한 후 레디스가 점유하고 있던 메모리가 어떤 데이터로 인한 것인지 검토하였다. 레디스 클라이언트(redis-cli)를 통해 저장된 데이터들의 키를 조회하였으며 운영중인 환경이 아니므로 KEYS 명령어를 수행하여 대략적인 키들을 확인했고 너무 많은 키들로 인하여 제대로 확인을 할 수 없다고 판단되어 스프링 세션 관련 키와 캐시로 저장하는 키들을 정리하고 스택오버플로우에 공유된 댓글 중 eval 명령어를 활용한 예시를 참고하여 아래와 같이 수행하였다.
eval "return #redis.call('keys', 'spring:session:*')" 0
eval "return #redis.call('keys', 'spring:session:sessions:*')" 0
eval "return #redis.call('keys', 'spring:session:sessions:expires*')" 0
eval "return #redis.call('keys', 'spring:session:expirations*')" 0세션 관련 키들은 약 60만 개가 등록되어있었으며 세션 관련 키들을 삭제하니 남아있던 캐시 데이터로 인해 점유중인 메모리의 사용량은 약 200MB가 되었다. 일부 테스트를 위한 사용자의 추가로 인하여 캐시되는 데이터의 양이 조금은 많아졌으나 시스템에 실시간으로 접속하는 사용자에 대한 세션은 많지 않기에 무분별하게 불필요한 세션 키들이 등록되었음을 인지하게 되었다. 단순하게 바라보면 일반적으로 세션의 만료 시간을 짧게 하는데 시스템 요구사항 특성 상 세션 타임아웃이 7일로 지정되어 있었기에 등록된 세션 관련 키들을 오래동안 레디스를 점유하게 되는 상황이 되어버렸다.
스프링 프레임워크의 구현을 이해하지 못한 이유로 불필요한 세션 정보를 저장
보안 요구사항에 의해 사용자의 요청이나 내부적인 스케줄 작업에 의해 호출되는 데이터베이스 요청에 대해서 일련의 과정을 감시할 수 있도록 API 요청에 대한 로그나 어떤 프로시저를 호출하는지 로그로써 기록해야했고 이 과정에서 데이터베이스에 대한 요청을 수행하는 세션의 아이디가 저장되어야할 항목에 포함되어있었다. 이 요구사항에 대한 작업은 공통 모듈로써 코드를 작성했는데 데이터베이스를 호출하는 클래스가 공통 모듈에 있었으며 해당 클래스가 스프링 컨테이너를 통해 빈으로 관리되는 것이 아니라 매번 생성되어야하는 구조로 되어있다보니 스프링에서 지원하는 AOP를 통해 데이터베이스 요청에 대해서 가로채어 기록할 수 없었다.
아무튼 데이터베이스에 대한 프로시저를 호출하는 과정에서 적당한 위치를 고려하여 선정했고 프로시저 명과 여러가지 정보와 함께 세션 아이디를 기록하기 위해서 스프링 프레임워크에서 제공하는 RequestContextHolder를 통해 RequestAttributes를 가져온 후 세션 아이디를 반환하는 함수를 호출하도록 작성하였다.
이 방식이 어떤 문제가 있는지 바로 알아챈 분들이라면 스프링 프레임워크 구현을 제대로 알거나 많은 경험이 있다고 보여진다. 아마 대부분은 저 함수를 호출하는게 왜 레디스와 연관이 있는지 예상하기 힘들것이다.
사실 단순히 저 함수명을 바라본다면 보안 요구사항에 대한 처리 로직 과정에서 무분별하게 세션 정보가 저장될 수 있는지 검토하는 건 코드 리뷰를 했더라도 어려웠을 것이라는 생각이 든다. 스프링 프레임워크에서 제공하는 인터페이스에 적혀있는 상세한 내용을 확인하면 아래와 같이 NULL 값이 될 수 없는 문자열이 반환되어야한다고 되어있기 때문이다.
/**
* Return an id for the current underlying session.
* @return the session id as String (never {@code null})
*/
String getSessionId();이에 따라 스프링 프레임워크에서는 ServletRequestAttributes 구현체에서 세션 아이디가 반드시 반환되어야하므로 요청 정보에서 세션을 가져올 때 없으면 생성되도록 인자가 반드시 true인 상태로 동작하게 구현해두었다. 일반적으로 세션 방식과 토큰 기반의 인증이나 API 요청으로 구분되는데 스프링 웹 MVC 에서는 두개 모두 서블릿 요청일 뿐이므로 스레드 로컬에 요청 스레드가 저장되어 언제든 가져올 수 있는 상태가 된다.
그런데, 세션 아이디라 함은 세션 방식의 요청에 대해서만 의미가 있으므로 세션이 활용되지 않는 토큰 기반 요청에 대해서는 내부적으로 세션을 저장하는 코드가 호출되지 않는다. 따라서, 토큰 기반 요청 시 세션이 생성되지 않아야 함에 불구하고 세션 아이디를 가져올 수 있는 위 함수를 호출하게 되면 새로운 세션이 생성되고 스프링 세션에 대한 필터가 가장 먼저 처리되므로 요청을 처리하고 응답하는 과정에서 생성된 세션이나 변경된 세션 정보를 갱신하기 위해 스프링 세션 레디스 구현 동작이 호출되어 레디스에 불필요한 세션 키들을 생성하게 된 것이다.
세션 아이디를 조회하는 코드 로직의 변경
스프링 프레임워크에서 제공하는 함수의 구현을 제대로 확인하지 못한 상태에서 요구사항을 처리한 나의 실수 인 것은 명확하다. ServletRequestAttributes를 통해 세션 아이디를 쉽게 가져올 수 있었으나 상황에 따라 예상하지 못했던 결과를 가져오게 되었으므로 세션 아이디를 조회하는 코드를 HttpServletRequest로부터 현재 스레드 로컬 내에 세션이 있다면 가져오도록 변경했다. 이제는 새로운 세션을 만드는 과정이 없으므로 토큰 기반 API가 요청될 때 레디스에 무수히 많은 세션 키가 등록되지 않는다.
운영적인 측면의 레디스 옵션 권고
tcp-backlog 1024
maxmemory 400mb
maxmemory-policy allkeys-lfuulimit -n 65535
echo 'net.ipv4.tcp_max_syn_backlog=1024' >> /etc/sysctl.conf
echo 'net.core.somaxconn = 65535' >> /etc/sysctl.conf
echo 'vm.overcommit_memory = 1' >> /etc/sysctl.conf
echo never > /sys/kernel/mm/transparent_hugepage/enabled레디스 결함으로 인해 확인된 레디스 옵션에 대한 문제도 검토하여 위와 같이 운영적인 측면에서의 옵션을 정리한 후 레디스 서버 환경에 적용할 준비를 하고 있다. 한가지 명확하지 않은 부분은 최대 메모리 옵션에 적용되어야할 적당한 수치가 무엇이냐인데 BGSAVE를 통해 RDB 스냅샷을 수행하는 경우 Fork 방식으로 프로세스를 복제하여 덤프 파일을 생성하기 때문에 실제로 메모리 사용량이 두배 이상이 될 수 있다는 점을 감안한다면 절반 이하의 메모리를 사용할 수 있도록 해야할 것 같다. 더구나 레디스 뿐만 아니라 CPU나 메모리를 사용할 수 있는 백신 프로그램이 구동중이므로 인터넷에 정리된 60% 정도의 메모리 설정은 적합하지 않다고 생각된다.
트러블슈팅 회고
개발자로써는 생각지도 못하게 단 한줄의 코드로 인하여 시스템을 마비시키는 경험을 한 큰 이슈였으며 고객의 입장에서는 사용중인 시스템에 대한 안정성과 신뢰성을 문제삼을 수 있는 건이었다. 아무튼 조직에서는 이에 대한 장애 보고를 고객 측에게 전달하기 위하여 관련 정보를 정리하고 있으며 관련 이슈가 발생하지 않도록 어떤 조치를 할 것인지를 고민하고 있다. 이 문제에 대해서 돌아보면서 확인하게 된 아래의 글들을 공유하며 마치고자 한다.