RCA: AwsQueueManager::deleteMessage — receipt handle has expired

Overview#

What Happened#

2026-07-28 11:49:31 KST에 cupixworks-capture-intelligence-agent production 인스턴스가 SQS FIFO 메시지 처리 중 Python 분석 프로세스에서 Process timeout(AbortError)을 만났고, 이어지는 에러 핸들러의 deleteMessage 호출이 SQS 로부터 The receipt handle has expired 응답을 받아 error 로그를 남겼다. 발생 건수는 1회이며 뒤이어 같은 메시지가 SQS 로부터 재전달되어 743078 capture 는 성공적으로 처리 완료되었다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-07-28 10:49:30 KST — captureId 743078 SQS 메시지 최초 수신 및 처리 시작 (BaseService::runByMessage, MessageId 9bc4b9a5-bab2-4d2b-8fa7-e108b3afb130, ApproximateReceiveCount 1)
2. 2026-07-28 10:49:31 ~ 10:49:49 KST — Python CaptureIntelligenceProcess 실행: 비디오 업로드, Gemini 호출, spacetime summary merge 시작 (40 sibling captures)
3. 2026-07-28 11:49:31 KST — 이후 처리에서 AbortSignal.timeout(TIMEOUT_MS) 이 발동, Process timeout (AbortError: The operation was aborted) 발생. CupixAuth::handleError | Undefined response 로그 기록.
4. 2026-07-28 11:49:31 KST — BaseService::handlingMessageErrors 가 deleteMessage 호출 → SQS 가 receipt handle has expired 반환 (오늘 RCA 대상 error 로그).
5. 2026-07-28 11:49:31 KST — 같은 메시지가 새 receipt handle 로 재수신되어 (ApproximateReceiveCount: 1, MessageId 동일) 두 번째 처리 시작.
6. 2026-07-28 11:50:04 KST — 두 번째 시도가 성공, capture/spacetime summary 저장 완료, deleteMessage 도 성공 (MessageId 9bc4b9a5).

Error Log#

Datadog Logs

AwsQueueManager::deleteMessage | end - Value AQEBKFoRn4bbiC+rcrQfFJu06IGrBvyffLknp4jOToRUlyxPe0TgHcMZLa3Ls+dRkZ7kud9ZoiNDog17on1b1Bg8wEcjhXu+t07QeUHw9Pv8l1JDstdkYYGj6wNn/QlcHY5QQ8ulbLTQtrdRJJddb/CZ83BrYo+46M03G14jjby6pUuHtUKKoEPvQ0wi82Tp+Q6MMqSI6uUNyETHjGyd/P1/rctOfGALftxObqqI1MMAIO/1sLTGpuFaX6Q27EcqgthnCooLqKYtdjxYXg6tOaHhJutvBX+bj/F8CktRPwFGvXep/ItD5XPbjJL28Yo7prEbxu/hWVkhguRo0mztW8yzfQ== for parameter ReceiptHandle is invalid. Reason: The receipt handle has expired.

Impact#

• Service: cupixworks-capture-intelligence-agent
• Team: whitingturner
• 발생 횟수: 1
• 최초 발생: 2026-07-28 11:49:31 KST
• 최근 발생: 2026-07-28 11:49:31 KST

두 번째 재전달 시도에서 captureId 743078 이 정상 처리되었으므로 최종 사용자 영향은 없다. 그러나 error 레벨 로그가 남아 알람/노이즈로 이어지고, 동일 메시지가 두 번 실행되며 (한 번은 무의미하게 GPU/Gemini 비용을 이미 소비) 아이덤포턴시 이슈를 부를 수 있는 설계 결함을 노출한다.

Root Cause Summary#

cupixworks-capture-intelligence-agent 는 SQS FIFO 큐(cupix-capture-intelligence-agent-production.fifo)에서 메시지를 받아 최대 60분(TIMEOUT_MS = 3,600,000 ms) 동안 Python 서브프로세스로 LLM summary 를 생성한다. 하지만 SQS 큐의 VisibilityTimeout 은 코드 상수로 600초(10분) 로 고정되어 있고, AwsQueueManager.changeMessageVisibility 는 정의되어 있음에도 처리 파이프라인 어디에서도 호출되지 않아 heartbeat 로 visibility 를 연장하지 않는다. 처리가 10분을 넘기면 receipt handle 이 만료되고, 이후 error 핸들러가 deleteMessage 를 시도하면 SQS 가 The receipt handle has expired 로 거절해 이번 error 로그가 발생한다. 실질적으로는 SQS 가 메시지를 재전달해 두 번째 실행이 성공하므로 데이터 손실은 없지만, "1 실행 = 1 처리" 라는 아이덤포턴시 가정이 깨진다.

Technical Analysis#

Code Path#

• Entry point: packages/base/src/base-service.ts:86 (BaseService::checkingQueue)
• SQS 폴링 후 메시지 처리: packages/base/src/base-service.ts:153 (BaseService::runByMessage)
• Python 서브프로세스 실행 (60 분 timeout): packages/cupix-capture-intelligence-agent/src/manager/capture-intelligence-process.manager.ts:20,74-78
• Error 발생 후 삭제 시도: packages/base/src/base-service.ts:290 (BaseService::handlingMessageErrors) → packages/base/src/base-service.ts:225 (deleteByMessage) → packages/base/src/manager/aws-queue.manager.ts:77 (AwsQueueManager::deleteMessage)
• Failure point: packages/base/src/manager/aws-queue.manager.ts:99 (SQS 콜백에서 err.message 로그)

SQS visibility timeout 은 다음과 같이 고정되어 있다.

export const QueueVisibilityTimeout = 600; // seconds

Python 서브프로세스의 timeout 은 이보다 6배 큰 60분.

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 });

changeMessageVisibility 는 매니저에는 존재하지만 호출부가 없어 heartbeat 없이 처리가 진행된다.

changeMessageVisibility = (message: AWS.SQS.Message): Promise<void> => new Promise((resolve, reject) => {
    const queueUrl = this.queueUrl;
    const receiptHandle = message.ReceiptHandle;
    logger.debug('AwsQueueManager::changeMessageVisibility | begin - queue url: %s', queueUrl);
    if (queueUrl == undefined || receiptHandle == undefined) {
        logger.warn('AwsQueueManager::changeMessageVisibility | end - undefined queueUrl or receiptHandle');
        return reject();
    }

    const params: AWS.SQS.Types.ChangeMessageVisibilityRequest = {
        QueueUrl: queueUrl,
        ReceiptHandle: receiptHandle,
        VisibilityTimeout: Constants.QueueVisibilityTimeout
    };
    // ...
});

Grep 결과 changeMessageVisibility 심볼은 aws-queue.manager.ts 한 파일에서만 등장한다 — 어떤 서비스도 호출하지 않는다.

실패 시 error 핸들러는 receive count 를 체크해 삭제를 시도한다:

private handlingMessageErrors = async (error: any): Promise<void> => {
    const errorAndMessage = { error: error, sqsMessage: {} };
    if (this.messageInProcess) {
        errorAndMessage.sqsMessage = { MessageId: this.messageInProcess.MessageId, Attributes: this.messageInProcess.Attributes };
        const apiErrorObject = this.getApiErrorToDeleteMessage(error);
        if (apiErrorObject != undefined || this.checkReceiveCountToDeleteMessage()) {
            try {
                errorAndMessage.error = apiErrorObject;
                await this.deleteByMessage(this.messageInProcess);
                // ...
            } catch (error) {
                logger.error('BaseService::handlingMessageErrors | Errors in error handling', error);
            }
        }
    }
    logger.error('BaseService::handlingMessageErrors | Error and message object - %s', JSON.stringify(errorAndMessage));

deleteMessage 실패는 다음 지점의 SQS 콜백 err.message 로그로 error 레벨로 남는다.

this.sqs.deleteMessage(params, (err: AWS.AWSError) => {
    if (err) {
        logger.error('AwsQueueManager::deleteMessage | end - %s', err.message);
        reject(err);
    } else {
        logger.info('AwsQueueManager::deleteMessage | end - message id: %s', message.MessageId);
        resolve();
    }
});

Log Evidence#

Datadog 쿼리:

service:cupixworks-capture-intelligence-agent status:error @environment:production "AwsQueueManager::deleteMessage"

24시간 검색 결과, 이 정확한 receipt handle 실패는 1회만 발생했다. 사건 시점 전후 로그 시퀀스 (UTC):

2026-07-28T02:26:45.209Z  AwsQueueManager::deleteMessage | begin (previous message 743394)
2026-07-28T02:26:45.218Z  AwsQueueManager::deleteMessage | end - message id: ad5608d0-...
                          [~20분 처리 공백 — 다음 메시지 폴링 및 오래 걸리는 처리]
2026-07-28T02:49:31.153Z  CupixAuth::handleError | Undefined response: AbortError "The operation was aborted", cause: "Process timeout"
2026-07-28T02:49:31.153Z  The operation was aborted
2026-07-28T02:49:31.154Z  AwsQueueManager::deleteMessage | begin
2026-07-28T02:49:31.163Z  AwsQueueManager::deleteMessage | end - Value AQEB... for parameter ReceiptHandle is invalid. Reason: The receipt handle has expired.
2026-07-28T02:49:31.164Z  BaseService::handlingMessageErrors | Error and message object - {"error":"undefined response","sqsMessage":{"MessageId":"9bc4b9a5-bab2-4d2b-8fa7-e108b3afb130","Attributes":{"ApproximateReceiveCount":"1"}}}
2026-07-28T02:49:31.248Z  BaseService::runByMessage | id: 743078            ← 같은 MessageId 재전달, receiptHandle 갱신됨
2026-07-28T02:49:31.310Z  CaptureIntelligenceService::run | begin - captureId: 743078
2026-07-28T02:50:04.724Z  CaptureIntelligenceService::run | end - captureId: 743078
2026-07-28T02:50:04.726Z  AwsQueueManager::deleteMessage | begin
2026-07-28T02:50:04.746Z  AwsQueueManager::deleteMessage | end - message id: 9bc4b9a5-bab2-4d2b-8fa7-e108b3afb130   ← 두 번째 시도 삭제 성공

핵심 관찰:

• 동일 MessageId 9bc4b9a5-bab2-4d2b-8fa7-e108b3afb130 가 두 번 처리되었고, 두 번째 시도의 deleteMessage 는 정상 성공했다 — 즉 새 receipt handle 은 유효하고, 실패한 것은 오래 된 receipt handle 뿐이다.
• handlingMessageErrors 가 남긴 sqsMessage.Attributes.ApproximateReceiveCount 가 1 로 나타나는데, 이는 첫 delivery 를 의미한다. 즉 첫 번째 attempt 가 visibility timeout 을 넘겨 receipt handle 이 무효화됐고, SQS 는 이를 실패로 간주해 재전달을 시작한 상태였다.
• 첫 attempt 의 Process timeout 에러는 CupixAuth::handleError 를 통해 발생했으며 stack trace 안에 /tmp/agent/dist/app.cjs:6707 (bundled AbortSignal.timeout 콜백) 프레임이 남아 CaptureIntelligenceProcessManager 의 60 분 timeout 이 발동한 것으로 확인된다.

"stack":"AbortError: The operation was aborted\n
    at abortChildProcess (node:child_process:725:27)\n
    ...
    at timeoutSignal.addEventListener.once (/tmp/agent/dist/app.cjs:6707:25)\n
    ...
"cause":{"stack":"Error: Process timeout\n    at timeoutSignal.addEventListener.once (/tmp/agent/dist/app.cjs:6707:31)..."}

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 없음. 이번 사건은 SQS 재전달로 자동 복구되었고 사용자 영향이 없다. 다만 error 레벨 로그가 알람 노이즈이고, 아래 단기 개선 없이 재발 시 매번 같은 에러가 반복될 것이므로 짧은 시일 내 대응이 필요하다.

단기 개선 (1주 이내)#

• Heartbeat 로 visibility timeout 연장 도입 — packages/base/src/base-service.ts:153 runByMessage 에서 처리 시작 시점에 setInterval 로 주기적으로 awsQueueManager.changeMessageVisibility(message) 를 호출하고, 성공/실패/timeout 시 clearInterval 로 정리한다. 이미 AwsQueueManager::changeMessageVisibility (packages/base/src/manager/aws-queue.manager.ts:138-162) 가 준비되어 있으므로 호출부만 추가하면 된다. 간격은 QueueVisibilityTimeout(600s) 의 1/3 인 200s, 연장 시간은 QueueVisibilityTimeout 그대로 사용하면 안전 마진이 확보된다.
• SQS 큐 자체의 VisibilityTimeout 을 상향 (Terraform / cupix-infrastructure) — 최소한 Python TIMEOUT_MS(60m) 와 동일하거나 그 이상으로 두는 것을 우선 검토하되, heartbeat 도입 이후에는 큐 설정은 그대로 두고 코드로 연장하는 편이 장애 시 복구 시간을 짧게 유지할 수 있다.
• deleteMessage 실패 시 receipt handle expired 만 warn 으로 격하 — packages/base/src/manager/aws-queue.manager.ts:99 에서 err.code === 'ReceiptHandleIsInvalid' 는 SQS 재전달로 자동 복구되는 예상된 실패이므로 logger.warn 으로 다운그레이드하고, 그 외 SQS 에러만 error 유지. (단, heartbeat 이 도입되면 receipt handle expired 자체가 거의 발생하지 않아야 하므로, warn 격하는 방어책이지 근본 해결책이 아니다.)

장기 개선 (재발 방지)#

• 아이덤포턴시 강화 — 같은 MessageId (곧 같은 captureId) 가 두 번 이상 처리될 수 있음을 전제로, updateCaptureSummary 가 동일 요청 시 idempotent 하도록 서버 측 또는 Python 프로세스 시작 전에 이미 summary_state = done 이면 skip 하는 가드 추가.
• 긴 처리에 SQS 대신 stateful job runner 검토 — 60 분 timeout 이 상시 필요하다면 SQS FIFO 소비자 패턴보다는 Step Functions / ECS one-shot task 처럼 job 단위 lifecycle 을 제공하는 실행 모델이 receipt handle expiration 을 근본적으로 없앤다.
• base-service.ts heartbeat 을 표준화 — 이 서비스뿐 아니라 si-lite-agent, pix-genie-preprocessor-agent, tesla-forge-agent 등도 동일한 SQS 소비 패턴을 상속하므로 BaseService 에 넣으면 모든 agent 가 자동 혜택. 각 서비스별 Python TIMEOUT_MS 가 큐 VisibilityTimeout 을 초과하는 다른 경우도 예방된다.

Monitoring#

• SQS 재전달 지표 — ApproximateNumberOfMessagesNotVisible 이 지속적으로 높거나, deleteMessage 실패 로그가 늘어나는지 알람.
• Receipt handle expired 에러 카운트

service:cupixworks-capture-intelligence-agent status:error @environment:production "receipt handle has expired"

• Python 처리 시간 상위 백분위 (10분/60분 임계)

service:cupixworks-capture-intelligence-agent @environment:production "CaptureIntelligenceProcess" "latency"

• Process timeout (AbortError) 발생 카운트

service:cupixworks-capture-intelligence-agent status:warn @environment:production "process timeout, aborting"

• SQS ApproximateAgeOfOldestMessage 메트릭 (cupix-infrastructure Datadog integration) — visibility timeout(600s) 대비 얼마나 오래 대기 중인지 추적.

Risk Assessment#

• Risk level: low — 사용자 데이터 손실 없음 (SQS 재전달로 두 번째 시도 성공). 다만 heartbeat 없는 소비자 패턴은 향후 처리 시간이 더 늘어나면 error 로그가 크게 증가할 수 있어 방치는 위험.
• 예상 복잡도: standard — BaseService::runByMessage 에 setInterval 기반 heartbeat 추가는 20-40 줄, 모든 agent 파생 클래스가 자동 승계. 기존 changeMessageVisibility 메서드를 그대로 사용할 수 있어 API/큐 설정 변경은 불필요.