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#
- 2026-06-19 13:03:24 KST —
BaseService::runByMessage | id: 717862(MessageId4f9fc010-9b09-43cf-b0e0-bb2588254514) 수신, ApproximateReceiveCount=1.CaptureIntelligenceService::run | begin - captureId: 717862, spacetimeId: 1463817실행, Pythonpython3 -m srcspawn. - 2026-06-19 13:13:24 KST (T+10m) — SQS visibility timeout 600s 경과, ReceiptHandle 무효화 (AWS 문서 기준 — 이 시점에 한해 직접 확인 로그는 없음, AWS SDK 응답으로 역추론).
- 2026-06-19 14:03:32 KST (T+60m) —
AbortSignal.timeout(TIMEOUT_MS=1h)발화:CaptureIntelligenceProcessManager | process timeout, aborting...→AbortError: The operation was aborted. - 2026-06-19 14:03:32 KST —
BaseService::handlingMessageErrors가deleteByMessage호출 →AwsQueueManager::deleteMessage가 만료된 ReceiptHandle 로 SDK 호출 →InvalidParameterValue: The receipt handle has expired(cluster505db6d9-...의 representative error). - 2026-06-19 14:03:33 KST — SQS 가 같은 메시지를 재배달, 동일 task 가
BaseService::runByMessage | id: 717862재시작. - 2026-06-19 14:07:09 KST — 재처리에서
CaptureIntelligenceProcessManager::execute | Output received - success: true로 정상 완료. - 2026-06-19 14:07:10 KST — 새 ReceiptHandle 로
AwsQueueManager::deleteMessage | end - message id: 4f9fc010-9b09-43cf-b0e0-bb2588254514정상 삭제.
Error Log#
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-115 — checkingQueue 가 SQS 에서 메시지 수신 후 runByMessages → runByMessage 호출.
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.
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.
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 = 600s 는 changeMessageVisibility 호출에 사용되는 상수이지만 — AwsQueueManager::changeMessageVisibility 는 BaseService 의 정상 흐름에서 호출되지 않는다 (Grep 결과 자체 호출 0건). 즉 메시지의 visibility 는 SQS queue 의 default 값으로만 유지된다.
Failure point: packages/base/src/manager/aws-queue.manager.ts:77-106 — abort 후 handlingMessageErrors 가 호출하는 deleteMessage.
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.
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 되었고,
DeleteMessage가InvalidParameterValue를 던진다. SQS 는delete를 받은 적이 없으므로 메시지를 다시 visible 로 만들어 재배달 —BaseService::handlingMessageErrors의 안전망 (max-receive-count 후 삭제) 효과가 사실상 우회된다.
Log Evidence#
Datadog 쿼리 (재현용):
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 변환):
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):
{
"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:20의TIMEOUT_MS와packages/base/src/config/constants.ts:3의QueueVisibilityTimeout을 일관되게 정렬: 둘 중 하나의 선택이 필요하다.- 선택지 A (권장): SQS queue 의 default visibility timeout 을
TIMEOUT_MS보다 충분히 크게 (예: 1.5h = 5400s, AWS 최대 12h) 설정. Terraformterraform/cupix-infrastructure의 capture-intelligence-agent FIFO queue resource 에서visibility_timeout_seconds를 조정. - 선택지 B:
BaseService또는CaptureIntelligenceProcessManager가 process 실행 중 주기적으로AwsQueueManager::changeMessageVisibility를 호출 (heartbeat 패턴). 약 5-8분 간격으로 갱신. 단 코드 변경 영향 큼. - 선택지 C:
TIMEOUT_MS를QueueVisibilityTimeout이하로 단축 (예: 9분). 그러나 capture summary 의 P95 처리 시간이 1-3분이지만 panos 200+ 케이스에서 더 길 수 있어 (capture 717862 의 abort 가 그 사례) summary 자체가 truncate 된다 — 권장하지 않음.
- 선택지 A (권장): SQS queue 의 default visibility timeout 을
- 본 incident 의 메시지는 자동 재배달로 자가복구되었으므로 수동 조치 불필요.
단기 개선 (1주 이내)#
BaseService::handlingMessageErrors의deleteByMessage실패 처리: 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#
sum:trace.aws.sqs.errors{service:cupixworks-capture-intelligence-agent,error_type:InvalidParameterValue}.as_count()
sum:logs{service:cupixworks-capture-intelligence-agent "process timeout, aborting"}.index("*").rollup(count, 300)
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 을 제안:
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 로 보장.