헬스체크가 빈 응답을 통과시켰다 — exit 124 타임아웃과 mise shim PATH 고정

러너가 이틀 동안 971분, 그러니까 16시간 11분을 돌고 발행한 글은 0편이었습니다. 그 사이 09-03~09-04 의 사이트 실행 24회가 하나도 빠짐없이 종료 코드 124 로 끝났고 매 실행 앞머리에 있는 인증 헬스체크는 네 번 모두 "이상 없음"을 냈습니다. 통과한 것이 고장의 원인이었습니다.

신호가 없었던 것도 아닙니다. 헬스체크에 걸린 시간이 평소 16초에서 121초로 늘어 네 번 똑같이 찍혔고 보드에는 (진행 표시 없음) 이 실행마다 11번씩 남았습니다. 이틀 내내 로그에 다 있었습니다. 그걸 신호로 읽는 코드가 한 줄도 없었을 뿐입니다.

전에 다른 글에서 "위험은 에러가 아니라 침묵입니다"라고 적어 뒀는데, 이번 건이 그 문장의 실증입니다. 무슨 일이 있었고, 어디를 고쳤고, 무엇을 아직 못 고쳤는지를 적습니다.

이틀 동안 24번 타임아웃, 러너가 낸 글은 0편

먼저 실행 이력입니다. 인증 확인 소요는 헬스체크 한 줄이 끝나기까지 걸린 시간이고 결과는 사이트별 종료 코드입니다.

971분은 침묵 실행 네 번(09-03 의 세 번과 09-04 05:00)만 더한 값입니다. 09-04 09:04 실행의 97분은 제가 중간에 죽인 것이라 뺐습니다. 넣으면 1,068분이 되는데, 그건 고장이 태운 시간이 아니라 제가 끊은 시간이라 성격이 다릅니다. 사이트 실행 24회가 전부 124 라는 것은 status 파일 24개를 전수로 확인한 값이고 네 실행 모두 마지막 줄이 중단: 모든 사이트 실패 였습니다. 그러니 러너 기준으로 0편입니다.

243분이라는 숫자도 우연이 아닙니다. 설정값 그대로입니다. 사이트 하나당 상한이 7200초이고(BLOG_TIMEOUT 기본값, daily.sh:48), 한 번에 셋씩 돌리므로(BLOG_PARALLEL 기본 3, daily.sh:57) 여섯 사이트는 두 파도입니다. 로그에도 그대로 찍혔습니다 — 05:02:36 에 세 사이트가 시작해 07:02:36 에 동시에 시간 초과, 07:02:41 에 다음 셋이 시작해 09:02:41 에 동시에 시간 초과. 2시간 × 2파도 = 4시간에 인증 121초와 마감 처리를 더하면 243분입니다. 타임아웃은 정확히 제 일을 했고 문제는 아무 일도 안 하는 프로세스를 두 시간씩 기다렸다는 것뿐입니다.

침묵 실행 넷은 인증 확인 시간이 121초로 똑같다. 정상 실행은 16초와 12초로 제각각이다.

헬스체크는 매번 통과했습니다 — 빈 문자열에 grep 을 걸면 그렇게 됩니다

러너는 사이트를 돌리기 전에 claude 인증이 살아 있는지 한 번 물어봅니다. 사이트마다 2초씩 실패하고 "모든 사이트 실패"로 끝나면 진짜 이유가 사이트별 요약 파일 안에만 남아 사람이 로그를 뒤져야 합니다. 그걸 앞에서 한 번에 걸러내려고 넣은 검사입니다. 사고 전 코드는 이랬습니다.

say "인증 확인"
AUTH_OUT="$(cd "$REPO" && timeout 120 claude -p "ok" --model haiku 2>&1 | head -3)"
if printf '%s' "$AUTH_OUT" | grep -qiE "not logged in|spend limit|usage limit|quota|invalid.*token|unauthor"; then
  die "..."
fi

이 검사는 "나쁜 문자열이 있나" 를 봅니다. 로그인이 안 됐다거나 한도가 찼다는 말이 응답에 섞여 있으면 멈추는 구조입니다. 그런데 이번 고장에서 claude 는 나쁜 말을 한 게 아니라 아무 말도 하지 않았습니다. 빈 문자열에는 나쁜 문자열이 없습니다. 그래서 통과했습니다.

이 기계에서 그대로 재현해 봤습니다.

$ printf '%s' "" | grep -qiE "not logged in|spend limit|usage limit|quota|invalid.*token|unauthor"; echo $?
1

grep 의 1 은 "매치 없음"이고 if 는 그걸 거짓으로 읽습니다. 이 코드에서 1 은 곧 "이상 없음" 입니다. 실패 판정을 나쁜 문자열의 존재로 하면, 침묵은 언제나 정상으로 분류됩니다. 검사가 잘못 돈 게 아니라 검사가 보는 대상이 잘못 잡혀 있었습니다.

판정 갈래가 둘뿐이라 빈 응답은 갈 곳이 통과밖에 없다.

120초 상한이 헬스체크 자신을 죽였습니다

timeout 120 은 이 헬스체크가 영원히 매달리지 않게 하려고 붙인 값입니다. 그런데 이번에는 그 상한이 실제로 발동했습니다. 정상 실행의 인증 확인이 16초와 12초인데 침묵 실행 넷은 121초로 네 번 똑같았습니다. 값이 네 번 같다는 것 자체가 증거입니다. 응답을 기다린 시간이 아니라 상한까지 꽉 채운 시간이니까요.

여기서 뼈아픈 부분은 판정에 쓸 종료 코드가 이미 손에 있었다는 것입니다.

$ set -o pipefail; OUT="$(timeout 1 sleep 5 2>&1 | head -3)"; echo "$? [$OUT]"
124 []

set -o pipefail 은 daily.sh:38 에 이미 켜져 있었습니다. 파이프 뒤에 head -3 이 붙어 있어도 종료 코드는 124 가 그대로 올라옵니다. 그러니 AUTH_OUT="$(...)" 바로 다음 줄에서 $? 를 한 번 읽기만 했으면 그 자리에서 멈췄을 겁니다. 아무도 안 읽었습니다. 켜 두는 것과 쓰는 것은 다른 일이었습니다.

참고로 exit 124 자체의 의미도 확인해 두는 편이 좋습니다. GNU coreutils 의 timeout 매뉴얼에는 124 가 "COMMAND times out, and --preserve-status is not specified"로 적혀 있습니다. 그 아래로 125 는 timeout 명령 자체의 실패, 126 은 찾았지만 실행 불가, 127 은 못 찾음, 137 은 KILL 시그널입니다. 즉 124 는 "죽었다"가 아니라 "제한 시간에 걸렸다" 입니다. 로그에서 124 를 보고 "claude 가 죽었다"로 읽으면 원인을 엉뚱한 데서 찾게 됩니다.

"진행 표시 없음"을 11번 찍으면서 "진행 중"이라고 보고했습니다

러너는 20분마다 보드에 진행 코멘트를 남깁니다(HEARTBEAT_SECS 기본 1200, daily.sh:60). 2시간짜리 작업이 깜깜하지 않도록 넣은 장치입니다. 코드는 이렇습니다.

hb="$(progress_all)"
if [ -z "$hb" ]; then hb="(진행 표시 없음)"; fi
track note "$ISSUE_ID" "$(printf '진행 중\n%s' "$hb")"

진행 내용이 비면 (진행 표시 없음) 으로 채우고, 그래도 진행 중 이라는 제목을 붙여 보드에 올립니다. 09-04 05:00 실행 로그에 실제로 나간 모습입니다.

[05:22:38]   보드| $ bun run pipeline/track.ts note "876e7751-…" "진행 중
[05:22:38]   보드| (진행 표시 없음)"
[05:22:38]   보드| TRACK_OK note

20분마다 열한 번, 보드에 "진행 중"이라고 보고하면서 안쪽은 매번 비어 있었습니다. 그것도 TRACK_OK 성공 처리로요. 하트비트는 살아 있다는 것을 증명했지 일하고 있다는 것을 증명하지 않았습니다.

대조군이 있어서 이게 더 분명해집니다. 09-02 실행도 종료 코드는 똑같이 124 인데 성격이 정반대입니다. 그날은 인증 확인이 16초에 통과했고 claude 가 실제로 두 시간 일하다 시간이 모자라 잘렸습니다. progress 라인이 386줄이고 (진행 표시 없음) 은 0회입니다. 침묵 실행 넷은 progress 라인 0줄에 (진행 표시 없음) 이 각 11회입니다. 그러니까 두 고장을 가르는 지표는 종료 코드가 아니라 진행 라인 수였습니다. 종료 코드만 보면 같은 사고로 묶이고, 진행 라인을 세면 즉시 갈립니다.

같은 종료 코드 124 인데 진행 라인 수는 386 대 0 이다. 이 축이 두 고장을 가른다.

원인은 실행 파일이었습니다 — 비대화형 셸에서 claude 를 찾는 세 갈래

여기까지가 "왜 못 잡았나"이고 실제 고장은 claude 실행 파일 쪽이었습니다. 이 기계에서 claude 로 갈 수 있는 길이 여러 갈래인데, 러너처럼 비대화형으로 도는 셸은 그중 어디로 갈지가 PATH 순서에 달려 있습니다.

mise shim 경로를 앞에 두고 최소 환경으로 불러 보면 이렇게 나옵니다.

$ env -i HOME=$HOME PATH=$HOME/.local/share/mise/shims:/usr/bin:/bin claude --version
mise ERROR No version is set for shim: claude
Set a global default version with one of the following:
mise use -g [email protected]
mise ERROR Version: 2026.8.12 macos-arm64 (2026-08-24)
mise ERROR Run with --verbose or MISE_VERBOSE=1 for more information
$ echo $?
1

shim 은 /opt/homebrew/bin/mise 를 가리키는 심링크라, 실제 바이너리로 가기 전에 mise 가 한 번 끼어들어 "어느 버전을 쓸지" 를 정해야 합니다. 대화형 셸에서는 프로필이 읽혀 그 판정이 되는데, 비대화형에서는 그게 없어 위처럼 멈춥니다. 그리고 이 실패도 종료 코드 1 로 정직하게 알려 줍니다. 앞의 타임아웃도 124 로 알려 줬습니다. 두 고장 모두 $? 에 참값을 넣어 줬는데, 코드가 그걸 안 봤을 뿐입니다.

세 번째 갈래로 Homebrew cask 로 깔린 바이너리도 있었는데, 이건 제가 남길 수 있는 근거가 그날 적어 둔 코드 주석 한 줄뿐입니다. daily.sh:87-88 에 "Homebrew cask 바이너리는 그날 _dyld_start 에서 멈춰"라고 적혀 있습니다. 지금은 Caskroom 이 비어 있어 재현이 안 되고, 그래서 그날 확인한 바로는 그랬다 이상으로는 쓰지 않겠습니다. 어느 갈래가 몇 초를 잡아먹었는지까지 나누는 것도 지금 근거로는 무리입니다.

shim 은 mise 를 한 번 거치고, ~/bin 링크는 실제 바이너리를 바로 가리킨다.

고친 것과 못 고친 것

고친 것은 두 군데입니다. 하나는 PATH 맨 앞에 $HOME/bin 을 박은 것입니다.

- export PATH="$HOME/.local/share/mise/shims:$HOME/.local/bin:/opt/homebrew/bin:..."
+ export PATH="$HOME/bin:$HOME/.local/share/mise/shims:$HOME/.local/bin:/opt/homebrew/bin:..."

~/bin/claude 는 ~/.local/share/mise/installs/node/24.15.0/bin/claude 를 가리키는 심링크입니다. shim(/opt/homebrew/bin/mise 를 가리킴)과 달리 중간에 아무도 안 끼는 실물 경로입니다. 버전 판정을 런타임에 하지 않겠다는 선택이고 그만큼 노드 버전을 올릴 때 이 링크를 같이 갈아 줘야 한다는 부담을 받아들인 셈입니다.

다른 하나는 헬스체크에 빈 응답 조건을 더한 것입니다(daily.sh:492-498).

if [ -z "$(printf '%s' "$AUTH_OUT" | tr -d '[:space:]')" ]; then
  die "$(printf 'claude 가 아무 응답도 하지 않습니다 — 실행 파일이나 PATH 문제입니다.\n\n확인:\n  which claude\n  claude --version\n\n돌려도 사이트마다 타임아웃까지 기다리다 전부 실패합니다.')"
fi

수정 후 10:41 실행은 인증 확인이 12초에 끝났고 그날 13:18 에 money·politics-left·travel 세 곳이 종료 코드 0 으로 끝나 커밋을 남겼습니다. 이 글이 발행되는 시점은 09-08 입니다. 그러니까 이 글 자체가 그 10:41 실행이 남긴 잔여물입니다 — 09-04 에 남겨진 채 나흘간 발행되지 않았고 note 의 마지막 발행은 그 사이에도 08-25 에 머물러 있었습니다. 러너가 멈춰도 그 소리가 바깥에 닿은 통로는 없었습니다. 이 글이 제 주제를 사례로 남기게 된 셈입니다.

그런데 못 고친 것을 분명히 적어 둡니다. 고친 검사도 여전히 종료 코드를 안 봅니다. 공백을 지운 문자열이 비었는지만 볼 뿐이라, claude 가 한 글자라도 뱉으면서 실패하면 지금 검사도 그대로 통과시킵니다. 이번 고장이 마침 완전한 침묵이어서 막힌 것이지, 같은 종류의 다음 고장이 막힌다는 보장은 없습니다. 하트비트도 그대로입니다 — daily.sh:181-182 는 지금도 진행 내용이 비어 있을 때 (진행 표시 없음) 을 채워 넣고 "진행 중"으로 올립니다.

같은 로그에 비슷한 침묵이 하나 더 숨어 있었습니다. 2026년 8월 27일부터 9월 4일까지 실행마다 API error 404: Issue not found 가 여섯 번씩 찍혔는데, 그날에는 원인이 이슈가 없는 게 아니라 토큰이 만료된 것이라고 판단했습니다. 개별 이슈 조회가 404 로 오는 바람에 "없는 이슈"처럼 보였고, 목록 조회를 해 보고서야 401 이 나왔습니다 — 이 관찰 자체는 그날 확인한 대로입니다. 그래서 그날(f163f21) track.ts 의 인증 실패 판정에 Issue not found 를 넣었습니다. 넣은 조건은 이렇습니다.

export const authFailed = (out: string): boolean =>
  /401|authentication required|unauthor|forbidden|403|Issue not found/i.test(out);

이 판단은 09-08 에 뒤집혔습니다. 09-04 이후 보드 기록이 통째로 끊긴 것을 다시 따져 봤는데 토큰 만료가 아니었습니다. 키 만료일은 2027-09-04 로 09-08 기준 361일이 남아 있었고 폐기되지도 않았습니다. 이슈도 실재했습니다 — CMP-14271, 숨겨진 이슈가 아니고 키 주인은 이 프로젝트의 owner 였습니다. 멈춰 있던 것은 키가 마지막으로 쓰인 시각, 그러니까 last_used_at 이었습니다. 2026-09-04 에서 그대로였습니다. 서버가 우리 키를 아예 받지 못하고 있었다는 뜻입니다.

진짜 원인은 Paperclip 쪽 루틴이 러너를 띄울 때 자식 프로세스에 PAPERCLIP_API_KEY 를 넣은 것이었습니다. 설정 어디에도 없는 값이 런타임에 주입되는데, CLI 는 환경변수를 저장된 프로필보다 먼저 쓰므로 러너는 그 키로 붙었고 그 키로는 이 이슈가 보이지 않았습니다. 서버가 401 이 아니라 404 로 답한 이유가 여기에 있습니다. 손으로 같은 명령을 치면 200 이 나왔습니다 — 그 셸에는 그 변수가 없고 러너에만 있었으므로 원인을 잡는 일은 더 늦어졌습니다.

코드 쪽 정리는 09-08 이 아니라 그날 저녁에 이미 있었습니다. Issue not found 를 authFailed 에 넣은 것이 기존 테스트 — 일시적 404 는 다시 건다는 것 — 를 깨뜨려 CI 가 두 번 실패했고 그날 글 3편의 배포가 막혔습니다. 404 한 번으로는 며칠 뒤 사라질 일시적 404 인지 만료처럼 계속되는 404 인지 가릴 수 없기 때문입니다. 그래서 같은 날(2afea6b) 이 조건을 authFailed 에서 빼고 연속 세 번 404 면 인증을 의심하는 noteNotFound 를 따로 두었습니다. 09-08 에는 원인 자체를 손댔습니다 — 러너가 CLI 를 부르는 명령 앞에 unset PAPERCLIP_API_KEY 를 붙였고 보드 감시는 만료일 대신 last_used_at 을 보게 했습니다.

종료 코드 두 고장에서는 $? 가 참값을 줬는데 읽는 코드가 없었습니다. 이번에는 404 라는 참값이 있었는데 "없는 이슈"로 잘못 읽은 셈입니다. 그 진단을 믿고 만료일을 지켜 보는 감시까지 만들었지만, 만료일은 대리 지표였고 이번에는 그 지표가 멀쩡해서 감시가 통째로 헛돌았습니다.

이 경고를 "실행당 한 번만 말한다"고 적고 싶었는데 그건 정확하지 않습니다. 억제 플래그가 모듈 변수인데 daily.sh 는 track 을 부를 때마다 프로세스를 새로 띄우기 때문에, 실제 보장 범위는 한 호출 안에서 한 번입니다.

정리하면 세 줄입니다. 실패 판정을 나쁜 문자열의 존재로 하면 침묵은 언제나 통과합니다. 종료 코드는 두 고장 모두에서 참값을 주고 있었는데 읽는 코드가 없었습니다. 그리고 하트비트는 살아 있음을 증명할 뿐이라, 일하고 있음을 보려면 진행 라인 수처럼 내용이 있는 지표를 세야 합니다.

근거와 참고

• 러너 로그 — ~/.blog-runner-logs/2026-09-02_*.log, 2026-09-03_*.log, 2026-09-04_050029.log, 2026-09-04_090400.log (인증 확인 소요, (진행 표시 없음) 11회, 보드 코멘트 원문)
• 사이트별 status 파일 24개 — 침묵 실행 4회 × 6사이트 전부 124
• 커밋 9a9e583 — fix(daily): claude 가 빈 응답이면 시작하지 않는다 + PATH 고정. 개정 전 코드는 git show 9a9e583^:pipeline/daily.sh
• 커밋 f163f21 — 보드 토큰 만료가 404 로 보인 건과 authFailed 수정
• 커밋 820aa8c — 토큰 만료를 30일 전에 알리는 보드 감시. 만료 진단(f163f21, 10:49)보다 늦은 09-04 11:59 에 만들어졌다
• 커밋 2afea6b — Issue not found 를 authFailed 에서 빼고 연속 404 를 세는 noteNotFound 로 갈라냄. f163f21 이 깬 테스트와 CI 이중 실패, 그날 글 3편 미배포 기록
• 커밋 3f38077 — 보드 404 의 진짜 원인. 러너 자식 프로세스에 주입된 PAPERCLIP_API_KEY 를 unset 하고 보드 감시를 만료일 대신 last_used_at 으로 바꿈
• 커밋 기록 — 09-04 13:18:22 에 세 사이트 커밋(b7796dd money · f4c1eac travel · 5de1eb3 politics-left), note 의 마지막 발행은 08-25(0413782)
• 저장소 코드 — pipeline/daily.sh (:38 pipefail, :48 BLOG_TIMEOUT, :57 BLOG_PARALLEL, :60 HEARTBEAT_SECS, :87-90 PATH 고정과 주석, :176-188 하트비트, :492-498 빈 응답 검사), pipeline/track.ts (:113-114 authFailed — 본문 인용은 f163f21 시점, :128-132 noteNotFound, :198 두 판정을 합치는 곳)
• 재현 명령 — printf '%s' "" | grep -qiE "..."; echo $? / set -o pipefail; OUT="$(timeout 1 sleep 5 2>&1 | head -3)"; echo "$?" / env -i HOME=$HOME PATH=$HOME/.local/share/mise/shims:/usr/bin:/bin claude --version
• timeout 종료 코드 — GNU coreutils 9.11 매뉴얼 /opt/homebrew/Cellar/coreutils/9.11/share/man/man1/gtimeout.1
• 도구 버전 — Claude Code 2.1.260, node 24.15.0, mise 2026.8.12, GNU coreutils 9.11
• 이 저장소의 앞선 기록 — Gatsby 멀티사이트와 SITE 환경변수 의 "위험은 에러가 아니라 침묵입니다", AI 에이전트 자동 발행 파이프라인 의 완료 계약과 기동 상한