settle:run 배치가 밀리면 손으로 다시 돌리는 일을 한 달에 열 번쯤 하고 있었다. 한 번에 5분이면 끝나서 빠르다는 이유로 계속 그렇게 처리했다.
Table of contents
Open Table of contents
매번 손으로 하던 것
한 번이 짧으니 이것이 얼마나 큰 비용인지 감이 없었는데 세어 보니 달라졌다. 알아채는 시간까지 포함하면 한 번에 20분쯤이고 한 달에 열 번이면 200분이며 반년이면 20시간이었다.
근본을 고치는 데 이틀이면 됐으므로 이미 그 이상을 쓴 셈이다. 한 번이 짧으면 전체가 큰지 알 수 없고 그래서 세어 보기 전에는 계속 그 방식이 싸 보인다.
원인 — 몰리는 날
storage/logs의 배치 로그에서 실행 시간을 grep으로 뽑아 보니 특정 날짜에만 평소의 몇 배가 걸렸다. 그 날짜의 주문 건수를 세니 주말 다음 날 주문이 몰려 있었다.
몰리는 날이 원인이므로 한 번에 전부 처리하지 않고 --date= 옵션으로 날짜별로 나눠 돌리게 고쳤다. 그러면 밀리더라도 그날 것부터 끝나고 다음으로 가므로 전체가 한꺼번에 실패하지 않는다.
조치 — 자동화와 상한
손으로 돌리던 것 자체도 cron으로 매시간 도는 작업으로 옮겼다. 밀린 대상을 찾아 다시 실행하되 retry_count가 3이 되면 멈추고 알리게 해서 무한히 돌지 않도록 상한을 뒀다.
두 가지 방법이 있었는데 손으로 돌리는 경로를 아예 없애는 것과 남기되 --force를 붙여야 실행되게 하는 것이다. 뒤쪽을 골랐다. 이유는 자동으로 다 되는 것이 아니어서 예외 상황에 사람이 돌릴 길이 있어야 해서다. 대신 실수로 두 번 도는 위험이 남는 것을 감수했고 그래서 손으로 돌린 것은 실행자와 대상 날짜를 기록하게 했다. 그 횟수를 세니 자동화 뒤에 한 달에 한 번꼴로 줄었다.
결과 — 반복하는 다른 조치
이 한 건을 고치고 나서 운영 로그에서 반복되는 다른 조치도 찾았다. 배치 재실행과 supervisorctl restart가 각각 수십 회, cache:clear와 queue:flush가 각각 십여 회로 넷이 나왔다.
앱 재시작이 한 달에 수십 번이라는 것은 메모리가 새고 있다는 신호였다. 각각 왜 하는지를 보고 하나씩 고쳤고 월별 수동 조치 횟수가 수십 회에서 십여 회로 줄었다. 급한 조치의 횟수 자체가 지표이고 그 숫자가 늘면 새 문제가 생긴 것이다.
교훈 — 사람이 하던 확인
손으로 하던 것을 자동으로 바꾸고 나서 새 문제가 생겼다. cron이 자동으로 다시 돌다가 같은 날짜를 두 번 처리한 적이 있었는데 손으로 할 때는 사람이 이미 했는지를 눈으로 확인하고 있었다.
settled_at이 이미 찍힌 날짜인지 확인하고 건너뛰는 분기를 넣어 막았다. 사람이 하던 확인을 코드로 옮기지 않으면 자동으로 바꾼 만큼 위험해진다. 무엇을 확인하고 있었는지 적어 보니 셋이 나왔고 하나씩 옮겼다.
정리
- 한 번이 짧으면 전체가 큰지 모르므로 세어 본다
- 반복 횟수와 시간으로 근본을 고치는 비용과 비교한다
- 왜 반복되는지 보면 몰리는 날 같은 조건이 나온다
- 한 번에 다 하지 말고
--date=로 나눠서 돌린다 - 손으로 하던 것을
cron으로 하되retry_count상한을 둔다 --force로 손으로 돌리는 것도 기록하고 센다- 급한 조치의 횟수가 지표이므로 매달 본다
- 사람이 하던 확인을 코드로 옮기지 않으면 자동화가 위험해진다