완료 제출이 산출물 저장보다 먼저 되는 반려 패턴 — 원인과 방지안

조사: 2026-09-28 09:14~09:25 KST, cowork. 코드는 고치지 않았다. 수정안은 codex 위임용으로만 적는다.

한 줄 결론

세 건 모두 "에이전트가 파일 저장 전에 보고를 먼저 냈다"도, "재시도가 파일을 만들었는데 장부만 failed로 남았다"도 아니다. 큐 워커가 게이트웨이(8642) 에이전트 세션을 약 60초에서 끊고 로컬 소형 모델(ollama/qwen3.5:4b)로 넘어가는데, 끊긴 게이트웨이 세션은 서버 쪽에서 계속 돌아 나중에 파일을 만든다. 워커는 소형 모델이 과제 본문에 적힌 경로를 그대로 따라 쓴 답변을 증거 게이트에 넣어 "경로 없음"으로 failed 확정하고, 뒤늦게 끝난 진짜 세션의 결과는 장부에 연결될 통로가 없다(고아 세션).

1. 시간표 (실측)

조회: sqlite3 -readonly /Users/ron/.hermes/data/ops_multiagent.db 2026-09-28 09:14:01 KST / 파일 stat -f '%SB %Sm' 09:14:01 / 게이트웨이 세션 ~/.hermes/state.db sessions·messages 09:20 KST

항목	#40249 (cowork)	#40250 (cowork)	#40251 (ron 대행)
created / claimed	08:25:16 / 08:25:17	08:25:16 / 08:28:34	08:41:03 / 08:41:03
게이트웨이 세션 시작	08:25:58 (api-c5762cb715b25554)	없음 (openai-codex/gpt-5.4 22.9분 쿨다운 중이라 호출 자체 안 함)	08:41:38 (api-b452a2d94a9a95a7)
워커 쪽 1순위 모델 결과	openai-codex/gpt-5.4 timeout=64s 실패 → 7연속, 쿨다운 진입	쿨다운 스킵	openai-codex/gpt-5.4 timeout=59s 실패
최종 답변 모델	ollama/qwen3.5:4b (성공 처리)	ollama/qwen3.5:4b	ollama/qwen3.5:4b(로그상 다음 후보)
completed_at = 반려 시각	08:27:45	08:29:47	08:43:11
반려 사유	execution_artifact_path_not_found: tests/test_server_bus_command_targets.py	verification_command_path_not_found + execution_artifact_path_not_found + source_log_path_not_found (…cron-restart-proposal.md)	verification_command_unverifiable + execution_artifact_path_not_found + source_log_path_not_found:/Users/ron/scripts/pipeline/market_indicator_tracker.py (존재하지 않는 경로 조합)
게이트웨이 세션의 실제 파일 저장	08:27:57 write_file → 파일 생성 08:27:58	—	08:46:46 write_file → 파일 생성 08:46:47
게이트웨이 세션 최종 답변	08:28:27 ("allowlist is fixed … 4 passed")	—	08:47:22
반려→파일 생성 간격	+13초	파일은 #40251 세션이 만든 것(#40250 자체는 영원히 안 만듦)	+3분 36초
게이트웨이 세션 소요	149초	—	344초

대조군 — 성공 건 #40252(ron): 게이트웨이 세션 08:57:25→08:58:11 = 46초, 워커 타임아웃(약 60초) 안에 끝나 done 저장. 즉 "세션이 60초 안에 끝나면 성공, 넘으면 고아"라는 경계가 실측으로 갈린다.

재현 중: 이 작업(#40255) 자체도 09:16:06에 워커가 llm_infra_failure_retry_deferred로 failed 처리했지만, 이 분석 세션(api-840e8ee80f1be2e4, 09:13:57 시작)은 그 뒤에도 계속 돌아 이 문서를 만들었다. 같은 시각 #40254(ron)도 09:15:46 failed인데 세션 api-e224766f121a28a6(09:13:58 시작)은 별도로 진행됐다. 같은 패턴이 지금도 계속 나고 있다.

2. 증거 — 로그와 코드

• 워커 로그 /Users/ron/.hermes/logs/agent-queue-cowork.log
• 179500~179503행: [model-timeout] model=openai-codex/gpt-5.4 timeout streak=7 → 22.9분 쿨다운 시작 → [model-fallback] agent=cowork model=openai-codex/gpt-5.4 failed (timeout=64s, remaining_budget=129s)
• 179504행: [model-timeout] model=ollama/qwen3.5:4b timeout streak reset — 이 문구는 _record_model_attempt_result() 성공 경로(scripts/agent_queue_worker.py 2810~2812행)에서만 찍힌다. 즉 #40249의 최종 note는 qwen 4b가 만들었다.
• 179505행: [completion-evidence-block] id=40249 … routed_status=failed
• 179512행: #40250 동일 패턴(1순위 모델은 쿨다운으로 스킵).
• 워커 로그 /Users/ron/.hermes/logs/agent-queue-ron.log 143199~143202행: openai-codex/gpt-5.4 failed (timeout=59s …) → [completion-evidence-block] id=40251.

• 40249 반려 note 본문(179506행)은 "2순위: tests/test_server_bus_command_targets.py 테스트 파일 생성"처럼 과제 본문의 할 일을 권고문으로 되풀이한 것이다. 실제 작업 결과가 아니다.

• 40250 과제 본문 732번째 글자에 260928_hermes_market-indicator-cron-restart-proposal 경로가 이미 들어 있다(instr(body,…)=732). 오케스트레이터가 산출물 경로를 미리 지정했고, qwen이 그 경로를 "근거"로 따라 적었다.

• 게이트: scripts/agent_queue_worker.py 4703~4719행 — 증거가 없으면 routed_status="failed"로 기록하고 /fail 경로로 저장한다(4716행 routed_status="failed",, 4718행 path = path.rsplit("/", 1)[0] + "/fail"). 이 이후 같은 id를 다시 열어 늦게 생긴 파일을 대조하는 경로는 파일 전체에 없다(late|orphan|reconcil 검색 0건).
• 3756행 ("execution_artifact_path_not_found", "실존하는 결과물 경로"),은 반려 사유를 "재시도 안내 문구"로 바꾸는 매핑표일 뿐이며 재시도 실행 자체를 하지 않는다. 3803~3817행 _completion_evidence_block_note()가 이 문구로 note를 만들고 끝난다.
• 모델 타임아웃 구조: LLM_BUDGET_SEC=200(2116~2125행 부근), fair_share = remaining / models_left(3035행), model_timeout = max(5, int(min(timeout, fair_share)))(3036행). 30초 숙고 대기 후 남은 약 129초를 후보 2개로 나눠 1순위에 59~64초만 준다. 반면 scripts/shared/llm.py 34행 PER_MODEL_TIMEOUT = max(300, _env_timeout)은 300초를 전제로 하므로 두 계층의 가정이 어긋난다.

3. 판정 — 두 가설 구분

가설	판정	근거
(가) 반려 뒤 재시도 실행이 파일을 만들었지만 장부는 failed로 남는 구조	부분적으로만 맞음	파일을 만든 건 "재시도"가 아니라 최초 호출과 같은 게이트웨이 세션이다. 워커가 기다리길 포기했을 뿐 서버 세션은 끝까지 돌았다. 장부는 그 결과를 받을 통로가 없어 failed로 굳는다.
(나) 에이전트가 파일 저장 전에 보고를 먼저 냈다	아님	실제 작업 세션은 저장(08:27:57/08:46:46) 뒤에 답변(08:28:27/08:47:22)을 냈다. 먼저 제출된 보고는 작업을 하지 않은 대체 모델(qwen 4b)의 답변이다.

부수 원인: 오케스트레이터가 과제 본문에 산출물 경로를 미리 박아 두면, 대체 모델이 그 경로를 복사해 "근거"로 적는다. 게이트는 정상 작동(없는 경로를 잡음)했지만, 반려 사유가 "근거 부족"으로 기록돼 진짜 원인(모델 인프라 타임아웃)이 가려진다. 그 결과 오케스트레이터가 "산출물 선저장 후 재제출"(#40251 제목) 같은 에이전트 행동 교정으로 대응해 같은 실패를 반복했다.

4. 방지안 (codex 위임용 — 코드 미수정)

1순위: 게이트웨이 세션 타임아웃을 세션 실측에 맞추고, 끊긴 뒤 대체 모델로 "완료 보고"를 만들지 않기

• 파일·함수: scripts/agent_queue_worker.py _call_llm_with_guardrails() 3026~3078행(모델 루프), 3035~3036행(fair_share 분할).
• 수정안: 1순위 모델이 8642 게이트웨이 에이전트 모드(openai-codex/*, anthropic/*)일 때는 fair_share 분할을 적용하지 않고 최소 360초(실측 최장 344초 + 여유)를 보장한다. 그 모델이 timeout으로 끝나면 ollama 등 소형 대체 모델로 넘어가지 말고 llm_infra_failure_retry_deferred로 보류한다(이미 8118행 부근에 이 note 형식 있음). 대체 모델은 파일 조작 능력이 없어 "작업 결과"를 만들 수 없고, 과제 본문 되풀이만 만든다.
• 기대효과: 오늘 3건 중 2건(#40249·#40251)은 세션이 149초·344초에 정상 종료했으므로 done으로 저장됐을 것. #40250은 쿨다운 중 보류로 바뀌어 거짓 반려 0건.

2순위: 늦게 끝난 세션 결과를 장부에 다시 연결(지연 대사)

• 파일·함수: scripts/agent_queue_worker.py 증거 게이트 4703~4719행 바로 뒤, 또는 오케스트레이터 정기 라운드.
• 수정안: 게이트웨이 호출 시 명령 id를 세션 제목/헤더로 넘기고, 워커 timeout으로 failed가 된 건은 late_result_pending 표식을 남긴다. 이후 30분 안에 해당 세션의 최종 답변이 state.db에 생기면 그 답변으로 증거 게이트를 다시 돌려 통과 시 failed→done으로 바꾸고 note에 late_result_reconciled를 적는다. 게이트는 그대로 두고 입력만 진짜 결과로 바꾸는 방식이라 증거 기준은 약해지지 않는다.
• 기대효과: #40249처럼 "코드는 반영됐는데 장부는 failed"인 불일치(오늘 #40254가 이 불일치 기록용으로 따로 발행됨)가 사라진다.

3순위: 반려 사유 분류 보정

• 파일·함수: 같은 게이트 4705~4708행 completion_block_reasons 조립부.
• 수정안: 최종 답변 모델이 대체 모델이고, 반려된 *_path_not_found 경로가 전부 과제 본문에 글자 그대로 있으면 사유에 fallback_model_echoed_task_path를 덧붙인다. 오케스트레이터는 이 사유를 보면 "에이전트에게 선저장 지시" 대신 인프라 보류로 다룬다.
• 기대효과: #40250→#40251 같은 잘못된 교정성 재발행 0건.

5. 리스크

• 1순위의 타임아웃 확대는 워커가 한 건에 최대 6분 묶인다. 큐 상한(에이전트당 2건)과 함께 보면 적체가 늘 수 있으므로 적용 첫날 claimed 체류 시간을 확인해야 한다.
• 2순위는 게이트웨이 세션과 명령 id를 잇는 표식이 필요하다. 표식이 없으면 제목 유사도에 기대게 되어 오대사 위험이 있다 — 반드시 명시적 id로 연결할 것.
• 단일 장애점: 1순위 모델(openai-codex/gpt-5.4) 쿨다운이 22.9분까지 늘어나 있어, 이 구간에 들어온 cowork 태스크는 전부 대체 모델로 떨어진다.

6. 검증 방법

• 적용 후 24시간 동안 [completion-evidence-block] 중 *_path_not_found 경로의 파일 생성시각이 completed_at보다 늦은 건수: 기대값 0건 (오늘 오전 기준 3건).
• sqlite3 -readonly /Users/ron/.hermes/data/ops_multiagent.db "SELECT count(*) FROM bus_commands WHERE date(created_at)=date('now','localtime') AND status='failed' AND result_note LIKE '%path_not_found%'" 기대값 감소.
• state.db에서 워커 failed 시각 이후 끝난 게이트웨이 세션(고아 세션) 수: 기대값 0.
• 롤백 조건: 에이전트 claimed 평균 체류가 10분을 넘거나, late_result 대사로 done 전환된 건 중 게이트 재검사 없이 바뀐 건이 1건이라도 나오면 되돌린다.