RCA: Api::V1::AssetsController#check_cover_uploading Latency (15.9s)

Overview#

What Happened#

2026-05-30 22:41 KST, eu-central-1 리전의 cupixworks-api에서 check_cover_uploading 엔드포인트가 15,928ms 응답 시간을 기록했다. 동일 시간대 다른 요청은 모두 470-490ms 내에 처리되었으며, DB 시간은 정상(22ms)이었으므로 S3 HEAD 요청의 지연이 원인으로 확인되었다.

Quick Facts#

Timeline#

1. 2026-05-30 22:41:14 KST — cover_upload_url 호출 완료 (58ms), 클라이언트에 presigned S3 URL 발급
2. 2026-05-30 22:41:15 KST — check_cover_uploading 요청 시작 (asset nhwhefcxcg3w)
3. 2026-05-30 22:41:31 KST — check_cover_uploading 응답 완료 (15,928ms, HTTP 200)
4. 2026-05-30 22:50:13 KST — Error Sweeper가 latency 클러스터로 감지

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::AssetsController#check_cover_uploading",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 15930,
  "max_ms": 15930,
  "sample_trace_id": "8300922806218568036"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 1
• 최초 발생: 2026-05-30 22:41 KST
• 최근 발생: 2026-05-30 22:41 KST
• 영향 범위: 단일 사용자(cupix-agent, team: hassan-allam)의 cover 업로드 확인 요청 1건. 최종 HTTP 200으로 기능적 실패는 없었으나 UX 지연 발생.

Root Cause Summary#

check_cover_uploading 액션은 S3 HEAD 요청(Aws::S3::Object#exists?)을 통해 커버 이미지 업로드 여부를 확인한다. Cupix::StorageService.object는 AWS SDK S3 클라이언트를 생성할 때 timeout이나 retry 설정을 명시하지 않아 기본값(open_timeout: 15s, retry: 3회)이 적용된다. 클라이언트가 cover_upload_url로 presigned URL을 받은 직후(~1초 이내) check_cover_uploading을 호출했으므로, S3 객체가 아직 존재하지 않거나 eventual consistency 지연으로 HEAD 요청이 반복 재시도되어 약 16초가 소요된 것으로 판단된다.

Technical Analysis#

Code Path#

1. Entry point — Controller action이 repository 호출:

def check_cover_uploading
  @model = repository_instance.check_cover_uploading
  render_api Renderable.new({
    contents: @model
  })
end

2. Repository — cover 상태가 :uploading 또는 :created이면 모델의 check_cover_uploading 호출:

def check_cover_uploading
  case @model.cover_state_name
  when :uploading, :created
    unless @model.check_cover_uploading
      raise Cupix::Errors::Resource.new(code: 'RESC10000', reason: 'Resource does not uploaded')
    end
  end

  @model
end

3. Model — cover_uploaded?를 호출하여 S3 객체 존재 여부 확인:

def check_cover_uploading
  if self.cover_uploaded?
    self.uploaded_cover_state
    true
  else
    false
  end
end

4. Failure point — S3 HEAD 요청 (exists?):

def cover_uploaded?
  cover_object.exists?
end

def cover_object
  Cupix::StorageService.object(
    storage_option: storage_option,
    bucket_name: hosting_bucket_name,
    key: cover_object_key
  )
end

5. S3 Client — timeout/retry 설정 없이 기본값으로 생성:

def object(storage_option: nil, **kwargs)
  opts = parse_storage_option(storage_option).merge(kwargs)
  opts[:force_path_style] = true

  check_required_params(opts, %i[region bucket_name key])

  Aws::S3::Object.new(opts)
end

기대 동작: S3 HEAD 요청이 100-500ms 내에 완료되어 전체 응답이 ~500ms. 실제 동작: S3 객체가 아직 업로드되지 않았거나 cross-region eventual consistency 지연으로 HEAD 요청이 타임아웃/재시도를 거치며 15.9초 소요.

Log Evidence#

Datadog 검색 쿼리:

service:cupixworks-api @http.url_details.path:*check_cover_uploading* env:production

동일 시간대 check_cover_uploading 요청 비교:

{"timestamp": "2026-05-30T13:40:57.121Z", "asset_key": "ab7doutbnjio", "duration_ms": 483.49, "db_ms": 21.72}
{"timestamp": "2026-05-30T13:41:05.123Z", "asset_key": "ucbkqcepkgi3", "duration_ms": 488.44, "db_ms": 22.09}
{"timestamp": "2026-05-30T13:41:11.124Z", "asset_key": "bi536ineo8cn", "duration_ms": 480.07, "db_ms": 21.12}
{"timestamp": "2026-05-30T13:41:31.127Z", "asset_key": "nhwhefcxcg3w", "duration_ms": 15928.42, "db_ms": 22.72}
{"timestamp": "2026-05-30T13:41:37.129Z", "asset_key": "a6ebu2v0xgwz", "duration_ms": 464.45, "db_ms": 21.17}

핵심 관찰:

• DB 시간은 모든 요청에서 21-23ms로 동일 → DB는 원인 아님
• serialization 시간 0ms → 뷰 렌더링도 원인 아님
• 15,928ms 중 약 15,905ms가 unaccounted → S3 I/O 대기 시간

cover_upload_url 호출 시각:

{"timestamp": "2026-05-30T13:41:14.856Z", "action": "cover_upload_url", "asset_key": "nhwhefcxcg3w", "duration_ms": 58.56}

presigned URL 발급 후 약 1초 만에 check_cover_uploading이 호출됨 — 실제 파일 업로드가 완료되기 전에 확인 요청이 도달.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• app/services/cupix/storage_service.rb:29-36: Aws::S3::Object.new 생성 시 http_open_timeout, http_read_timeout을 3-5초로, retry_limit를 1-2회로 명시 설정하여 최악의 경우에도 10초 이상 블로킹되지 않도록 제한.
• app/models/concerns/coverable.rb:36-37: cover_uploaded?가 false를 반환할 때 즉시 에러를 발생시키는 기존 로직은 정상이므로 변경 불필요. 다만 클라이언트 측에서 업로드 완료 후 확인 요청을 보내도록 시퀀스 개선 필요.

단기 개선 (1주 이내)#

• check_cover_uploading 액션에 전체 요청 timeout (예: Rack::Timeout 또는 controller-level timeout 5초)을 설정하여 S3 지연이 전체 요청을 15초 이상 블로킹하지 않도록 방어.
• 클라이언트(cupix-agent)가 cover_upload_url 발급 후 실제 S3 업로드 완료를 확인한 다음 check_cover_uploading을 호출하도록 클라이언트 로직 검토. 현재는 presigned URL 발급 즉시 확인 요청을 보내는 것으로 보임.

장기 개선 (재발 방지)#

• S3 upload 확인을 동기 HEAD 요청 대신 S3 Event Notification + Lambda/SQS 기반 비동기 확인으로 전환. 클라이언트는 업로드 후 콜백이나 polling 대신 이벤트 기반으로 상태 갱신을 받도록 아키텍처 변경.
• Cupix::StorageService 전체에 대해 timeout/retry 기본값을 명시적으로 설정하는 설정 계층(initializer)을 추가하여 다른 S3 호출에서도 동일 문제가 발생하지 않도록 일관된 정책 적용.

Monitoring#

• S3 HEAD 요청 duration 메트릭 추가 (custom instrumentation 또는 APM span)
• Datadog APM에서 check_cover_uploading 엔드포인트 p95 latency 알림 설정:

avg(last_5m):p95:trace.rack.request{service:cupixworks-api,resource_name:Api::V1::AssetsController#check_cover_uploading} > 3000

• S3 exists? 호출 실패/재시도 카운터를 로깅하여 어떤 asset에서 반복 발생하는지 추적

Risk Assessment#

• Risk level: low — 단발 이벤트(1회), HTTP 200으로 기능적 실패 없음, UX 지연만 발생
• 예상 복잡도: standard — S3 client timeout 설정은 간단하나, 클라이언트 호출 시퀀스 개선은 cupix-agent 수정 필요