정상 종료가 오류로 기록됐다

수집 프로그램을 점검하려고 손으로 껐다. 곧바로 오류 알림이 왔다.

[알림] collector 비정상 종료 (device D012)

정상적으로 껐는데 비정상으로 잡힌다.

Open Table of contents

종료를 한 가지로 다루고 있었다
조치 — 종료 이유를 파일에 남기기
시작할 때 파일을 지웠다
이유를 모를 때 보는 세 가지
계획된 재시작의 표시
재시작 횟수를 셌다
정리

종료를 한 가지로 다루고 있었다

감시 스크립트를 열어 봤다.

while true; do
  if ! pgrep -f collector >/dev/null; then
    notify "collector 비정상 종료"
    /opt/collector/start.sh
  fi
  sleep 30
done

pgrep 으로 프로세스가 없는 것만 보고 비정상으로 판정한다. 왜 없는지는 아무것도 안 본다.

SIGTERM 으로 껐든 갑자기 죽었든 pgrep 결과는 똑같이 비어 있다. 사라졌다는 사실만 있고 이유가 없으니 구분할 재료 자체가 없었다.

이 상태에서는 알림이 신호 구실을 못 한다. 점검할 때마다 오니 받는 쪽이 무시하게 되고 그러면 진짜 비정상 종료가 왔을 때도 안 본다.

조치 — 종료 이유를 파일에 남기기

프로그램이 끝날 때 이유를 남기게 고쳤다.

static void on_signal(int sig) {
    write_exit_reason(sig == SIGTERM ? "SIGTERM" : "SIGNAL");
    cleanup();
    exit(0);
}

int main(void) {
    signal(SIGTERM, on_signal);
    signal(SIGINT,  on_signal);
    ...
    write_exit_reason("NORMAL");
    return 0;
}

SIGTERM 을 받아 접는 경로와 제 할 일을 마치고 끝나는 경로가 각각 write_exit_reason 을 부른다. 이유는 파일 하나에 쓴다.

/var/run/collector.exit

감시 스크립트는 프로세스가 사라졌을 때 그 파일을 먼저 읽는다.

if ! pgrep -f collector >/dev/null; then
  reason=$(cat /var/run/collector.exit 2>/dev/null || echo "UNKNOWN")
  case "$reason" in
    SIGTERM|NORMAL) echo "정상 종료 ($reason). 재시작 안 함" ;;
    *)              notify "비정상 종료 ($reason)"; /opt/collector/start.sh ;;
  esac
fi

SIGTERM 이나 NORMAL 이면 알리지도 않고 다시 띄우지도 않는다. 사람이 끈 것을 감시가 다시 켜면 그것대로 곤란하다.

SIGKILL 로 강제 종료되거나 그 자리에서 죽으면 write_exit_reason 이 안 돈다. 그래서 파일이 없다는 것 자체가 그런 종료였다는 신호가 된다.

시작할 때 파일을 지웠다

이 방식에는 함정이 하나 있었다. 지난번 종료 이유가 남아 있으면 다음번 급사도 정상으로 읽는다.

int main(void) {
    unlink("/var/run/collector.exit");
    ...
}

시작할 때 unlink 로 먼저 지운다. 그러면 파일이 없는 상태는 돌고 있거나 갑자기 죽은 것 둘 중 하나가 된다.

collector.exit 같은 상태 파일은 언제 만들지만 정하면 안 된다. 언제 없앨지를 같이 정해야 그 파일이 말하는 바가 하나로 고정된다.

이유를 모를 때 보는 세 가지

파일이 없으면 왜 죽었는지를 따로 찾아야 한다. 세 자리를 순서대로 봤다.

메모리가 모자라 커널이 죽인 경우는 시스템 로그에 남는다.

$ grep -i "killed process" /var/log/messages | tail -5

비정상 종료면 덤프가 생기므로 그것도 본다.

$ ls -lt /var/crash/ | head -5

셋째는 collector.log 자신의 마지막 줄이고 그것이 어디까지 갔는지를 말해 준다.

그래서 알림에 그 마지막 줄을 붙여 보내게 했다.

notify "비정상 종료. 마지막 로그: $(tail -3 /var/log/collector.log)"

tail -3 을 알림에 실으니 접속하기 전에 짐작이 선다. 알림을 받고 서버에 들어가 다시 로그를 여는 단계가 한 번 줄었다.

계획된 재시작의 표시

배포할 때도 프로세스를 끄므로 그때마다 알림이 오면 시끄럽다. 배포 스크립트가 표시를 남기게 했다.

touch /var/run/collector.maintenance
systemctl stop collector
# ... 배포 ...
systemctl start collector
rm -f /var/run/collector.maintenance

감시는 collector.maintenance 가 있으면 조용히 넘어간다. 그런데 배포가 중간에 실패해 이 파일이 안 지워지면 감시가 영영 조용해진다.

그래서 파일의 나이를 보게 했다.

if [ -f /var/run/collector.maintenance ]; then
  age=$(( $(date +%s) - $(stat -c%Y /var/run/collector.maintenance) ))
  if [ "$age" -lt 600 ]; then
    exit 0     # 10분 안이면 작업 중으로 본다
  fi
  notify "작업 표시가 10분 넘게 남아 있습니다"
fi

stat -c%Y 로 만든 시각을 읽어 10분이 안 지났으면 작업 중으로 본다. 넘었으면 표시가 남아 있다는 사실 자체를 알린다.

touch 로 감시를 끄는 장치에는 스스로 풀리는 조건이 있어야 했다. 없으면 꺼 둔 것을 아무도 모르는 상태가 계속된다.

재시작 횟수를 셌다

재시작이 반복되는 것은 그 자체가 문제다. start.sh 가 자동으로 계속 띄우면 증상만 가리고 원인은 그대로 남는다.

CNT_FILE=/var/run/collector.restart_count
cnt=$(cat "$CNT_FILE" 2>/dev/null || echo 0)
cnt=$((cnt + 1))
echo "$cnt" > "$CNT_FILE"

if [ "$cnt" -ge 5 ]; then
  notify "1시간 내 재시작 ${cnt}회. 자동 재시작 중단"
  exit 1
fi

restart_count 를 세어 한 시간에 다섯 번을 넘으면 자동 재시작을 멈춘다. 횟수는 한 시간마다 초기화했다.

exit 1 로 멈춰 세우는 것이 목적이 아니라 사람이 보게 만드는 것이 목적이었다. 계속 살아나면 아무도 그 장비를 안 들여다본다.

정리

종료 이유를 구분하지 않으면 정상까지 오류로 센다
점검할 때마다 알림이 오면 받는 쪽이 무시하게 된다
끝나는 경로에서 이유를 파일에 쓰고 감시가 그것을 읽는다
SIGKILL 이나 급사에서는 그 줄이 안 도니 파일 없음이 곧 신호다
손으로 끈 것은 알리지도 않고 다시 띄우지도 않는다
시작할 때 unlink 로 이유 파일을 지운다
상태 파일은 언제 만들고 언제 없앨지를 함께 정한다
이유를 모르면 시스템 로그와 덤프와 마지막 로그를 순서대로 본다
작업 표시에 나이를 두어 오래되면 스스로 풀리게 한다
재시작 횟수를 세고 임계를 넘으면 자동 재시작을 멈춘다