CompleteService::handlingMessageErrors | Error and message object - {"error":{"statusCode":400,"requ

RCA: CompleteService::handlingMessageErrors | InvalidState - State not changed

Overview#

What Happened#

2026-04-23 08:40~~08:41 UTC, cupixworks-any-complete-agent 서비스에서 job 완료 처리 중 Tesla API가 400 InvalidState ("State not changed") 에러를 반환했다. job 1031095에 대해 SQS 메시지가 2~~3회 재시도되었으며, 같은 시간대에 job 1031025, 1030983에서도 동일한 에러가 발생했다.

Quick Facts#

Field	Value
exception.class	`Cupix::Errors::InvalidState`
exception.message	`State not changed`
top_frame	`app/concerns/parameter/job.rb:52-53`
env	production, us-west-2

Timeline#

08:39:30 UTC — CompleteService가 job 1031095에 대한 SQS 메시지 수신 시작 (runByMessage | id: 1031095)
08:40:03 UTC — 추가 메시지 수신 (ApproximateReceiveCount 증가)
08:40:52 UTC — 두 건의 runByMessage 동시 처리 시도
08:40:57 UTC — 첫 번째 에러 발생 (ReceiveCount: 3) — job이 이미 stopped 상태
08:41:03 UTC — 두 번째 에러 발생 (ReceiveCount: 2, 다른 MessageId) — 동일한 "State not changed" 에러

Error Log#

Datadog Logs

text

CompleteService::handlingMessageErrors | Error and message object - {"error":{"statusCode":400,"requestUriHref":"http://api-tesla.cupix.internal/api/v1/jobs/1031095?fields%5B0%5D=id&fields%5B1%5D=kind&fields%5B2%5D=state&fields%5B3%5D=error_code&fields%5B4%5D=progress&fields%5B5%5D=processing_status&fields%5B6%5D=jobable&fields%5B7%5D=option&fields%5B8%5D=process_option&fields%5B9%5D=node&fields%5B10%5D=created_at&fields%5B11%5D=updated_at","bodyResult":{"code":"STAT40000","type":"Cupix::Errors::InvalidState","reason":"State not changed","message":"State not changed"}},"sqsMessage":{"MessageId":"498fd737-f494-4977-97bf-c04d32f984f0","Attributes":{"ApproximateReceiveCount":"3"}}}

Impact#

Service: cupixworks-any-complete-agent
발생 횟수: 2 (이 클러스터), 동일 시간대 총 7건 (job 1031095, 1031025, 1030983 포함)
최초 발생: 2026-04-23T08:40:57.877Z
최근 발생: 2026-04-23T08:41:03.965Z

Root Cause Summary#

Complete-agent가 SQS 메시지를 받아 job 상태를 전이시키는 PUT /api/v1/jobs/{id} 요청을 보내지만, 해당 job이 이미 목표 상태(예: stopped)에 있을 때 Tesla API의 idempotency guard가 400 InvalidState 에러를 반환한다. 이는 SQS의 at-least-once 전달 특성 또는 동시에 여러 consumer가 같은 job을 처리하면서 발생하는 정상적인 경쟁 조건이다. BaseService.handlingMessageErrors는 이 에러를 올바르게 처리(SQS 메시지 삭제)하지만, error 레벨로 로깅하여 불필요한 에러 노이즈를 생성한다.

Technical Analysis#

Code Path#

Entry point: BaseService.runByMessage — SQS 메시지를 파싱하고 run(targetId, msgObject)를 호출

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);
        const targetId = Environment.DEBUG_MODE && Environment.CPX_MODEL_ID ? Environment.CPX_MODEL_ID : (msgObject.id ?? msgObject.model?.id);
        // ...
        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);       // ← 여기서 에러 발생
                await this.cleanUpAnythingRelatedModel();
                await this.deleteByMessage(message);
            });
        } catch (error) {
            TraceUtils.finishSpan(span, false, error);
            throw error;  // ← handlingMessageErrors로 전파
        }
    }
};

run() 구현체에서 job.update() 호출 시 Tesla API에 PUT /api/v1/jobs/{id} 요청을 보냄

packages/api/src/api/job.api.ts:17-22typescript

@SkipInDebug()
async update(id: number, body: TESLA.UpdateJobRequest): Promise<TESLA.Job> {
    const api = await this.api();
    const res = await api.updateJob(id, Fields.JobFields, body);  // ← fields가 query param으로 전달
    return unwrapAttributes(res);
}

Failure point: Tesla API의 parameter/job.rb — job이 이미 목표 상태일 때 InvalidState 에러를 발생시키는 idempotency guard

app/concerns/parameter/job.rb:33-58ruby

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

Error handler: BaseService.handlingMessageErrors — 400 에러이므로 getApiErrorToDeleteMessage가 에러 객체를 반환하고, SQS 메시지를 삭제한 후 error 레벨로 로깅

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);  // ← 메시지 삭제 (올바른 동작)
                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));  // ← error 레벨 로깅
};

SQS 메시지 삭제 판단: getApiErrorToDeleteMessage는 statusCode >= 400 && statusCode <= 500 (401 제외) 조건에서 삭제를 결정

packages/base/src/base-service.ts:270-274typescript

if (statusCode != undefined && statusCode >= 400 && statusCode <= 500) {
    if (statusCode === 401) return;  // 401은 재시도
    return errorMsg;  // ← 400 InvalidState는 여기서 삭제 결정
}

기대 동작: Job이 이미 목표 상태에 있으면 API가 200을 반환하거나, 최소한 agent가 "State not changed"를 정상 완료로 간주해야 함.

실제 동작: Tesla API가 400 에러를 반환하고, agent의 handlingMessageErrors가 이를 error로 로깅. SQS 메시지 삭제는 정상적으로 수행되어 실제 데이터 영향은 없음.

Log Evidence#

Datadog 검색 쿼리:

text

service:cupixworks-any-complete-agent status:error "CompleteService::handlingMessageErrors"

Job 1031095의 전체 처리 타임라인 (검색 쿼리: service:cupixworks-any-complete-agent 1031095):

text

08:39:30 [info]  CompleteService::runByMessage | id: 1031095
08:40:03 [info]  CompleteService::runByMessage | id: 1031095
08:40:52 [info]  CompleteService::runByMessage | id: 1031095
08:40:52 [info]  CompleteService::runByMessage | id: 1031095
08:40:57 [warn]  CupixAuth::handleError | Response statusCode: 400, requestUriHref: .../jobs/1031095...
08:40:57 [warn]  CompleteService::getApiErrorToDeleteMessage | error msg - {"statusCode":400,...,"bodyResult":{"code":"STAT40000","type":"Cupix::Errors::InvalidState","reason":"State not changed"}}
08:40:57 [error] CompleteService::handlingMessageErrors | Error and message object - {...,"sqsMessage":{"MessageId":"498fd737-...","Attributes":{"ApproximateReceiveCount":"3"}}}
08:41:03 [warn]  CupixAuth::handleError | Response statusCode: 400, requestUriHref: .../jobs/1031095...
08:41:03 [warn]  CompleteService::getApiErrorToDeleteMessage | error msg - {"statusCode":400,...}
08:41:03 [error] CompleteService::handlingMessageErrors | Error and message object - {...,"sqsMessage":{"MessageId":"7bebcac9-...","Attributes":{"ApproximateReceiveCount":"2"}}}

동일 시간대 다른 job에서도 같은 에러 패턴 발생 (504 timeout → 재시도 → 400 State not changed):

text

08:09:37 [error] job 1030983 — State not changed (ReceiveCount: 6)
08:13:35 [error] job 1031025 — 504 Gateway Time-out (ReceiveCount: 8)
08:14:54 [error] job 1031025 — State not changed (ReceiveCount: 10)
08:15:08 [error] job 1031025 — State not changed (ReceiveCount: 9)

핵심 패턴: job 1031025는 08:13:35에 504 timeout을 받았는데, 이 timeout 동안 서버 측에서는 상태 전이가 성공적으로 완료되었을 가능성이 높다. 이후 재시도 시 이미 상태가 변경된 상태이므로 "State not changed" 에러가 발생했다. 이는 전형적인 timeout-then-idempotent-retry 패턴이다.

Hypotheses Considered#

#	Hypothesis	Evidence for	Evidence against	Verdict
H1	SQS at-least-once 전달로 인한 중복 처리: 이미 상태 전이가 완료된 job에 대해 중복 메시지가 다시 처리됨	job 1031095: 08:39:30부터 4회 `runByMessage` 호출, 서로 다른 MessageId 2개에서 에러 발생. job 1031025: 504 timeout 후 재시도 시 "State not changed" 에러	—	Confirmed
H2	잘못된 상태 전이 요청: agent가 유효하지 않은 상태 전이를 시도	—	에러 코드가 `STAT40000` ("State not changed")이지 `STAT10000` ("Invalid transition")이 아님. `parameter/job.rb:35-55`에서 `STAT40000`은 동일 상태 요청 시에만 발생. 또한 `stopped_state!`는 `transition any => :stopped`로 모든 상태에서 전이 가능	Rejected
H3	API 서버 과부하로 인한 504 timeout 후 실제 처리 성공: 504를 받은 후 재시도하지만 서버 측에서는 이미 처리 완료	job 1031025: 08:13:35에 504 timeout 발생 후, 08:14:54~08:15:08에 "State not changed" 에러. 504는 nginx gateway timeout으로 서버 측 처리는 완료되었을 수 있음	—	Confirmed

Fix Recommendation#

즉시 조치 (Critical)#

BaseService.handlingMessageErrors (packages/base/src/base-service.ts:311): STAT40000 ("State not changed") 에러는 error 대신 warn 레벨로 로깅해야 한다. 이 에러는 SQS의 at-least-once 전달 특성상 정상적으로 발생할 수 있는 상황이며, 메시지 삭제가 올바르게 수행되므로 데이터 영향은 없다.
또는 getApiErrorToDeleteMessage 단계에서 bodyResult.code === 'STAT40000'인 경우를 별도로 처리하여, 에러 핸들러가 이를 "정상 완료"로 간주하도록 로직 추가.

단기 개선 (1주 이내)#

Complete-agent의 run() 구현에서 job 상태를 먼저 확인(loadJob)한 후 이미 목표 상태라면 state transition 요청을 건너뛰는 로직 추가. 불필요한 API 호출을 줄이고 에러 노이즈를 원천적으로 제거할 수 있다.
Tesla API의 parameter/job.rb에서 동일 상태 요청 시 에러 대신 현재 상태를 그대로 반환하는 idempotent 동작 검토. STAT40000 에러를 없애면 모든 agent 서비스가 혜택을 받는다.

장기 개선 (재발 방지)#

Agent 서비스 전반에 걸쳐 "expected operational errors"와 "unexpected errors"를 구분하는 에러 분류 체계 도입. STAT40000, 401 cross-region token, rate limit 등은 warn 레벨로 통일.
SQS 메시지 처리에 idempotency key 패턴 적용 — 동일 job에 대한 중복 처리를 agent 레벨에서 감지하고 스킵.

Monitoring#

"State not changed" 에러 빈도 추적:

text

service:cupixworks-any-complete-agent status:error "STAT40000"

504 timeout 후 재시도 패턴 모니터링:

text

service:cupixworks-any-complete-agent "504 Gateway Time-out"

SQS ReceiveCount가 높은 메시지 (≥5) 빈도 추적

Risk Assessment#

Risk level: low
예상 복잡도: trivial
데이터 영향 없음 — SQS 메시지가 올바르게 삭제되고, job 상태는 이미 목표 상태에 있으므로 기능적 문제는 없다. 에러 로그 노이즈만 발생.