배치가 중단됐다가 재실행됐는데 예상한 시간 안에 끝나지 않았다. Spot 인스턴스를 쓰고 있어서 실행 환경 쪽 문제인가 하는 생각부터 들었다.
Table of contents
Open Table of contents
문제 — 막힌 측정 경로
API 호출이 얼마나 걸리는지를 재려 했는데 쓸 수 있는 두 경로가 다 막혀 있었다. 직접 curl로 호출하는 쪽은 Bearer 토큰이 만료된 상태였다.
프록시로 재현하는 쪽은 응답이 커서 서빙 태스크가 메모리 초과로 죽을 위험이 있었다. 측정하려다 운영을 건드리는 것은 안 되므로 다른 길을 찾아야 했다.
조치 — 계측 로그에서 분리한 서버 시간
API 서비스에 계측이 이미 있어서 요청마다 duration_ms를 로그에 남기고 있었다. CloudWatch Logs Insights에서 filter와 stats로 그 값만 걸러 세 달치를 뽑았다.
내 코드를 안 건드리고 부하도 안 주면서 실제 운영 요청의 값을 얻었다. 직접 측정이 막혔을 때 이미 남고 있는 계측을 쓰는 것이 가장 싸고 실제 값에 가깝다.
검증 — 서버 밖의 대부분
뽑아 보니 서버 측 소요는 어느 달이든 10초 안팎이었다. 그런데 배치는 월당 2분 가까이 걸리고 있었다.
서버가 10초 남짓이고 전체가 2분이니 나머지 대부분이 서버 밖에 있었다. 배치 코드에서 무엇을 하는지 보니 대용량 응답을 전송받아 파싱하고 수십만 행을 pandas로 여러 축과 세 기간으로 groupby 집계한 뒤 필터와 매핑을 만들고 gzip 압축해서 S3에 두 번 업로드하고 있었다.
원인 — 구조적 특성이라는 결론
그중 집계 단계가 가장 컸는데 채널과 카테고리와 셀러와 상품과 키워드를 축으로 당월과 전월과 전년을 각각 돌리니 조합이 많았다.
소요 시간이 실행 환경이나 인스턴스 종류와 무관한 구조적 특성이었다. Spot 인스턴스여서도 아니고 실행 시간 한도 때문도 아니라 원래 그만큼 걸리는 일이었다. 느리다고 인프라 원인을 먼저 의심하면 측정할 곳을 잘못 고르게 된다.
의심했던 다른 후보도 배제했다. 이름 조회를 반복하는 함수가 있었는데 대분류 코드별 lru_cache가 걸려 있고 코드 종류가 제한적이라 호출이 월당 수십 회로 바운드됐다. 이것을 확인 안 했으면 주범이 아닌 곳을 최적화했을 것이다.
판단 기준 — 고칠 수 있고 지금은 안 한다
두 가지 방법이 있었는데 집계를 서버 측 SQL로 옮기는 것과 지금 구조를 그대로 두는 것이다. 앞쪽이면 전송량이 수백 분의 일로 줄고 집계도 데이터베이스가 하는 편이 빠르다.
뒤쪽을 골랐다. 이유는 원본을 S3에 보존해서 재집계 입력으로 쓰는 설계 의도가 있어서 서버 집계 결과만 받으면 축이 바뀔 때 다시 만들 원본이 없어져서다. 그리고 일 1회 새벽에 5분대이면 아무도 안 기다린다. 대신 새벽 배치가 그만큼 오래 도는 것을 감수했다.
느리다는 것이 고쳐야 한다는 뜻은 아니고 언제 도는지와 누가 기다리는지를 봐야 한다. 결론에는 원인이 무엇이고 어떻게 고칠 수 있으며 지금은 안 고친다는 것까지 적었으므로 나중에 요구가 바뀌면 이 문서에서 시작하면 된다.
정리
- 느릴 때 서버 시간과 클라이언트 시간을 분리해서 잰다
- 직접 측정이 막히면
duration_ms계측 로그에서 뽑는다 - 서버가 빠른데 전체가 느리면 그 뒤 단계를 본다
- 대용량 전송과 파싱과 다차원 집계가 본체일 수 있다
- 느리다고 인프라 원인을 먼저 의심하지 않는다
- 의심한 후보는 배제도 확인한다
- 느리다는 것이 고쳐야 한다는 뜻은 아니다
- 안 고치기로 했으면 고칠 수 있고 지금은 안 한다까지 적는다