손으로 돌리던 배치를 자동으로 돌게 바꿨다. 돌아가는데 문제가 생겼을 때 아무도 몰랐다.
Table of contents
Open Table of contents
배경 — 손으로 돌 때는 사람이 봤다
손으로 돌리면 화면이 이렇게 나온다.
$ php batch/settle.php 2018-04-13
정산 대상 1,842건
처리 중... 1000/1842
처리 중... 1842/1842
완료. 성공 1,840건, 실패 2건
돌리는 사람이 stdout 을 보고 있으니 실패 2건 이 그 자리에서 눈에 든다.
숫자가 이상하면 중간에 끊기도 했는데 평소 1,800건이던 대상이 40,000건으로 나오면 조건이 잘못된 것이다.
사람이 지켜보는 것 자체가 통제 장치였는데 settle.php 어디에도 적혀 있지 않아서 그것이 장치라는 인식도 없었다.
돌리는 사람은 자기가 무언가를 검사한다고 생각하지 않았을 것이다. stdout 이 보이니 보고 이상하면 Ctrl-C 를 누르는 것이 자연스러운 동작이었다.
원인 — 자동으로 돌리니 그것이 없어졌다
자동으로 돌리는 것은 한 줄이었다.
0 3 * * * /usr/bin/php /app/batch/settle.php $(date -d yesterday +\%F)
crontab 으로 돌리니 stdout 에 나오던 것이 아무 데도 안 나온다.
실패 2건은 그대로 사라졌고 며칠 뒤 정산이 안 맞는다는 말이 나왔을 때 그것이 쌓여 있었다.
실행만 옮기고 그 옆에 있던 것은 안 가져온 셈인데 옮길 대상이 php batch/settle.php 한 줄로 보였기 때문이다.
자동화는 crontab 에 한 줄 거는 일로 읽히기 쉽다. 실제로는 사람이 하던 판단까지 함께 옮겨야 같은 상태가 유지된다.
조치 — 사람이 하던 것을 코드로
지켜보던 사람이 무엇을 하고 있었는지 적어 봤다.
1. 대상 건수가 평소와 비슷한지 본다
2. 진행이 멈추지 않는지 본다
3. 실패 건수를 본다
4. 실패한 것을 열어 본다
5. 이상하면 중단한다
다섯 가지였고 이것을 settle.php 안으로 하나씩 옮겼다.
$count = count($targets);
if ($count > $avg * 3 || $count < $avg / 3) {
log_error("대상 건수가 평소와 크게 다릅니다: {$count} (평소 {$avg})");
exit(1);
}
$count 가 평소와 크게 다르면 시작하지 않고 $avg 는 지난 30일 평균으로 구했다.
$avg * 3 이라는 기준은 임의로 정한 것이다. 감으로 하던 판단을 숫자로 옮기면 그 숫자를 정해야 한다. 근거가 마땅치 않아도 없는 것보다는 나았다.
$avg / 3 쪽이 너무 좁으면 정상인 날에도 멈추고 너무 넓으면 아무것도 안 걸린다. 몇 달 돌려 보고 걸린 건을 세어 다시 정하기로 남겨 뒀다.
대응 — 멈춘 것과 시간 상한
진행이 멈춘 것도 알게 했다.
$lastProgress = time();
foreach ($targets as $i => $t) {
process($t);
if (time() - $lastProgress > 300) {
log_error("5분간 진행이 없습니다. {$i}/{$count}");
}
$lastProgress = time();
}
멈춘 것과 느린 것을 가르기 어려워서 lastProgress 로 진행이 없는 시간을 봤다.
배치 전체에도 상한을 뒀다.
0 3 * * * timeout 3600 /usr/bin/php /app/batch/settle.php ...
timeout 3600 을 넘으면 끊는데 안 끊으면 다음 날 배치와 겹친다.
끝나지 않은 채 남아 있는 것보다 실패로 끝나는 편이 알아채기 쉬웠고 겹쳐 도는 것은 그 자체로 다른 사고를 만든다.
같은 날짜를 두 settle.php 가 동시에 처리하면 결과가 어떻게 될지 알 수 없다. timeout 을 둔 것은 느린 것을 막기 위해서가 아니라 그 겹침을 막기 위해서였다.
설정 — 0건이어도 보내는 보고
실패를 남기고 알리게 했다.
if ($fails) {
$db->insert('batch_fail', [...]);
notify("정산 배치 실패 " . count($fails) . "건", implode("\n", $failDetails));
}
여기에 더해 batch_fail 이 비어도 요약은 보냈다.
정산 배치 2018-04-14
대상 1,842건 (평소 1,830건)
성공 1,840건
실패 2건
소요 12분
notify 를 실패에만 걸면 조용한 것이 정상인지 알림이 안 오는 것인지 갈리지 않는다.
배치가 아예 안 돌면 실패 알림도 안 오므로 매일 오던 보고가 안 오는 것 자체가 신호가 되도록 0건이어도 보내게 했다.
notify 가 늘어나는 것은 그 값으로 받아들였다. 매일 오는 한 줄이 감시가 살아 있다는 것을 알려 준다고 봤다.
제약 — 사람 몫과 손으로 돌리는 경로
전부 자동으로 하지는 않았다.
이상하면 중단한다는 판단은 사람이 해야 하는 것이라 대신 판단할 재료를 주고 기다리게 했다.
if ($suspicious) {
$db->update('batch_job', $jobNo, ['state' => 'HOLD', 'reason' => $why]);
notify("정산 배치 보류: {$why}", "확인 후 재개해 주십시오.");
exit(2);
}
HOLD 로 두면 자동으로 넘어가지도 않고 그냥 실패하지도 않는다.
손으로 돌리는 경로도 남겼는데 재실행하거나 특정 날짜만 다시 할 일이 있었다.
$ php batch/settle.php 2018-04-13 --verbose
--verbose 를 주면 전처럼 진행이 화면에 나오고 자동으로 돌 때는 안 나온다.
같은 코드가 두 방식으로 돌게 두니 자동에서 이상할 때 손으로 돌려 보면서 확인할 수 있었고 그것이 가장 빠른 확인 방법이었다.
자동으로만 돌게 두면 이상할 때 볼 수 있는 것이 log_error 가 남긴 줄뿐이 된다. 손으로 돌리는 경로를 남겨 두는 값이 거기에 있었다.
정리
- 손으로 돌 때는 사람이 지켜보는 것 자체가 통제 장치였다
- 코드로 적혀 있지 않아서 그것이 장치라는 인식도 없었다
- 자동으로 바꾸면 그 장치가 함께 사라진다
- 옮길 것이 명령 한 줄로 보여서 그 한 줄만 옮기게 된다
- 사람이 무엇을 보고 있었는지 적어 본다
- 평소 값과 크게 다르면 시작하지 않는다
- 감으로 하던 판단을 숫자로 옮기면 그 숫자를 정해야 한다
- 진행이 멈춘 것을 알게 하고 전체에도 시간 상한을 둔다
- 끝나지 않는 것보다 실패로 끝나는 편이 낫다
- 실패가 0건이어도 보낸다. 안 오는 것과 구분한다
- 사람이 판단할 것은 보류로 두고 기다린다
- 손으로도 돌릴 수 있게 남겨 두면 이상할 때 그것으로 본다