「Control request timeout: initialize」의 정체는 SIGKILL 이었던 이야기 (Claude Code CLI)

production의 Celery task 로그에 이 문자열이 나타나기 시작했을 때, 처음에는 머리를 싸매고 고민했습니다.

ERROR analyze_code_specification failed:
Control request timeout: initialize

Codens Green에서는 리포지토리의 내용을 해석하는 analyze_code_specification이라는 Celery task가 있으며, 그 안에서 Claude Code CLI를 subprocess로서 호출하고 있습니다. staging에서는 정상적으로 통과하는데, production에서만 몇 번에 한 번씩 이것이 발생합니다. 완전히 재현되는 것도 아니고, 간헐적으로 떨어집니다.

「Control request timeout: initialize」라는 문자열은 마치 Claude Code의 MCP 초기화 핸드셰이크 (handshake)가 timeout 된 것처럼 읽힙니다. 실제로 Claude Code Agent SDK의 내부에는 이러한 init handshake 페이즈가 있으며, 그곳에서 stdio가 막히면 유사한 문구가 나옵니다. 그래서 처음에는 완전히 「Claude Code 측의 init bug를 겪었구나」라고 확신하며 꼬박 하루를 허비했습니다. 이것이 이번 이야기의 본론입니다. 결론부터 말씀드리면, Claude Code는 아무런 잘못이 없었고, handshake도 timeout 되지 않았습니다. OS의 OOM killer가 CLI process를 죽였고, 외부에서 보기에는 init timeout처럼 보였을 뿐이라는 결말이었습니다.

에러 메시지에 휘둘린 하루

처음 몇 시간 동안은 에러 문자열을 곧이곧대로 믿고 Claude Code 측을 의심했습니다.

순차적으로 시도한 작업은 다음과 같습니다.

• stdio가 막히지 않았는지: subprocess의 stdout / stderr의 pipe를 PIPE에서 DEVNULL로 바꾸거나, 반대로 버퍼 사이즈를 높여보았습니다. 변화 없음.
• protocol version mismatch: Agent SDK의 version을 하나 올리거나 내려보았습니다. 이 또한 변화 없음.
• agent SDK의 config: timeout 값 (init_timeout_ms 같은 것)을 2배로 늘려보았습니다. 이것은 production 로그에 변화가 생길 것이라 생각했지만, 에러가 발생하는 빈도는 거의 동일했습니다. timeout이 원인이라면 시간을 늘렸을 때 확률이 낮아져야 하는데, 낮아지지 않았습니다.
• staging에서 재현시키기: staging에서는 나오지 않습니다. production에서는 나옵니다. 동일한 image, 동일한 entrypoint, 동일한 Claude Code version. 무엇이 다른지 몇 시간 동안 추궁했습니다.

이 시점에서 「Claude Code SDK가 production의 env var 중 무언가 때문에 죽고 있다」와 같은 가설을 몇 가지 세우고, env var를 하나하나 binary search로 staging과 diff 하기 시작했습니다. 이것이 잘못된 방향으로 나아간 전형적인 사례였는데, 에러 문자열에 너무 많은 의미를 부여했던 것입니다. 「Control request timeout: initialize」라는 문자열을 보면, 인간의 뇌가 멋대로 「init phase의 timeout」이라는 이야기를 만들어 버립니다. 실제로는 이 문자열이 SDK가 「자식 process와의 통신이 확립되지 않은 채 window가 닫혔을」 때의 generic한 문구일 뿐이며, 왜 통신이 확립되지 않았는지는 아무것도 알려주지 않습니다.

로그를 믿고 깊이 파고드는 것과, 로그를 의심하고 관측점을 바꾸는 것 사이의 전환이 늦었다는 것이 솔직한 반성입니다.

exit code를 보는 것만으로 끝날 이야기였다

가설이 다 떨어져 갈 때쯤, 문득 「애초에 자식 process는 어떻게 죽었는가」를 확인하지 않았다는 사실을 깨달았습니다. Python의 subprocess.run은 returncode를 반환하므로, 이를 wrapper 안에서 그대로 출력하기만 하면 됩니다.

result = subprocess.run(
    claude_cli_cmd,
    capture_output=True,
    ...

이것을 production에 심어두고 재현을 기다렸더니, 나온 값이 -9였습니다.

POSIX 상에서 subprocess의 returncode가 음수일 때, 그 절대값은 자식 프로세스(child process)를 종료시킨 시그널(signal)의 번호입니다. -9는 시그널 9, 즉 SIGKILL입니다.

이 순간 머릿속의 그림이 단번에 바뀌었습니다. SDK의 핸드셰이크(handshake)가 타임아웃(timeout)된 것이 아니라, Claude Code CLI가 초기화(initialize) 도중에 OS에 의해 살해당하고 있었던 것입니다. SDK 측에서 보면 "자식 프로세스가 응답하지 않고 파이프(pipe)가 닫혔다"라고만 보이기 때문에, 로그에 "Control request timeout: initialize"라고 기록합니다. 문자열 자체는 거짓이 아니지만, 원인의 직전 단계에서 멈춰 있는 상태였습니다.

SIGKILL을 "외부에서 누구나 보낼 수 있다"는 점은 확실하지만, Linux에서 짐작 가는 곳 없는 SIGKILL이 날아오는 대표적인 범인은 커널(kernel)의 OOM killer입니다. 여기서부터는 Claude Code의 이야기가 아니라, OS의 메모리 계정(memory accounting)에 관한 이야기가 됩니다.

OOM killer의 범인 영상

dmesg를 확인하니 단번에 알 수 있었습니다.

Out of memory: Killed process 1842 (node) total-vm:2148364kB,
anon-rss:1456892kB, file-rss:0kB, shmem-rss:0kB, UID:1000

Claude Code CLI는 내부적으로 Node 런타임(runtime)을 실행하여 그곳에서 컨텍스트(context)를 로드(load)하여 동작합니다. 이것이 꽤 무겁습니다. 이번에 프로덕션(production) 환경에서 실측해 보니, 1회 호출(invocation)당 RSS가 500 MB ~ 1500 MB 사이를 움직이고 있었습니다. 안정적으로 500 MB를 유지하는 것이 아니라, 분석하는 리포지토리(repository)의 크기에 따라 1.5 GB까지 부풀어 오릅니다.

문제는 이쪽 워커(worker)의 사이징(sizing)이었습니다. analyze_code_specification을 담당하던 Celery 워커는 원래 범용 Python 태스크(task)용으로 구성되어 있어 메모리 제한(memory limit)이 그리 크지 않았습니다. 게다가 Celery의 기본 설정(default)대로, 프리포크(prefork) 방식으로 하나의 워커에서 여러 태스크를 병렬로 실행하고 있었습니다.

즉, 프로덕션에서 일어나고 있었던 일은 다음과 같습니다.

• 특정 시점에 analyze_code_specification이 2개 인큐(enqueue)됨 - 동일한 워커의 서로 다른 자식 프로세스(child process)가 둘 다 이를 픽업(pickup)함
• 각각이 Claude Code CLI를 서브프로세스(subprocess)로 실행함
• 두 개의 CLI가 병렬로 메모리를 부풀리기 시작함
• 워커의 메모리 천장(memory ceiling)을 초과함
• 커널 OOM killer가 작동하여 가장 큰 프로세스(대개 Claude Code의 Node)를 SIGKILL로 종료시킴 - 부모인 Python 입장에서는 자식의 stdio가 갑자기 닫히면서 "init handshake가 응답하지 않음" 상태가 됨
• SDK가 "Control request timeout: initialize"를 출력함

스테이징(staging) 환경에서 나타나지 않았던 이유는 단순합니다. 스테이징에서는 analyze_code_specification이 병렬로 실행되는 시나리오를 밟지 않았기 때문입니다. 단지 부하를 재현하지 못했을 뿐이었습니다.

해결책은 4가지의 조합

해결 방법은 분해하면 4가지가 있으며, 그중 하나라도 빠지면 재발합니다.

1. 전용 큐(dedicated queue)로 분리

먼저 Celery의 task_routes를 수정하여, analyze_code_specification만 analysis라는 새로운 큐(queue)로 흐르도록 했습니다. 그 외의 태스크는 기존처럼 default, fixing, control_plane, plan_monitor에 남겨둡니다.

# celery_app.py
task_routes = {
"tasks.analyze_code_specification": {"queue": "analysis"},
...

queue를 물리적으로 분리하지 않으면, 다음의 「전용 worker」 「concurrency=1」 설정이 애초에 적용될 수 없습니다. 「무거운 task는 무거운 worker에게」를 실현하기 위한 전제 조건입니다.

2. dedicated ECS Fargate worker tier 구축

analysis

1 CLI invocation이 peak 1.5 GB라고 가정할 때, headroom(여유 공간)을 5 GB 이상 남기는 sizing. CLI의 peak 자체가 분석 대상인 repo size에 따라 변동되므로, margin(마진)을 넉넉하게 잡았습니다. Node의 GC (Garbage Collection) 동작을 고려하면, 타이트하게 구성할 경우 결국 다시 OOM (Out of Memory)을 겪게 되므로, 이 부분은 여유 있게 가져가고 싶었습니다.

3. concurrency = 1로 기동

새로운 worker는 명시적으로 --concurrency 1로 기동합니다.

celery -A app worker \
-Q analysis \
--concurrency 1 \
...

이 부분이 이번 사건에서 가장 중요한 부분입니다. memory를 8 GB로 늘렸으니 「2개 병렬 정도라면」 하고 concurrency를 2로 설정하고 싶어지겠지만, 그렇게 하면 1.5 GB × 2 = 3 GB 전후로 끝나지 않는 날(한쪽이 2 GB를 초과하는 날)이 반드시 옵니다. OOM killer는 average(평균)가 아니라 peak(최대치)를 기준으로 발동하기 때문에, 「대체로 괜찮겠지」라는 생각은 통하지 않습니다.

게다가 Claude Code CLI를 동일한 instance에서 병렬로 실행하면 Node의 기동 비용, file system cache의 경합, stdout의 혼선 등 다른 문제들도 따라옵니다. 1 invocation 당 1 worker로 딱 잘라 생각하면 디버깅도 훨씬 수월해집니다.

--max-tasks-per-child 50은 장기간 구동하는 동안 Python 측의 RSS (Resident Set Size)가 서서히 늘어나는 현상에 대한 대책입니다. Claude Code 측이라기보다는, 이쪽 Celery worker 프로세스 자체의 문제입니다.

4. 메모리 계산 근거를 남겨두기

최종적인 배분은 다음과 같은 형태가 되었습니다.

• worker service: ECS Fargate 전용 tier (범용 tier와는 별도 service)
• memory: 8,192 MB
• concurrency: 1
• 1 invocation peak: 약 1,500 MB (worst case)
• 동시 실행 수: 1
• headroom: 6 GB 이상

이 수치들을 README와 runbook에 적어두는 것이 중요합니다. 그래야 반년 뒤의 내가 「concurrency 1은 낭비니까 2로 바꾸자」라고 생각했을 때 멈출 수 있습니다.

테스트로는 routing 주변에 핀포인트 assertion (단언)을 추가했습니다.

• analyze_code_specification은 analysis queue에 올라가는지
• control_plane 계열 task는 새로운 queue로 rerouting(재라우팅)되지 않는지
• plan_monitor의 isolation (격리)이 깨지지 않았는지

이 부분을 테스트로 고정해두지 않으면, 나중에 task_routes를 수정했을 때 조용히(silent) 원래대로 돌아가 버릴 위험이 있습니다.

tradeoff (트레이드오프) 이야기

dedicated worker tier를 구축하면 눈에 보이는 몇 가지 비용이 발생합니다.

• infra cost (인프라 비용)가 단순하게 증가한다. 전용 instance를 상시 기동하므로, idle (유휴) 시간만큼의 비용이 고스란히 낭비된다.
• scale-out (확장) 응답이 느리다. 범용 worker는 이미 warm (예열된) 상태인 instance에 task가 쌓이기만 하면 되지만, analysis tier는 원래 수가 적기 때문에 burst (급증)가 발생했을 때 대기 시간이 생기기 쉽다.
• 모니터링 대상이 하나 더 늘어난다. alert (경보) 규칙, metrics (지표) 대시보드, deploy (배포) pipeline 모두 추가해야 한다.
• queue의 생사 여부도 별도로 관리해야 한다. analysis queue가 막혀 있어도 default queue는 건강한 상태가 발생할 수 있다.

그럼에도 불구하고 분리하기로 결정한 이유는, analyze_code_specification

때문입니다. analyze_code_specification만이 memory profile (메모리 프로파일)도 latency profile (지연 시간 프로파일)도 다른 것들과 완전히 별개이기 때문입니다. 이것을 범용 worker (워커)에 계속 공존시키면, 다른 가벼운 task (태스크)들까지 OOM (Out Of Memory)의 여파로 함께 죽게 됩니다. "무거운 이웃이 다른 거주자를 휘말리게 하는 것"을 막는 것이 이번 routing (라우팅)의 진짜 목적이었습니다.

솔직히 말하면, 처음부터 queue (큐)를 나누어 놓았으면 좋았을 것입니다.

이 디버깅에서 남은 교훈

이번 건을 통해 제 자신에게 남겨두어야 할 두 가지 교훈이 있습니다.

첫 번째. AI CLI를 subprocess (서브프로세스)로 품고 있는 Python service (파이썬 서비스)의 memory accounting (메모리 계정)은 일반적인 Python task (파이썬 태스크)와는 완전히 다른 세상입니다. CLI 측은 자체적으로 JS runtime (JS 런타임)이나 Python runtime (파이썬 런타임) 또는 ML model (ML 모델)을 품고 있기 때문에, "부모 worker (워커)에게 보이지 않는 거대한 자식"이 반드시 따라붙습니다. Celery의 concurrency (동시성)는 Python 측의 동시 실행 수만 보고 있으며, 자식 process (프로세스)의 memory (메모리)까지는 관리해주지 않습니다. worker (워커)의 sizing (사이징)은 자식 process (프로세스)의 peak RSS (피크 RSS)를 주인공으로 하여 구성할 필요가 있습니다.

두 번째. 오도하는 error string (에러 문자열)을 발견하면, 우선 exit code (종료 코드)를 확인하십시오. 이번 경우, Control request timeout: initialize라는 문자열은 기술적으로 틀린 것은 아니지만, "자식 process (프로세스)가 initialize (초기화) 중에 무언가로 인해 실패했다"는 점까지만 말해줍니다. 왜 실패했는지는 해당 문자열을 출력한 SDK (SDK)도 알지 못합니다. OS (운영체제)가 보낸 SIGKILL (시그킬)일 수도 있고, 자식 process (프로세스)가 assertion (어설션)으로 인해 떨어졌을 수도 있으며, segfault (세그폴트)일 수도 있습니다. returncode (리턴 코드)를 로그 한 줄에 추가하는 것만으로도, 대부분의 분기점은 해결됩니다. 빨리 할수록 시간을 아낄 수 있습니다.

이러한 부분은 AI CLI를 자사 서비스에 통합할 때 매번 어딘가에서 밟게 되는 지뢰라고 생각하기에 공유해 둡니다.

Codens (https://www.codens.ai/)에서는 이러한 "AI를 production (프로덕션)에 올렸을 때의 미묘한 OS layer (OS 레이어)의 싸움"을 겪은 만큼 harness (하네스)로 굳히고 있습니다. 같은 구멍에 빠지는 사람을 단 한 명이라도 줄일 수 있다면, 이 글의 역할은 끝입니다.