주문 알림이 안 가는 문제가 있었다. 원인을 찾아 고쳤는데 여전히 가끔 안 갔다.
Table of contents
Open Table of contents
원인 — 첫 번째 것
sms_log 에 남은 발송 로그를 봤다.
2015-04-15 14:22 주문 41022 발송 실패 Connection timed out
문자 발송 업체 응답이 늦을 때 실패하고 있었다. CURLOPT_TIMEOUT 이 3초였다.
curl_setopt($ch, CURLOPT_TIMEOUT, 10);
curl_setopt 로 10초로 늘리고 재시도를 넣었다. 실패가 줄었다.
줄었는데 없어지지 않았다
고치기 전 하루 12건
고친 뒤 하루 3건
3건이 남았다. CURLOPT_TIMEOUT 을 늘리고 재시도까지 넣었는데 남는다는 것이 이상했다.
하나를 고쳤는데 0이 안 되면 다른 원인이 있는 것이다. 12에서 3으로 줄어든 것에 만족하고 넘어갈 뻔했다.
남은 3건을 봤다
남은 것에는 발송 로그 자체가 없어서 orders 와 sms_log 를 맞춰 봤다.
SELECT o.no FROM orders o
LEFT JOIN sms_log s ON o.no = s.order_no
WHERE o.reg_date >= ? AND s.no IS NULL;
sms_log 에 시도한 기록이 없었다. 발송 함수가 아예 안 불린 것이다.
if ($order['member_no'] > 0) {
$this->sms->send($order['phone'], $msg);
}
member_no 가 0인 비회원 주문에는 안 보내고 있었다. 조건이 옛날에 들어간 것이었고 그때는 비회원 주문을 안 받았다.
비회원 주문을 받게 되면서 이 조건이 틀린 것이 됐는데 아무도 안 봤다.
두 원인이 겹쳐 있었다
증상이 같아서 하나로 보였다. 실제로는 성격이 다른 둘이었다.
하나는 밖에서 나는 것이고 하나는 member_no 조건이 낡은 것이었다. sms_log 행이 있는 것과 없는 것으로 갈렸다.
로그가 있는 실패와 로그조차 없는 실패를 나눠 세지 않았던 것이 처음에 못 본 이유였다. 한 숫자로 보면 줄어든 것만 보이고 남은 것의 성격이 안 보인다.
검증 — 나눠 센 두 숫자
result 와 LEFT JOIN 으로 둘을 따로 세게 했다.
-- 시도했고 실패한 것
SELECT COUNT(*) FROM sms_log WHERE result = 'FAIL' AND reg_date >= ?;
-- 시도조차 안 한 것
SELECT COUNT(*) FROM orders o LEFT JOIN sms_log s ON o.no = s.order_no
WHERE o.reg_date >= ? AND s.no IS NULL;
crontab 에 걸어 매일 아침 둘 다 나온다.
2015-04-21 발송 실패 2건, 미시도 0건
미시도가 0이 아니면 조건 쪽 문제다. 어디를 볼지가 바로 갈린다.
두 원인을 다 고치고 나서 다시 셌다.
발송 실패 0~1건, 미시도 0건
남은 1건은 상대 업체가 잠깐 안 될 때였고 send 의 재시도로 결국 나갔다. 0이 되고 나서야 끝난 것으로 봤다.
이 뒤로 무엇이 안 된다는 말을 들으면 먼저 나눠 세었다. 시도했는데 실패한 것과 시도조차 안 한 것은 원인이 달라서 앞은 밖이나 조건이고 뒤는 코드 흐름이다. 메일 발송과 재고 차감과 정산 반영에도 같은 방식을 적용했고 재고 차감에서 미처리 건이 나왔다.
정리
- 하나를 고쳤는데 0이 안 되면 다른 원인이 남아 있는 것이다
- 줄어든 것에 만족하고 넘어가지 않는다
- 로그가 있는 실패와 로그조차 없는 실패를 나눠 센다
sms_log에 기록이 없으면 발송 함수가 안 불린 것이다- 증상이 같아도 원인이 여럿일 수 있다
- 조건은 그 자리에 들어갈 때 맞았어도 나중에 틀린 것이 된다
LEFT JOIN ... IS NULL로 시도조차 안 한 것을 따로 센다- 나눠서 세면 어디를 볼지가 바로 갈린다
- 0이 될 때까지 보고 남은 것이 왜 남는지 설명할 수 있어야 끝난 것이다
- 같은 방식을 다른 자리에도 쓰면 안 보던 곳에서 나온다