ES /docs

CaptureIntelligenceProcessManager timeout과 SQS visibility timeout 동기화 오류

RCA: AwsQueueManager::deleteMessage | ReceiptHandle expired

Overview#

What Happened#

2026-06-19 14:03:32 KST, cupixworks-capture-intelligence-agent (us-west-2 production)에서 SQS 메시지 4f9fc010-9b09-43cf-b0e0-bb2588254514를 처리하던 중 Python 자식 프로세스가 1시간 timeout에 도달하여 abort되었다. 에러 처리 경로에서 AwsQueueManager::deleteMessage가 호출되었으나, 메시지의 SQS visibility timeout(600초)이 이미 만료되어 ReceiptHandle is invalid. Reason: The receipt handle has expired. 에러가 발생했다. 동일 메시지는 이후 14:07:10 KST에 재전달되어 정상 처리되었다.

Quick Facts#

Field Value
exception.class AWS.SQS InvalidParameterValue (ReceiptHandle expired)
exception.message The receipt handle has expired.
top_frame packages/base/src/manager/aws-queue.manager.ts:99
runtime Node.js (aws-sdk v2 SQS)
env production / us-west-2

Affected Teams#

Team / Domain Error Count Impact
clark-vdc / capture-intelligence-agent 1 단건 처리 1회 실패 후 SQS 자동 재전달로 정상 복구 (capture summary 생성 약 4분 지연)

Timeline#

  1. 2026-06-19 13:0x KST 부근 — Python summary 분석 프로세스 spawn (capture summary 작업)
  2. 2026-06-19 14:03:32 KSTCaptureIntelligenceProcessManager | process timeout, aborting... (TIMEOUT_MS = 1시간 도달)
  3. 2026-06-19 14:03:32 KSTCaptureIntelligenceProcess | process error: The operation was aborted
  4. 2026-06-19 14:03:32 KSTCupixAuth::handleError | Undefined response: AbortError ... Process timeout
  5. 2026-06-19 14:03:32 KSTBaseService::handlingMessageErrorsdeleteByMessage 호출 (ApproximateReceiveCount=1)
  6. 2026-06-19 14:03:32 KSTAwsQueueManager::deleteMessage | end - ... receipt handle has expired (본 cluster의 root error log)
  7. 2026-06-19 14:07:10 KST — 동일 MessageId 4f9fc010-... SQS 재전달 후 정상 처리 완료 (deleteMessage | end - message id: 4f9fc010-9b09-43cf-b0e0-bb2588254514)

Error Log#

Datadog Logs

text
AwsQueueManager::deleteMessage | end - Value AQEBv742zXXB5AzpRv1JTEEhI6yPQZAr/J0jH4eu95Qp5bEj86DYf55dFEaywsGeDSgWGmoZMVb/ZSt1JqvSfHRp0STQ2DNoX0vuAoxQz/X3Es0TUutBXWHL62TPnSU0eKuS2OxD/XcdQDCTmumVMC1Yq+f6uCKbB2emT3VXJj15kRS++/wJbu7Vl+uDfZSC7cr/lQ7wB0j1iqsU/49bWWGXf3cAl81w0NNyrJQqykl9RBy8JUitizGbJr1GVukvabVJO4XkkeEpCK3vRB1NU6GXUotayRwZ49fxu5PP/WIel/736tFzKyfkv28WsGQ3kZ3m for parameter ReceiptHandle is invalid. Reason: The receipt handle has expired.

Impact#

  • Service: cupixworks-capture-intelligence-agent
  • Team: clark-vdc
  • 발생 횟수: 1
  • 최초 발생: 2026-06-19 14:03:32 KST
  • 최근 발생: 2026-06-19 14:03:32 KST

이 에러는 단일 발생이며 SQS의 자동 재전달 메커니즘으로 약 4분 후 정상 복구되었다. 다만 동일 시점(14:03:32 KST)에 sibling cluster 두 건(4d627d4a-... process timeout, 505db6d9-... BaseService handlingMessageErrors)이 함께 트리거되어 svc:cupixworks-capture-intelligence-agent service degraded 인시던트(2026-06-19-svc-cupixworks-capture-intelligence-agent-1, resolved)로 묶였다. 사용자 가시적 영향은 capture summary 1건의 생성 지연 약 4분.

Root Cause Summary#

Python summary 분석 프로세스의 timeout(CaptureIntelligenceProcessManager.TIMEOUT_MS = 60 * 60 * 1000 = 1시간)이 SQS visibility timeout(QueueVisibilityTimeout = 600 초 = 10분)보다 6배 길게 설정되어 있어, 처리 시간이 600초를 초과하면 SQS broker가 receipt handle을 만료시키고 메시지를 다른 consumer에게 재전달한다. 이후 process timeout이 발생하면 BaseService::handlingMessageErrorsdeleteByMessage 경로에서 이미 만료된 receipt handle로 deleteMessage를 호출하기 때문에 AWS SQS가 ReceiptHandle is invalid. Reason: The receipt handle has expired.를 반환한다. 즉, timeout 설정 불일치 + 처리 중 visibility 갱신 부재가 근본 원인이다.

Technical Analysis#

Code Path#

Entry point: packages/base/src/base-service.ts:86 (checkingQueue) → runByMessagesrunByMessage.

처리 루프는 SQS에서 메시지를 받아 1건씩 runByMessage에서 실행하고, 성공 시 deleteByMessage를 호출한다.

packages/base/src/base-service.ts:153-185typescript
protected runByMessage = async (message: AWS.SQS.Message) => {
    this._messageInProcess = message;
    const messageBody = message.Body;
    if (messageBody && CPUtils.isJsonString(messageBody)) {
        const msgObject = JSON.parse(messageBody);
        // ...
        try {
            await TraceUtils.activateSpan(span, async () => {
                this.setLogMeta(msgObject);
                logger.info('BaseService::runByMessage | id: %d', targetId);

                await this.authenticateByMessage(msgObject);
                await this.run(targetId, msgObject);          // Python process spawn (1h timeout)
                await this.cleanUpAnythingRelatedModel();
                await this.deleteByMessage(message);          // 정상 경로의 delete

run() 내부에서 CaptureIntelligenceProcessManager.execute가 Python child process를 spawn하고, AbortSignal.timeout(this.TIMEOUT_MS)으로 timeout을 건다.

packages/cupix-capture-intelligence-agent/src/manager/capture-intelligence-process.manager.ts:18-78typescript
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 });

한편 AwsQueueManager의 visibility timeout은 600초로 고정되어 있다. 처리 중 visibility를 연장하는 호출은 정상 경로에 없다(changeMessageVisibility는 정의되어 있으나 runByMessage 흐름에서 호출되지 않음).

packages/base/src/config/constants.ts:1-10typescript
export * from '@agents/shared-config';

export const QueueVisibilityTimeout = 600; // seconds
export const MaximumNumberOfRunTask = 10;
export const ScaleOutCoolDown = 120000; // ms

처리가 10분(600초)을 넘기면 SQS broker는 receipt handle을 만료시키고 메시지를 다른 consumer에게 재전달한다. 이후 process timeout(1시간)이 발생하면 catch 경로가 발동한다.

packages/base/src/base-service.ts:107-115typescript
} else {
    this._countWaitedToStopTask = 0;
    try {
        await this.runByMessages();
    } catch (error) {
        await this.handlingMessageErrors(error);   // 여기서 expired handle 사용
    }

handlingMessageErrors는 에러를 분석하여 메시지를 삭제할지 결정한다. AbortError는 getApiErrorToDeleteMessage에서 response가 undefined로 판정되어 문자열 'undefined response'(truthy)를 반환한다. 따라서 deleteByMessage가 호출된다.

packages/base/src/base-service.ts:240-275typescript
private getApiErrorToDeleteMessage = (error: any): any => {
    if (error == undefined) { /* ... */ return 'undefined error'; }
    if (error.errno != undefined && error.code != undefined && error.syscall != undefined) {
        // nodejs common system error → return undefined (no delete)
        return;
    }
    const response = CPUtils.isJsonString(error) ? JSON.parse(error) : error.response;
    if (response == undefined) {
        logger.warn('BaseService::getApiErrorToDeleteMessage | undefined response', error);
        return 'undefined response';                 // truthy → triggers deleteByMessage
    }
packages/base/src/base-service.ts:290-313typescript
private handlingMessageErrors = async (error: any): Promise<void> => {
    // ...
    if (this.messageInProcess) {
        // ...
        const apiErrorObject = this.getApiErrorToDeleteMessage(error);
        if (apiErrorObject != undefined || this.checkReceiveCountToDeleteMessage()) {
            try {
                errorAndMessage.error = apiErrorObject;
                await this.deleteByMessage(this.messageInProcess);   // 만료된 handle로 호출

Failure point: packages/base/src/manager/aws-queue.manager.ts:97-105sqs.deleteMessage가 만료된 ReceiptHandle을 거부한다.

packages/base/src/manager/aws-queue.manager.ts:77-106typescript
deleteMessage = (message: AWS.SQS.Message): Promise<void> => new Promise((resolve, reject) => {
    if (this.debugMode) return resolve();

    const queueUrl = this.queueUrl;
    logger.info('AwsQueueManager::deleteMessage | begin - queue url: %s', queueUrl);
    // ...
    const params: AWS.SQS.DeleteMessageRequest = {
        QueueUrl: queueUrl,
        ReceiptHandle: messageReceiptHandle
    };
    this.sqs.deleteMessage(params, (err: AWS.AWSError) => {
        if (err) {
            logger.error('AwsQueueManager::deleteMessage | end - %s', err.message);  // 본 cluster의 에러 라인
            reject(err);
        } else {
            logger.info('AwsQueueManager::deleteMessage | end - message id: %s', message.MessageId);
            resolve();
        }
    });
});

기대 동작: 처리가 visibility timeout(600초) 안에 끝나거나, 처리 중 changeMessageVisibility로 visibility를 연장하여 receipt handle을 유효하게 유지한다. 실제 동작: Python 프로세스가 600초 이상 실행되어 visibility가 만료된 채 1시간 timeout까지 진행했고, 이후 정리 로직이 만료된 handle로 delete를 시도해 실패했다.

Log Evidence#

Datadog 쿼리:

text
service:cupixworks-capture-intelligence-agent (status:error OR status:warn)
시간 범위: 2026-06-19T03:30:00Z ~ 2026-06-19T05:10:00Z
text
service:cupixworks-capture-intelligence-agent "AwsQueueManager::deleteMessage"
시간 범위: now-2h

핵심 로그(시간순):

text
2026-06-19 14:03:32  warn   CaptureIntelligenceProcessManager | process timeout, aborting...
2026-06-19 14:03:32  error  CaptureIntelligenceProcess | process error: The operation was aborted
2026-06-19 14:03:32  warn   The operation was aborted
2026-06-19 14:03:32  warn   CupixAuth::handleError | Undefined response: {"stack":"AbortError: The operation was aborted ... ","cause":{"message":"Process timeout","name":"Error"},"code":"ABORT_ERR","name":"AbortError"}
2026-06-19 14:03:32  warn   BaseService::cleanUpAnythingRelatedModel | end - undefined modelDirPath
2026-06-19 14:03:32  info   AwsQueueManager::deleteMessage | begin - queue url: https://sqs.us-west-2.amazonaws.com/002596530511/cupix-capture-intelligence-agent-production.fifo
2026-06-19 14:03:32  error  AwsQueueManager::deleteMessage | end - Value AQEB... for parameter ReceiptHandle is invalid. Reason: The receipt handle has expired.
2026-06-19 14:03:32  error  BaseService::handlingMessageErrors | Error and message object - {"error":"undefined response","sqsMessage":{"MessageId":"4f9fc010-9b09-43cf-b0e0-bb2588254514","Attributes":{"ApproximateReceiveCount":"1"}}}
2026-06-19 14:07:10  info   AwsQueueManager::deleteMessage | begin - queue url: https://sqs.us-west-2.amazonaws.com/002596530511/cupix-capture-intelligence-agent-production.fifo
2026-06-19 14:07:10  info   AwsQueueManager::deleteMessage | end - message id: 4f9fc010-9b09-43cf-b0e0-bb2588254514

주목할 점:

  • ApproximateReceiveCount:"1"이지만 SQS-side에서 visibility timeout이 만료되어 receipt handle이 invalidated된 케이스. FIFO 큐의 in-flight message는 visibility 만료 시 동일 consumer-group에 재전달될 수 있고, 14:07:10에 같은 MessageId가 다른 receipt handle로 정상 삭제되었다는 사실은 재전달 후 두 번째 처리 시도가 성공했음을 의미한다.
  • sibling cluster 4d627d4a-...에서도 동일 시각의 Process timeout이 RCA되었고(root_cause_type: timeout, affected_component: CaptureIntelligenceProcessManager#analyze), 505db6d9-...BaseService#handlingMessageErrors로 RCA되어 동일 인과 사슬임이 확인된다.

Status board:

text
incident: 2026-06-19-svc-cupixworks-capture-intelligence-agent-1 (resolved)
clusters: [4d627d4a-..., 607be229-... (this), 505db6d9-...]

Hypotheses Considered#

# Hypothesis Evidence for Evidence against Verdict
H1 Python summary 프로세스 처리시간이 SQS visibility timeout(600s)을 초과하여 receipt handle 만료 후 1시간 process timeout 발동 시 expired handle로 delete 시도 동시각 CaptureIntelligenceProcessManager &#124; process timeout, aborting... 발생 (14:03:32); TIMEOUT_MS = 60 * 60 * 1000 (process.manager.ts:20); QueueVisibilityTimeout = 600 (constants.ts:3); 동일 MessageId 4f9fc010-...가 14:07:10에 재전달되어 정상 삭제됨 Confirmed
H2 BaseService::handlingMessageErrors의 receive-count 기반 삭제 결정 로직 자체 결함으로 정상 메시지가 잘못 삭제됨 sibling cluster 505db6d9-...handlingMessageErrors를 affected_component로 지목 ApproximateReceiveCount:"1"이고 동일 메시지가 4분 후 재전달 처리되어 데이터 손실 없음. handle expiration이 결과이지 원인이 아님 Rejected
H3 aws-sdk 버전 이슈 또는 일시적 AWS SQS API 장애 같은 시간대에 동일 큐로 정상 deleteMessage 다수 성공 (12:49 ~ 14:07 사이 30+건); status board상 외부 dependency 인시던트 없음 Rejected
H4 메시지가 매우 늦게 도착해 broker 측에서 이미 expired된 handle을 전달 처리 시작 시 정상 receive되었고 다른 메시지들은 정상 처리됨; 본 메시지만 1시간 process timeout 직격 Rejected

Fix Recommendation#

즉시 조치 (Critical)#

수정 대상 파일: packages/cupix-capture-intelligence-agent/src/manager/capture-intelligence-process.manager.ts:20

TIMEOUT_MS를 SQS visibility timeout과 정합되도록 600초(또는 그 이내)로 낮추거나, QueueVisibilityTimeout 상수를 process timeout(3600초)에 맞춰 상향 조정. 두 값이 어긋난 채 운영되면 처리 시간이 길어질 때 항상 receipt handle expiration이 발생한다. 어느 쪽으로 정합할지는 capture summary 분석에 실제로 필요한 시간 분포(P95/P99)를 메트릭으로 확인 후 결정한다.

수정 대상 파일: packages/base/src/base-service.ts:225-229 (deleteByMessage) 및 packages/base/src/manager/aws-queue.manager.ts:97-100

handlingMessageErrors 경로에서 receipt handle이 만료되었을 가능성이 있으므로, deleteMessage 실패가 ReceiptHandle ... has expired인 경우는 broker가 재전달하므로 무시해도 안전하다. 이 케이스를 warn 레벨로 다운그레이드하여 노이즈 알람을 줄이는 방향이 적절하다.

단기 개선 (1주 이내)#

runByMessage의 long-running 작업에 대해 처리 중 주기적으로 AwsQueueManager.changeMessageVisibility를 호출하여 visibility를 연장하는 heartbeat 로직 추가. 예: 처리 시작 직후부터 (visibility timeout / 3) 간격으로 visibility를 갱신하고, 처리 완료/실패 시 timer 정리. 이는 SQS heartbeat 패턴의 표준 적용이며, process timeout과 visibility timeout의 강결합을 끊어준다.

BaseService::getApiErrorToDeleteMessage의 AbortError 처리 분기 검토. 현재 AbortError는 response == undefined로 판정되어 'undefined response'를 반환 → 메시지 즉시 삭제 시도. 하지만 process timeout은 본질적으로 retry 가능한 일시 오류이므로, AbortError는 nodejs system error와 동일하게 undefined를 반환하여 SQS 재전달에 맡기는 편이 안전하다.

장기 개선 (재발 방지)#

  • timeout 설정값들을 @agents/shared-config로 모아 SQS visibility timeout과 process timeout, retry 정책을 한곳에서 관리하고 정합성 검증을 추가.
  • capture summary 분석 자체의 P95/P99 처리 시간을 추적하는 metric 수집(현재 trace span은 있으나 duration 메트릭 부재). 600초를 넘는 입력에 대해서는 사전에 chunking/배치 처리로 분해하는 전략 검토.

Monitoring#

추가할 알람/메트릭:

text
service:cupixworks-capture-intelligence-agent "receipt handle has expired"
text
service:cupixworks-capture-intelligence-agent "CaptureIntelligenceProcessManager | process timeout"
text
service:cupixworks-capture-intelligence-agent status:error @message:"AwsQueueManager::deleteMessage"

처리 시간 추이 추적용:

text
service:cupixworks-capture-intelligence-agent "CaptureIntelligenceService::run | end"

Risk Assessment#

  • Risk level: low (현 시점 기준)
    • SQS 자동 재전달로 데이터 손실 없이 약 4분 후 복구됨
    • 1시간 동안 단 1회 발생, 동일 패턴이 반복되면 medium으로 상향 검토
  • 예상 복잡도: standard
    • 즉시 조치(timeout 정합화 + 에러 다운그레이드)는 trivial
    • heartbeat 로직 추가는 standard 수준 (timer 관리, abort 시 cleanup 등)