블로그 워커 감시 크론

관련 파일: scripts/worker-health/worker_health.py, scripts/dashboard/server.py, scripts/dashboard/app.js

블로그 운영 대시보드는 워커가 멈췄는지, 마지막 실행에 오류가 있었는지를 이미 계산해서 보여준다. 문제는 사람이 그 화면을 열어야 보인다는 것이었다. 워커가 조용히 멈추면 누군가 대시보드를 열 때까지 아무도 모른다.

대시보드를 읽는 감시기

처음 붙인 자리는 Pi 전체를 보는 pi-health-monitor였다. 그런데 알림이 Bark의 Pi 그룹으로 왔고, 사용자가 방향을 바꿨다.

음… 이걸 pi-health-monitor보다는 별도 blog 크론으로 붙이는 게 맞는 것 같아, 둘 다.

그래서 scripts/worker-health/worker_health.py가 따로 생겼다(08c3ed82). 5분마다 cron-gate blog-worker-health 뒤에서 돈다. 감시기는 워커 로그를 직접 읽지 않고 대시보드의 /api/summary를 읽는다. 워커가 stale인지 판정하는 기준, 마지막 실행 구간만 오류 스캔 대상으로 보는 규칙, cron-gate 정지 상태까지 대시보드가 이미 다 들고 있어서, 감시기가 같은 판정을 한 번 더 구현하면 두 판정이 어긋날 자리가 생긴다. 대시보드가 응답하지 않으면 감시기는 로그만 남기고 끝난다. 대시보드 자체가 죽은 것은 pi-health-monitor가 알린다.

보는 것은 세 가지다.

• 워커 정지. 로그가 주기의 2.5배 넘게 멈췄거나(stale) 아예 없다(missing).
• 워커 오류. 마지막 실행 로그에 오류 줄이 있다.
• 크론 등록 누락과 autopush 타이머 비활성. crontab에서 잡이 사라졌거나 blog-autopush.timer가 active가 아니다.

두 번 보고 한 번 알리기

모든 조건은 같은 상태 기계를 탄다.

if bad:
    entry = old or {"count": 0, "alerted": False, "since": now_iso()}
    entry["count"] = int(entry.get("count", 0)) + 1
    if entry["count"] >= THRESHOLD and not entry.get("alerted"):
        if self.notify(title, body, recovery=False):
            entry["alerted"] = True
    conds[key] = entry
    return
if not old:
    return
if old.get("alerted") and not old.get("muted"):
    if not self.notify(f"복구: {title}", "현재 점검에서 정상 상태로 돌아왔습니다.",
                       recovery=True):
        return
conds.pop(key, None)

THRESHOLD는 2다. 5분 간격 점검에서 두 번 연속 나쁘면 한 번 알리고, 좋아지면 복구 알림을 한 번 더 보낸다. 알림 전송이 실패하면 alerted를 세우지 않으므로 다음 점검에서 다시 시도한다. 복구 알림이 실패하면 조건을 지우지 않는다.

첫 실행은 조용하다. 상태 파일이 없는 첫 실행에서 이미 나빠 있는 조건은 muted로 기준선에 넣고 알리지 않는다. 설치하는 순간 이미 있던 이상이 한꺼번에 울리는 것을 막기 위한 것이다. 기준선에 있던 조건은 한 번 좋아졌다 다시 나빠질 때부터 정상적으로 알린다.

정지와 워커 자신의 알림

두 종류의 오탐을 걸렀다.

하나는 정지다. cron-gate로 정지한 워커는 로그가 늙는 게 당연하므로 stale을 보지 않는다. 까다로운 건 정지를 푼 직후다. 정지 동안 늙은 로그가 그대로 남아 있어서, 재개한 순간 다음 실행이 돌기 전까지는 stale로 읽힌다. 그래서 마지막으로 정지를 본 시각부터 한 주기에 15분을 더한 동안은 stale 판정을 억제한다.

다른 하나는 중복 알림이다. 사용자가 이 지점을 먼저 물었다.

근데 블로그 워커들이 실패 시에 혹시 별도로 Bark 알림을 보내지 않아? 그럼 방금 추가한 이게 겹치지 안ㅢ뉘ㅏ 싶어서.

겹친다. 번역 워커는 실패하면 failure_notice를 세우고 쿨다운을 지켜 알리고, 용어 추출 워커는 글 단위 실패를 세다가 세 번째에 그 글을 격리하며 알린다. 그래서 워커별로 “이 오류는 워커가 이미 붙잡아 관리 중인가”를 묻는 함수를 두었다.

def translation_handled(now: float) -> bool:
    """번역 실패는 record_failure 가 failure_notice 를 세우고 쿨다운을 지켜 알린다."""
    st = load_json(TRANSLATION_STATE) or {}
    return bool(st.get("failure_notice"))

WORKER_HANDLED = {
    "translation": lambda now, interval: translation_handled(now),
    "terms": terms_handled,
}

붙잡힌 실패는 감시기가 다시 알리지 않는다. 붙잡히지 않은 실패, 예컨대 워커가 예외로 죽어 자기 state에 흔적을 못 남긴 경우는 그대로 알린다. 워커의 자체 알림 경로가 닿지 못하는 곳만 감시기가 덮는 분업이다. 알림은 전부 -g blog로 보낸다. 처음에 Pi 그룹으로 오던 것이 사용자가 처음 짚은 불편이었다.

감시기가 읽는 대시보드 쪽 정비

감시기가 대시보드 판정을 그대로 믿으려면 그 판정이 워커 단위로 정확해야 했다. 번역 워커와 한글 수정 후속 워커는 로그 파일 하나(translation.log)를 같이 쓰는데, 대시보드는 둘을 워커 하나로 묶어 “00시부터 4시간 · 후속은 02시부터 4시간”이라고 표시하고 주기는 2시간으로 잡고 있었다. 후속 워커만 멈춰도 본 워커가 로그를 갱신하니 정지가 보이지 않는다. 8e327dcb는 두 워커를 별개 항목으로 가르고, 공유 로그를 KO-FOLLOWUP: 접두사로 나눠 읽는다.

def worker_log_lines(w, n=2000):
    """공유 번역 로그의 후속 접두사와 그 연속 줄을 같은 워커에 귀속한다."""
    lines = tail(w["log"], 20000, maxbytes=2_000_000)
    kind = w.get("log_kind")
    if kind:
        selected = []
        followup = False
        for ln in lines:
            if _RUN_TS_RE.match(ln.lstrip("[")):
                followup = bool(re.match(r"^\[[^]]+\] KO-FOLLOWUP:", ln))
            if followup == (kind == "followup"):
                selected.append(ln)
        lines = selected
    return lines[-n:]

타임스탬프로 시작하는 줄에서 접두사를 보고 그 뒤의 연속 줄(여러 줄짜리 verdict 등)을 같은 쪽에 붙인다. 주기도 각자 4시간(interval=14400)이 됐다. 이 줄 귀속 규칙은 번역 워커의 로그 문구에 의존하므로, 워커가 접두사를 바꾸면 조용히 한쪽으로 쏠린다.

크론 표는 두 번 손봤다. 60eeda0e는 시각을 shortKst()로 KST MM-DD HH:MM에 맞추고, 크론식을 읽는 문장을 “매시 15분부터 30분 간격”처럼 바꿨다. dff887c6은 파싱하지 못한 원시 크론식이 옆 칸으로 넘치던 것을 말줄임으로 자르고(원문은 title 툴팁에 남는다), 쿼터 정지 때 강제재개와 정지 두 버튼이 한 줄에 들어가도록 버튼 칸을 넓혔다. 감시기가 알림을 보내면 사람은 결국 이 표를 연다. 워커가 멈췄다는 소식을 10분 안에 들고 오는 감시기라니, 나보다 성실하다. 나는 불려야 온다.