자산 화면 응답이 느리다는 이야기를 듣고 AssetController 를 열었더니 반복문 안에서 balanceRepository.findByMemberAndCoin() 을 부르는 자리가 눈에 띄었다. 며칠 걸려 그것을 한 번의 IN 조회로 합쳤는데 체감이 그대로였다.
Table of contents
Open Table of contents
증상 — 추측으로 고친 자리
코드를 읽고 개선할 곳이 보이면 그것이 원인이라고 생각하기 쉽다. 그 자리가 실제로 느린지는 확인하지 않은 채였다.
고친 결과가 안 보이는데 왜 안 보이는지도 알 수 없었다. 추측으로 고치면 안 나아졌을 때 다음에 무엇을 볼지도 안 정해진다.
측정 — 구간별로 찍은 시간
요청이 들어와서 나갈 때까지 Spring 의 StopWatch 로 각 구간에 시각을 찍었다. 인증과 잔고 조회와 외부 호출과 응답 생성이 각각 얼마를 쓰는지가 나왔다.
전체의 대부분이 외부 호출에서 쓰이고 있었고 내가 고친 잔고 조회는 십 분의 일 남짓이었다. 그것을 절반으로 줄여도 전체는 몇 퍼센트만 나아지므로 체감이 안 바뀐 것이 당연했다.
조치 — 코드보다 큰 호출 구조
외부 호출을 들여다보니 한 요청에 시세 API 와 원화 환율과 KYC 상태를 순서대로 세 번 부르고 있었다. 서로 의존하지 않는 것을 확인하고 CompletableFuture.allOf() 로 동시에 부르게 하니 그 구간이 삼분의 일로 줄었다.
코인 목록에서 항목마다 같은 coin_master 설정을 반복 조회하는 것도 있어서 한 번 받아 재사용하게 했다. 코드 안을 다듬는 것보다 호출 구조를 바꾸는 쪽이 훨씬 크게 움직였다.
판단 기준 — 평균이 감추는 소수
처음에는 평균 응답 시간을 봤고 나쁘지 않은 값이었다. 그런데 불만이 계속 나와서 분포를 봤다.
두 가지 방법이 있었다. 평균을 계속 지표로 두고 목표치만 낮추는 것과, Micrometer 공식 문서대로 Timer 에 publishPercentiles(0.5, 0.95, 0.99) 를 주고 p99 를 지표로 삼는 것이다. 뒤쪽을 골랐다. 이유는 대부분은 빠른데 소수가 몇 초씩 걸리고 있었고 불만은 그 소수에서 나왔기 때문이다. 대신 백분위는 차원을 넘어 합산이 안 되어 서비스별로 따로 봐야 하는 것을 감수했다. 평균을 낮추는 것과 오래 걸리는 쪽을 없애는 것은 다른 목표다.
느린 쪽을 모아 보면 공통점이 있다
오래 걸리는 요청만 따로 모으니 보유 코인이 많은 계정과 일정산 배치가 겹치는 시간대와 시세 API 가 느린 순간 셋으로 갈렸다. 앞의 둘은 우리가 손댈 수 있고 마지막은 우리 문제가 아니었다.
그래서 시세 호출에 RestTemplate 의 readTimeout 을 두고 안 오면 그 항목만 비운 채로 나머지를 보여 주게 했다. 전에는 하나가 느리면 전체가 느렸는데 이제는 하나가 느리면 그 자리만 빈다.
정리
- 추측으로 고치면 엉뚱한 자리를 고치게 된다
- 안 나아졌을 때 다음에 무엇을 볼지도 안 정해진다
StopWatch로 구간별 시각을 찍으면 어디서 시간이 쓰이는지 보인다- 코드 안을 다듬는 것보다 호출 구조가 클 때가 많다
- 순서대로 부르던 것을
CompletableFuture로 동시에 부르고 반복 조회를 한 번으로 합친다 - 평균은 오래 걸리는 소수를 감추므로
p99를 본다 - 느린 쪽만 모아 보면 공통점이 갈린다
- 외부가 느린 것은
readTimeout을 두고 그 자리만 비운다