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#
- 2026-06-19 13:0x KST 부근 — Python summary 분석 프로세스 spawn (capture summary 작업)
- 2026-06-19 14:03:32 KST —
CaptureIntelligenceProcessManager | process timeout, aborting...(TIMEOUT_MS = 1시간 도달) - 2026-06-19 14:03:32 KST —
CaptureIntelligenceProcess | process error: The operation was aborted - 2026-06-19 14:03:32 KST —
CupixAuth::handleError | Undefined response: AbortError ... Process timeout - 2026-06-19 14:03:32 KST —
BaseService::handlingMessageErrors가deleteByMessage호출 (ApproximateReceiveCount=1) - 2026-06-19 14:03:32 KST —
AwsQueueManager::deleteMessage | end - ... receipt handle has expired(본 cluster의 root error log) - 2026-06-19 14:07:10 KST — 동일 MessageId
4f9fc010-...SQS 재전달 후 정상 처리 완료 (deleteMessage | end - message id: 4f9fc010-9b09-43cf-b0e0-bb2588254514)
Error Log#
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::handlingMessageErrors → deleteByMessage 경로에서 이미 만료된 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) → runByMessages → runByMessage.
처리 루프는 SQS에서 메시지를 받아 1건씩 runByMessage에서 실행하고, 성공 시 deleteByMessage를 호출한다.
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을 건다.
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 흐름에서 호출되지 않음).
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 경로가 발동한다.
} 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가 호출된다.
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
}
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-105 — sqs.deleteMessage가 만료된 ReceiptHandle을 거부한다.
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 쿼리:
service:cupixworks-capture-intelligence-agent (status:error OR status:warn)
시간 범위: 2026-06-19T03:30:00Z ~ 2026-06-19T05:10:00Z
service:cupixworks-capture-intelligence-agent "AwsQueueManager::deleteMessage"
시간 범위: now-2h
핵심 로그(시간순):
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:
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 | 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#
추가할 알람/메트릭:
service:cupixworks-capture-intelligence-agent "receipt handle has expired"
service:cupixworks-capture-intelligence-agent "CaptureIntelligenceProcessManager | process timeout"
service:cupixworks-capture-intelligence-agent status:error @message:"AwsQueueManager::deleteMessage"
처리 시간 추이 추적용:
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 등)