PG가 5초 늦거나 답이 없을 때, 결제 승인은 어떻게 되나

결제 사고는 대부분 PG에서 난다

결제 사고 사례를 찾아보면 대부분이 같은 유형이다. 결제 서버 자체가 아니라 PG나 카드사가 느려지거나 멈추고, 그 여파로 결제 실패율이 치솟는다. 그때 결제 서버가 같이 멈추면 결제 한 건의 문제가 서비스 전체의 문제가 된다.

그래서 PG가 5초씩 늦을 때와 아예 답을 안 할 때 승인 API가 어떻게 되는지 숫자로 확인했다.

PG 응답을 늦추거나 끊고, 고치기 전에 먼저 재고 고친 다음 같은 부하로 다시 잰다.

PG가 5초 늦으면 승인이 30초를 기다리다 실패한다

원인은 PG가 아니라 DB 커넥션이었다.

DB 커넥션 풀 10개, 톰캣 스레드 200인 서버에 PG 응답을 5초 늦추고 동시 50건, 90초 뒤 동시 100건의 승인을 넣었다. 총 150건이다.

트랜잭션 안에서 PG를 부르던 예전 구조는 150건 중 20건만 살아남았다

지금 코드는 토스 호출을 트랜잭션 밖으로 뺀 상태다. 승인 전체를 트랜잭션 하나로 감싸던 예전 구조로 먼저 돌렸다.

150건 중 20건만 PG에 닿았다. 나머지 130건은 PG를 부르기도 전에 죽었다. 타임아웃 로그 스택에 처음 찍힌 결제 코드가 전부 트랜잭션 시작이다. 예전 구조는 트랜잭션을 열면서 DB 커넥션을 먼저 잡고, 그 커넥션을 반납하지 않은 채 PG 응답 5초를 기다린다. 커넥션이 10개니 50명 중 10명만 받고, 나머지 40명은 커넥션을 기다리는 한도인 30초를 다 쓰고 실패한다.

• 커넥션 풀 패널에서 대기(pending)가 50에서 100으로 선다. 최대는 10에 고정이다.
• 커넥션 대기 타임아웃이 분당 120건 가까이 쌓인다. 승인 성공은 초당 0.4건이 전부다.

• HTTP 500이 초당 3건씩 나가는 동안 CPU는 20%를 넘지 않는다. 서버가 바쁜 것이 아니라 커넥션을 기다리고 있었다.
• 스레드가 32에서 140으로 늘어난 것은 요청 스레드가 대기열에 묶여 있기 때문이다.

트랜잭션을 분리한 현재 코드도 150건 중 27건만 살아남았다

현재 코드로 돌아와 같은 부하를 넣었다. 예상은 "다 살아남는다"였다.

트랜잭션 분리로 150건 전부 PG에 닿았다. 그런데 승인은 82%가 실패했고 123건은 승인 뒤 보상 취소로 돌아갔다. 보상 취소는 PG에서 승인까지 끝난 돈을 서버가 되돌리는 취소다. 고객에게는 카드 승인 문자와 취소 문자가 연달아 온다.

• 대기(pending)가 50, 50, 100으로 세 번 선다. 50건 단계에서 두 번, 100건 단계에서 한 번이다.
• 승인 결과 패널의 라벨이 db_failed다. PG는 승인했고 DB 저장에서 죽었다는 뜻이다. 실패 지점이 PG에서 DB로 옮겨 왔다.

• 스레드 140, CPU 40%. 예전 구조보다 CPU를 더 쓴 것은 150건 전부 PG까지 갔다가 돌아왔기 때문이다.

커밋 직후 알림 처리가 두 번째 커넥션을 요구한다

결제가 저장되면 결제 완료 알림과 영수증 알림을 보내는 리스너가 있다. 리스너는 AFTER_COMMIT으로 커밋 직후 실행되고, 알림 저장은 REQUIRES_NEW라 DB 커넥션을 1개 더 잡는다.

타임아웃 로그 606줄의 스택에 어느 결제 코드가 몇 번 찍혔는지 세어 봤다. 한 스택에 여러 곳이 나오기도 해서 합은 606이 되지 않는다.

알림 리스너가 33번 찍힌 것이 단서였다.

1. PG가 5초 뒤 50건에 동시에 답한다. 50건이 동시에 결제 저장에 들어온다.
2. 커넥션 10개를 받은 10건이 저장을 끝내고 커밋한다.
3. 커밋 직후 알림 처리가 시작되고, 알림을 저장하려고 커넥션을 1개 더 요청한다. 그런데 첫 커넥션은 아직 반납 전이다.
4. 10건 모두 첫 커넥션을 반납하지 않은 채 두 번째 커넥션을 기다린다. 풀에 남은 커넥션은 0개다.
5. 나머지 40건은 저장에 들어가지도 못하고 30초를 기다리다 죽는다.
6. 죽은 40건은 보상 취소를 부른다. 취소 뒤 주문을 FAILED로 바꾸는 것마저 커넥션을 못 받아, 주문이 결제 진행중 PAYMENT_PENDING으로 남는다.

처음에는 가설을 버렸다. 로그를 에러마다 40줄씩 잘라 "알림 처리" 줄을 찾았는데 0건이었다. 실제 스택은 40줄보다 길어서 잘린 부분에 있었다. 60줄로 다시 자르고, 알림 실패 로그 40건의 원인이 전부 Could not open JPA EntityManager for transaction, 트랜잭션을 열 커넥션을 못 받은 것임을 확인한 뒤에 가설이 섰다. 측정 도구가 아니라 내가 로그를 자른 폭이 틀렸던 것이다.

풀 확대와 트랜잭션 안 알림 저장은 고르지 않았다

• 커넥션 풀을 10 → 20으로 늘리는 방법은 요청 하나가 커넥션을 2개 쓰는 구조 그대로라, 동시 커밋이 10건을 넘으면 같은 방식으로 다시 막힌다. 무너지는 숫자만 옮긴다.
• 알림 저장을 결제 트랜잭션 안에서 같이 하는 방법은 커넥션은 안 늘지만, 알림 저장이 실패하면 결제 저장까지 되돌아간다. 알림 중복을 잡는 처리가 트랜잭션 전체를 취소 대상으로 표시하기 때문이다. 실제 로그에 UnexpectedRollbackException 이력이 있었다.
• 알림 처리를 다른 스레드로 넘기는 방법을 골랐다. 결제를 처리한 스레드는 커밋 직후 커넥션을 반납하고, 알림은 전용 스레드 최대 4개가 나중에 자기 커넥션으로 처리한다. 알림이 실패해도 결제는 그대로다.

알림 처리를 다른 스레드로 넘기자 150건 전부 성공했다

원장 항등식은 PG 승인 건수 = PAID 주문 + 취소 + 사고 기록. 사고 기록은 취소까지 실패해 자동으로 못 닫은 건을 사람이 보라고 따로 남긴 것이다. 식이 안 맞으면 PG는 승인했는데 서버에는 아무 흔적도 없는 건이 있다는 뜻이다. 세 번 모두 맞았다.

동시 100건이 6초 안에 전부 끝났다. PG 지연 5초를 빼면 서버가 쓴 시간은 1초 남짓이다. 처리량으로 쓰면 약 16 TPS인데, PG 지연에 묶인 값이라 서버 용량은 아니다.

복구 배치가 잔류 주문을 정리하지 못하던 문제도 같이 고쳤다

트랜잭션을 분리한 현재 코드로 돌렸을 때 PAYMENT_PENDING으로 남은 40건은 10분마다 도는 복구 배치가 정리해야 한다. 그런데 배치는 PG 상태가 CANCELED면 아무것도 바꾸지 않고 다음 회차로 넘기고 있었다. 보상 취소된 주문은 PG 상태가 항상 CANCELED라 배치가 몇 번을 돌아도 그대로 남는다. 배치에 CANCELED → FAILED 분기를 추가했다.

PG가 아예 답을 안 할 때 요청마다 30초씩 멈춘다

PG가 답을 안 하는 동안 건마다 사고 기록과 운영자 알람이 쌓였다. 서킷브레이커를 두어 PG가 죽었다고 판단되면 PG를 부르지 않고 바로 실패를 돌려준다.

PG를 무응답 상태로 두고 동시 50건을 넣었다.

승인 15초에 결과 조회 15초가 더 붙는다

PG가 답을 안 하면 승인 요청은 15초를 기다리고 포기한다. 그런데 승인이 실제로 됐는지 모르는 상태라 그 주문이 승인됐는지 PG에 한 번 더 물어보고, 그것도 15초를 기다린다. 그래서 요청 하나가 30초 동안 서버 스레드를 잡는다. 두 번째 조회까지 실패하면 사고 기록을 남기고 운영자에게 알람을 보내므로, 건마다 사고와 메일이 쌓인다. 서버가 동시에 처리할 수 있는 요청이 200개니, 동시 200건이면 서버 전체가 30초씩 멈춘다.

타임아웃 단축과 재시도는 고르지 않았다

• 기다리는 시간을 줄이는 방법은 정상 승인도 가끔 느리다는 점에서 막힌다. 짧게 자르면 성공할 결제까지 실패로 만든다.
• 재시도는 죽은 PG에 부하만 더한다.
• 서킷브레이커를 골랐다. 실패가 쌓이면 PG를 부르지 않고 바로 실패를 돌려준다. 승인 호출에만 적용한다. 취소와 조회는 돈을 되돌리는 복구 경로라 차단하지 않는다.

최근 20건 중 실패가 50%를 넘으면 열리고, 판단은 최소 10건이 모인 뒤부터다. 열린 뒤 30초가 지나면 3건만 시험으로 보내고, 다 성공하면 닫힌다. 카드 한도 초과 같은 4xx 거절은 PG가 정상이라는 뜻이라 실패로 세지 않는다. 열려 있는 동안은 승인 자체를 안 하니 돈이 움직이지 않고, 조회도 취소도 사고 기록도 없다.

서킷브레이커가 열린 뒤에는 0.5초 만에 실패를 돌려준다

첫 20건은 그대로 30초를 겪는다. 차단기는 실패가 쌓인 뒤에 열리기 때문이다. PG가 20분 죽었다면 서킷브레이커가 없을 때는 20분 내내 요청마다 30초와 사고와 알람이지만, 있으면 첫 30초뿐이다.

• 커넥션 대기 타임아웃 0건. 무응답 테스트는 커넥션이 아니라 PG 대기에서 막히므로 풀 그래프에는 아무것도 서지 않는다.
• 16:51에 대기(pending)가 29로 한 번 튄다. 차단기가 열린 순간 50건이 동시에 즉시 실패 처리되며 주문 상태를 바꾸는 DB 쓰기가 몰린 것이다.

• HTTP 503이 새로 보인다. 차단기가 열려 PG 호출 없이 즉시 실패시킨 응답이다. 16:48~16:49의 빈 구간은 서킷브레이커 배포로 프로세스를 재기동한 시간이다.

실패율 경보가 PG 장애를 2분 3초 만에 알렸다

경보가 없으면 PG 장애를 누군가 결제가 안 된다고 말해 줄 때까지 모른다. 최근 5분 동안 승인 실패율이 20%를 넘고 실패가 5건 이상이면, 그 상태가 1분 이어질 때 경보를 보낸다.

서킷브레이커를 둔 뒤 무응답을 다시 넣은 회차에서 쟀다. 07:50에 주입했고 경보가 07:51에 pending, **07:52에 firing**으로 바뀌었다가 07:53에 풀렸다. 장애 주입 기준 2분 3초, 첫 실패 기준 1분 27초 만에 감지했다.

차단기가 바로 거절한 50건은 pg_unavailable이라는 새 종류의 실패로 집계되는데, 그 종류가 그 순간 처음 생겨 Prometheus가 0에서 50으로 늘어난 것을 계산하지 못했다. 직전 값이 없으면 얼마나 늘었는지 셀 수 없기 때문이다. 경보는 그 앞의 일반 실패 20건만으로 울렸다. 서버가 켜질 때 실패 종류마다 0을 미리 등록하면 해결된다.

동시 50건과 100건으로 잡은 이유

• 먼저 막힐 자리로 본 커넥션 풀 10개의 5배와 10배. 풀보다 조금 큰 부하는 가끔 느려지는 것으로 끝나 원인이 갈리지 않는데, 5배면 풀이 고갈될 때 확실히 무너진다. 실제로 82%가 실패했다.
• 실서비스 순간 피크보다 몇 배 센 조건이다. 승인 한 경로에 동시 50 ~ 100건은 실서비스 전체 API 합보다 크다.
• 테스트 환경 한도. 승인 API는 회원당 분당 10건 제한이라 테스트 계정 30개로 한 번에 넣을 수 있는 승인이 최대 300건이고, 그 안에서 50 → 100 두 단계로 잡았다.

남은 것

• PG 정상 응답 0.3초 조건에서 50 → 100 → 200 → 300으로 올리는 용량 측정. p95가 꺾이는 지점과 TPS
• 승인 결과 지표를 CloudWatch로 보내는 운영 경보
• 실패 종류별 카운터를 기동 시 0으로 등록하는 사전 등록
• 새벽 구독 갱신 배치. 순차 처리라 건수에 정비례하고, 자정을 넘기면 다음 날 배치와 겹쳐 이중 결제가 나는지

정리

트랜잭션 분리는 PG 도달까지만 보장했다. 그 뒤에 숨어 있던 두 번째 커넥션 요구는 부하를 실제로 걸기 전에는 보이지 않았다.