ES /docs

Value AQEBv742zXXB5AzpRv1JTEEhI6yPQZAr/J0jH4eu95Qp5bEj86DYf55dFEaywsGeDSgWGmoZMVb/ZSt1JqvSfHRp0STQ2D

RCA: SQS ReceiptHandle expired during deleteMessage in cupix-capture-intelligence-agent

Overview#

What Happened#

2026-06-19 14:03:32 KST 에 production us-west-2 의 cupixworks-capture-intelligence-agent ECS task 가 capture 717862 의 Python summary 분석 process 가 1시간 timeout 으로 abort 된 후, 만료된 SQS ReceiptHandle 로 DeleteMessage 를 호출하다 InvalidParameterValue: receipt handle has expired 로 실패했다. 동일 시점에 같은 incident scope 에서 3 개의 cluster (timeout abort, deleteMessage 실패, BaseService error handling) 가 동시에 발생했고 status board 에서 incident 2026-06-19-svc-cupixworks-capture-intelligence-agent-1 로 묶였다. 메시지는 SQS visibility timeout 만료로 자동 재배달되어 14:03:33 KST 에 같은 captureId 로 다시 처리되어 14:07:09 KST 에 정상 완료되었으므로 사용자 데이터 손실은 없다.

Quick Facts#

Field Value
exception.class AWS.SQS InvalidParameterValue
exception.message Value AQEB... for parameter ReceiptHandle is invalid. Reason: The receipt handle has expired.
top_frame packages/base/src/manager/aws-queue.manager.ts:97-100
triggering_class CaptureIntelligenceProcessManager
triggering_cause AbortError: Process timeout (TIMEOUT_MS = 60 * 60 * 1000)
queue cupix-capture-intelligence-agent-production.fifo
env production / us-west-2
MessageId 4f9fc010-9b09-43cf-b0e0-bb2588254514
captureId 717862 (spacetimeId 1463817)

Affected Teams#

Team / Domain Error Count Impact
clark-vdc / capture intelligence (LLM summary) 3 clusters (1 incident) capture 717862 1회 1차 처리 실패, 재배달로 자가복구. 사용자 가시 영향 없음.

Timeline#

  1. 2026-06-19 13:03:24 KSTBaseService::runByMessage | id: 717862 (MessageId 4f9fc010-9b09-43cf-b0e0-bb2588254514) 수신, ApproximateReceiveCount=1. CaptureIntelligenceService::run | begin - captureId: 717862, spacetimeId: 1463817 실행, Python python3 -m src spawn.
  2. 2026-06-19 13:13:24 KST (T+10m) — SQS visibility timeout 600s 경과, ReceiptHandle 무효화 (AWS 문서 기준 — 이 시점에 한해 직접 확인 로그는 없음, AWS SDK 응답으로 역추론).
  3. 2026-06-19 14:03:32 KST (T+60m)AbortSignal.timeout(TIMEOUT_MS=1h) 발화: CaptureIntelligenceProcessManager | process timeout, aborting...AbortError: The operation was aborted.
  4. 2026-06-19 14:03:32 KSTBaseService::handlingMessageErrorsdeleteByMessage 호출 → AwsQueueManager::deleteMessage 가 만료된 ReceiptHandle 로 SDK 호출 → InvalidParameterValue: The receipt handle has expired (cluster 505db6d9-... 의 representative error).
  5. 2026-06-19 14:03:33 KST — SQS 가 같은 메시지를 재배달, 동일 task 가 BaseService::runByMessage | id: 717862 재시작.
  6. 2026-06-19 14:07:09 KST — 재처리에서 CaptureIntelligenceProcessManager::execute | Output received - success: true 로 정상 완료.
  7. 2026-06-19 14:07:10 KST — 새 ReceiptHandle 로 AwsQueueManager::deleteMessage | end - message id: 4f9fc010-9b09-43cf-b0e0-bb2588254514 정상 삭제.

Error Log#

Datadog Logs

text
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 (단, 같은 incident scope 내에 3 개의 동시 발생 cluster)
  • 최초 발생: 2026-06-19 14:03:32 KST
  • 최근 발생: 2026-06-19 14:03:32 KST
  • 사용자 영향: 없음. 메시지가 SQS 자동 재배달되어 14:07:09 KST 에 정상 완료. capture/spacetime summary 가 정상 생성됨.
  • 운영 영향: Datadog status:error noise. 동일 시점 동일 cause 로 3 cluster 분기 (status board incident 2026-06-19-svc-cupixworks-capture-intelligence-agent-1).

Root Cause Summary#

SQS visibility timeout (QueueVisibilityTimeout = 600s = 10분) 보다 Python summary process 의 timeout (TIMEOUT_MS = 1h) 이 6배 길어 mismatch 가 존재한다. capture 717862 의 Python process 가 1시간 가까이 동안 출력 파일을 만들지 못해 AbortSignal.timeout 으로 abort 되었고, 이때 BaseService 의 handlingMessageErrors 가 처음 받았던 ReceiptHandle 로 DeleteMessage 를 호출했지만 그 핸들은 50분 전에 이미 만료된 상태였다. 코드는 visibility timeout 갱신 (changeMessageVisibility) 호출이 없으므로 visibility timeout 보다 오래 걸리는 process 는 항상 이 패턴으로 실패한다. 단, SQS 가 visibility 만료 후 자동 재배달하므로 메시지 자체는 손실되지 않는다 — 이번 케이스도 1초 후 같은 ECS task 가 같은 captureId 로 정상 재처리했다.

Technical Analysis#

Code Path#

Entry point: packages/base/src/base-service.ts:86-115checkingQueue 가 SQS 에서 메시지 수신 후 runByMessagesrunByMessage 호출.

packages/base/src/base-service.ts:153-191typescript
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 실행. 최대 1h 소요.
                await this.cleanUpAnythingRelatedModel();
                await this.deleteByMessage(message);  // ← 정상 흐름의 DeleteMessage
                // ...

Python process timeout: packages/cupix-capture-intelligence-agent/src/manager/capture-intelligence-process.manager.ts:20, 70-95.

packages/cupix-capture-intelligence-agent/src/manager/capture-intelligence-process.manager.ts:18-95typescript
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', [...], {
                env: process.env,
                stdio: ['ignore', 'pipe', 'pipe'],
                cwd: workDir,
                signal: abortController.signal  // ← timeout 발화 시 SIGTERM
            });
            // ...

SQS visibility timeout 설정: packages/base/src/config/constants.ts:3.

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
export const AwsS3MaxTransferSize = 10;

export const DefaultAwsQueueName = 'cupix-development';

export const DefaultDataDirName = 'json_data';

QueueVisibilityTimeout = 600schangeMessageVisibility 호출에 사용되는 상수이지만 — AwsQueueManager::changeMessageVisibilityBaseService 의 정상 흐름에서 호출되지 않는다 (Grep 결과 자체 호출 0건). 즉 메시지의 visibility 는 SQS queue 의 default 값으로만 유지된다.

Failure point: packages/base/src/manager/aws-queue.manager.ts:77-106 — abort 후 handlingMessageErrors 가 호출하는 deleteMessage.

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);
    if (queueUrl == undefined) {
        logger.error('AwsQueueManager::deleteMessage | end - undefined queueUrl');
        return reject();
    }

    const messageReceiptHandle = message && message.ReceiptHandle;
    if (messageReceiptHandle == undefined) {
        logger.error('AwsQueueManager::deleteMessage | end - undefined messageReceiptHandle');
        return reject();
    }

    const params: AWS.SQS.DeleteMessageRequest = {
        QueueUrl: queueUrl,
        ReceiptHandle: messageReceiptHandle  // ← 1시간 전에 받은 handle. 이미 만료.
    };
    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();
        }
    });
});

Error handling path: packages/base/src/base-service.ts:290-313.

packages/base/src/base-service.ts:290-313typescript
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);  // ← 만료 핸들로 호출, throw
                if (this._modelInProcess != undefined && this._modelInProcess.id > 0) await this.updateErrorState(this._modelInProcess);
            } catch (error) {
                logger.error('BaseService::handlingMessageErrors | Errors in error handling', error);
            }
        }
    }
    logger.error('BaseService::handlingMessageErrors | Error and message object - %s', JSON.stringify(errorAndMessage));
    resetLogMeta();
};

getApiErrorToDeleteMessage (lines 240-276) 는 AbortError 같이 .errno/.code/.syscall 도 없고 HTTP response 도 없는 에러를 만나면 'undefined response' 문자열을 반환 (line 252). 이 값이 apiErrorObject != undefined 조건을 통과시켜 deleteByMessage 호출로 진입한다 — 즉 timeout 같은 비-API 에러도 메시지를 즉시 삭제하려 시도하는 의도된 path 이다.

기대 동작 vs 실제 동작:

  • 기대: Python process 가 1h 내에 끝나거나, 끝나지 못할 경우 메시지 삭제로 무한 재배달을 막음.
  • 실제: visibility timeout (10분) <<< process timeout (1시간). 따라서 process timeout 시점에서는 ReceiptHandle 이 이미 50분 전에 expire 되었고, DeleteMessageInvalidParameterValue 를 던진다. SQS 는 delete 를 받은 적이 없으므로 메시지를 다시 visible 로 만들어 재배달 — BaseService::handlingMessageErrors 의 안전망 (max-receive-count 후 삭제) 효과가 사실상 우회된다.

Log Evidence#

Datadog 쿼리 (재현용):

text
service:cupixworks-capture-intelligence-agent ("run | begin" OR "Output received" OR "process timeout" OR "process error" OR "deleteMessage" OR "ReceiptHandle")

시간 범위: 2026-06-19T03:00:00Z ~ 2026-06-19T05:30:00Z.

핵심 타임라인 로그 (UTC → KST 변환):

text
2026-06-19 13:03:24 KST   info   BaseService::runByMessage | id: 717862
2026-06-19 13:03:24 KST   info   CaptureIntelligenceService::run | begin - captureId: 717862, spacetimeId: 1463817, type: cupixworks
2026-06-19 13:03:24 KST   info   CaptureIntelligenceProcessManager::execute | captureId: 717862, ...
2026-06-19 13:03:24 KST   info   CaptureIntelligenceProcessManager::runPythonProcess | executing: python3 -m src --input ...
... (이후 1 시간 동안 동일 ECS task 의 capture-intelligence Python 출력 없음)
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   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 KST   error  AwsQueueManager::deleteMessage | end - Value AQEB... for parameter ReceiptHandle is invalid. Reason: The receipt handle has expired.
2026-06-19 14:03:32 KST   error  BaseService::handlingMessageErrors | Error and message object - {"error":"undefined response","sqsMessage":{"MessageId":"4f9fc010-9b09-43cf-b0e0-bb2588254514","Attributes":{"ApproximateReceiveCount":"1"}}}
2026-06-19 14:03:33 KST   info   BaseService::runByMessage | id: 717862        ← SQS 자동 재배달 (ReceiveCount=2)
2026-06-19 14:07:09 KST   info   CaptureIntelligenceProcessManager::execute | Output received - success: true
2026-06-19 14:07:10 KST   info   AwsQueueManager::deleteMessage | end - message id: 4f9fc010-9b09-43cf-b0e0-bb2588254514

Abort error 본문 (raw):

json
{
  "stack": "AbortError: The operation was aborted\n    at abortChildProcess (node:child_process:725:27)\n    ...",
  "message": "The operation was aborted",
  "cause": {
    "stack": "Error: Process timeout\n    at timeoutSignal.addEventListener.once (/tmp/agent/dist/app.cjs:6485:31)\n    ...",
    "message": "Process timeout",
    "name": "Error"
  },
  "code": "ABORT_ERR",
  "name": "AbortError"
}

cause.message: "Process timeout"AbortSignal.timeout(TIMEOUT_MS) 발화임을 단정 — TIMEOUT_MS = 60 * 60 * 1000 코드 상수와 정확히 일치 (handle 수신 13:03:24 → abort 14:03:32, +60m 8s).

ApproximateReceiveCount=1: 위의 handlingMessageErrors 로그가 Attributes.ApproximateReceiveCount=1 를 보여준다 — 즉 max-receive-count (10) 의 안전망은 발동되지 않은 상태였다. 안전망이 의도한대로 작동하려면 메시지 삭제가 성공해야 하는데 핸들이 만료되어 삭제도 실패했다.

상태 board correlation: incident 2026-06-19-svc-cupixworks-capture-intelligence-agent-1 가 같은 ms 단위 (2026-06-19T05:03:32.870/.903/.904Z) 에 3 cluster (4d627d4a-..., 607be229-..., 505db6d9-...) 를 묶었다 — 모두 동일한 abort/delete 실패 시퀀스의 다른 로그 라인에서 파생된 것으로 추정.

Hypotheses Considered#

# Hypothesis Evidence for Evidence against Verdict
H1 Python summary process 가 1h TIMEOUT_MS 로 abort 된 후, 만료된 ReceiptHandle 로 DeleteMessage 가 호출되어 SQS InvalidParameterValue 를 받았다 (visibility timeout 600s ≪ process timeout 3600s). 로그: 13:03:24 KST runByMessage id 717862 → 14:03:32 KST process timeout, aborting... (+60m). cause.message: "Process timeout". QueueVisibilityTimeout=600 (constants.ts:3) vs TIMEOUT_MS=60*60*1000 (process.manager.ts:20). changeMessageVisibility 호출이 정상 흐름에 없음 (Grep 결과). Confirmed
H2 AWS SQS 또는 us-west-2 region 의 일시 장애. Status board scope 가 svc:cupixworks-capture-intelligence-agent (외부 dep 가 아닌 service-internal). AwsQueueManager::deleteMessage 의 다른 호출 (13:32:21, 13:48:21, 13:51:49 등) 모두 정상 응답. AWS 에러 메시지가 region/throttle/network 가 아닌 정확한 ReceiptHandle is invalid. Reason: The receipt handle has expired. 로 deterministic. Rejected
H3 같은 메시지를 두 task 가 동시에 처리해서 한 쪽 receipt 가 다른 쪽에서 invalidate 되었다 (FIFO group concurrency). FIFO queue 사용 (...intelligence-agent-production.fifo). FIFO + MessageGroupId=capture_id 로 동일 group 동시 처리 불가. ApproximateReceiveCount=1 은 첫 수신을 의미하며, 14:03:33 의 재배달도 같은 task 가 처리. 이중 처리 흔적 없음. Rejected
H4 LLM/외부 API 가 hang 해서 Python 이 1시간 내내 응답 대기. cause.message: "Process timeout" (AbortSignal.timeout 발화). 1시간 동안 CaptureIntelligenceProcess 출력 로그가 보이지 않음 (위 timeline 참고). Python 내부 동작은 Datadog 에서 보이지 않아 trigger 측면은 inconclusive. 단 본 RCA 의 root cause (ReceiptHandle 만료) 는 trigger 와 독립적으로 visibility/process timeout mismatch 라는 구조적 결함에서 발생. Inconclusive (보조 가설; H1 의 root cause 와 무관)

Fix Recommendation#

즉시 조치 (Critical)#

  • packages/cupix-capture-intelligence-agent/src/manager/capture-intelligence-process.manager.ts:20TIMEOUT_MSpackages/base/src/config/constants.ts:3QueueVisibilityTimeout 을 일관되게 정렬: 둘 중 하나의 선택이 필요하다.
    • 선택지 A (권장): SQS queue 의 default visibility timeout 을 TIMEOUT_MS 보다 충분히 크게 (예: 1.5h = 5400s, AWS 최대 12h) 설정. Terraform terraform/cupix-infrastructure 의 capture-intelligence-agent FIFO queue resource 에서 visibility_timeout_seconds 를 조정.
    • 선택지 B: BaseService 또는 CaptureIntelligenceProcessManager 가 process 실행 중 주기적으로 AwsQueueManager::changeMessageVisibility 를 호출 (heartbeat 패턴). 약 5-8분 간격으로 갱신. 단 코드 변경 영향 큼.
    • 선택지 C: TIMEOUT_MSQueueVisibilityTimeout 이하로 단축 (예: 9분). 그러나 capture summary 의 P95 처리 시간이 1-3분이지만 panos 200+ 케이스에서 더 길 수 있어 (capture 717862 의 abort 가 그 사례) summary 자체가 truncate 된다 — 권장하지 않음.
  • 본 incident 의 메시지는 자동 재배달로 자가복구되었으므로 수동 조치 불필요.

단기 개선 (1주 이내)#

  • BaseService::handlingMessageErrorsdeleteByMessage 실패 처리: ReceiptHandle 만료 에러 (InvalidParameterValue + expired) 를 별도로 분기하여 logger.warn 으로 다운그레이드 (이 케이스는 SQS 가 자동 재배달하므로 메시지 손실이 없고 status:error noise 만 발생).
  • Status board 가 같은 cause 로 3 cluster 를 묶었다는 건 fingerprint 가 너무 좁다는 신호 — error-sweeper/lib/classifier 의 fingerprint 가 ReceiptHandle base64 값을 그대로 포함하지 않는지 확인. (각 메시지마다 다른 receipt 값이 noise 생성.)

장기 개선 (재발 방지)#

  • Capture summary Python pipeline 의 P95/P99 latency 메트릭화 (현재는 1h timeout 까지 가는 케이스가 sampling 안 됨). 1h 는 너무 관대 — Python 이 진짜 hang 하면 worker pool 1개를 1시간 묶음.
  • Heartbeat-based visibility timeout 패턴을 BaseService 추상에 도입해 cupix-tesla-compute-agent, cupix-tesla-forge-agent, cupix-si-lite-agent 등 동일 구조의 다른 agent (Grep 결과 7+ 개) 에 일관되게 적용 — 이들도 같은 mismatch 를 갖고 있어 langer-running job 에서 동일 패턴 재발 가능.

Monitoring#

text
sum:trace.aws.sqs.errors{service:cupixworks-capture-intelligence-agent,error_type:InvalidParameterValue}.as_count()
text
sum:logs{service:cupixworks-capture-intelligence-agent "process timeout, aborting"}.index("*").rollup(count, 300)
text
sum:logs{service:cupixworks-capture-intelligence-agent "receipt handle has expired"}.index("*").rollup(count, 300)

이 세 쿼리를 release dashboard timeseries widget 에 적재해 (1) Python 1h timeout 발생 빈도, (2) ReceiptHandle 만료 deleteMessage 실패 빈도, (3) 둘의 correlation 을 추적. 두 카운트가 1:1 로 일치하면 mismatch 가 fix 되지 않았다는 신호.

추가로 capture summary 처리 시간 histogram 을 제안:

text
avg:trace.python.duration{service:capture-summary,resource_name:generate_works_capture_summary_with_video}

(uncertain — capture-summary Python 서비스가 Datadog tracing 송신 여부는 검증 필요.)

Risk Assessment#

  • Risk level: low (자동 재배달로 사용자 영향 없음, 단 status:error noise 발생).
  • 예상 복잡도: standard (선택지 A 는 Terraform 1 줄 변경, 선택지 B 는 BaseService 추상 변경으로 7+ agent 영향).
  • Blast radius: 단일 capture 처리 1회 지연 + Datadog noise. 메시지 자체는 SQS 의 redelivery 로 보장.