CompleteService::handlingMessageErrors | Error and message object - {"sqsMessage":{"MessageId":"7feb
RCA: CompleteService::handlingMessageErrors | InvalidState (STAT40000) 및 SQS MaxReceiveCount 초과
Overview#
What Happened#
2026-04-23 08:00~09:00 UTC 시간대에 cupixworks-any-complete-agent 서비스에서 CompleteService::handlingMessageErrors 에러가 7건 발생했다. 에이전트가 Tesla API로 job 상태 전이(PUT /api/v1/jobs/{id})를 요청했으나, 해당 job이 이미 목표 상태에 도달해 있어 Cupix::Errors::InvalidState (STAT40000, "State not changed") 400 응답을 받았다. 일부 케이스에서는 504 Gateway Timeout이 선행되어 후속 재시도에서 idempotent하지 않은 상태 전이가 실패하는 연쇄 패턴이 확인되었다. 대표 에러(MessageId 7feb8cfe)는 error 객체 없이 ApproximateReceiveCount: 11로 MaxReceiveCount(10)를 초과하여 삭제된 케이스이다.
Quick Facts#
| Field | Value |
|---|---|
| exception.class | Cupix::Errors::InvalidState |
| exception.message | State not changed |
| top_frame | base-service.ts:311 (handlingMessageErrors) |
| env | production, us-west-2 |
Timeline#
- 2026-04-23 08:09:37 UTC — Job 1030983 최초
STAT40000에러 발생 (ReceiveCount: 6) - 2026-04-23 08:13:35 UTC — Job 1031025 504 Gateway Timeout 발생 (ReceiveCount: 8)
- 2026-04-23 08:14:54 UTC — Job 1031025
STAT40000에러 발생 (ReceiveCount: 10) — 이전 504에서 실제 상태는 변경됐지만 에이전트가 인지하지 못해 재시도 - 2026-04-23 08:28:33 UTC — MessageId
7feb8cfeerror 객체 없이 ReceiveCount 11로 삭제됨 (대표 에러) - 2026-04-23 08:40:57 UTC — Job 1031095
STAT40000에러 발생 (ReceiveCount: 2~3)
Error Log#
CompleteService::handlingMessageErrors | Error and message object - {"sqsMessage":{"MessageId":"7feb8cfe-a9c8-4e5a-b6ff-dfa65bed142a","Attributes":{"ApproximateReceiveCount":"11"}}}
Impact#
- Service:
cupixworks-any-complete-agent - 발생 횟수: 7건 (2시간 윈도우 내)
- 최초 발생: 2026-04-23T08:09:37Z
- 최근 발생: 2026-04-23T08:41:03Z
- 영향 범위: Job 3건(1030983, 1031025, 1031095) + 미확인 1건(MessageId
7feb8cfe). job 상태 전이 에러이므로 후속 callback (jobable 상태 업데이트)에 영향이 있을 수 있으나,handlingMessageErrors에서 메시지 삭제 +updateErrorState호출로 에러 상태 복구가 이루어짐.
Root Cause Summary#
complete-agent가 SQS 메시지를 수신하여 job 처리를 완료한 후 Tesla API에 상태 전이를 요청하는 과정에서, job이 이미 목표 상태에 있으면 Tesla API가 STAT40000 InvalidState "State not changed" 에러를 반환한다. 이는 Parameter::Job#set_parameters(tesla/app/concerns/parameter/job.rb:37-53)에서 현재 상태와 요청 상태가 동일한 경우 idempotent하게 처리하지 않고 에러를 발생시키기 때문이다. 특히 504 Gateway Timeout이 먼저 발생한 경우, 서버 측에서는 상태 변경이 이미 커밋되었지만 응답이 타임아웃되어 에이전트가 실패로 인식하고 재시도하면서 "이미 변경된 상태"에 대해 STAT40000 에러를 받게 되는 연쇄 패턴이 발생한다.
대표 에러(MessageId 7feb8cfe)는 error 객체가 undefined인데, 이는 BaseService.getApiErrorToDeleteMessage가 undefined 에러를 받아 'undefined error' 문자열을 반환하여 truthy로 평가되면서 메시지가 삭제된 케이스이다. ReceiveCount가 11로 MaxReceiveCount(10)를 이미 초과한 상태이므로, checkReceiveCountToDeleteMessage에서도 삭제 조건이 충족된다.
Technical Analysis#
Code Path#
1. Entry point — SQS 메시지 수신 및 처리:
BaseService.checkingQueue가 SQS에서 메시지를 가져와 runByMessages를 호출한다.
} else {
this._countWaitedToStopTask = 0;
try {
await this.runByMessages();
} catch (error) {
await this.handlingMessageErrors(error);
}
this.resetMessages();
await CPUtils.sleep(500);
await this.checkingQueue();
}
2. 메시지 처리 — runByMessage:
각 메시지에 대해 인증, run() 실행, 정리, 삭제를 수행한다. run() 내부에서 JobManager.updateCompleteActionJob을 통해 Tesla API에 job 상태 업데이트 PUT을 호출한다.
try {
this.reset();
const res = await this.cupixApi.job.update(jobId, {
progress: 100,
state: state,
processing_status: actionName,
});
if (this.updateActionJob) {
await this.cupixApi.job.completeAction(jobId, actionName);
}
logger.debug('JobManager::updateCompleteActionJob | end - progress: %d, status: %s', res.progress, res.processing_status);
} catch (error) {
logger.warn('JobManager::updateCompleteActionJob | end - %s', error);
}
3. Tesla API 상태 전이 거부 — Parameter::Job#set_parameters:
Tesla API의 job 업데이트 핸들러에서 요청된 상태가 현재 상태와 동일하면 STAT40000 에러를 발생시킨다.
begin
if params[:state].present?
case params[:state]
when 'pending'
raise Cupix::Errors::InvalidState.new(code: 'STAT40000', reason: 'State not changed') if @model.pending?
@model.pending_state!
when 'starting'
raise Cupix::Errors::InvalidState.new(code: 'STAT40000', reason: 'State not changed') if @model.starting?
@model.starting_state!
when 'running'
raise Cupix::Errors::InvalidState.new(code: 'STAT40000', reason: 'State not changed') if @model.running?
@model.running_state!
when 'stopping'
raise Cupix::Errors::InvalidState.new(code: 'STAT40000', reason: 'State not changed') if @model.stopping?
@model.stopping_state!
when 'stopped'
raise Cupix::Errors::InvalidState.new(code: 'STAT40000', reason: 'State not changed') if @model.stopped?
@model.stopped_state!
else
raise Cupix::Errors::InvalidState.new(code: ' STAT10000', reason: "Invalid state: #{params[:state]}")
end
end
rescue StateMachines::InvalidTransition => e
raise Cupix::Errors::InvalidState.new(code: 'STAT10000', reason: e.to_s, message: e.message)
end
4. Failure point — handlingMessageErrors:
에러가 발생하면 getApiErrorToDeleteMessage에서 HTTP 상태코드가 400~500 범위(401 제외)인지 확인한다. 400은 이 범위에 해당하므로 메시지 삭제 + updateErrorState 호출이 실행된다.
if (statusCode != undefined && statusCode >= 400 && statusCode <= 500) {
if (statusCode === 401) return;
return errorMsg;
}
return;
504(Gateway Timeout)는 이 범위를 벗어나므로 (statusCode > 500) 메시지가 삭제되지 않고 SQS에 남아 재시도된다. 이 재시도에서 이미 서버가 상태를 변경한 상태이므로 STAT40000을 받게 된다.
5. 대표 에러의 undefined error 처리:
private getApiErrorToDeleteMessage = (error: any): any => {
if (error == undefined) {
logger.warn('BaseService::getApiErrorToDeleteMessage | undefined error');
return 'undefined error';
}
error가 undefined일 때 문자열 'undefined error'를 반환하여 truthy로 평가 → 메시지 삭제가 진행된다. 동시에 checkReceiveCountToDeleteMessage에서 ReceiveCount(11) >= MaxReceiveCount(10)이므로 역시 삭제 조건이 충족된다.
Log Evidence#
Datadog 쿼리:
service:cupixworks-any-complete-agent status:error "CompleteService::handlingMessageErrors"
패턴 1: 504 Timeout 후 STAT40000 연쇄 에러 (Job 1031025)
504가 먼저 발생한 후, 동일 SQS 메시지가 재시도되면서 STAT40000 에러가 발생했다:
{
"timestamp": "2026-04-23 17:13:35 KST",
"status": "error",
"message": "CompleteService::handlingMessageErrors | Error and message object - {\"error\":{\"response\":{\"statusCode\":504},\"body\":{},\"statusCode\":504,\"name\":\"HttpError\"},\"sqsMessage\":{\"MessageId\":\"2438e2e9-577f-44aa-9233-4ecb143e4dd3\",\"Attributes\":{\"ApproximateReceiveCount\":\"8\"}}}"
}
{
"timestamp": "2026-04-23 17:14:54 KST",
"status": "error",
"message": "CompleteService::handlingMessageErrors | Error and message object - {\"error\":{\"statusCode\":400,\"bodyResult\":{\"code\":\"STAT40000\",\"type\":\"Cupix::Errors::InvalidState\",\"reason\":\"State not changed\"}},\"sqsMessage\":{\"MessageId\":\"2438e2e9-577f-44aa-9233-4ecb143e4dd3\",\"Attributes\":{\"ApproximateReceiveCount\":\"10\"}}}"
}
패턴 2: undefined error + MaxReceiveCount 초과 (대표 에러)
error 객체 없이 ReceiveCount 11로 메시지가 삭제됨:
{
"timestamp": "2026-04-23 17:28:33 KST",
"status": "error",
"message": "CompleteService::handlingMessageErrors | Error and message object - {\"sqsMessage\":{\"MessageId\":\"7feb8cfe-a9c8-4e5a-b6ff-dfa65bed142a\",\"Attributes\":{\"ApproximateReceiveCount\":\"11\"}}}"
}
이 메시지의 삭제 확인 로그:
2026-04-23 17:28:33 KST | info | AwsQueueManager::deleteMessage | end - message id: 7feb8cfe-a9c8-4e5a-b6ff-dfa65bed142a
패턴 3: 반복 수신 후 STAT40000 (Job 1030983, 1031095)
Job 1030983은 ReceiveCount 6에서, Job 1031095는 ReceiveCount 2~3에서 STAT40000이 발생. 이는 에이전트가 SQS 메시지를 수신하고 처리를 시도하는 동안 다른 에이전트 인스턴스나 이전 시도에서 이미 job을 완료한 경우에 해당한다.
Hypotheses Considered#
| # | Hypothesis | Evidence for | Evidence against | Verdict |
|---|---|---|---|---|
| H1 | 504 Timeout 후 서버 측 상태 변경이 커밋되어 재시도 시 STAT40000 발생 | Job 1031025: 08:13:35 UTC 504 발생(ReceiveCount 8) → 08:14:54 UTC STAT40000(ReceiveCount 10). 동일 MessageId 2438e2e9에서 504 후 400 순서로 에러 발생. getApiErrorToDeleteMessage에서 504는 statusCode > 500이므로 메시지 미삭제 → 재시도 |
— | Confirmed |
| H2 | 동일 job에 대한 중복 SQS 메시지로 인한 경합 | Job 1031095에서 동일 시각(17:40:52)에 runByMessage info 로그가 2건 중복 기록됨. ReceiveCount 2~3의 서로 다른 MessageId(7bebcac9, 498fd737)에서 동일 job에 대해 STAT40000 발생 |
이는 504 후 재시도 패턴과는 별개의 원인 | Confirmed (보조 원인) |
| H3 | Tesla API의 job 상태 전이가 idempotent하지 않음 | parameter/job.rb:37-53: 현재 상태와 요청 상태 동일 시 에러 발생 (예: if @model.stopped? → raise). Idempotent 설계라면 동일 상태 요청은 무시하고 성공 응답을 반환해야 함 |
Tesla API의 의도적 설계일 수 있음 (state 변경 추적 목적) | Confirmed (근본 원인) |
| H4 | 에이전트 코드 버그로 error 객체가 undefined | 대표 에러(MessageId 7feb8cfe)에서 error 필드가 없음. handlingMessageErrors에서 errorAndMessage.error = apiErrorObject로 덮어쓰는데, getApiErrorToDeleteMessage가 'undefined error' 반환 시 errorAndMessage.error도 이 문자열로 대체됨. 그러나 로그에는 error 키 자체가 없으므로, catch된 원본 error가 undefined였을 가능성 |
JSON.stringify에서 undefined 값은 생략됨 — 원본 error가 undefined이면 error 키가 출력되지 않음. ReceiveCount 11에서 checkReceiveCountToDeleteMessage가 true → 메시지 삭제 |
Confirmed (특수 케이스) |
Fix Recommendation#
즉시 조치 (Critical)#
- 에러 레벨 하향 검토:
base-service.ts:311의handlingMessageErrors에러 로그에서,STAT40000(State not changed)은 예상 가능한 운영 시나리오이므로error가 아닌warn레벨로 변경하는 것이 적절하다. 이를 통해 불필요한 에러 알림을 줄일 수 있다.
단기 개선 (1주 이내)#
- 504 Timeout 시 재시도 전 상태 확인:
handlingMessageErrors에서 504 에러를 받은 경우, 재시도 전에 Tesla API로 job 현재 상태를 GET으로 확인하고, 이미 목표 상태에 도달한 경우 메시지를 삭제하도록 로직을 추가한다. 이렇게 하면 504 → STAT40000 연쇄 에러를 방지할 수 있다. - Tesla API idempotent 상태 전이:
tesla/app/concerns/parameter/job.rb:37-53에서 현재 상태와 요청 상태가 동일한 경우 에러 대신 성공 응답(현재 상태 반환)으로 처리하는 것이 분산 시스템에서의 모범 사례이다. 이는 에이전트뿐만 아니라 모든 API 클라이언트의 재시도 안정성을 향상시킨다.
장기 개선 (재발 방지)#
- SQS 메시지 처리의 at-least-once 패턴 강화: 에이전트가 동일 job에 대해 여러 SQS 메시지를 수신할 수 있으므로, job 처리 시작 시 현재 상태를 확인하고 이미 완료된 job은 메시지만 삭제하는 방어적 패턴을 적용한다.
- Dead Letter Queue (DLQ) 활용: MaxReceiveCount 초과 시 에이전트 내 코드에서 삭제하는 것보다 SQS DLQ로 이동시키는 것이 더 안전하며, 추후 분석 및 재처리가 가능하다.
Monitoring#
- STAT40000 에러의 빈도를 추적하여 급증 시 알림:
service:cupixworks-any-complete-agent status:error "STAT40000"
- 504 Timeout 발생 빈도 모니터링:
service:cupixworks-any-complete-agent "statusCode\":504"
- MaxReceiveCount 초과로 삭제되는 메시지 건수 추적:
service:cupixworks-any-complete-agent "checkReceiveCountToDeleteMessage" "receive count"
Risk Assessment#
- Risk level: low
- 예상 복잡도: standard
- 근거: 에러 발생 시
handlingMessageErrors에서 메시지 삭제 및updateErrorState호출로 복구가 이루어지고 있다. job 상태가 이미 목표에 도달한 경우이므로 데이터 손실이나 사용자 영향은 없다. 다만, 반복적인 SQS 재시도로 인한 불필요한 API 호출과 에러 노이즈가 운영 가시성을 저하시킬 수 있다.