RCA: CaptureIntelligenceProcess process timeout abort

Overview#

What Happened#

cupixworks-capture-intelligence-agent 가 captureId 717862 의 Python summary analysis 자식 프로세스를 1시간 (TIMEOUT_MS = 60 * 60 * 1000) 동안 실행한 뒤 AbortController 로 강제 종료했다. 같은 시각에 SQS receipt handle 이 만료되어 AwsQueueManager::deleteMessage 가 실패했고, 동일 메시지가 곧바로 재전달되어 8 초 뒤 재시도 (start 14:03:40 KST → success 14:07:09 KST) 에서 정상 처리되었다. 이 클러스터는 status board 가 자동 감지한 인시던트 2026-06-19-svc-cupixworks-capture-intelligence-agent-1 의 일부이다 (3 cluster, 34 ms 이내 도착).

Quick Facts#

Affected Teams#

Timeline#

1. 2026-06-19 13:03:32 KST — CaptureIntelligenceProcessManager::runPythonProcess 가 captureId 717862, spacetimeId 1463817 로 Python 프로세스 시작 (workdir capture_intelligence_717862_1781841812853).
2. 2026-06-19 14:03:32 KST — TIMEOUT_MS (60 분) 만료, AbortSignal.timeout 이 AbortController.abort(new Error('Process timeout')) 호출. CaptureIntelligenceProcessManager | process timeout, aborting... warn 로그 출력.
3. 2026-06-19 14:03:32 KST — 자식 프로세스가 abort signal 로 종료, childProcess.on('error') 가 AbortError: The operation was aborted 수신 → 클러스터 4d627d4a 의 error 로그 발행.
4. 2026-06-19 14:03:32 KST — abort 직후 AwsQueueManager::deleteMessage 가 SQS 에 호출되었으나 visibility timeout 이 이미 경과 → The receipt handle has expired 응답 (클러스터 607be229, 505db6d9).
5. 2026-06-19 14:03:40 KST — SQS 가 동일 메시지를 재전달, 새 worker 가 captureId 717862 재처리 시작 (workdir capture_intelligence_717862_1781845420204).
6. 2026-06-19 14:07:09 KST — 재시도 성공: CaptureIntelligenceProcessManager::execute | Output received - success: true.

Error Log#

Datadog Logs

CaptureIntelligenceProcess | process error: The operation was aborted

Impact#

• Service: cupixworks-capture-intelligence-agent
• Team: clark-vdc
• 발생 횟수: 1 (related cluster 2 개 포함 시 3)
• 최초 발생: 2026-06-19 14:03:32 KST
• 최근 발생: 2026-06-19 14:03:32 KST
• 사용자 영향: captureId 717862 의 capture intelligence summary 결과가 약 4 분 지연됨 (재시도 후 정상 완료). 데이터 손실 없음.

Root Cause Summary#

CaptureIntelligenceProcessManager 는 Python summary analysis 자식 프로세스에 1 시간 (TIMEOUT_MS) hard timeout 을 적용한다 (capture-intelligence-process.manager.ts:20). captureId 717862 의 분석이 60 분을 초과하자 AbortSignal.timeout 이 발화하여 AbortController.abort 가 호출되고, spawn 의 signal 옵션 (capture-intelligence-process.manager.ts:90) 이 자식 프로세스를 강제 종료했다. 그 결과 childProcess.on('error') 핸들러가 AbortError 를 받아 process error: The operation was aborted 를 error 레벨로 로깅했다 (line 122). 동시에 SQS visibility timeout 이 이 1 시간을 버티지 못해 receipt handle 이 만료되었고, 처리 종료 후 호출한 AwsQueueManager::deleteMessage 가 ReceiptHandle is invalid. Reason: The receipt handle has expired 로 실패하여 메시지가 재전달되었다. SQS 의 at-least-once 전달 덕분에 재시도가 성공하여 사용자 영향은 단발성 지연에 그쳤지만, 본 에러는 처리 시간이 worker 의 timeout budget 을 정확히 끝까지 소진했다는 신호다.

Technical Analysis#

Code Path#

• Entry point: capture-intelligence-process.manager.ts:37 (execute)
• 자식 프로세스 spawn: capture-intelligence-process.manager.ts:82-91
• Timeout 설정: capture-intelligence-process.manager.ts:74-78
• Failure point (로그 발행): capture-intelligence-process.manager.ts:121-124

export class CaptureIntelligenceProcessManager {
	/** Maximum execution time before process is killed (1 hour). */
	private readonly TIMEOUT_MS = 60 * 60 * 1000;

private runPythonProcess(inputPath: string, outputPath: string, workDir: string): Promise<void> {
    return new Promise((resolve, reject) => {
        const abortController = new AbortController();

        const timeoutSignal = AbortSignal.timeout(this.TIMEOUT_MS);
        timeoutSignal.addEventListener('abort', () => {
            logger.warn('CaptureIntelligenceProcessManager | process timeout, aborting...');
            abortController.abort(new Error('Process timeout'));
        }, { once: true });
        // ...
        const childProcess = spawn('python3', [
            '-m', 'src',
            '--input', inputPath,
            '--output', outputPath
        ], {
            env: process.env,
            stdio: ['ignore', 'pipe', 'pipe'],
            cwd: workDir,
            signal: abortController.signal
        });

childProcess.on('error', (error) => {
    logger.error('CaptureIntelligenceProcess | process error: %s', error.message);
    reject(error);
});

기대 동작: 정상 흐름이라면 Python 프로세스가 60 분 안에 종료하여 close 핸들러 (line 111-119) 가 exit code 0 으로 resolve. 실제 동작: 60 분 초과 → AbortSignal.timeout 발화 → signal 로 spawn 된 자식 프로세스가 abort 처리되며 error 이벤트 발생 → AbortError 가 error 레벨로 로깅됨. SQS 메시지 처리 자체는 같은 worker 흐름 안에서 이루어지므로, 1 시간이 SQS visibility timeout 을 초과하면 receipt handle 이 무효화된다.

Log Evidence#

Datadog 쿼리 (재현 가능):

service:cupixworks-capture-intelligence-agent "operation was aborted"
service:cupixworks-capture-intelligence-agent "ReceiptHandle"
service:cupixworks-capture-intelligence-agent "executing: python3"

Timeout 발생 직전/직후 로그 시퀀스:

2026-06-19 13:03:32 KST  info  CaptureIntelligenceProcessManager::runPythonProcess | executing: python3 -m src --input /tmp/workspace/capture_intelligence_717862_1781841812853/input.json --output /tmp/workspace/capture_intelligence_717862_1781841812853/output.json
2026-06-19 14:03:32 KST  warn  CaptureIntelligenceProcessManager | process timeout, aborting...
2026-06-19 14:03:32 KST  error CaptureIntelligenceProcess | process error: The operation was aborted
2026-06-19 14:03:32 KST  warn  The operation was aborted
2026-06-19 14:03:32 KST  error AwsQueueManager::deleteMessage | end - Value AQEBv742... for parameter ReceiptHandle is invalid. Reason: The receipt handle has expired.
2026-06-19 14:03:40 KST  info  CaptureIntelligenceProcessManager::execute | captureId: 717862, type: cupixworks, spacetimeId: 1463817
2026-06-19 14:03:40 KST  info  CaptureIntelligenceProcessManager::runPythonProcess | executing: python3 -m src --input /tmp/workspace/capture_intelligence_717862_1781845420204/input.json --output /tmp/workspace/capture_intelligence_717862_1781845420204/output.json
2026-06-19 14:07:09 KST  info  CaptureIntelligenceProcessManager::execute | Output received - success: true

Abort 시점의 stack trace 와 cause 체인 (warn 로그 CupixAuth::handleError | Undefined response 안에 그대로 노출):

{
  "stack": "AbortError: The operation was aborted\n    at abortChildProcess (node:child_process:725:27)\n    at EventTarget.onAbortListener (node:child_process:795:7)\n    ... at AbortController.abort (node:internal/abort_controller:392:5)\n    at timeoutSignal.addEventListener.once (/tmp/agent/dist/app.cjs:6485:25)",
  "message": "The operation was aborted",
  "cause": {
    "stack": "Error: Process timeout\n    at timeoutSignal.addEventListener.once (/tmp/agent/dist/app.cjs:6485:31)\n    at Timeout._onTimeout (node:internal/abort_controller:127:7)",
    "message": "Process timeout",
    "name": "Error"
  },
  "code": "ABORT_ERR",
  "name": "AbortError"
}

Cause 체인 (Error: Process timeout) 이 abort 의 원인을 명시적으로 가리킨다. captureId 717862 가 13:03:32 KST 시작, 14:03:32 KST abort, 14:03:40 KST 재시작으로 동일 ID 가 두 번 처리된 사실이 SQS 메시지 재전달 (visibility timeout 만료 후 redelivery) 임을 확증한다.

Status board 결과 (bun run cli/incident-board.ts for-cluster 4d627d4a-1944-4585-83c1-4c18baf5ff79):

{
  "scope": "svc:cupixworks-capture-intelligence-agent",
  "active": {
    "id": "2026-06-19-svc-cupixworks-capture-intelligence-agent-1",
    "title": "cupixworks-capture-intelligence-agent service degraded",
    "status": "open",
    "cluster_ids": [
      "4d627d4a-1944-4585-83c1-4c18baf5ff79",
      "607be229-428b-4596-9cb0-9a672cc5ac1e",
      "505db6d9-dad5-4285-b718-17e0f8cab40a"
    ]
  }
}

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 로그 레벨 재검토: applications/agents/packages/cupix-capture-intelligence-agent/src/manager/capture-intelligence-process.manager.ts:122 의 logger.error 호출이 AbortError (의도적 timeout) 까지 error 로 발행한다. SQS at-least-once 재시도로 자동 복구되는 정상 운영 시나리오라면 warn 으로 낮추거나 error.name === 'AbortError' 분기 처리 권장. 메모리 노트의 패턴 (cross-region tokens, transient 상황은 warn) 와 동일.
• 인시던트 확인: status board 인시던트 2026-06-19-svc-cupixworks-capture-intelligence-agent-1 (DOCS_SITE_URL/status) 를 모니터링. 추가 cluster 가 동일 captureId 패턴으로 누적되면 Python 측 hang root cause 를 별도로 조사 필요.

단기 개선 (1주 이내)#

• SQS visibility timeout 정렬: 큐 visibility timeout 이 TIMEOUT_MS (60 분) 보다 충분히 커야 한다. 현재는 처리 시간이 60 분에 도달하면 receipt handle 이 동시에 만료되어 deleteMessage 가 항상 실패하고 메시지가 재전달된다. visibility timeout 을 75–90 분으로 상향 조정하거나, SQS ChangeMessageVisibility 를 주기적으로 호출하는 heartbeat 도입 검토.
• Python 측 진행 로그 추가: 1 시간 동안 STDOUT/STDERR 로그가 한 줄도 없다는 점이 이상 (captureId: 717862 info 로그 이후 process timeout 까지 침묵). Python src 모듈에 단계별 진행 로그를 추가해 어느 단계 (LLM call, S3 fetch, parsing 등) 에서 멈추는지 추적 가능하도록 한다.
• 재시도 멱등성 검증: 같은 captureId 가 재처리되면서 워크디렉토리만 다른 (*_1781841812853 → *_1781845420204) 케이스에서 데이터 정합성/중복 작성 위험이 없는지 확인.

장기 개선 (재발 방지)#

• Hung process 진단 메트릭: 자식 프로세스 wall-clock duration 히스토그램과 process timeout warn 카운터를 Datadog 메트릭으로 노출하여 P95 처리 시간이 timeout 에 근접하는지 추적.
• Heartbeat 기반 visibility timeout 갱신: 장기 실행 worker 의 표준 패턴으로, 처리 중 주기적으로 SQS ChangeMessageVisibility 를 호출해 receipt handle 을 갱신. 이렇게 하면 timeout 도달 시점에 visibility timeout 만료가 동시에 일어나는 race condition 자체를 제거.
• Timeout 분리: 외부 LLM 호출 timeout 과 전체 프로세스 timeout 을 분리하여, hang 발생 시 더 빠르게 (60 분이 아닌 5–10 분 내) 회수 가능하게 한다.

Monitoring#

writing-datadog-monitoring-queries 가이드를 따라 timeseries widget 에서 동작하는 syntax 만 사용한다.

• 자식 프로세스 timeout abort 빈도 (warn 로그 카운트):

sum:logs.hits{service:cupixworks-capture-intelligence-agent,@message:"process timeout, aborting"}.as_count()

• SQS receipt handle 만료 빈도 (deleteMessage 실패):

sum:logs.hits{service:cupixworks-capture-intelligence-agent,@message:"receipt handle has expired"}.as_count()

• AbortError 의 error 레벨 발행 빈도 (현재 로그 레벨로):

sum:logs.hits{service:cupixworks-capture-intelligence-agent,status:error,@message:"process error: The operation was aborted"}.as_count()

• 정상 처리 success 카운트 (분모로 사용):

sum:logs.hits{service:cupixworks-capture-intelligence-agent,@message:"Output received - success: true"}.as_count()

알람 권장: process timeout, aborting 1 시간 누적 ≥ 3 건이면 Python 측 hang 가능성 조사. receipt handle has expired ≥ 1 건/일이면 visibility timeout 정렬 확인.

Risk Assessment#

• Risk level: low
• 예상 복잡도: standard
• 근거: SQS at-least-once 재전달이 자동 복구를 보장하고 있어 사용자 영향은 단발성 지연 (4 분). 다만 1 시간이라는 timeout 이 운영 정상 한도에 가까우면 재발 빈도가 늘어 receipt handle 만료가 상시 발생할 수 있으므로, visibility timeout 정렬과 Python 진단 로그는 단기 내 처리 권장.