오늘도 경험 한 스푼
Published on

PG가 답하지 않을 때, 카드 취소 알림은 10초 안에 처리되나

Authors
  • avatar
    Name
    김민석
    Twitter

취소 알림을 놓치면 카드사에서는 취소인데 결제 기록은 완료로 남는다

카드 결제를 취소하면 PG가 서버로 취소 알림을 보낸다. 알림을 처리하지 못하면 돈은 고객에게 돌아갔는데 서버 기록은 결제 완료로 남는다. 수강권도 회수되지 않고 정산도 그대로다. 승인은 서버가 요청해서 결과를 바로 받지만, 취소는 남이 알려줘야 아는 일이라 알림 한 건이 곧 정합성이다.

알림 하나가 어긋나면 어떻게 되는지는 두 번 겪었다. 한 번은 결제창을 열어 둔 채 방치해 만료된 알림까지 결제를 찾으러 갔다. 승인된 적이 없는 결제라 찾을 수 없어 404로 답했는데, PG는 그것을 실패로 보고 3일 19시간 동안 같은 알림을 다시 보냈다. 전송 실패로 끝난 알림이 3건 남았다. 취소 계열이 아닌 알림은 결제를 찾기 전에 200으로 끊어 고쳤다. 다른 한 번은 반대 방향이다. 승인 결과를 저장하기 전에 취소 알림이 먼저 도착하면 결제를 못 찾는데, 여기서는 일부러 404로 답해 다음 전달에서 처리한다. 같은 404라도 하나는 버그고 하나는 설계다.

그래서 알림 내용을 그대로 믿지 않는다. 취소 알림이 오면 PG에 결제 상태를 다시 물어보고, 조회 결과가 취소일 때만 주문을 CANCELED로 바꾸고 츄르를 회수하고 환불 기록과 고객 알림을 남긴다. 위조된 알림이 와도 조회 결과가 진실이라 거짓 취소가 생기지 않는다.

문제는 조회가 외부 호출이라는 것이다. 토스는 웹훅을 보낸 뒤 10초 안에 200 응답을 받지 못하면 실패로 보고 같은 알림을 다시 보낸다. 최대 7회, 처음 보낸 때로부터 3일 19시간까지다. 재전송 간격은 1분, 4분, 16분으로 4배씩 벌어진다. 조회가 늦으면 응답도 늦고, 응답이 10초를 넘으면 처리에 성공했든 아니든 토스는 실패로 센다.

두 가지를 숫자로 확인했다. PG가 답하지 않거나 느릴 때 알림 응답이 얼마나 걸리고 취소가 언제 반영되는지, 그리고 재전송이 한꺼번에 몰릴 때 서버가 그것을 받아낼 수 있는지다.

츄르 충전 결제 100건을 승인해 두고 PG에서 전부 취소한 다음, 그 취소 알림 100건1분에 걸쳐 서버로 보냈다. PG 조회는 세 가지 상태로 나눠 걸었다. 아예 답하지 않는 상태, 8초 뒤에 답하는 상태, 정상인 300ms다. 조회 타임아웃을 예전 값인 읽기 15초로 되돌려 먼저 재고, 현재 코드로 돌아와 같은 조건으로 다시 쟀다.

image.png
  • 취소 알림 한 건이 위에서 아래로 흐른다. 회원이 카드사에서 결제를 취소하면 카드사가 결제 서버로 취소 알림을 보내고, 결제 서버는 알림을 그대로 믿지 않고 카드사에 결제 상태를 다시 물어본다.
  • 카드사가 답하지 않으면 예전에는 15초를 기다린 뒤 실패로 답했고 지금은 3초에 끊는다. 어느 쪽이든 취소는 반영되지 않고, 1분 뒤 재전송에서 답이 와야 주문 취소와 환불 기록이 남는다.

조회가 15초를 기다리면 알림 응답도 15초가 된다

PG가 답하지 않는 상태에서 취소 알림 100건을 보냈다. 100건 전부 502로 돌아왔고 응답 시간은 가장 빠른 건이 15.02초, 가장 느린 건이 15.24초였다. 10초 예산을 넘긴 건이 100%다.

항목결과
HTTP 응답502 100건, 200 0건
응답 시간 최소 / 중앙 / p95 / 최대15,022 / 15,040 / 15,221 / 15,238 ms
10초 초과100건, 100%
취소 반영 / 미반영0 / 100
동시에 잡힌 요청 스레드25개
DB 커넥션 사용0
원장 항등식100 = 0 + 100

조회 타임아웃이 읽기 15초라 요청 하나가 15초를 기다린다. 초당 1.67건이 들어오니 15초 동안 25건이 겹쳐 스레드 25개가 동시에 묶였다. DB 커넥션은 0인데, 조회를 트랜잭션과 락 밖에서 부르기 때문이다. 외부 호출이 길어져도 DB 락을 잡고 있지는 않다.

원장 항등식은 PG에서 취소한 결제 = 취소로 바뀐 주문 + 아직 반영 안 된 주문이다. 식이 안 맞으면 돈이 어디로 샌 것이다. 무응답 회차는 100 = 0 + 100이고, 아홉 회차 전부 맞았다. 결제 900건을 승인해 전부 취소하고 나서 테스터 잔액 합계도 시작 값으로 돌아왔다.

502로 답한 것 자체는 맞다. 조회에 실패했으면 취소를 반영하면 안 되고, 2xx가 아니면 토스가 다시 보내주니 재전송이 곧 재시도가 된다. 문제는 시간이다. 토스는 10초에 이미 실패로 판정하고 재전송 대기열에 넣는데, 서버는 그 뒤로도 5초를 더 기다렸다가 아무도 읽지 않을 응답을 보낸다. 기다린 15초 전부가 버린 시간이다.

버려지는 것은 서버 쪽만이 아니다. 조회를 15초에 끊어도 PG 쪽 요청은 살아 있었다. 무응답을 푼 순간까지 4분 가까이 잡혀 있다가 그때 답이 돌아왔는데, 서버는 이미 502를 보낸 뒤라 그 답을 쓸 데가 없다.

image.png
  • 왼쪽 그래프의 응답 시간 선이 15초에 붙어 있고 빨간 10초 기준선 위로 올라가 있다.
  • 오른쪽 그래프에는 502 선 하나뿐이고 200은 한 건도 없다.

image.png
  • JVM 스레드가 36개에서 53개로 늘어 회차가 끝날 때까지 그대로다.

8초 느린 PG는 15초 타임아웃이 그 자리에서 견뎠다

조회를 8초 뒤에 답하도록 바꾸고 같은 목록을 다시 보냈다. 이번엔 100건 전부 200이고 응답은 8.07초에서 8.22초 사이다. 10초 예산 안이라 초과는 0이고, 취소도 그 자리에서 100건 전부 반영됐다.

항목결과
HTTP 응답200 100건
응답 시간 중앙 / 최대8,106 / 8,224 ms
10초 초과0건
취소 반영100 / 100
환불 기록 / 고객 알림 / 츄르 회수100 / 100 / 5,000

조회가 8초 걸려도 타임아웃이 15초면 기다려서 답을 받는다. 받은 뒤 주문 취소와 츄르 회수, 환불 기록, 고객 알림까지 도는 데 70ms에서 220ms가 더 걸렸다. 여유가 1.8초 남았다.

image.png
  • 왼쪽 그래프의 응답 시간 선이 8초에 있고 빨간 10초 선 아래다.
  • 오른쪽 그래프는 200 선만 올라오고 502는 바닥에 붙어 있다.

같은 알림을 두 번 받아도 환불은 한 번만 된다

이미 취소가 반영된 목록 100건을 그대로 한 번 더 보냈다.

항목결과
HTTP 응답200 100건
응답 시간 중앙 / p95 / 최대17 / 25 / 65 ms
PG 조회0회
환불 기록 / 고객 알림 / 츄르 회수100 / 100 / 5,000, 중복 0

결제가 이미 CANCELED면 조회 전에 200으로 끝내기 때문이다. 취소를 반영하는 쪽도 결제 행에 락을 잡고 상태를 한 번 더 확인해 이미 취소된 건이면 그대로 돌아가므로, 같은 알림 두 건이 동시에 들어와도 환불 기록은 한 줄이다. 앞단 게이트가 없애는 것은 토스가 최대 7회 재전송하는 동안 매번 따라붙는 PG 조회와 락이다.

조회 타임아웃 하나가 알림 응답 시간을 결정한다

응답이 15초가 된 이유는 조회 클라이언트 한 곳이다.

  1. 취소 알림이 오면 결제를 찾고, 이미 취소된 건이면 조회 없이 200으로 끝낸다.
  2. 아직 DONE이면 PG에 결제 상태를 조회한다. 조회가 승인 경로와 같은 클라이언트를 쓰고 있었고, 그 읽기 타임아웃이 15초였다.
  3. 조회가 성공하면 취소를 반영하고 200, 실패하면 예외가 나면서 502다.

승인과 웹훅이 같은 조회 API를 부른다는 이유로 같은 클라이언트를 썼다. 승인은 사람이 결제창 앞에서 기다리는 일이라 15초가 맞지만, 웹훅은 토스가 10초에 끊는다.

200을 먼저 주고 뒤에서 처리하는 방법은 고르지 않았다

  • 조회 타임아웃을 그대로 두고 응답만 빨리 주는 방법은 취소를 반영하지 않은 채 200을 주는 것이라, 토스가 재전송을 멈춰 그 취소가 다시 오지 않아서 막힌다.
  • 알림을 받자마자 200을 주고 처리는 뒤에서 하는 방법은 조회가 실패한 건을 서버가 직접 다시 시도해야 해서 막힌다. 토스가 이미 7회, 3일 19시간 동안 재전송해 주는데 같은 큐를 하나 더 만드는 셈이고, 큐를 안 만들면 조회 실패 건이 그대로 유실된다.
  • 조회에만 짧은 타임아웃을 따로 두고, 실패하면 5xx로 답해 토스 재전송을 재시도 큐로 쓰는 방법을 골랐다. 반영은 동기로 확정하되 기다리는 시간만 예산 안으로 자른다.

조회에만 3초 타임아웃을 따로 뒀다

재확정 조회를 연결 2초, 읽기 3초짜리 전용 클라이언트로 분리했다. 승인과 취소, 복구 배치는 기존 15초 클라이언트를 그대로 쓴다.

3초로 잡은 근거는 정상 조회에 걸리는 시간이다. 조회를 300ms로 두고 잰 회차에서 알림 응답이 p95 478ms, 가장 느린 건이 597ms였다. 3초는 그 조회 시간의 열 배고, 조회 3초에 취소 반영과 응답까지 더해도 3.7초10초 예산의 절반 아래다. 여유를 8초까지 주면 8초 느린 PG를 그 자리에서 반영할 수 있지만, 무응답일 때 응답이 8초가 되어 예산 여유가 사라진다.

무응답에서 응답이 15초에서 3초로 줄고 예산 초과가 사라졌다

같은 조건으로 다시 쟀다. 100건 전부 502인 것은 같지만 응답이 3.02초에서 3.11초다.

항목고치기 전 코드고친 코드
응답 시간 중앙15,040 ms3,027 ms
응답 시간 p9515,221 ms3,059 ms
응답 시간 최대15,238 ms3,110 ms
10초 초과100건, 100%0건, 0%
동시에 잡힌 요청 스레드25개5개

응답이 5배 빨라졌고 10초를 넘긴 건이 하나도 없다. 스레드도 25개에서 5개로 줄었다. 기다리는 시간이 5분의 1이 되니 겹치는 요청도 5분의 1이다.

image.png
  • 왼쪽 그래프의 응답 시간 선이 주황 3초 선에 붙어 있고 빨간 10초 선과 멀다.
  • 오른쪽 그래프에 502 선 하나뿐인 것은 앞과 같다.

8초 느린 PG는 그 자리에서 반영하지 못하는 것이 대가다

3초로 자르면 잃는 것도 있다. 조회를 8초 뒤에 답하는 상태에서 같은 목록을 보내자 100건 전부 502가 되고 취소는 한 건도 반영되지 않았다.

항목고치기 전 코드고친 코드
HTTP 응답200 100건502 100건
응답 시간 중앙8,106 ms3,026 ms
그 자리에서 취소 반영100 / 1000 / 100

살아 있지만 3초보다 느린 PG 앞에서는 답을 기다리지 않고 물러난다. 대신 토스가 1분 뒤 같은 알림을 다시 보내고, 그때 조회가 3초 안에 끝나면 반영된다. 재전송 간격이 1분, 4분, 16분으로 벌어지므로 첫 재전송이 성공해야 1분이고 아니면 더 밀린다. 반영이 최소 1분 늦어지는 것이 3초의 대가다.

PG가 살아나면 재전송 한 번으로 100건이 전부 반영된다

502를 받은 그 목록을 PG가 정상으로 돌아온 뒤 다시 보냈다.

항목결과
HTTP 응답200 100건
응답 시간 중앙 / p95 / 최대76 / 146 / 377 ms
취소 반영100 / 100
환불 기록 / 고객 알림 / 츄르 회수100 / 100 / 5,000
한 번 더 보냈을 때200 100건, 중앙 16 ms, 환불 기록 100 그대로, 중복 0

취소가 100건 전부 반영됐고 환불 기록과 고객 알림, 츄르 회수까지 앞선 회차와 같은 모양으로 남았다. 물러난 취소가 재전송으로 반영되고, 반영된 취소는 몇 번을 다시 받아도 한 번만 처리된다.

image.png
  • 왼쪽 그래프에서 앞쪽 3초 선이 502로 물러난 회차, 뒤쪽 바닥에 붙은 두 선이 재전송으로 반영한 회차와 중복 확인 회차다.
  • 오른쪽 그래프에서 502 봉우리 하나 뒤에 200 봉우리가 둘 이어진다.

정상 PG에서는 0.48초에 끝난다

조회를 300ms로 두고 같은 부하를 넣었다.

항목결과
HTTP 응답200 100건, 429 0건
응답 시간 최소 / 중앙 / p95 / 최대358 / 394 / 478 / 597 ms
10초 초과0건
취소 반영100 / 100
PG 조회 시간300 ms, 가장 느린 건 314 ms

조회 300ms에 취소 반영과 응답이 60ms에서 300ms다. 평소에는 예산의 20분의 1도 쓰지 않는다.

image.png
  • 왼쪽 그래프의 응답 시간 선이 0.4초 근처 바닥에 있다.
  • 오른쪽 그래프는 200 선만 올라오고 502는 바닥에 붙어 있다.

재전송이 몰리자 200건 중 51건이 429로 막혔다

여기까지는 알림이 1분100건씩 고르게 들어오는 조건이다. 실제 재전송은 그렇게 오지 않는다. PG가 1분 동안 답하지 않으면 그 1분치 알림이 전부 실패하고, 1분 뒤에 한꺼번에 다시 온다.

취소 200건30초에 몰아 보냈다. 200149건, 42951건이다.

항목결과
HTTP 응답200 149건, 429 51건
200 응답 중앙 / 최대366 / 445 ms
429 응답 중앙9 ms
폭주 직후 반영 / 미반영149 / 51
61초 뒤 재전송200 200건, 429 0건
최종 반영 / 중복200 / 200, 중복 0
원장 항등식폭주 직후 200 = 149 + 51, 재전송 뒤 200 = 200 + 0

웹훅 경로에는 IP당 분당 100건 한도가 걸려 있다. 버킷 100에 밀리초 단위로 분당 100씩 채워지는 구조라 30초 동안 쓸 수 있는 건 100에 보충 50을 더한 150건이고, 실측이 149건 통과에 51건 거절이다. 429 응답은 9ms에 돌아온다. 한도 필터가 컨트롤러 앞에서 끊기 때문이다.

거절된 51건이 사라지지는 않는다. 토스는 429도 실패로 보고 다시 보내므로, 61초 뒤 재전송에서 전부 반영됐다. 반영 시각을 분 단위로 보면 폭주 때 149건, 재전송에서 7건44건으로 나뉜다. 유실은 없지만 51건의 반영이 1분에서 3분 늦어졌다.

image.png
  • 오른쪽 그래프에서 200이 초당 5.5건까지 올랐다 꺾이고, 꺾이는 자리에서 파란 429 선이 올라온다.
  • 뒤쪽 낮은 봉우리가 61초 뒤 재전송이다. 왼쪽 응답 시간은 두 번 다 바닥에 붙어 있다.

웹훅 결과를 세는 지표가 없어 로그를 세고 있었다

또 하나 걸린 것은 관측이다. 취소가 반영됐는지, 중복이라 건너뛰었는지, 조회가 실패했는지를 대시보드에서 볼 방법이 없어 서버 로그를 grep으로 세고 있었다. 429는 더 나쁘다. 한도 필터가 컨트롤러 앞에서 끊는 탓에 HTTP 지표에 경로 이름이 UNKNOWN으로 남아, 51건이 지표에는 있는데 그것이 웹훅 거절인지 알 수 없었다.

그래서 웹훅 처리 결과를 12종으로 나눠 세는 카운터를 넣었다. 전액 반영, 부분 반영, 중복 건너뜀, 결제 없음, 조회 실패, 상태 불일치, 반영 실패, DB 실패, 그리고 처리하지 않는 이벤트와 상태, 서명 거부, 본문 파싱 실패다. 조회 시간과 전체 처리 시간은 따로 타이머로 재고, 전체 처리 타이머에는 10초를 넘겼는지를 표시로 붙였다. 카운터와 타이머는 서버가 뜰 때 0으로 등록해 첫 건부터 그래프에 잡히게 했다. 한도 거절도 규칙 이름을 붙인 카운터로 따로 세어, 429가 웹훅에서 나온 것인지 대시보드에서 바로 갈린다.

여기서 하나를 놓치고 있었다는 것도 드러났다. 조회는 성공했는데 그 뒤 취소 반영이 실패하는 경로는 어느 카운터에도 세어지지 않았다. PG에서 환불은 이미 끝났는데 서버 기록만 결제 완료로 남는, 가장 손해가 큰 경우가 지표에도 경보에도 없었다. 반영 실패와 DB 실패를 따로 세고 첫 건부터 경보가 뜨도록 했다.

경보는 넷이다. 10초를 넘긴 건이 생기면, 취소 반영이 실패하면, 조회 실패가 5분2건 이상 쌓인 채로 1분이 이어지면, 한도 거절이 나오면 각각 발화한다.

한도를 300으로 올리자 200건이 모두 통과했다

한도는 IP당 분당 100건에서 300건으로 올렸다. 토스 재전송은 실패분이 1분 뒤 한꺼번에 오므로 버스트 상한은 1분 안에 실패할 수 있는 알림 수에 그 사이 새로 오는 알림을 더한 값이어야 한다. 실측 폭주가 200건이라 그 1.5배로 잡았다. 버킷이 채워지는 속도는 초당 1.67건에서 5건이 됐다. 그보다 빠르게 계속 들어오면 여전히 막히므로 봇 폭주 방어는 남는다.

같은 조건으로 다시 쟀다.

항목한도 100건한도 300건
200 / 429149 / 51200 / 0
200 응답 중앙 / p95366 / 405 ms368 / 442 ms
폭주 직후 반영149200
반영까지 지연51건1~3분0
동시에 잡힌 요청 스레드3개5개

200건이 모두 한 번에 통과했고 429는 하나도 없다. 61초 뒤 재전송은 200건 전부 중복 건너뜀으로 끝나 응답이 중앙 17ms, 가장 느린 건이 38ms다. 조회를 탄 건이 하나도 없다.

대가는 동시 점유다. 51건이 더 통과하면서 겹친 요청이 3개에서 5개로 늘고, 가장 느린 응답이 445ms에서 658ms가 됐다. 10초 예산에는 여전히 한참 못 미친다.

image.png
  • 왼쪽 위가 응답 시간, 오른쪽 위가 HTTP 상태다. 오른쪽 위에는 200 선 하나뿐이고 429는 한 건도 없어 선이 그려지지 않았다.
  • 아래 두 패널이 새로 넣은 지표다. 왼쪽에서 전액 반영이 200 위까지 솟았다 떨어지고 뒤이어 중복 건너뜀 선이 올라오며, 오른쪽 전체 처리와 조회 시간은 0.5초0.35초로 주황 3초 선 아래다.

부하를 100건과 200건으로 잡은 이유

분당 100건은 한도 안이라 429가 섞이지 않는다. 조회 타임아웃이 응답 시간에 미치는 영향만 떼어 보려고 그 크기를 골랐다.

폭주 회차는 처음에 분당 200건으로 잡았다가 바꿨다. 한도가 밀리초 단위로 계속 채워지는 구조라 200건1분에 고르게 보내면 버킷 100에 보충 100이 더해져 전부 통과한다. 한도를 실제로 때리려면 채워지는 속도보다 빨라야 해서 200건30초에 보냈다.

남은 것

  • 부분 취소 경로 측정. 조회 결과가 부분 취소일 때 부분 반영으로 가는 분기는 이번에 재지 못했다. 카운터는 0으로 등록만 돼 있다.
  • 여러 대로 늘렸을 때의 한도. 지금 한도는 서버 한 대의 메모리에 있어 대수만큼 실효 한도가 커진다.
  • 조회 실패가 3일 19시간 동안 이어질 때의 처리. 토스 재전송이 소진되면 그 취소는 사라지므로 대사로 잡아야 한다.
  • 실서비스 취소 알림의 분당 건수와 PG 조회 응답 시간. 부하 100건과 읽기 3초는 한도와 걸어 둔 조회 300ms에서 계산한 값이다.

정리

문제고친 것고치기 전 → 고친 뒤
PG가 답하지 않으면 알림 응답이 15초가 되어 토스 예산을 넘긴다재확정 조회에만 연결 2초, 읽기 3초 클라이언트를 분리응답 p95 15.2초3.06초, 10초 초과 100%0%
조회를 기다리는 동안 요청 스레드가 묶인다같은 분리동시 점유 25개5개
재전송이 몰리면 한도에 걸려 반영이 밀린다IP당 분당 100건300건, 채워지는 속도는 초당 1.67건5건이라 봇 폭주 방어는 유지429 51건0, 반영 지연 1~3분0
웹훅 처리 결과는 로그로만 세고, 429 거절은 경로 이름이 UNKNOWN이라 웹훅 것인지 갈리지 않는다결과별 카운터 12종과 조회·처리 타이머, 규칙 이름을 붙인 거절 카운터, 경보 4개로그 grep → 대시보드 카운터
취소 반영이 실패하면 아무 데도 안 남는다반영 실패와 DB 실패를 따로 세고 첫 건부터 경보지표 없음 → 카운터와 경보

취소 알림은 돈이 이미 움직인 뒤에 오는 소식이라 늦거나 빠지면 그대로 정합성 문제가 된다. 조회를 3초에 끊는 선택은 8초 느린 PG 앞에서 반영을 최소 1분 미루는 대신, PG가 답하지 않을 때도 느릴 때도 응답을 3초대에서 끝냈다. 답을 못 주는 건은 토스가 7회 다시 보내주므로 재시도 큐를 따로 만들 필요가 없었다.