회사에서 PG사를 통해 현금을 결제하여 포인트를 구매할 수 있는 서비스의 전반적인 백엔드 부분을 담당하여 개발을 진행하였습니다.
입사 이후 진행하는 첫 신규 서비스 개발 프로젝트이기도 하고, 소중한 고객의 돈과 관련된 기능인 만큼 장애가 발생한다면 굉장히 크리티컬한 서비스 개발이였기에 설계부터 개발, 테스트까지 나름대로 신경써서 개발을 진행하였습니다.
기존 포인트 DB의 정합성이 틀어진 문제가 있어서, 데이터 정합성이 보장되도록 하기 위한 로직 개발과 DB설계부터 PG 연동 플로우 설계, 기존 API 마이그레이션, 기존 데이터 이관 업무 전부 혼자 담당하려다보니 벅차기도 하였지만 우여곡절 끝에 개발을 완료하였고 개발서버, Stage 서버 QA까지 마무리 한 뒤 대망의 결제 시스템을 오픈하였습니다.
라이브 배포 직후 다같이 모여서 대망의 첫 포인트 구매를 진행해보는데..
왜인지 모르게 구매는 성공했지만 실패 팝업이 노출되는 이슈가 발생하였습니다. QA 기간중에는 발견되지 않았던 이슈였고, 나름대로 심혈을 기울여서 개발을 한 터라 당시에는 많이 당황했습니다.. ㅜㅜ
유저 입장에서도 돈이 빠져나갔는데 포인트 구매가 실패했다는 팝업이 뜬다면(실제로는 정상적으로 구매가 되었지만) 당황스러울 수도 있을 것 같습니다.
처음에는 이러한 이슈가 프론트 쪽에서 응답에 따른 팝업 노출 로직이 잘못되었나.. 싶기도 하였지만 곰곰히 제가 만들었던 코드들에 대하여 생각해보니 머릿속에 "혹시 트랜잭션 격리 수준에 따른 이슈가 아닐까?" 하는 생각이 스쳐 지나갔습니다.
실험을 통하여 제가 생각했던 문제가 맞았다는 것을 알아냈고, 30분 안으로 빠르게 핫픽스로 배포가 나갈 수 있었습니다.
트랜잭션 격리 수준에 따른 이슈는 공부할 때 실무에서는 처음 만났지만, 앞으로도 이에 주의하면서 개발할 수 있도록 구체적으로 해결한 과정을 기록하려 합니다.
📌 이슈 발생 과정
먼저 이슈가 발생한 과정을 알기 위하여 결제가 성공하고, 포인트가 충전된 이후 포인트 구매 성공/실패 팝업이 노출되기 까지 내부 과정을 이해해야합니다.
1. 프론트에서 스트라이프 서버에 결제 요청을 합니다.
2. 결제에 성공한 경우 스트라이프 서버에서 백엔드 서버에 웹훅을 보냅니다.
3. 백엔드 서버에서는 스트라이프 서버에서 보낸 결제 성공 웹훅을 받아 포인트 충전을 진행합니다. (이 때 포인트 구매 내역도 저장됩니다.)
4. 프론트에서 백엔드 서버에 결제 ID에 알맞는 포인트 구매내역 존재 유무 조회를 API를 통하여 요청합니다.
5. 백엔드 서버에서는 (3)에서 DB에 저장한 포인트 구매내역이 존재하는지 조회합니다.
6. 스트라이프 서버에서 웹훅이 늦게 오는 경우도 고려하여 내역이 조회되지 않는 경우 2초마다 1번씩 총 5번 재조회(Retry) 합니다
7. 조회 결과(충전내역 존재 유무)를 프론트에 반환하여 결과에 따라 다른 팝업을 노출합니다.
나름대로 웹훅이 늦게 오는 경우까지 고려하여 재시도 로직을 작성하였으나, 포인트 구매 실패 팝업이 노출된 이슈가 발생하였고 해결을 위해 서버 로그와 데이터를 확인해보니 이슈 발생 과정의 시간 순서는 다음과 같았습니다.
16분 56초 : 프론트엔드에서 유료 포인트 충전 내역 존재 유무 조회 요청
16분 59초 : 유료 포인트 충전 내역 저장 (DB의 created_at 컬럼을 통해 확인)
17분 06초 : 10초간 5회 재조회까지 했음에도 불구하고 유료 포인트 충전 내역 조회가 안되어 false 응답 반환 (서버 로그를 통해 확인)
논리적으로 생각하면 16분 59초에 충전 내역 저장이 완료되었고, 저장된 이후에 조회를 시도했기에 존재 유무는 true가 반환되어야 정상이지만 실제로는 조회가 안되어 false 응답이 반환되었다는 것을 확인하였습니다.
📌 Repeatable Read 격리수준
위와 같은 현상이 발생한 이유를 알기 위해서 먼저 트랜잭션 격리수준 중 Repeatable Read 격리 수준에 대한 이해가 필요합니다.
그 전에 앞서 트랜잭션 격리 수준이란 간단하게 트랜잭션끼리 얼마나 고립되어있는 지를 나타내는 수준입니다. 격리 수준이 낮은 순서대로 다음과 같이 4가지 단계로 이루어져있습니다.
- Read Uncommited
- Read Commited
- Repeatable Read
- Serializable
스프링에서는 데이터베이스 트랜잭션의 ACID를 @Transactional 애노테이션과 AOP를 통하여 보장하는데,
해당 애노테이션을 사용하며 특별하게 격리수준을 설정하지 않는다면 사용하는 DBMS의 기본 격리수준을 따르게 됩니다.
따라서, MySQL의 InnoDB 스토리지 엔진은 Repeatable Read를 기본 트랜잭션 격리수준으로 채택하기에 스프링에서도 기본 격리수준은 Repeatable Read를 사용합니다.
Mysql의 InnoDB 스토리지 엔진은 변경 전의 데이터를 언두 로그에 백업해두며, Repeatable Read 격리 수준으로 데이터 조회 시 백업 된 데이터를 읽습니다. 이런 원리로 Repeatable Read는 한 트랜잭션 내에서 늘 동일한 조회 결과를 보장한다는 특징이 있습니다.
또한 Mysql의 InnoDB 스토리지 엔진에서 Repeatable Read는 다른 DBMS와는 다르게 유령 레코드가 조회되는 Phantom Read가 발생하지 않습니다.(일반적인 상황에서는 발생하지 않지만, 특정 상황에서는 Phantom Read가 발생할 수 있습니다.)
이에 관련한 자세한 내용을 다루게되면 글이 너무 길어져 궁금하신 분들은 잠깐 "Mysql Repeatable Read Phantom Read" 키워드로 검색해보면 정리가 잘 된 좋은 글들이 많으니 보고 오시는 것을 추천드립니다.
📌 이슈 원인
위에서 살펴본 개념을 토대로, 재시도 로직이 작성된 코드와 이슈가 발생했던 과정의 그림을 살펴보겠습니다.
포인트 구매내역 존재 유무 조회 코드
@Transactional(readOnly = true)
public ExampleResponse checkPurchase(String paymentId) {
boolean exists = false;
int retryCount = 5;
while(!exists) {
exists = pointReader.existsPurchaseBy(paymentId); // (1)
retryCount--;
if (retryCount == 0) break;
if (!exists) sleep(2000);
}
if (!exists) { // (2)
log.error("에러 로그")
}
return new ExampleResponse(exists);
}
(1) : 데이터베이스에서 포인트 구매 내역이 존재하는지 조회합니다.
(2) : 10초간 5번의 재시도를 했음에도 불구하고 구매내역이 존재하지 않는다면, 결제에는 성공하였지만 포인트 충전이 안된 경우이므로 에러 로그를 남깁니다.
@Transactional 내부에 재시도 로직이 작성되었고, 별 다른 격리수준 설정이 없기에 Reapeatable Read 격리수준으로 조회한다는 것을 알 수 있습니다.
따라서, 최초로 조회한 시점부터 늘 동일한 결과가 조회가 되기에 이러한 문제가 발생한 것이였습니다.
- 1번 트랜잭션(Tx1)에서 트랜잭션을 시작하고, 포인트 구매내역 존재 여부를 DB에서 조회합니다. 이 때 저장된 내역이 없기에 존재 유무는 false로 반환됩니다.
- 2번 트랜잭션(Tx2)에서 트랜잭션을 시작하고, Tx1이 재시도 하는 와중에 유료 포인트 충전 내역을 저장합니다.
- 1번 트랜잭션 중간에 2번 트랜잭션이 구매 내역을 저장하였으나, 트랜잭션의 격리 수준이 Repeatable Read이기에 1번 트랜잭션의 시작시점부터 동일한 조회 결과를 보장하여 2번 트랜잭션이 저장한 충전 내역 레코드를 조회할 수 없습니다. 따라서 충전 내역 존재 유무는 false로 반환됩니다.
📌 해결 과정
위에서 파악한 원인을 토대로 해결방법 두가지를 생각해볼 수 있습니다.
- 포인트 충전내역 존재 유무 조회 시 트랜잭션 격리 수준을 Read Committed로 낮추어 트랜잭션 중간에 새로운 레코드가 삽입되더라도 읽을 수 있도록 한다.
- 포인트 충전내역 존재 유무 조회를 재시도할 때 마다 새로운 데이터베이스 트랜잭션을 시작한다.
둘 다 이슈의 해결책으로 사용할 수 있으나, 2번의 방법을 통하여 이슈를 해결하였습니다.
현재 안정성을 더하기 위하여 재시도를 2초에 한번씩 총 15번 시도하는 것으로 변경하였는데, 1번해결방법은 데이터베이스 트랜잭션을 최악의 경우 무려 30초간 수행합니다. 이는 곧 데이터베이스 커넥션을 30초간 점유하고 있다는 뜻으로도 직결됩니다.
커넥션 풀의 커넥션 갯수는 유한하기에 트랜잭션은 가능한 수행 시간이 짧으면 짧을수록 좋습니다. 따라서 조회가 끝나면 커넥션을 바로 반납하는 2번의 해결방법을 채택하였습니다.
2번의 해결방법을 코드 상으로 구현하려면 간단하게 @Transactional 범위 바깥에서 재시도하는 로직을 작성하면 됩니다.
제가 개발하고 있는 백엔드 어플리케이션은 기본적으로 Controller → Facade → Service → Repository 순으로 메소드가 호출되는데, 여기서 Service 레이어부터 @Transactional이 시작됩니다.
기존에는 재시도 로직을 Service에 작성 하여 트랜잭션 내부에서 재조회를 수행하였으나, 재조회 로직을 상위 레이어로 옮겨 매번 새로운 트랜잭션에서 조회를 수행하도록 하였습니다. 이러면 Repeatable Read여도 매번 새로운 트랜잭션에서 조회하기 때문에, 조회를 수행하는 시점마다 커밋된 데이터를 읽게 됩니다.
상위 레이어로 옮긴 수정 코드
public ExampleResponse checkPurchase(String paymentId) {
boolean exists = false;
int retryCount = 15;
while(!exists) {
exists = exampleService.checkPurchase(paymentId);
retryCount--;
if (retryCount == 0) break;
if (!exists) sleep(2000);
}
// 결제에는 성공하였지만 포인트 구매 내역이 존재하지 않는 경우
if (!exists) {
log.error("에러 로그 출력");
}
return new ExampleResponse(exists);
}
위의 코드 변경을 통하여 수행 과정을 도식화 하면 다음과 같습니다.
- Tx1이 유료포인트 충전 내역을 조회합니다. 아직 충전내역이 저장이 안되었기에 조회가 안되며 데이터베이스 트랜잭션을 종료하고 커넥션을 반납합니다.
- Tx2가 유료포인트 충전 내역을 조회합니다. 아직 충전내역이 저장이 안되었기에 조회가 안되며 데이터베이스 트랜잭션을 종료하고 커넥션을 반납합니다.
- Tx3이 유료포인트 충전 내역을 저장하고 데이터베이스 트랜잭션을 종료합니다.
- Tx4가 유료포인트 충전 내역을 조회합니다. 이 때 저장된 유료 포인트 충전 내역이 조회가 되며 데이터베이스 트랜잭션을 종료하고 커넥션을 반납한 뒤 더이상 재시도하지 않습니다.
📌 Reference
'트러블 슈팅' 카테고리의 다른 글
EC2 메모리 부족 빌드 실패 해결 (Gradle build daemon disappered unexpectedly) (0) | 2024.08.07 |
---|---|
@RequestParam MultiValueMap의 내부 List 타입 불일치 문제 해결 (0) | 2023.11.11 |
개발을 하며 만났던 문제들과 해결 과정, 공부한 내용 등을 기록합니다.
포스팅이 좋았다면 "좋아요❤️" 또는 "구독👍🏻" 해주세요!