RCA: Api::V1::CapturesController#check_zip_uploading (avg 10881ms, max 10881ms)

Overview#

What Happened#

2026-07-11 04:20 KST 경 cupixworks-api production 환경에서 PUT /api/v1/captures/:id/check_zip_uploading 요청이 평균/최대 10.88초의 지연을 보이는 latency 클러스터가 감지됨. 같은 endpoint 를 이 시간 창에서 다른 capture 로 재확인한 결과 6~29초 수준의 완주 시간이 반복적으로 관측됨. request 는 [200] 로 종료되지만 대부분의 시간을 순차 S3 HEAD 호출과 DB round-trip 으로 소진.

Quick Facts#

Timeline#

1. 2026-07-11 04:19:54 KST — capture 42584 request 진입 (si_trace_id: 8e386f5b...), Capture 상태 검증 로그 기록.
2. 2026-07-11 04:20:12 KST — cluster first_seen. APM span 이 10.88s 지연으로 latency 클러스터 생성.
3. 2026-07-11 04:20:46 KST — capture 42584 의 최종 request 로그 [200] PUT /api/v1/captures/42584/check_zip_uploading, duration: 272.07 ms (동일 endpoint 의 빠른 케이스).
4. 2026-07-11 04:23:08 KST — capture 732899 동일 endpoint 6408 ms 완주.
5. 2026-07-11 04:29:02 KST — capture 732857 동일 endpoint 6115 ms 완주.
6. 2026-07-11 04:45:38 KST — capture 732973 동일 endpoint 28797 ms 완주 (db: 4340 ms).

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::CapturesController#check_zip_uploading",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 10881,
  "max_ms": 10881,
  "sample_trace_id": "4434648144236775311"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 1 (클러스터 기준; 시간창 확장 시 동일 endpoint 의 >5s 요청 다수 관측)
• 최초 발생: 2026-07-11 04:20 KST
• 최근 발생: 2026-07-11 04:20 KST
• 사용자 영향: capture zip 다운로드 워크플로우에서 클라이언트(axios/1.6.7)가 zip 상태 폴링 시 매 요청마다 5~29초 대기. 다수 team (mcalvain=1038, whitingturner=140, weoneil=664, bimtec=125) 에서 동일 지연 재현되어 특정 tenant 국한이 아닌 endpoint 자체의 구조적 문제.

Root Cause Summary#

check_zip_uploading 은 zip 상태가 :zipping 인 capture 에 대해 pano 를 200 개 단위로 나눈 pano_page_count 만큼의 zip object 존재 여부를 순차적으로 S3 HEAD 로 확인한다 (zippable/capture.rb:45-61). pano 가 많은 capture 일수록 S3 head 왕복이 선형 증가하며, HEAD 하나가 수백 ms 만 걸려도 페이지 10개면 수 초, 페이지 수십 개면 20초 이상 소모된다. 이 endpoint 는 클라이언트가 zip 진행 상황을 얻기 위해 폴링으로 호출하므로, 대형 capture 에서 매 폴링마다 동일한 N 회 HEAD 를 반복해 사용자 체감 지연과 API 서버 리소스 낭비를 동시에 유발한다.

Technical Analysis#

Code Path#

• Entry: config/routes.rb:1053 — put 'check_zip_uploading' 이 Api::V1::CapturesController#check_zip_uploading 으로 매핑.
• Controller: app/controllers/concerns/zippable_controller.rb:4-11 — repository 위임.
• Repository: app/repositories/concerns/zippable_repository.rb:4-17 — 상태가 :zipping 일 때 model 의 check_zip_uploading 을 호출하고, 반환이 truthy 이면 done_zip_state transition.
• Model (failure point / 병목): app/models/concerns/zippable/capture.rb:45-61 — pano_page_count.times 루프에서 페이지마다 새 S3 object 를 만들고 exists? 호출.
• S3 layer: app/services/cupix/storage_service.rb:29-36 — Aws::S3::Object.new(opts) 를 리턴. .exists? 는 aws-sdk 의 동기 HEAD 요청.

def check_zip_uploading
  @model = repository_instance.check_zip_uploading

  render_api Renderable.new({
    contents: @model,
    serializer_option: @serializer_option
  })
end

def check_zip_uploading
  case @model.zip_state_name
  when :zipping
    unless @model.check_zip_uploading
      raise Cupix::Errors::Resource.new(code: 'RESC10000', reason: 'Zip does not uploaded')
    end

    @model.done_zip_state
  else
    raise Cupix::Errors::InvalidState.new(code: 'STAT10000', reason: "Invalid state: #{@model.zip_state}")
  end

  @model
end

def check_zip_uploading
  pano_count, pano_page_count = self.get_pano_count(pano_per_page: 200)

  pano_page_count.times do |page|
    page += 1
    _object = self.zip_object(ver: zip_revision + 1, page: page)

    unless _object.exists?
      self.missing_zip_state
      return false
    end
  end

  increase_zip_revision
  save_zip_source_timestamp
  true
end

def zip_object(ver: nil, page: nil)
  _ver = ver || self.zip_revision
  _page = page || 0

  Cupix::StorageService.object(
    storage_option: storage_option,
    bucket_name: storage_option.s3_hosting_bucket_name,
    key: zip_object_key(ver: _ver, page: page)
  )
end

기대 동작 vs 실제 동작:

• 기대: zip 업로드 완료 폴링은 O(1) 또는 O(page 수 / 병렬 처리) 로 빠르게 상태 반환.
• 실제: page 수만큼 직렬 S3 HEAD (exists?) 를 실행. 예를 들어 200 pano/page × 10 페이지 = 2000 pano capture 라면 10 회 HEAD, 각 200500 ms 이면 총 25 초. 페이지 수가 30 을 넘으면 15~30 초까지 확장 가능. 추가로 상태 전이 시 done_zip_state 가 state_machine transition 을 트리거하며 save 콜백/DB 쓰기가 동반됨.

Log Evidence#

Datadog query (재현용):

service:cupixworks-api "check_zip_uploading" @duration:>5000

시간창 2026-07-10T19:00:00Z ~ 2026-07-10T20:00:00Z 에서 관측된 대표 slow request 3건:

{
  "timestamp": "2026-07-10T19:29:02.738Z",
  "message": "[200] PUT /api/v1/captures/732857/check_zip_uploading",
  "duration": 6115.87,
  "db": 488.5,
  "region": "us-west-2",
  "team": { "domain": "mcalvain", "id": 1038 },
  "user_agent": "axios/1.6.7"
}

{
  "timestamp": "2026-07-10T19:23:08.997Z",
  "message": "[200] PUT /api/v1/captures/732899/check_zip_uploading",
  "duration": 6408.05,
  "region": "us-west-2",
  "team": { "domain": "weoneil", "id": 664 }
}

{
  "timestamp": "2026-07-10T19:45:38.240Z",
  "message": "[200] PUT /api/v1/captures/732973/check_zip_uploading",
  "duration": 28797.23,
  "db": 4340.17,
  "region": "us-west-2",
  "team": { "domain": "whitingturner", "id": 140 }
}

동일 endpoint 라도 소형 capture 에서는 빠르게 반환됨 (대조군):

{
  "timestamp": "2026-07-10T19:20:46.859Z",
  "message": "[200] PUT /api/v1/captures/42584/check_zip_uploading",
  "duration": 272.07,
  "db": 31.32,
  "region": "eu-central-1",
  "team": { "domain": "bimtec", "id": 125 }
}

• 소형 capture (42584): 272 ms, DB 31 ms → 페이지 1개 수준.
• 대형 capture (732973): 28797 ms, DB 4340 ms → DB 외 시간 24.4 s 가 S3 HEAD 루프 + state 저장에 소진.
• 다중 team 관측 → tenant 특정 이슈 아님, endpoint 구조 문제.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 대상 파일: app/models/concerns/zippable/capture.rb:45-61 (Zippable::Capture#check_zip_uploading).
• 방향: S3 HEAD 호출을 병렬화하거나 (예: Parallel.map / Concurrent::Promises) 단일 API 로 대체 (list_objects_v2 prefix 로 한 번에 조회 후 클라이언트 사이드에서 pano_page_count 페이지 존재 여부 검증). Cupix::StorageService.object_list 가 이미 prefix 기반 나열을 지원하므로, #{hex}/zipped_captures/#{s3_region_code}/#{id}/v#{zip_revision + 1}/ prefix 로 1회 list 후 p1..pN 를 비교하는 방식이 자연스러움.
• 근거: zip_object_key 규칙이 #{hex}/zipped_captures/#{region}/#{id}/v#{ver}/p#{page} 로 페이지 접두어가 정렬 가능한 형태 (app/models/concerns/decorators/zip.rb:5-10). 단일 ListObjectsV2 로 O(1) 왕복에 축소 가능.
• 코드 자체는 이번 리포트에서는 방향만 제시 (2줄 이상 변경).

단기 개선 (1주 이내)#

• check_zip_uploading 폴링 결과를 캐싱: 첫 호출에서 pano_page_count 만큼 확인해 성공하면 상태를 done 으로 전이하고, 실패 페이지는 짧게 캐시(TTL 수 초)해 재폴링 시 동일 HEAD 반복을 방지.
• 상태 전이 (done_zip_state) 가 발생시키는 state_machine 콜백/save 비용 프로파일링 (app/models/concerns/statable/capture.rb:309-337). 필요하면 콜백 슬리밍.
• endpoint 에 timeout budget 을 두어 예: 5초를 넘기면 202 Accepted + 진행 중 응답을 리턴해 클라이언트가 백오프 폴링하도록 계약 변경.

장기 개선 (재발 방지)#

• zip 완료 이벤트를 push 로 전환: 현재는 client polling → server 가 매번 S3 HEAD 로 확인. Zip lambda 완료 시 SQS/SNS → tesla worker 가 capture state 를 :done 으로 전이하고, API 는 DB 만 읽어 응답 (S3 HEAD 제거). app/models/concerns/zippable/capture.rb:114-130 의 run_zip lambda invocation 흐름과 짝을 이루는 완료 콜백을 추가.
• APM 대시보드에 endpoint 별 p95/p99 를 alert 로 설정해 이번과 같은 latency 클러스터가 서비스 저하 인시던트로 확대되기 전에 감지.

Monitoring#

• 추가할 SLO: check_zip_uploading p95 < 2s. 초과 시 alert.
• Datadog timeseries 쿼리 (dashboard widget 용):

avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::capturescontroller#check_zip_uploading} by {region}

p95:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::capturescontroller#check_zip_uploading}

sum:trace.rack.request.hits{service:cupixworks-api,resource_name:api::v1::capturescontroller#check_zip_uploading}.as_rate()

• 로그 기반 지연 분포 대시:

service:cupixworks-api "check_zip_uploading" @duration:>5000

Risk Assessment#

• Risk level: medium — 사용자 체감 지연은 명확 (다운로드 워크플로우), 그러나 500/에러가 아닌 200 응답이라 SLA 관점 알람이 늦게 잡힘. 대형 capture 가 많은 team 일수록 영향 확대.
• 예상 복잡도: standard — List 로 교체하거나 병렬 HEAD 로 바꾸는 것은 자연스러운 리팩터. 장기적 push 모델 전환은 별도 스코프.