report HAN-559 jarvis final 2026-06-08

[HAN-559] Pantheon startup-audit 이중 dispatch 인시던트 보고

Summary

bridge가 watchdog force-exit으로 재시작되는 동안 사용자가 보낸 메시지가 startup-audit + Slack 지연 재전송 두 경로로 중복 처리되어, 이미 완료된 작업이 재실행되고 진행 중인 신규 요청이 interrupt되는 사고가 2026-06-08 발생했다.

Incident Timeline

시각 이벤트
19:15:02 jini BrokenPipeError 연속 발생 시작
19:16:27 watchdog DEGRADED 감지 (5/6 active, jini inactive)
19:16:40 audit-fallback이 이전 in-flight("네 이번엔 넘어가고...") retrigger → Jarvis kill/재처리
19:17:28 Jarvis LLM 완료 (HAN-559 이슈 생성 완료, 46.8s)
19:17:30~57 사용자가 "채널에도 리포트해주세요" 전송 (추정 구간)
19:17:57 watchdog WEDGED (partial-conns 60s) → Force-exit
19:18:09 bridge 재시작 완료
19:18:39 startup-audit 30s 대기 완료 후 스캔 시작
19:19:06 startup-audit이 "채널에도 리포트해주세요"를 미응답 스레드로 탐지 → Jarvis dispatch (1차)
19:19:08 retrigger dispatched: jarvis → 채널 리포트 포스팅 완료
19:24:14 사용자가 "그러면 재배포해볼까요?" 전송 → Jarvis in-flight 시작
19:24:54 Slack이 "채널에도 리포트해주세요" 이벤트를 Socket Mode로 지연 재전송 (5분 38초 후)
19:24:54 handle_user_message가 in-flight kill → 채널 리포트 재실행 (2차)
19:25:10 (별도) jini 스레드 interrupt

Root Cause Analysis

핵심: startup-audit + Slack Socket Mode 재전송의 race condition

사용자 메시지 전송 (19:17:30~57)
           ↓
  bridge offline (19:17:57 force-exit)
  ┌──────────────────────────────────────────┐
  │ Slack Socket Mode:                       │
  │   ACK 미수신 → 메시지 재전송 큐에 적재   │
  └────────────────────────┬─────────────────┘
           ↓               ↓
  bridge 재시작            (Slack 재전송 큐 대기 중)
  startup-audit 스캔
  conversation.history에서 동일 메시지 발견
  fake_event로 handle_user_message 호출 (1차)
  → 채널 리포트 완료 ✅
           ↓
  사용자: "그러면 재배포해볼까요?" → in-flight 시작
           ↓
  Slack 재전송 큐에서 지연 전송 도착 (19:24:54, 5분 38초 후)
  → handle_user_message 정상 호출 (2차) ← 이게 버그
  → in-flight KILL → 재배포 요청 interrupt
  → 채널 리포트 재실행 ❌

왜 5분 38초 지연?

bridge 재시작 후에도 jini BrokenPipeError가 계속되어 Socket Mode 연결이 불안정했다. Slack은 ACK 미수신 이벤트를 백오프 재시도하며, 안정적인 연결이 확보된 19:24:54에 최종 전달한 것으로 추정된다.

취소 메커니즘의 한계

handle_user_message 내 interrupt 로직(_in_flight.kill())은 같은 thread_ts의 더 최신 메시지가 오면 이전 처리를 중단하는 설계다. 그러나 startup-audit의 fake_event는 conversation.history 기반이고 Slack 재전송 이벤트는 원본 ts를 가지므로, 두 이벤트는 별개의 메시지로 동일하게 유효하다. 중복 여부를 감지하는 장치가 없다.

Evidence

로그 근거 (bridge.log, 2026-06-08)

# 1차 처리 — startup-audit
19:19:06.625 [startup-audit] jarvis: msg text="[재시작 복구] ... '채널에도 리포트해주세요...'
19:19:08.108 [startup-audit] jarvis: [audit] retrigger dispatched: jarvis thread=1780912675.785339

# 2차 처리 — Slack 지연 재전송 (5분 38초 후)
19:24:14.953 [ThreadPoolExecutor-0_3] jarvis: msg text='그러면 재배포해볼까요?'
19:24:54.624 [ThreadPoolExecutor-0_0] jarvis: msg text='채널에도 리포트해주세요...'  ← 동일 메시지 재도착
19:24:54.982 [ThreadPoolExecutor-0_0] jarvis: interrupt: killed in-flight for thread_ts=1780912675.785339
19:24:55.001 [claude-jarvis] jarvis: in-flight process killed by interrupt — discarding

# watchdog force-exit (재시작 원인)
19:17:57.323 [CRITICAL][watchdog] WEDGED (partial-conns) - active=5/6 for 60s. Force-exit.

코드 근거

Impact

항목 내용
사용자 피해 "그러면 재배포해볼까요?" 요청 interrupt, 중복 채널 리포트 게시
발생 조건 watchdog force-exit → 재시작 → startup-audit 처리 완료 후 Slack 지연 재전송 도착
빈도 재시작 빈번 기간(jini BrokenPipeError 다발) + 사용자 메시지 타이밍 일치 시

Fix Proposals

Option A (권장): 처리된 ts 집합 dedup — _audit_dispatched_ts

startup-audit / audit-fallback이 fake_event를 dispatch할 때, 실제 메시지 ts를 _audit_dispatched_ts: set[str] (global)에 기록.
handle_user_message 진입부에서 event["ts"]가 이 집합에 있으면 skip + log.

# bridge.py — 전역
_audit_dispatched_ts: set[str] = set()

# _audit_retrigger / _audit_jarvis_fallback — fake_event dispatch 직후
_audit_dispatched_ts.add(last_user["ts"])  # 원본 메시지 ts

# handle_user_message — 진입부
if event.get("ts") in _audit_dispatched_ts:
    log.info("[%s] skipping duplicate (already audit-dispatched ts=%s)", persona, event["ts"])
    return

Option B: Slack event dedup (envelope_id 기반)

Slack이 보내는 envelope_id로 이미 처리한 이벤트 skip. 현재 bridge가 envelope_id를 tracking하지 않음 → 구현 비용 더 높음.

Option C: startup-audit 비활성화 (STARTUP_AUDIT_ENABLED=false)

근본 원인 제거. 단, 재시작 중 누락된 메시지 미복구 → UX 저하. 권장 안 아님.

Decisions

결정 근거
Option A 채택 구현 최소, fake_event 발원지에서 기록 → 정상 경로에서 skip. 가장 직접적
TTL 기반 자동 만료 set 무한 증가 방지, 재시작 후 장시간 경과한 ts는 충돌 위험 없음

Related