RCA: BaseService::handlingMessageErrors — 403 ENT4000 on trashed capture

Overview#

What Happened#

2026-07-24 16:34 KST, cupixworks-si-lite-agent (Sprouts tenant, us-west-2) 가 capture 736992 에 대해 SI Lite 분석을 실행하려 했으나, Tesla API GET /api/v1/captures/736992 가 HTTP 403 + ENT4000 / Cupix::Errors::NotFound / "Capture not found" 로 응답했다. 캡처는 실제로 존재하지만 전날 (2026-07-24 01:53 KST) cycle_state=trashed 로 이동된 상태였고, base_repository.rb 의 in_trash scope 가 이를 걸러내면서 API 가 NotFound 를 던졌다. 동일 capture id 로 발생한 3개 클러스터 (23a74e95, 619a1e49, ab8a602b) 는 모두 같은 원인이며 총 1회 발생 (SQS 메시지 1건).

Quick Facts#

Affected Teams#

Timeline#

1. 2026-07-17 17:14 KST — SI Lite 첫 실행 성공 (SiliteProcessManager::execute | captureId: 736992, workareas: 1, trades: 9).
2. 2026-07-24 01:53 KST — Capture 736992 가 trash 로 이동됨 (cycle_state_updated_at=2026-07-23T16:53:36Z, Kibana captures index).
3. 2026-07-24 16:34:56 KST — SiliteService::run | begin - captureId: 736992 — SQS 메시지 53531766-cc74-4823-8c03-26026d6962c5 (ApproximateReceiveCount=1) 수신.
4. 2026-07-24 16:34:56 KST — Tesla API GET → 403 ENT4000. updateSiLiteState(processing) 및 updateSiLiteState(error) 도 동일하게 403.
5. 2026-07-24 16:34:56 KST — BaseService::handlingMessageErrors 가 최종 에러 로그 출력. getApiErrorToDeleteMessage 가 4xx 이므로 SQS 메시지 삭제 후 종료.

Error Log#

Datadog Logs

BaseService::handlingMessageErrors | Error and message object - {"error":{"statusCode":403,"requestUriHref":"http://api-tesla.cupix.internal/api/v1/captures/736992?fields%5B0%5D=id&...&fields%5B44%5D=summary_state","bodyResult":{"code":"ENT4000","type":"Cupix::Errors::NotFound","reason":"Capture not found","message":"Capture not found"},"modelId":736992},"sqsMessage":{"MessageId":"53531766-cc74-4823-8c03-26026d6962c5","Attributes":{"ApproximateReceiveCount":"1"}}}

Impact#

• Service: cupixworks-si-lite-agent
• Team: sprouts
• 발생 횟수: 1
• 최초 발생: 2026-07-24 16:34 KST
• 최근 발생: 2026-07-24 16:34 KST

동일 원인으로 같은 시점 (0.04초 window) 에 다른 두 클러스터 (619a1e49 updateSiLiteState state:processing 403, ab8a602b updateSiLiteState state:error 403) 도 함께 발생. 총 사용자 영향은 없음 — 이미 사용자가 trash 로 이동한 capture 에 대한 stale SQS 메시지.

Root Cause Summary#

Tesla API 의 BaseRepository#find_by 는 visibility_scope 로 캡처를 조회하고, 조회 결과가 nil 이면서 where(attrs).in_trash.present? 가 true 이면 Cupix::Errors::NotFound.new(code: 'ENT4000') 를 raise 한다 (entity.yml 의 ENT4000 메시지는 실제로 "Record has trashed"). 이 예외는 client_error_controller.rb:27 의 rescue_from Cupix::Errors::NotFound, with: :not_found_403_error 에 의해 HTTP 403 으로 응답된다. Capture 736992 는 2026-07-23T16:53:36Z 에 cycle_state=trashed 로 이동되었고, Trashable::Capture.in_trash scope = cycle_state_trashed(trashing|trashed) 이 이를 매칭해 ENT4000 이 반환됐다. SI-Lite agent 는 그 시점 이후 대기 중이던 SQS 메시지를 소비하면서 트래시된 캡처를 조회하려 했고, 트래시 여부를 사전 확인하는 로직이 없어 상위 3개의 로그 (run 진입 → updateSiLiteState:processing 실패 → updateSiLiteState:error 실패 → handlingMessageErrors) 가 모두 error 레벨로 기록됐다. Agent 는 4xx 응답에 대해 getApiErrorToDeleteMessage 로 SQS 메시지를 삭제하므로 무한 retry 는 아니나, 정상적인 "이미 삭제됨" 케이스가 error 레벨로 alert 를 오염시키고 있다.

Technical Analysis#

Code Path#

Entry point: si-lite-agent 가 SQS 메시지 ({ id: 736992 }) 를 수신 → BaseService::runByMessage → SiliteService.run(736992).

protected override run = async (targetId: number, _msgObject: SqsMessageBody): Promise<void> => {
    logger.info('SiliteService::run | begin - captureId: %d', targetId);

    try {
        await this.updateSiLiteState(targetId, TESLA.SiLiteState.Processing);
        const cpCapture = await this.fetchAndValidateCapture(targetId);
        // ...

updateSiLiteState(Processing) 는 PATCH /api/v1/captures/:id 를 호출 (silite-service.ts:343-357) 하는데, 이 역시 동일한 BaseRepository#find_by 를 거치므로 트래시 캡처에 대해 즉시 403 ENT4000 을 받는다. catch 절은 updateSiLiteState(Error) 를 다시 호출해 두 번째 동일 오류가 발생하고, 이후 throw error 로 BaseService 의 handler 로 전파된다.

private async updateSiLiteState(captureId: number, state: TESLA.SiLiteState): Promise<void> {
    if (DEBUG_MODE) { /* ... */ return; }
    try {
        await this.cupixApi.capture.update(captureId, { si_lite_state: state });
        logger.debug('SiliteService::updateSiLiteState | updated - ...');
    } catch (error) {
        logger.error('SiliteService::updateSiLiteState | failed - captureId: %d, state: %s, error: %s',
            captureId, state, stringifyError(error));
        throw error;
    }
}

Failure point: Tesla API BaseRepository#find_by.

scope = current_class.visibility_scope(visibility)
model = query.merge(scope).first

if model.nil? && current_user.present? && current_user.team.domain == 'admin'
    unless (::UserRepository.new(model: current_user).group_codes & %w[administrator senior_editing_engineers]).empty?
        model = self.where(attrs).merge(scope).first
    end
end

if model.nil?
    if self.where(attrs).in_trash.present?
        raise Cupix::Errors::NotFound.new(code: 'ENT4000', reason: "#{current_class.name} not found")
    else
        raise Cupix::Errors::NotFound.new(code: 'ARG10002', reason: "#{current_class.name} not found")
    end
end

Trashable::Capture.in_trash 정의:

def self.in_trash
    trashed.or(where(record: ::Record.in_trash)).or(where(level: ::Level.in_trash))
end

trashed scope 는 cyclable/base_scope.rb:62-65 에서 where(cycle_state: %w[trashing trashed]). Kibana captures index 로 확인한 736992 의 cycle_state=trashed 이므로 이 조건에 매칭된다.

ENT4000 → HTTP 403 변환:

rescue_from Cupix::Errors::NotFound, with: :not_found_403_error
# ...
def not_found_403_error(exception)
    raise_error(403, exception)
end

Agent 는 이 403 을 4xx 로 인식해 SQS 메시지 삭제 대상으로 분류:

private getApiErrorToDeleteMessage = (error: any): any => {
    // ...
    if (statusCode != undefined && statusCode >= 400 && statusCode <= 500) {
        if (statusCode === 401) return;
        return errorMsg;
    }
    return;
};

기대 동작: 트래시된 캡처는 SI-Lite 분석 대상이 아니므로 agent 가 warn 레벨로 skip 하거나, Tesla API 가 별도 상태 코드 (예: 410 Gone 또는 body state: trashed) 를 반환해 agent 가 정상 흐름으로 처리해야 함.

실제 동작: agent 는 트래시 여부를 알 수 없고, 403 ENT4000 을 다른 authorization 실패와 동일하게 error 로그로 남긴다. run 의 catch 절이 updateSiLiteState(Error) 를 재호출해 오류가 중복 로깅된다.

Log Evidence#

Datadog query:

service:cupixworks-si-lite-agent 736992

성공한 첫 실행 (7-17) → 트래시 이후 실패 (7-24) 로그 시퀀스:

2026-07-17 17:14:46 [info]  BaseService::runByMessage | id: 736992
2026-07-17 17:14:46 [info]  SiliteService::run | begin - captureId: 736992
2026-07-17 17:14:47 [info]  SiliteProcessManager::execute | captureId: 736992, workareas: 1, trades: 9
2026-07-17 17:14:50 [warn]  SiliteService::updateErrorState | captureId: 736992
--- 캡처 trash 이동: 2026-07-24 01:53 KST ---
2026-07-24 16:34:56 [info]  BaseService::runByMessage | id: 736992
2026-07-24 16:34:56 [info]  SiliteService::run | begin - captureId: 736992
2026-07-24 16:34:56 [warn]  CupixAuth::handleError | Response statusCode: 403, requestUriHref: .../captures/736992..., body.result: {"code":"ENT4000","type":"Cupix::Errors::NotFound","reason":"Capture not found","message":"Capture not found"}
2026-07-24 16:34:56 [error] SiliteService::updateSiLiteState | failed - captureId: 736992, state: processing, error: {"statusCode":403,...}
2026-07-24 16:34:56 [error] SiliteService::updateSiLiteState | failed - captureId: 736992, state: error, error: {"statusCode":403,...}
2026-07-24 16:34:56 [warn]  BaseService::getApiErrorToDeleteMessage | error msg - {"statusCode":403,...,"bodyResult":{"code":"ENT4000",...}}
2026-07-24 16:34:56 [error] BaseService::handlingMessageErrors | Error and message object - {...ENT4000...}

Kibana captures index (env=prod, id=736992) 발췌:

{
  "id": 736992,
  "state": "done",
  "trashed_at": null,
  "cycle_state": "trashed",
  "cycle_state_updated_at": "2026-07-23T16:53:36.000Z",
  "team": { "id": 1185, "domain": "sprouts" },
  "facility": { "id": 21347, "cycle_state": "created" },
  "record": { "id": 138303 },
  "level":  { "id": 86715 }
}

부모 record 138303 및 level 86715 는 trashed_at: null, cycle_state: "created" — 즉 캡처 본인만 trashed 상태. Trashable::Capture.in_trash 는 trashed (cycle_state 매칭) OR (record/level in_trash) 이므로 이 조건이 성립한다.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 없음. 데이터 손상이나 사용자 노출 영향이 없으며 SQS 메시지가 자동으로 삭제되어 자체 회복됨. 코드 변경 불필요.

단기 개선 (1주 이내)#

• si-lite-agent 에서 trashed capture 를 정상 skip 처리: applications/agents/packages/cupix-si-lite-agent/src/silite-service.ts:84-112 의 run 시작부에서 최초 updateSiLiteState(Processing) 호출 전에 fetchAndValidateCapture 로 캡처를 먼저 fetch 하고, 응답이 403 + body.code === 'ENT4000' 인 경우를 별도 분기로 처리. 이 경우 logger.warn('SiliteService::run | capture in trash, skipping - captureId: %d', targetId) 로 warn 레벨 로그만 남기고 SQS 메시지를 정상 처리(삭제)로 종료하도록 흐름 변경. 지금은 run 이 Processing 상태 갱신을 먼저 시도해 두 번의 404/403 및 최종 handlingMessageErrors 로그가 error 레벨로 남는 구조.
• BaseService::handlingMessageErrors 의 4xx-ENT4000 로그 레벨 다운그레이드: applications/agents/packages/base/src/base-service.ts:290-313 에서 getApiErrorToDeleteMessage 가 반환한 bodyResult.code === 'ENT4000' (또는 4xx 이면서 삭제 대상) 인 케이스는 warn 레벨로 로깅. 이는 "이미 삭제/트래시된 리소스" 케이스로 alert 대상이 아님. 단, 로그 레벨 다운그레이드는 특정 code (ENT4000) 로 좁혀야 하며 모든 4xx 를 warn 으로 낮추면 다른 진짜 오류를 놓칠 수 있음.
• 참고: memory 노트 — "warn-level 다운그레이드는 특정 예외 클래스/코드로 좁힐 것" 원칙을 준수.

장기 개선 (재발 방지)#

• Tesla API 응답 semantics 정리: ENT4000 는 실제로 "Record has trashed" 이지만 (config/error_code/entity.yml:49-50) reason 필드에는 "#{current_class.name} not found" 로 다르게 표기 (base_repository.rb:353). 이 불일치가 클라이언트 debug 를 어렵게 함. reason 을 "#{current_class.name} is trashed" 로 수정하거나, 별도 HTTP status (예: 410 Gone) 로 응답해 클라이언트가 명확히 구분할 수 있게 함. 다만 이 변경은 여러 클라이언트에 영향이 있어 프런트엔드/agent 팀 조율 필요 — 이 RCA 의 자동화 fix 대상에는 포함하지 않음.
• si-lite job dispatch 시점 필터: Tesla 측에서 run_si_lite_sync? (app/models/concerns/si_lite_sync.rb:65-67) 에 !capture.trashed? 조건 추가를 검토. 다만 이번 케이스는 이미 큐잉 후 소비 전에 trash 로 이동한 케이스이므로 dispatch 시점 필터로는 완전히 막을 수 없음 — agent 측 skip 로직 (단기 개선) 이 근본 대책.

Monitoring#

• ENT4000 발생 추이 (si-lite-agent):

service:cupixworks-si-lite-agent "ENT4000"

• si-lite-agent error 전체:

service:cupixworks-si-lite-agent status:error

• handlingMessageErrors 발생량:

service:cupixworks-si-lite-agent "BaseService::handlingMessageErrors"

Risk Assessment#

• Risk level: low
• 예상 복잡도: trivial (사용자 영향 없음, self-heal, 즉시 조치 없음)
• 단기 개선 (agent 측 trashed-capture skip) 복잡도: standard