RCA: [CupixAerialMap] preprocess fail — AerialMap not found (ENT4000)

Overview#

What Happened#

2026-07-17 07:47 KST 에 aerial-map-service 의 preprocess Fargate 태스크가 실행 도중 Cupix::Errors::NotFound (ENT4000, "AerialMap not found") 응답을 받아 실패했다. 원인은 사용자가 POST /api/v1/aerial_maps/46/invoke 로 처리를 시작한 뒤 preprocess 컨테이너가 실제로 API 호출을 시작하기 전에 같은 aerial map 을 PUT /api/v1/aerial_maps/46/trash 로 휴지통으로 옮긴 것이다. tesla 쪽 BaseRepository#find_by(base_repository.rb:353) 가 trashed 레코드를 ENT4000 으로 거부하면서 preprocess 의 첫 API 호출인 saveProcessingState 가 실패했다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-07-17 07:46:27–29 KST — 사용자가 AerialMap 46 에 항공 사진 8장을 업로드 (POST .../aerial_photos/{id}/upload_url, PUT .../check_uploading 모두 200)
2. 2026-07-17 07:46:31 KST — POST /api/v1/aerial_maps/46/invoke (200), Aerial map step function executed on AerialMap 46 — Step Function / Fargate preprocess 태스크 시작
3. 2026-07-17 07:47:19 KST — PUT /api/v1/aerial_maps/46/trash (204) — 사용자가 처리 진행 중인 aerial map 을 휴지통으로 이동
4. 2026-07-17 07:47:24 KST — preprocess Fargate 컨테이너가 실제로 부팅되어 preprocess fargate memory limit, method, outputs, resolution 로그 출력
5. 2026-07-17 07:47:25 KST — saveProcessingState → PUT /api/v1/aerial_maps/46 이 403 ENT4000 응답, 내부 catch 에서 saveError 재호출도 같은 403 (연속된 두 PUT 로그)
6. 2026-07-17 07:47:25 KST — preprocess 프로세스가 두 error 라인을 남기고 process.exit(1) (preprocess/index.ts:148, :175) → 클러스터 943116b3 와 7b2a836a 두 개 생성
7. 2026-07-17 07:47:45 KST — 후속 조회 [403] GET /api/v1/aerial_maps/45 등 인접 AerialMap 도 trash 흐름 진행 중임이 관찰됨

Error Log#

[Datadog Logs](https://app.datadoghq.com/logs?query=service%3Aaerial-map-service%20status%3Aerror%20%40environment%3Aproduction%20%22%5BCupixAerialMap%5D%20preprocess%20fail%20-%20error%3A(%7B%7D)%20%2F%20message%3A(%7Bresult%3A%7Bcode%3AENT4000%2Ctype%3ACupix%3A%3A%22&from_ts=1784238420000&to_ts=1784245680000&live=false)

[CupixAerialMap] preprocess fail - error:({}) / message:({"result":{"code":"ENT4000","type":"Cupix::Errors::NotFound","reason":"AerialMap not found","message":"AerialMap not found"}})

Impact#

• Service: aerial-map-service
• 발생 횟수: 1건 (동일 잡에서 두 개 로그 라인 → 두 개 fingerprint 클러스터 생성)
• 최초 발생: 2026-07-17 07:47:24 KST
• 최근 발생: 2026-07-17 07:47:24 KST
• 사용자 영향: 낮음 — 사용자가 이미 aerial map 을 trash 로 옮긴 뒤 실패가 발생했으므로 결과 상태(휴지통) 는 사용자의 최종 의도와 일치. Pix4D 프로젝트 생성 전에 실패해 외부 비용 소모 없음. 단, 이미 시작된 Step Function / Fargate 태스크가 실행 자원을 소비 후 실패로 종료됨.

Root Cause Summary#

사용자가 aerial map 처리(invoke) 를 시작한 뒤 preprocess Fargate 컨테이너가 실제로 API 호출을 시작하기까지 약 53초의 지연이 있고, 그 사이 사용자가 같은 aerial map 을 PUT .../trash 로 휴지통으로 옮기면 preprocess 의 첫 tesla API 호출인 saveProcessingState 가 ENT4000 "AerialMap not found" 를 받는다. tesla AerialMapRepository#invoke (app/repositories/aerial_map_repository.rb:225-247) 는 시작 시점의 state 만 검증할 뿐 Step Function 실행을 중단할 수 있는 신호가 없고, AerialMapsController#trash 는 처리 상태와 무관하게 trash 를 허용한다. 결과적으로 이미 시작된 Fargate 잡은 뒤늦게 trashed 레코드를 대상으로 API 를 호출하다 실패한다.

Technical Analysis#

Code Path#

• Entry point: applications/aerial-map-service/src/code/src/preprocess/index.ts:168-179 (IIFE 로 app(input) 호출)
• Failure point: saveProcessingState 첫 호출 (preprocess/index.ts:45) → 내부적으로 updateAerialMap (common/api.ts:646-658) → PUT /api/v1/aerial_maps/46 이 403 ENT4000 응답
• 두 로그 라인이 남는 위치: inner catch (preprocess/index.ts:148) 와 outer catch (:175)
• tesla 측 실패 지점: BaseRepository#find_by 가 trashed record 를 감지하고 ENT4000 재발생 (app/repositories/base_repository.rb:351-357)

preprocess 시작 부분 — 순서상 saveProcessingState 가 첫 API 호출이다:

  try {
    await cupixApi.saveProcessingState(aerialMapId, 'preprocessing', { preprocessBeginTimestamp: beginTime });

    // aerial map camera data
    const aerialPhotos = await cupixApi.getAerialPhotosByAerialMapId(aerialMapId);
    const sortedAerialPhotos = aerialPhotos.sort((a, b) => a.id - b.id);
    const firstAerialPhoto = sortedAerialPhotos[0];
    if (!firstAerialPhoto) throw new AerialMapError('AMB404');

catch 블록이 tesla 에러 응답을 JSON 문자열로 재래핑해서 두 개의 서로 다른 포맷 로그를 남긴다:

  } catch (error: any) {
    if (error instanceof AerialMapError) {
      await cupixApi.saveError(aerialMapId, error.code, error.reason);
    } else {
      logger.error(`[CupixAerialMap] preprocess fail ${error.message}`);
      await cupixApi.saveError(aerialMapId, ERROR_CODE['AMB710'].code, ERROR_CODE['AMB710'].reason);
    }

    throw error;
  }

(async () => {
  try {
    await app(input);
    logger.info(`[CupixAerialMap] preprocess success`);
    await sleep(30000); // sleep for log push
    process.exit(0);
  } catch (error: any) {
    logger.error(`[CupixAerialMap] preprocess fail - error:(${JSON.stringify(error)}) / message:(${error.message})`);
    await sleep(30000); // sleep for log push
    process.exit(1);
  }
})();

updateAerialMap 은 axios 에러의 원본 응답을 JSON.stringify 해서 새 Error 로 던진다. 이 때문에 error instanceof AerialMapError 조건이 false 로 빠지고, error.message 는 {"result":{"code":"ENT4000",...}} JSON 문자열이 된다:

  private async updateAerialMap(aerialMapId: number, param: IAerialMapUpdateParam) {
    try {
      console.log(`[CupixApi] updateAerialMap - /api/v1/aerial_maps/${aerialMapId}`);
      const response = await axios.put(`${this._endpoint}/api/v1/aerial_maps/${aerialMapId}?fields=id,key`, param, {
        headers: { 'x-cupix-auth': `${this._accessToken}` },
      });

      return response.data;
    } catch (error: any) {
      console.error(`[CupixApi] updateAerialMap - /api/v1/aerial_maps/${aerialMapId} - ${error.message}`);
      throw new Error(JSON.stringify(error.response?.data || error.message));
    }
  }

tesla 측 트래시된 레코드 거부 로직 — in_trash 인 경우 ENT4000 을 사용한다:

    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

AerialMapRepository#invoke — 시작 시점 state 만 확인하며, Step Function 실행을 중단할 수 있는 handle 을 저장하지 않는다:

  def invoke
    if @model.state_preprocessing? || @model.state_processing? || @model.state_postprocessing?
      raise Cupix::Errors::InvalidState.new(code: 'STAT10000', reason: 'Aerial map is on processing')
    elsif @model.state_done?
      raise Cupix::Errors::InvalidState.new(code: 'STAT10000', reason: 'Aerial map is already processed')
    elsif @model.state_uploading? || @model.state_created?
      raise Cupix::Errors::InvalidState.new(code: 'STAT10000', reason: 'Aerial photo are not uploaded')
    end
    # ...
    @model.invoke_process
    @model
  end

기대 동작: 사용자가 처리 중인 aerial map 을 trash 로 옮기면 (a) 진행 중 Step Function 이 정상적으로 정지되거나 (b) preprocess 가 시작 시점에 "trashed" 상태를 감지하고 warn 레벨로 조용히 종료. 실제 동작: preprocess 가 error 레벨 로그 두 개를 남기며 실패 종료 → error-sweeper 가 두 클러스터를 만듦.

Log Evidence#

Datadog 쿼리:

service:aerial-map-service status:error @environment:production "[CupixAerialMap] preprocess fail"

두 클러스터의 실제 로그 라인 (동일 잡, 같은 초):

2026-07-17 07:47:24 KST  error  [CupixAerialMap] preprocess fail {"result":{"code":"ENT4000","type":"Cupix::Errors::NotFound","reason":"AerialMap not found","message":"AerialMap not found"}}
2026-07-17 07:47:24 KST  error  [CupixAerialMap] preprocess fail - error:({}) / message:({"result":{"code":"ENT4000","type":"Cupix::Errors::NotFound","reason":"AerialMap not found","message":"AerialMap not found"}})

tesla API 접근 로그(같은 aerial_map_id=46) — invoke → trash → PUT 실패 순서가 명확:

service:cupixworks-api @environment:production "aerial_maps/46"

2026-07-17 07:46:31 KST  info  [200] POST /api/v1/aerial_maps/46/invoke (Api::V1::AerialMapsController#invoke)
2026-07-17 07:46:31 KST  info  Aerial map step function executed on AerialMap 46  (class=AerialMap, function=invoke_process)
2026-07-17 07:47:19 KST  info  [204] PUT /api/v1/aerial_maps/46/trash (Api::V1::AerialMapsController#trash)
2026-07-17 07:47:25 KST  info  [403] PUT /api/v1/aerial_maps/46 (Api::V1::AerialMapsController#update)  error={reason:"AerialMap not found", code:"ENT4000"}
2026-07-17 07:47:25 KST  info  [403] PUT /api/v1/aerial_maps/46 (Api::V1::AerialMapsController#update)  error={reason:"AerialMap not found", code:"ENT4000"}

preprocess 컨테이너의 성공/실패 시퀀스 비교 (최근 24시간, 성공 실행은 preprocess fargate memory limit → method → outputs → resolution → camera maker/model → create pix4d project 순으로 로그가 이어지지만 실패 실행은 resolution 직후 error 로그로 끊긴다):

# 실패한 실행 (aerial_map=46, 07:47:23–25 KST)
07:47:23  info  [CupixAerialMap] preprocess fargate memory limit: 2048 MB
07:47:23  info  [CupixAerialMap] aerial map method: nadir
07:47:23  info  [CupixAerialMap] aerial map outputs: ["orthomosaic","dsm"]
07:47:23  info  [CupixAerialMap] aerial map resolution: high
07:47:24  error [CupixAerialMap] preprocess fail {"result":{"code":"ENT4000",...}}
07:47:24  error [CupixAerialMap] preprocess fail - error:({}) / message:({"result":{"code":"ENT4000",...}})

# 정상 실행 (같은 시간대 다른 aerial_map, 07:52:25–07:55:33 KST)
07:52:25  info  [CupixAerialMap] preprocess fargate memory limit: 2048 MB
07:52:25  info  [CupixAerialMap] aerial map method: nadir
07:52:25  info  [CupixAerialMap] aerial map outputs: ["orthomosaic","mesh","dsm"]
07:52:25  info  [CupixAerialMap] aerial map resolution: high
07:52:29  info  [CupixAerialMap] camera maker: DJI, camera model: M4E, ...
07:52:29  info  [CupixAerialMap] create pix4d project - project name: cupix-production-fluor-47-...
...
07:55:33  info  [CupixAerialMap] preprocess success

실패 실행은 resolution 다음(preprocess/index.ts 기준 line 30 다음) 에 아무 tesla-API-derived 로그가 없음 → 첫 API 호출인 saveProcessingState (line 45) 에서 즉시 예외. 07:47:25 에 tesla 쪽 PUT 두 번이 나란히 실패한 것과 정확히 일치. 두 번째 PUT 은 inner catch 안의 saveError (line 149) 가 같은 trashed 레코드에 시도한 것.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• preprocess/index.ts:45 첫 API 호출을 방어적으로 처리 — saveProcessingState 호출 실패 응답이 ENT4000 (Cupix::Errors::NotFound) 이면 "aerial map removed during preprocessing" 으로 판정, logger.warn 로 종료하고 process.exit(0) 로 조용히 빠져나온다. 이는 예상 가능한 사용자 액션이므로 error 레벨 로그로 알림을 발생시킬 필요가 없다.
• preprocess/index.ts:149 의 saveError 도 trashed 대상이면 스킵 — 이미 trash 로 옮긴 레코드에 두 번째 PUT 을 시도해 두 번째 403 을 만드는 부분(로그 스팸의 원인) 을 제거.

단기 개선 (1주 이내)#

• 에러 분류/로깅 개선 — common/api.ts:646-658 updateAerialMap 등 API client 가 error.response?.data 를 JSON.stringify 해서 새 Error 로 던지는 방식은 두 개의 서로 다른 fingerprint 를 만든다(preprocess fail ${error.message} vs preprocess fail - error:(${JSON.stringify(error)}) / message:(...)). 커스텀 에러 클래스(AerialMapApiError { code, message, isNotFound }) 로 감싸서 상위 catch 가 조건 분기하도록 정리하면 클러스터 중복도 함께 해소.
• AerialMapsController#trash (aerial_maps_controller.rb) — 진행 중(state_preprocessing? || state_processing? || state_postprocessing?) 인 경우 400/409 (STAT10000) 로 거부하거나, trash 를 허용하되 tesla 쪽에서 AerialMap#invoke_process 로 시작한 Step Function 실행 ARN 을 저장했다가 StopExecution API 를 호출. 최소한 사용자에게 "처리 중이라 완전 삭제까지 시간이 걸릴 수 있다" 는 경고를 노출.

장기 개선 (재발 방지)#

• Step Function 실행 ARN 을 AerialMap 모델에 저장하고 trash/untrash 시 Aws::States::Client#stop_execution 을 호출해 진행 중 Fargate 태스크를 명시적으로 종료. 현재 코드베이스에는 aerial map 용 Step Function 취소 경로가 존재하지 않음 (tesla 전체에서 stop_execution grep 결과 0건 확인).
• preprocess 컨테이너 부팅 시간 (07:46:31 → 07:47:23 = 약 52초) 이 사용자 액션과의 race window 를 만든다. Fargate 태스크가 시작 즉시 aerial map 존재/state 를 확인하고, 부팅 후에도 이 확인을 유지하는 heartbeat 를 두면 race 진입을 조기 차단.

Monitoring#

writing-datadog-monitoring-queries 규칙에 따라 dashboard timeseries 위젯에 그대로 넣을 수 있는 형태로 작성:

• preprocess 실패율 (전체):

sum:aerial_map.preprocess.fail{env:production}.as_count()

• ENT4000 로 인한 preprocess 실패 (log-based metric 을 별도 정의한 뒤):

sum:aerial_map.preprocess.fail_ent4000{env:production}.as_count()

• invoke → trash race 발생 근사값 (aerial_map 이 trash 된 시각과 invoke 시각의 근접 여부는 log-based facet 이 필요) — 최소한 Datadog log query 로 라이브 확인:

service:aerial-map-service status:error @environment:production "AerialMap not found"

• Fargate preprocess 부팅 지연 (invoke 시각 vs preprocess fargate memory limit 로그 시각 차이) 을 트래킹하는 커스텀 메트릭 도입 후:

avg:aerial_map.preprocess.boot_lag_seconds{env:production}

알림: sum:aerial_map.preprocess.fail_ent4000{env:production}.as_count() 가 15분 창에서 5건 이상이면 Slack 통지 (사용자 액션 오작동 vs 시스템 문제 구분에 유의).

Risk Assessment#

• Risk level: low — 단일 사용자 액션 race, 결과적으로 사용자의 최종 의도(trash) 와 일치. 데이터 손실 없음, Pix4D 자원 소모 없음.
• 예상 복잡도: trivial — preprocess/index.ts:44-153 catch 분기 조정만으로 즉시 조치 가능. 단기/장기 항목은 tesla 컨트롤러 변경과 AWS Step Functions 통합이 필요해 standard 수준.