장애 상황
이슈 생성 API의 부하 테스트를 통해 안정적인 서비스 제공과 우수한 성능을 달성하는 것을 목표로 설정했습니다.
그러기 위해서 대규모 조직(1000명 이상)에서 50~100명의 사용자가 동시에 이슈를 생성하는 상황을 가정했을 때, 다음과 같이 요청-응답 시간(MTT)은 1~2초 이내, TPS는 30~40, 에러율은 0.1% 이하, 테스트 시간은 1분 이내인 성능 지표를 목표로 삼았습니다
💡 TPS를 30~40으로 잡은 이유 (1000명 조직 기준 예상 시나리오)
- 1인당 하루 평균 5-10개 이슈 생성
- 8시간 근무 기준: 1000명 × 10개 ÷ 8시간 ÷ 3600초 ≈ 0.34 TPS
- 피크 타임(10배 부하) 고려: 약 3 TPS - 버퍼(10-20배)를 둬서 30-40 TPS 설정
가상 사용자(VUser)를 점진적으로 늘려가던 중, 20명인 시점에서 문제가 발생했습니다.
20명임에도 불구하고, 높은 에러율과 MTT가 제 눈에 봐도 정상적인 상황은 아니었습니다.
원인 분석
💡 장애 발생 시 가장 먼저 해야 할 일은 뭘까
만약 배포 직후 장애가 발생했다면 가장 먼저 롤백을 진행합니다. 롤백 시에는 feature 브랜치에서 배포된 버전을 되돌리는 것이 아니라, master 브랜치에서 새로운 브랜치를 따서 배포를 진행합니다. 이때 리비전 없이 마스터를 바로 내보내는 것이 중요합니다.
문제가 된 feature 브랜치는 어떻게 할까요? 이 브랜치는 테스트 서버나 스테이징 서버에 배포하여 문제를 확인합니다. 특히 스테이징 서버는 운영 환경과 동일하게 구성되어 있기 때문에 정확한 테스트가 가능합니다.
배포와 관계없이 장애가 발생할 수도 있습니다. 이런 경우는 상황에 따라 대응 방법이 달라집니다. 트래픽 급증으로 인한 장애이고, AWS를 사용하고 있다면, 오토스케일링을 활용해 빠르게 서버를 증설하거나, 스팟 서버를 추가로 띄워서 대응할 수 있습니다.
인바운드나 아웃바운드 같은 정책 문제라면 즉시 인프라팀에 연락해서 상황을 전달합니다. 이런 문제는 개발팀 단독으로 해결하기 어렵기 때문이죠.
💡 장애 원인은 어떻게 찾나요?
1. 로그 기반 분석
로그 시스템이 잘 구축된 회사라면 장애 발생 시의 로그가 남아있을 것입니다. 직접 로그를 분석하면 되고, 만약에 로그가 날아가면 배포 시점의 에러 로그를 최대한 수집해서 분석해야 합니다.
💡 배포 시점의 에러 로그 최대한 수집이란?
보통 서비스에서는 로그를 저장하는 두 가지 방식이 있습니다.
1. 서버 로컬에 로그 저장
- 서버에 직접 로그 파일을 저장
- 서버가 재시작되거나 롤백되면 로그가 사라질 수 있음
2. 중앙 로그 시스템 사용 (ELK, CloudWatch 등)
- 로그를 외부 시스템에 실시간으로 저장
- 서버가 재시작되어도 로그가 보존됨
만약 중앙 로그 시스템이 없고 로컬에만 로그를 저장하는 상황이라면, 장애가 발생했을 때 롤백하기 전에 현재 서버의 로그를 다른 곳에 빠르게 복사해 두거나, 에러 메시지를 캡처해 두거나 로그 파일을 다운로드하여두는 등의 작업을 해야 합니다.
왜냐하면 롤백을 하면 서버가 재시작되면서 로컬의 로그가 모두 사라질 수 있기 때문입니다. 이렇게 미리 로그를 수집해두지 않으면, 나중에 어떤 에러가 발생했었는지 분석하기 어려워집니다.
2. 테스트 환경에서 재현
여러 개의 존(zone)이 있다면, 다른 존에 배포해서 동일한 상황을 재현해 볼 수 있습니다. 테스트 존에 같은 트래픽을 발생시켜 문제 상황을 재현하고 분석하는 거죠.
💡 특수한 장애 상황별 대처법
- OOM이나 힙 메모리가 가득 찬 경우: 힙덤프를 추출하여 분석
- API 응답이 현저히 느려진 경우: 스레드덤프를 추출하고 분석기로 확인
- 갑작스러운 에러 로그 급증: 인프라 환경을 먼저 확인
💡 그래서 내 서버의 장애는 어떻게 파악했는가
develop 브랜치로 테스트 서버에 배포해서 부하테스트를 진행 중이라, 롤백을 할 필요가 없었습니다. 서버도 재시작하지 않았기 때문에 SSH로 서버에 들어가, 로그파일을 확인해 보니 Could not open JPA EntityManager for Transaction 줄과 request timeout (30000ms) 줄이 동시에 찍혀 있었습니다.
EntityManager가 트랜잭션을 열수 없다는 것은 즉, db 커넥션이 없다는 건데, 아마 HikariPool에 생성된 커넥션이 고갈되었다는 것이고, 요청이 제대로 이루어지지 않아 대기하다가 타임아웃이 걸렸다는 추측을 했습니다.
💡 JPA EntityManager와 DB 커넥션의 관계
EntityManager는 DB와의 연결을 위해 커넥션 풀(HikariCP)에서 커넥션을 가져와 사용합니다. 이때 사용 가능한 커넥션을 얻지 못하면 "Could not open JPA EntityManager for Transaction" 에러가 발생하게 되죠.
🔍 더 알고 싶다면?
EntityManager가 DB와 통신하는 전체 과정은 꽤 흥미롭습니다. DB와 HikariCP의 커넥션 수립(3-way handshake), 하이버네이트 세션 생성, EntityManager의 ThreadLocal 세션 관리 등 자세한 내용이 있습니다.
이 부분이 궁금하시다면 하이버네이트 공식 문서나 관련 기술 블로그들을 참고해 보세요.
더 정확한 원인을 찾기 위해 상황을 재연하여 커넥션 풀과 스레드 상태를 확인해 보면 좋을 것 같다는 생각이 들었습니다.
💡 모니터링 도구 선택
스레드 덤프를 뜨기 위한 도구는 여러 가지 있습니다.
급하게 혹은, 특정 시점의 스레드 상태만 확인하기 위해서는 kill -3 PID, jstack 명령어를 활용하면 스레드 덤프를 생성할 수 있습니다.
JProfiler는 시스템 성능, 메모리 사용량, 잠재적인 메모리 누수, 스레드 프로파일링을 볼 수 있는 인터페이스를 제공합니다. 이는 원격 시스템에 아무것도 설치하지 않고도 원격시스템에서 실행되는 Java 애플리케이션을 프로파일링 할 수 있습니다.
또한, DB모니터링도 가능하며 DB 호출트리(SQL 쿼리 실행 경로, N+1 문제 식별), 커넥션 누수 감지(커넥션 풀 상태 모니터링)의 기능이 있습니다. 그리고 객체 인스턴스의 메모리 사용량을 볼 수 있는 데 라이브 객체 ,가비지 수집 객체 모두 선택하는 기능도 제공합니다.
YourKit는 스레드, 가비지 수집, 메모리 사용 및 메모리 누수를 시각화합니다. 또한 어떤 예외가 발생했고 각 예외가 발생한 횟수를 쉽게 확인할 수 있습니다. 조건부 프로파일링이 가능하며 SQL,NoSQL 호출을 프로파일링 가능합니다.
VisualVM은 메모리 및 CPU 프로파일링을 지원하고 SSH 터널링이 지원되지 않아 자격 증명(호스트 이름 및 IP 및 비밀번호)을 제공해야 합니다. 또한 실시간 프로파일링이 가능합니다. 추가적으로 스냅샷을 찍을 수 있습니다.
스레드 상태와 커넥션 풀 모니터링을 위해 VisualVM을 사용했습니다. 가장 많이 쓰이기도 하고, 사용법도 직관적이라 선택했습니다.
💡 스레드 덤프 분석
부하테스트를 2분간 진행하며, 다음 에러가 로그에 찍힐 때 스레드 덤프를 찍었습니다.
해당 로그를 살펴보면, HikariPool에선 10개의 커넥션이 각 스레드에 할당되어 활성화 중입니다. 그리고 더 이상 커넥션은 없어 20개의 스레드가 대기 중인 상태이며, 커넥션을 기다리는 스레드들이 30초간 기다리다가 타임아웃이 발생하여 에러가 발생했습니다.
그래서 이 타임아웃이 왜 발생했는지, 왜 30초동안 커넥션을 받지 못했는지 알기 위해 그 시간대 근처의 스레드 덤프를 확인하기 위해 해당 덤프를 https://fastthread.io/ 에 분석해 봤습니다.
23개의 톰캣 스레드가 TIMED_WAITED 상태이고, 15번 스레드의 스택 트레이스를 확인해 보겠습니다.
이슈를 생성하기 전, 생성하려는 멤버가 프로젝트에 속한 멤버인지 확인하기 위해 먼저 프로젝트를 가져오기 위해 커넥션이 필요합니다. 이때 커넥션이 부족해 대기상태로 변한 상태를 보여주고 있습니다.
이번엔 1번 스레드의 스택 트레이스를 보겠습니다.
Epic 타입의 이슈를 생성하는 과정에 이슈번호를 생성하기 위해 커넥션이 필요한 상황입니다. handleExistingTransaction의 메소드가 호출한 것을 보아하니 이미 해당 스레드에선 트랜잭션을 갖고 있는 상태입니다.
handleExistingTransaction을 조금 더 살펴보면,
호출된 메소드의 트랜잭션 전파속성이 5번인 PROPAGATION_NEVER일 때는 트랜잭션이 이미 존재한다면서 예외가 발생합니다.
4번인 PROPAGATION_NOT_SUPPOERTED일 때는 진행 중이었던 트랜잭션은 중단(suspend)하고 트랜잭션 없이 진행됩니다.
3번인 PROPAGATION_REQUIRES_NEW 일 때는 새로운 트랜잭션이 시작됩니다.
IssueNumberGenerator의 generate 메소드는 전파속성이 PROPAGATION_REQUIRES_NEW 이기 때문에 새로운 커넥션을 기다리고 있습니다.
1번 스레드와 같은 애들이 10개, 15번 스레드와 같은 애들이 13개 존재했습니다. 원인을 찾았으니, 이제 그림을 그려 다시 전체적인 모습을 보여드리겠습니다.
💡 트랜잭션 경계 설정 잘못으로 인해 발생한 커넥션 고갈 도식화
Ngrinder Agent를 통해 WAS로 요청이 들어오면, Tomcat Thread Pool에서 요청을 처리하기 시작합니다.
각 스레드(1번, 15번 등)는 DB 작업을 위해 HikariCP의 커넥션 풀에 접근하게 됩니다.
1. 10개의 스레드가 첫 번째 트랜잭션에서 커넥션을 이미 보유한 상태
2. 동일한 스레드들이 두 번째 커넥션을 요청했지만 커넥션 풀이 고갈된 상태
3. 각 스레드는 30초, 10초, 20초 등 서로 다른 타임아웃 시점에 커넥션을 기다리는 중
4. 커넥션 타임아웃(30초)이 발생하면 예외가 발생하고 스레드는 보유하던 커넥션을 반납
5. 반납된 커넥션은 대기 중이던 다른 스레드(예: 15번)가 획득하여 같은 패턴을 반복
이러한 순환적인 대기 상태가 계속되면서 시스템의 성능이 저하되고 요청 처리가 지연되는 문제가 발생합니다.
문제해결 : 트랜잭션 전파 속성과 커넥션 풀 최적화
IssueNumberGenerator에서 이슈 번호를 생성할 때, 전파속성을 REQUIRES_NEW 로 한 이유는 동시성 문제를 막기 위해 비관적 락을 두고, 짧은 트랜잭션을 가져가 성능을 챙기기 위함이었습니다.
하지만 커넥션 풀 개수를 잘못 설정하면 요청이 증가할수록 커넥션 데드락이 발생하기 쉬워지고 개수 설정도 쉽지 않았습니다. 당장 성능보다 중요한 것은 장애가 발생하면 안 되는 것이기 때문에 이슈생성을 하나의 트랜잭션에서 수행하도록 REQUIRES_NEW -> REQUIRED 기본값 이 가장 적절하여 변경했습니다.
💡 톰캣 스레드 풀과 HikariCP 커넥션 풀 설정
톰캣 스레드 풀 > HikariCP 커넥션 풀 일 때는 많은 스레드가 적은 수의 커넥션을 기다리는 상황이 발생하고 불필요한 스레드 생성과 컨텍스트 스위칭 오버헤드가 발생합니다.
톰캣 스레드 풀이 너무 작으면 커넥션 풀의 리소스가 충분히 활용되지 않아 전체적인 처리량이 감소합니다. 따라서 서로 매우 밀접한 관계를 갖고 있기 때문에 부하테스트를 통해 가장 적절한 개수를 찾았습니다.
maximum-pool-size와 minimum-pool-size를 동일하게 맞춰 항상 커넥션이 살아있도록 유지하고 connection-time-out은 기본설정 30초는 너무 길기 때문에 5초로 빠른 응답을 할 수 있도록 했습니다. (또한 3초는 너무 짧아 에러율이 높으므로 최적의 설정이 5초)
HikariCP의 max-lifetime은 50초로 둬, MySQL의 wait_timeout보다 짧게 줬습니다.
pool size는 부하테스트를 진행하여 최적의 개수가 8개임을 확인 (너무 많이 줘도 개선이 크게 일어나지 않고, 리소스는 많이 잡아먹는 상황이기 때문), 톰캣 스레드 최대 개수는 10개가 최적임을 확인했습니다.
💡 HikariCP의 max-lifetime을 MySQL wait_timeout 보다 짧게 준 이유
MySQL 서버는 wait_timeout 시간 동안 유휴 상태인 연결을 자동으로 종료합니다. 이때 애플리케이션은 해당 연결이 끊어졌다는 사실을 즉시 알 수 없기 때문에, 끊어진 연결을 통해 쿼리를 실행하려고 시도하면 "The last packet successfully received from the server was X milliseconds ago" 같은 에러가 발생할 수 있습니다.
HikariCP의 max-lifetime을 MySQL의 wait_timeout보다 짧게 설정하면, 커넥션 풀이 MySQL 서버가 연결을 강제로 끊기 전에 선제적으로 연결을 갱신할 수 있습니다. 예를 들어 MySQL의 wait_timeout이 28800초(8시간)로 설정되어 있다면, HikariCP의 max-lifetime은 1800초(30분)이나 그 이하로 설정하는 것이 좋습니다.
💡 결과
VUser 100인 상황에서도 더 이상 에러율이 발생하지 않았지만, MTT와 TPS는 처음 목표에 달성하지 못했습니다.
성능 개선: Redis atomic ICNR 연산
💡 Redis를 사용한 이유
이슈 번호 생성 시 사용된 비관적 락이 이슈 생성 전체에 걸렸기 때문에 낮은 성능을 보여줍니다.
우선적으로 시도한 건, 이슈 생성 시 많은 조회 쿼리가 발생하기에 해당 쿼리 익스프레인을 확인했습니다.
가장 의심이 갔던 left join이 2번 진행됐지만, 인덱스 걸린 외래키로 조인하기 때문에 성능 상 문제가 없었습니다.
두 번째 낙관적락으로 Retry 3회로 바꾸고 성능을 측정했지만, 충돌 증가로 비관적락보다 성능이 더 저하되었습니다.
이를 해결하기 위해 NoSQL 중 Redis를 선택했습니다. 그 이유는 인메모리 기반으로 동작하여 디스크 I/O가 발생하지 않아 매우 빠른 속도를 보장하며, Redis의 INCR 명령어가 단일 스레드로 동작하고 원자성을 보장하기 때문에, 별도의 락 처리 없이도 동시성 문제를 해결할 수 있었습니다. 마지막으로 Redis는 이미 저희 시스템에서 캐시용도로 사용 중 이기 때문에, 추가적인 인프라 구축 없이 도입이 가능했습니다.
💡 Redis의 캐싱 전략 선택 : Write-Behind
Redis의 캐싱 전략은 다음과 같습니다.
- Cache-Aside (Lazy Loading): 데이터를 찾을 때 먼저 Redis를 확인하고, 없으면 DB에서 가져와 Redis에 저장합니다. 실시간성이 중요하지 않은 데이터에 적합합니다.
- Write-Through: 데이터를 쓸 때 DB와 Redis에 동시에 작성합니다. 데이터 일관성은 보장되지만 쓰기 지연이 발생할 수 있습니다.
- Write-Behind (Write-Back): 데이터를 먼저 Redis에 쓰고, 나중에 비동기적으로 DB에 기록합니다. 높은 쓰기 성능이 필요할 때 유용합니다.
- Read-Through: 애플리케이션이 캐시 계층에만 요청하고, 캐시가 없으면 캐시가 직접 DB에서 로드합니다.
저희의 목적은 이슈 번호 생성을 Redis에 옮겨서 쓰기 성능을 높이기 위함이기 때문에, Write-Behind 전략을 이용했습니다.
동기화 전략은 Redis의 이슈 번호 데이터를 30초마다 스케줄러로 비동기식으로 DB에 동기화하는 방식으로 구현했습니다.
💡 동기화 주기를 30초로 정한 이유는 뭔가요
동기화 주기는 서비스의 데이터 특성과 사용 패턴을 고려해서 30초로 정했습니다. Redis에서 생성된 순수 이슈 번호는 즉시 'PRJ-123'과 같은 형태로 가공되어 별도 테이블에 저장되고, 실제 서비스에서는 이 가공된 형태로만 조회됩니다.
따라서 Redis의 원본 번호가 RDB와 일시적으로 동기화가 안 되어도 서비스 동작에는 전혀 영향이 없었습니다.
이런 구조적 특성 덕분에 동기화 주기를 너무 짧게 가져갈 필요가 없었고, 30초 정도면 시스템 부하와 리소스 사용 측면에서 적절한 밸런스를 보여줬습니다.
💡 Redis가 갑자기 장애가 발생한다면
Write-Behind 전략이기 때문에 더더욱이나 가용성에 신경 써야 했습니다. Redis Replication과 Redis Cluster 방식으로 고가용성을 보장할 수 있는데, 이슈 번호 생성이라는 단순한 카운터 용도였고, 데이터 크기도 크지 않아 Replication만으로도 충분한 가용성을 확보할 수 있었습니다.
Cluster는 복제 및 스케일아웃의 장점이 있지만, 구성이 복잡하고 관리 포인트가 늘어나는데 비해, 현재 요구사항에서는 그만한 이점이 없다고 판단했습니다.
또한 고가용성을 보장하려면 단순히 Replication을 쓰면 Master 노드가 내려갈 때 Replica 노드가 Master로 되기 위해서 수동으로 조작해야 하지만 Sentinel을 도입하여 자동 페일오버가 이뤄지도록 했습니다. Sentinel은 Master 노드의 헬스체크를 수행하다가 장애를 감지하면, Replica 중에서 새로운 Master를 선출하고 클라이언트에게 새로운 Master 정보를 전달합니다.
💡 Replication에 대해 더 많은 내용은 다음 글에 정리했습니다.
https://evoblog.life/redis-replication/
최종 결과
최종적으로 100 VUser 기준 1분간 부하테스트 결과, TPS가 33에서 68로 증가하고 평균 응답시간이 2.9초에서 1.4초로 개선되어 당초 목표였던 응답시간 2초 이내를 달성할 수 있었습니다.
이번 경험을 통해, 프로젝트에 맞는 HikariPool과 톰캣 스레드의 설정의 중요성과 Redis 성능 개선 체감을 더 할 수 있었던 경험이었습니다.
'toy > AgileHub' 카테고리의 다른 글
[이슈 #2] 멤버 초대 이메일 발송 설계 (1) | 2024.12.23 |
---|---|
이슈 번호 생성의 동시성 문제와 커넥션 풀 최적화 여정 (2) | 2024.11.09 |
이슈 전체 조회 성능 개선하기 (0) | 2024.07.06 |
배포 하는데 걸리던 시간 13분을 5분으로 줄이기 (0) | 2024.05.14 |
docker volume 제대로 설정하자 (0) | 2024.05.09 |