RCA: BaseService::handlingMessageErrors — Pano already stitched (STAT10000)

Overview#

What Happened#

2026-07-01 12:51 KST, cupixworks-capture-singleshot-agent(us-west-2, production)이 capture 725649 / pano 90901091 처리 도중 PUT /api/v1/panos/90901091/stitched 호출에서 400 STAT10000 "Pano already stitched"를 받아 SQS 메시지 처리를 실패로 종료했다. 단일 capture 1건에서만 발생한 이벤트로, 실제 스티칭 자체는 성공했으나 후속 S3 리소스 shift 단계에서 발생한 502를 클라이언트가 재시도하면서 이미 stitched=true로 커밋된 상태를 다시 호출해 발생한 결과다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-07-01 12:50:39 KST — SQS 메시지 수신, runByMessage | id: 725649 (capture 로드 시작)
2. 2026-07-01 12:50:40 KST — runAlign | begin | captureId: 725649, workspace: /tmp/workspace/725649
3. 2026-07-01 12:50:45 KST — runAlign | pano downloaded | id: 90901091 ... 90901091.insp
4. 2026-07-01 12:51:02 KST — runAlign | stitched pano copied | panoId: 90901091 ... 90901091_stitched.jpg (스티칭 산출물 워크스페이스 확보)
5. 2026-07-01 12:51:27 KST — 첫 번째 PUT /api/v1/panos/90901091/stitched — [502] Aws::S3::Errors::InvalidRequest: This copy request is illegal because it is trying to copy an object to itself. Tesla API는 pano.stitched=true를 커밋한 뒤 shift_stitched_panorama!의 S3 copy_to에서 예외로 502 반환.
6. 2026-07-01 12:51:28 KST — 에이전트가 retryable(statusCode > 500) 규칙에 따라 재시도. Tesla API 응답 [400] STAT10000 "Pano already stitched".
7. 2026-07-01 12:51:26 KST — CupixAuth::handleError warn / BaseService::getApiErrorToDeleteMessage warn / BaseService::handlingMessageErrors error 순으로 클러스터 대표 로그 기록, SQS 메시지 삭제 및 cleanUpAnythingRelatedModel.

Error Log#

Datadog Logs

BaseService::handlingMessageErrors | Error and message object - {"error":{"statusCode":400,"requestUriHref":"http://api-tesla.cupix.internal/api/v1/panos/90901091/stitched?fields%5B0%5D=id&...","bodyResult":{"code":"STAT10000","type":"Cupix::Errors::InvalidState","reason":"Pano already stitched","message":"Pano already stitched"},"modelId":725649},"sqsMessage":{"MessageId":"6692e252-5476-467e-b955-84ea8235203c","Attributes":{"ApproximateReceiveCount":"1"}}}

Impact#

• Service: cupixworks-capture-singleshot-agent
• Team: chrischoi
• 발생 횟수: 1
• 최초 발생: 2026-07-01 12:51 KST
• 최근 발생: 2026-07-01 12:51 KST
• SQS ApproximateReceiveCount: 1 — 재수신 없이 첫 시도에서 삭제됨. Capture 725649의 singleshot 파이프라인은 에러 상태로 마감(updateErrorState → singleshot_state: stopped)되지만, 실제로는 Tesla DB에 pano.stitched=true가 이미 커밋되어 있어 데이터 상태는 "스티칭 완료"로 남아 있다. 다만 shift_stitched_panorama!의 S3 리비전 shift(revision 2로 복사)는 실패했다.

Root Cause Summary#

에이전트가 스티칭 완료를 Tesla API에 알리는 PUT /panos/:id/stitched 호출은 두 단계로 구성된다: (1) PanoRepository#stitched가 @model.update!(stitched: true, ...)로 DB 플래그를 즉시 커밋하고, (2) 이어서 shift_stitched_panorama!가 revision 2 키로 S3 copy_to를 실행한다. Pano 90901091의 경우 (2)에서 Aws::S3::Errors::InvalidRequest: "trying to copy an object to itself"가 발생해 컨트롤러가 502로 응답했다. 하지만 (1)의 DB 커밋은 이미 성공했기 때문에 pano의 상태는 이미 stitched=true가 되어 있었다. 에이전트 측 CupixAuth::retryable은 statusCode > 500을 무조건 재시도 대상으로 취급하므로 이 502를 자동 재시도했고, 재시도 요청은 line 38의 사전 체크 raise ... if @model.stitched?에 걸려 400 STAT10000으로 실패했다. 최종적으로 에이전트가 관측한 표면적 에러는 "Pano already stitched"지만, 실제 근본 원인은 (a) DB 커밋과 S3 shift가 하나의 트랜잭션/원자적 단위로 묶여 있지 않아 부분 성공 상태가 남는 것, (b) 재시도가 안전하지 않은(비-idempotent) 상태 전환에도 5xx 재시도가 적용되는 것 두 가지가 결합한 결과다.

Technical Analysis#

Code Path#

• Entry point: packages/base/src/base-service.ts:108 (await this.runByMessages())
• Failure surface: packages/base/src/base-service.ts:311 (handlingMessageErrors error 로그)
• Underlying call chain: SingleshotService::uploadStitchedPano → cupixApi.pano.updateStitched → Rails Api::V1::PanosController#stitched → PanoRepository#stitched → shift_stitched_panorama!
• Retry wrapper: packages/api/src/authentication/cupix-auth.ts:59 (retryable)

에이전트 측 스티칭 알림 호출:

await this.cupixApi.pano.updateStitched(panoId, {
    original_panorama_format: TESLA.UpdatePanoStitchRequest.OriginalPanoramaFormatEnum.Equirectangular
});

Tesla 컨트롤러가 호출하는 리포지토리 로직 — update!가 먼저 커밋되고, 그 뒤 shift_stitched_panorama!가 실행된다:

def stitched(params = {})
  raise Cupix::Errors::InvalidState.new(code: 'STAT10000', reason: 'Pano already stitched') if @model.stitched?

  @model.update!(
    stitched: true,
    original_panorama_format: params[:original_panorama_format]
  )

  @model.shift_stitched_panorama! if @model.resource_shift_eligible?

  @model
end

shift_stitched_panorama!가 S3 CopyObject를 실행하는 구간 — source/destination 키가 동일해지면 AWS가 InvalidRequest를 반환한다:

def shift_stitched_panorama!
  check_resource_shift_eligable

  resource = self.resource
  storage_option = resource.storage_option
  bucket_name = storage_option.s3_source_bucket_name
  next_revision = self.revision + 1
  object = resource.object

  copy_args = {
    bucket: bucket_name,
    key: resource.object(next_revision).key,
    acl: 'bucket-owner-full-control'
  }
  # ...
  object.copy_to(copy_args)

  update(resource_shifted_at: DateTime.now)
rescue StandardError => e
  raise e

에이전트 측 5xx 자동 재시도 — 400은 재시도하지 않지만 502는 재시도한다:

retryable = <T>(f: () => Promise<T>, retries?: number): Promise<T> => new Promise((resolve, reject) => {
    const _retries = retries != undefined ? retries : 0;
    f()
        .then(response => resolve(response))
        .catch(e => {
            if (e && e.statusCode > 500 && _retries < Constants.MaxRetries) {
                // ...
                setTimeout(() => {
                    this.retryable(f, _retries + 1).then(resolve).catch(reject);
                }, delay);
            } else {
                reject(e);
            }
        });
});

기대 동작: updateStitched 한 번의 호출이 성공하면 pano의 stitched=true DB 상태와 revision 2로의 S3 shift가 함께 완료되어야 한다. 실패하면 두 상태 모두 롤백되어야 한다.

실제 동작: DB 상태 전환은 커밋되었으나 S3 shift가 502로 실패했다. retryable이 이 502를 자동 재시도했지만, 재시도 요청은 line 38의 pre-check에 걸려 400을 반환. 최종적으로 SDK가 던지는 에러 메시지("Pano already stitched")는 실제 근본 원인(S3 copy-to-self)을 가리게 된다.

에이전트의 handlingMessageErrors는 statusCode 400을 getApiErrorToDeleteMessage가 delete 대상으로 판정하기 때문에 SQS 메시지를 삭제하고 종료한다:

if (statusCode != undefined && statusCode >= 400 && statusCode <= 500) {
    if (statusCode === 401) return;

    return errorMsg;
}

Log Evidence#

Datadog 쿼리:

service:cupixworks-capture-singleshot-agent 725649

에이전트 실행 흐름 (KST 변환):

12:50:39  BaseService::runByMessage | id: 725649
12:50:39  SingleshotService::getCaptureById | captureId: 725649
12:50:40  SingleshotService::runAlignScript | params: {"workspace":"/tmp/workspace/725649","captureId":725649,"awsRegion":"us-west-2","envName":"production"}
12:50:40  runAlign | begin | captureId: 725649, workspace: /tmp/workspace/725649
12:50:40  runAlign | capture loaded | id: 725649, creation_platform: app, method: singleshot
12:50:45  runAlign | pano downloaded | id: 90901091, key: 90901091, path: /tmp/workspace/725649/original_panos/90901091.insp
12:51:02  runAlign | stitched pano copied | panoId: 90901091, path: /tmp/workspace/725649/input_panos/90901091_stitched.jpg
12:51:26  CupixAuth::handleError | Response statusCode: 400 ... body.result: {"code":"STAT10000","reason":"Pano already stitched"}
12:51:26  BaseService::getApiErrorToDeleteMessage | error msg - {"statusCode":400,...,"modelId":725649}
12:51:26  BaseService::handlingMessageErrors | Error and message object - {"error":{"statusCode":400,...}}
12:51:26  BaseService::cleanUpAnythingRelatedModel | path: /tmp/workspace/725649

Datadog 쿼리 (Tesla API 측):

service:cupixworks-api 90901091 stitched

두 개의 연속 요청이 관측됨:

{
  "timestamp": "2026-07-01 12:51:27",
  "status": "info",
  "message": "[502] PUT /api/v1/panos/90901091/stitched (Api::V1::PanosController#stitched)",
  "error": {
    "code": "InvalidRequest",
    "message": "This copy request is illegal because it is trying to copy an object to itself without changing the object's metadata, storage class, website redirect location or encryption attributes.",
    "class": "Aws::S3::Errors::InvalidRequest"
  }
}

{
  "timestamp": "2026-07-01 12:51:28",
  "status": "info",
  "message": "[400] PUT /api/v1/panos/90901091/stitched (Api::V1::PanosController#stitched)",
  "error": {
    "reason": "Pano already stitched",
    "code": "STAT10000",
    "message": "Pano already stitched",
    "class": "Cupix::Errors::InvalidState"
  }
}

첫 요청(502)이 실제 근본 원인이며, 두 번째(400)는 그 결과로 나타난 표면적 증상이다. 재시도 간격 약 1초는 retryable의 지수 백오프 첫 단계(Math.pow(2, 0) * 1000 = 1000ms)와 정확히 일치한다.

Datadog 쿼리 (동일 pano에 대한 다른 재발 여부):

service:cupixworks-api "copy request is illegal"

지난 7일 이내 동일 유형의 S3 self-copy는 1건(위 12:51:27)만 관측 — recurring pattern이 아닌 단일 사건. 다만 cupixworks-capture-singleshot-agent::unknown 스코프에서 2026-06-24에도 유사 서비스 저하 인시던트가 해소된 이력이 있음(status-board).

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 없음. 단일 발생(1건)이고 데이터 손상은 없다. Pano 90901091은 DB에 stitched=true로 커밋된 상태로 남아 있고, S3 revision 2 shift만 미완료다. 서비스 SLA에 즉시 영향 없음.

단기 개선 (1주 이내)#

1. 재시도 조건 좁히기 — packages/api/src/authentication/cupix-auth.ts:64의 statusCode > 500 조건은 updateStitched처럼 서버가 부분 상태 전환을 이미 커밋했을 가능성이 있는 비-idempotent 경로에 대해 안전하지 않다. 502를 무조건 재시도하지 말고, (a) idempotent HTTP verb(GET/PUT-with-idempotency-key)에만 적용하거나, (b) 502에 대해서는 재시도하지 않고 상위(에이전트) 로직이 상태 확인 후 판단하도록 축소하는 방향으로 좁힌다.
2. PanoRepository#stitched 원자성 회복 — app/repositories/pano_repository.rb:37-48에서 @model.update!(stitched: true, ...)와 shift_stitched_panorama!를 하나의 ActiveRecord::Base.transaction 블록으로 묶어, S3 shift 실패 시 DB stitched 플래그도 롤백되도록 한다. 이렇게 하면 재시도가 안전(idempotent)해진다.
   • 주의: shift_stitched_panorama!의 S3 copy_to는 트랜잭션 롤백 대상이 아니므로, 실패 시 S3 잔여 객체 정리 정책을 별도로 정의하거나, 이미 존재하는 revision 2 객체는 그대로 두고 재시도 시 재사용하는 정책이 필요.
3. 에이전트의 상태 정합화 — SingleshotService::uploadStitchedPano가 updateStitched 실패를 받았을 때, 서버에 상태를 조회하여 이미 stitched=true인 경우 성공으로 간주하도록 회복 로직 추가. packages/cupix-tesla-singleshot-agent/src/singleshot-service.ts:132-134 근처에서 catch로 400 STAT10000을 별도 처리.

장기 개선 (재발 방지)#

1. "S3 copy-to-self" 조건 원인 규명 — resource.object.key와 resource.object(next_revision).key가 같아지는 조건을 확정해야 한다. resource.object는 (아마도) 현재 revision(self.revision)의 키를 반환하고, object(next_revision)은 다음 revision 키를 반환하므로 두 키가 같아지려면 object 헬퍼가 인자 없이 호출될 때 next_revision을 기본값으로 사용하거나, resource_shifted_at이 이미 세팅되어 있음에도 check_resource_shift_eligable이 잘못 통과한 등의 상황이 필요. 이 부분은 pano 90901091의 DB 상태(revision, resource_shifted_at) 실측 후 재현이 필요.
2. 비-idempotent API에 idempotency key 도입 — Tesla API PUT /panos/:id/stitched처럼 상태 전환을 유발하는 엔드포인트에 클라이언트가 idempotency key를 넣도록 하고, 서버는 동일 key의 중복 요청을 성공으로 처리(same response replay).

Monitoring#

• Tesla API 측 S3 self-copy 에러 추이:

service:cupixworks-api "copy request is illegal"

• Singleshot 에이전트의 "already stitched" retry 실패 추이:

service:cupixworks-capture-singleshot-agent "Pano already stitched"

• PUT /panos/*/stitched 502 응답 추이:

service:cupixworks-api "PUT /api/v1/panos" "stitched" status:info @http.status_code:502

• 502가 발생한 pano id와 뒤이은 400의 pano id를 대조하여 "502→400 retry 실패" 조합만 골라내는 재발 감시:

service:cupixworks-api "PanosController#stitched" (status_code:502 OR status_code:400)

Risk Assessment#

• Risk level: low (단일 capture 1건, 데이터 손상 없음, 재발 관측 없음)
• 예상 복잡도: standard (Tesla API 트랜잭션 경계 조정 + 에이전트 재시도 정책 축소)