48KB짜리 에러 로그가 정상 상태였고, 그래서 13일간 0건을 못 봤습니다

관제판에 봇을 37개 올려두고 매일 봅니다. 그런데 관제판은 제가 행을 만든 것만 봅니다. launchctl list와 대조해 봤더니 18개가 밖에 있었고, 그중 프로젝트 하나가 통째로 밖이었습니다. 수집기 6개가 8월 26일부터 매일 돌면서 라이브 사이트에 데이터를 넣고 있었는데 감시가 없었습니다.

들어가 보니 세 겹이었습니다. 그리고 두 번째 겹이 첫 번째 겹을 13일 동안 가리고 있었습니다.

1. 첫 번째 겹 — 아무것도 못 모으면서 매일 성공

try:
    import yfinance as yf
except ImportError:
    log.warning("yfinance 미설치 — 옵션 섹션 스킵(pip install yfinance로 활성화)")
    return          # rc=0

경고를 찍고 return 합니다. 종료코드는 0입니다. launchd는 성공으로 기록하고, 로그 파일은 정상적으로 갱신됩니다. 산출물 신선도로 감시해도 초록입니다.

설치하면 되지 않냐고요? 이 잡은 시스템 python3으로 돕니다. macOS의 시스템 python3은 PEP 668로 패키지 설치가 막혀 있습니다. 설치가 물리적으로 불가능한 환경에서 "설치하세요"라는 힌트를 13일 동안 찍고 있었습니다. 그동안 라이브 사이트의 옵션 섹션은 계속 비어 있었습니다.

2. 두 번째 겹 — 왜 아무도 그 경고를 못 봤나

같은 프로젝트의 로그 파일을 열면 이런 게 수천 줄입니다.

ERROR:...:upsert 실패 GME/borrow_fee_pct: 409 {"code":"23505",
  "details":"Key (ticker, metric, asof_date)=(GME, borrow_fee_pct, 2026-09-07) already exists."}

에러 로그 하나가 48KB였습니다. 그게 정상 상태였습니다.

원인은 한 줄이었습니다.

url = f"{base}/rest/v1/ticker_snapshots"          # on_conflict 없음
headers = {..., "Prefer": "resolution=merge-duplicates"}

PostgREST의 resolution=merge-duplicates는 충돌 대상을 알아야 동작합니다. 유니크 제약이 기본키가 아니면 ?on_conflict=<컬럼들>을 줘야 합니다. 안 주면 그냥 insert이고, 같은 (ticker, metric, asof_date)를 다시 쓸 때마다 409가 납니다.

즉 upsert가 upsert가 아니었습니다. 그리고 그 실패가 매일 수백 줄씩 쌓이니, 로그에서 ERROR를 찾는 것은 아무 의미가 없어졌습니다. 노이즈 플로어가 신호보다 높으면 신호는 없는 것과 같습니다.

여기서 잠깐. 당신의 파이프라인 로그에서 grep -c ERROR를 하면 몇 개가 나옵니까? 그 숫자가 0이 아니고, 그런데도 당신이 신경 쓰지 않고 있다면 — 이미 같은 상태입니다.

3. 세 번째 겹 — 실패가 종료코드에 없었다

upsert()는 이미 bool을 돌려주고 있었습니다.

def upsert(...) -> bool:
    ...
    if r.status_code not in (200, 201, 204):
        log.error(...)
        return False

호출부 여섯 곳이 전부 반환값을 버렸습니다. 그래서 모든 쓰기가 실패해도 프로세스는 rc=0으로 끝납니다. 로그에만 있고, 종료코드에는 없고, 감시판은 종료코드와 산출물만 봅니다.

4. 고친 것

겹	고침
해석기	프로젝트 `venv`를 만들고 러너가 강제. 없으면 exit 1
409 홍수	`?on_conflict=ticker,metric,asof_date` — 진짜 upsert
무성 실패	`FAILURES` 집계 + `finish()`가 실패 시 exit 1
회차 완결	끝에 `[end] ok` 또는 `[end] 실패 N건` 한 줄
옵션 0건	옵션 체인은 매일 있습니다. 0건은 "오늘 데이터 없음"이 아니라 언제나 고장 → exit 1

마지막 줄이 중요합니다. 같은 규칙을 다른 수집기에 쓰면 안 됩니다. 결제불이행이나 공매도 잔고는 발표 주기가 길어서 0건이 정상입니다. "0건이면 실패"는 매일 데이터가 존재하는 지표에만 참입니다.

결과: 옵션 데이터가 처음으로 들어갔습니다(GME OI 100,084 · 맥스페인 18.5 / TSLA 224,747 · 357.5). 여섯 개를 launchd로 재기동하니 전부 [end] ok, ERROR 0건.

5. 감시판에 올리자 이번엔 반대로 보였습니다

여섯 행을 추가했더니 방금 고친 네 개가 빨강, 13일간 0건이던 하나가 초록으로 떴습니다.

이유는 단순했습니다. 로그는 launchd의 StandardErrorPath 리다이렉션으로만 쌓입니다. 제가 터미널에서 돌린 실행은 로그에 한 줄도 안 남았습니다. 그래서 로그에는 여전히 어제의 ERROR가, 옵션 로그에는 ERROR 없는 WARNING만 있었습니다.

판정선을 "ERROR가 있는가"에서 "회차가 어떻게 끝났는가"([end] 실패 또는 Traceback)로 바꾸고, launchctl kickstart로 여섯 개를 실제로 돌려서 확인했습니다. 산출물 신선도만 보면 안 되는 이유와 같은 계열인데, 이번엔 제가 감시 규칙 쪽에서 같은 실수를 했습니다.

6. 진짜 고침은 "다음 봇"입니다

감시판 밖 봇을 놓친 게 이번이 세 번째입니다. 세 번 다 원인이 같았습니다 — 행을 안 만든 것. 그리고 세 번 다 사람이 우연히 발견했습니다.

그래서 발견을 우연에 맡기지 않기로 했습니다.

def uncovered():
    """감시판에도 없고 면제 목록에도 없는 launchd 잡."""
    rows = {r[0] for g in FLEET.values() for r in g}
    loaded = ...   # launchctl list 파싱
    return sorted(loaded - rows - set(COVERAGE_EXEMPT))

--selfcheck가 이걸 어기면 초록을 안 주고, 관제판 푸터에도 빨갛게 뜹니다. COVERAGE_EXEMPT에는 이유를 적어야 들어갑니다. 그 목록이 곧 변명이기 때문입니다.

그리고 마지막에 제 코드를 다시 읽다가 하나 잡았습니다. uncovered()가 launchctl 조회에 실패하면 빈 목록을 돌려주고 있었습니다. 그러면 "감시 밖 0개"라는 없는 사실이 화면에 찍힙니다. 종일 고친 그 계열을 마지막 줄에서 제가 다시 저지를 뻔했습니다.

자가진단 3가지

로그에서 grep -c ERROR를 해보세요. 0이 아닌데 무시하고 있다면, 그 로그는 이미 감시 도구가 아닙니다. 상시 에러부터 없애야 나머지가 보입니다.
쓰기 함수의 반환값을 버리고 있지 않습니까? 실패가 로그에만 있고 종료코드에 없으면 launchd·cron·CI 어디에서도 안 보입니다.
launchctl list(또는 crontab -l)와 당신의 감시 목록을 오늘 한 번 대조해 보세요. 저는 18개가 밖에 있었습니다.

솔직한 부분

세 겹 중 어느 것도 어려운 문제가 아니었습니다. on_conflict 한 줄, 반환값 확인 한 줄, exit 1 한 줄입니다. 어려웠던 건 볼 이유를 만드는 것이었습니다. 13일 동안 이 잡들은 매일 돌았고, 로그를 남겼고, 종료코드 0을 반환했습니다. 전부 정상의 모양을 하고 있었습니다.

오늘 launchctl list | wc -l과 당신 대시보드의 행 수를 비교해 보세요. 두 숫자가 다르면, 그 차이만큼이 당신이 못 보고 있는 것입니다.