조회가 몰리면 웹훅이 10초를 넘겨서 조회를 먼저 돌려보냈다

PG가 느린 동안 상품 조회가 몰리자 웹훅이 토스 규약(10초 안에 2xx)을 넘겼습니다. 조회가 초당 200건만 더해져도 웹훅의 15.6%가 10초를 넘었습니다. 진행 중인 조회가 16개에 닿으면 새 조회를 바로 503으로 돌려보내게 하자, 같은 부하에서 웹훅 p95가 152~186ms, 10초 초과가 0%가 됐습니다. 대가로 조회의 31~83%를 돌려보냈습니다.

개요

토스페이먼츠는 결제 상태가 바뀌면 웹훅을 보내고 10초 안에 2xx를 받지 못하면 다시 보냅니다. 이 쇼핑몰의 웹훅 컨트롤러는 PG를 부르지 않고 받은 내용을 저장한 뒤 바로 200을 줍니다. 구조상 빨라야 하는데 결제·조회와 톰캣 워커와 DB 커넥션 풀(20개)을 같이 씁니다.

앞선 측정에서 PG가 5초 늦을 때 웹훅의 26.1%가 10초를 넘었고 PG 동시 호출 상한(40)을 걸자 0%가 됐습니다. 상한이 PG를 기다리는 워커 수를 묶어 나머지 워커를 남겨 두었기 때문입니다. 그런데 상한이 묶는 것은 PG를 부르는 워커뿐입니다. PG가 아닌 이유로 자원이 마르면 웹훅은 여전히 같은 줄에 섭니다.

늦을 때의 대가는 요청마다 다릅니다. 웹훅이 늦으면 재전송이 오고 결제가 늦으면 미확정이 되어 복구 배치의 일거리가 됩니다. 조회는 사용자가 다시 누르면 됩니다.

재현되는가

PG 지연 5초, 상한 40(기본값), 결제 초당 50건, 웹훅 초당 10건에 상품 조회(검색 40%, 필터 목록 30%, 넓은 목록 20%, 패싯 10%)를 초당 0~1,600건 더했습니다. 세 부하 모두 서버가 느려져도 도착률이 줄지 않는 열린 루프로 45초씩 보냈습니다.

재현됐습니다. 커넥션 대기가 47까지 쌓였습니다. 웹훅은 PG를 부르지 않지만 저장하려면 DB 커넥션이 필요하고 그 커넥션을 조회와 같은 풀에서 기다립니다. 결제도 주문을 만들 때 같은 풀을 써서 함께 늦어졌습니다.

조회를 먼저 돌려보낸다

필터 하나를 보안 체인 앞에 걸었습니다. 진행 중인 조회 요청(상품 목록·검색·홈·카테고리 조회)이 16개면 새 조회를 바로 503과 Retry-After: 1로 돌려보냅니다. 16은 커넥션 20개 중 4개를 결제와 웹훅 몫으로 남긴 값이고 측정 전에 이슈에 적었습니다. 웹훅과 결제, 주문은 이 필터가 돌려보내지 않습니다.

세는 단위를 “진행 중인 조회”로 잡은 데는 이유가 있습니다. 막히는 자원은 커넥션인데 전체 요청 수로 세면 PG를 기다리는 결제(커넥션을 쥐지 않습니다) 40개가 늘 문턱을 먹습니다.

측정 전에 정한 기준(웹훅 p95 1초 이하, 10초 초과 0%)을 세 부하 모두 넘어서 기본값으로 켰습니다. 결제도 p95 15.8~27.5초에서 5.5초로 돌아왔습니다. 5초는 PG 지연 그대로입니다.

잃은 것도 적어 둡니다. 초당 200건에서 조회를 31% 돌려보냈고 처리한 조회 수도 45초에 7,613건에서 6,179건으로 줄었습니다. 셰딩이 없을 때 처리한 조회는 p95 12초짜리라 사용자에게는 실패에 가까웠지만 건수만 보면 셰딩 쪽이 적습니다.

정리

• 자원이 마르면 늦을 때 대가가 가장 싼 조회를 먼저 돌려보냅니다
• 문턱 16은 하나만 쟀습니다. 커넥션 풀 크기를 바꾸면 문턱도 같이 바꿔야 합니다
• 조회 용량을 재는 벤치마크는 이 필터를 끄고 잽니다. 켠 채로 재면 용량 대신 문턱이 나옵니다
• 실제 토스 재전송을 받아 본 것은 아닙니다. 잰 것은 우리 응답 시간이고, 재전송은 그 결과로 일어날 수 있는 일입니다