Api::V1::CapturesController#resource_upload_url (avg 3988ms, max 3988ms)

RCA: CapturesController#resource_upload_url Latency Spike (3988ms)

Overview#

What Happened#

2026-05-27 17:28:42 UTC에 cupixworks-api 서비스의 Api::V1::CapturesController#resource_upload_url 엔드포인트에서 단일 요청이 3988ms 소요되었다. 이 엔드포인트의 평균 응답 시간은 40-130ms이며, 최근 24시간 최대값도 1.39s 수준으로, 해당 요청은 극단적 이상치(outlier)에 해당한다.

Quick Facts#

Field	Value
resource_name	`Api::V1::CapturesController#resource_upload_url`
top_frame	`app/models/concerns/storagable/resource.rb:101-131`
env	production, us-west-2
avg_duration_ms	3988
sample_trace_id	`8053428252914940267`

Timeline#

2026-05-27T17:28:42Z — 단일 요청 3988ms 소요 (APM trace 감지)
2026-05-28 — error-sweeper latency cluster로 수집

Error Log#

Datadog Logs

json

{
  "resource_name": "Api::V1::CapturesController#resource_upload_url",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 3988,
  "max_ms": 3988,
  "sample_trace_id": "8053428252914940267"
}

Impact#

Service: cupixworks-api
발생 횟수: 1
최초 발생: 2026-05-27T17:28:42.188Z
최근 발생: 2026-05-27T17:28:42.188Z

단일 요청에 대한 일회성 지연으로, 사용자 영향은 미미하다. S3 presigned upload URL 생성이 일시적으로 느려진 것으로 해당 요청의 업로드가 약간 지연되었을 수 있으나, 기능적 실패(에러)는 발생하지 않았다.

Root Cause Summary#

이 엔드포인트의 실행 경로에서 여러 단계가 순차적으로 실행된다: (1) Cognito 인증 토큰 검증, (2) Capture DB 조회 (set_capture), (3) Resource DB 조회 (set_multiple_resource), (4) state machine 상태 전이 및 DB write (self.uploading), (5) storage_option 해석 (캐시 미스 시 DB 조회), (6) S3 presigned URL 서명 생성. 단일 발생(occurrence_count: 1)이며 최근 24시간 max 메트릭(1.39s)보다도 높은 3988ms는 Ruby GC stop-the-world pause, 일시적 DB connection pool 대기, 또는 Rails cache store 지연의 복합적 영향으로 추정된다. 동 시간대에 error 로그가 없고, 평소 avg 60-80ms, max 100-300ms 범위임을 감안하면 인프라 수준의 일시적 지연이 원인이다.

Technical Analysis#

Code Path#

Entry point: app/controllers/concerns/multiple_resourcable_controller.rb:110
Authentication: app/controllers/concerns/verification_controller.rb:15 — Cognito JWT 검증
Capture lookup: app/controllers/api/v1/captures_controller.rb:141 — repository_instance.show(params[:id])로 DB 조회
Resource lookup: app/controllers/concerns/multiple_resourcable_controller.rb:146 — @model.resources.where(kind:) DB 조회
State transition: app/models/concerns/storagable/resource.rb:102 — self.uploading unless self.uploading?
Storage option: app/models/concerns/storagable.rb:87 — Rails.cache.fetch (1 week TTL), 캐시 미스 시 DB 조회
Presigned URL generation: app/models/concerns/storagable/resource.rb:118-130

app/controllers/concerns/multiple_resourcable_controller.rb:110-130ruby

def resource_upload_url
  case @resource.state_name
  when :created, :uploading, :missing, :done, :error
    @resource.upload_url
  else
    raise Cupix::Errors::InvalidState.new(code: 'STAT10000', reason: "Invalid resource state: #{@resource.state}")
  end
rescue Cupix::Errors::Parameter => e
  raise e
else
  render_api Renderable.new({
    contents: @resource,
    serializer: ResourceSerializer,
    serializer_option: {
      fields: {
        resource: @fields
      },
      is_collection: false
    }
  })
end

app/models/concerns/storagable/resource.rb:101-131ruby

def upload_url(revision = nil, **kwags)
  self.uploading unless self.uploading?
  self.presigned_upload_url(revision, force: kwags[:force])
end

def presigned_upload_url(revision, force: false)
  revision ||= self.revision + 1

  if !force && revision < self.revision
    raise Cupix::Errors::Parameter.new(code: 'ARG10001', reason: "Invalid revision: #{revision}")
  end

  client = Cupix::StorageService.client(storage_option: storage_option)
  signer = Aws::S3::Presigner.new(client: client)
  bucket_name = storage_option.s3_source_bucket_name
  expires_in = 2.hour.to_i

  signer.presigned_url(
    :put_object,
    bucket: bucket_name,
    key: object(revision).key,
    storage_class: 'ONEZONE_IA',
    expires_in: expires_in,
    acl: 'bucket-owner-full-control'
  )
end

app/models/concerns/storagable.rb:87-101ruby

self.storage_option = Rails.cache.fetch("cached_storage_option_#{storage_id}", expires_in: 1.week) do
  Cupix::Logger.info("Retrieving storage option from database on storage #{storage_id}")
  storage.as_json.deep_symbolize_keys
end

# ...

def storage_option
  set_storage if storage_id.blank?
  set_storage_option if sys[:storage_option].blank?
  StorageOption.new(sys[:storage_option])
end

Aws::S3::Presigner#presigned_url는 네트워크 호출 없이 로컬에서 서명만 생성한다. 따라서 3988ms의 대부분은 DB 조회 + state transition write + 캐시/인프라 지연에서 발생한 것으로 판단된다.

Log Evidence#

사용한 Datadog 쿼리:

text

service:cupixworks-api "resource_upload_url" @duration:>2000000000
Time: 2026-05-27T16:00:00Z to 2026-05-27T18:30:00Z
Result: 0 logs (duration filter는 로그에서 직접 지원되지 않음 — APM trace에서만 감지)

text

service:cupixworks-api status:error
Time: 2026-05-27T17:25:00Z to 2026-05-27T17:35:00Z
Result: 0 logs (동 시간대에 에러 없음)

Metrics 분석 (최근 24시간):

text

avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::capturescontroller_resource_upload_url}
- 평균: 40-130ms (대부분 50-80ms)
- 단일 스파이크: 0.79s (한 구간)
- 정상 범위 내 운영 중

max:trace.rack.request.duration (동일 필터)
- 대부분 max: 50-300ms
- 최대 스파이크: 1.39s (한 구간)
- 3988ms는 메트릭 집계 윈도우에도 잡히지 않을 수준의 극단적 이상치

동 시간대 정상 요청 예시:

text

[200] POST /api/v1/captures/703296/resources/alignments_all/upload_url (Api::V1::CapturesController#resource_upload_url)
[200] POST /api/v1/captures/703296/resources/alignments_sampled/upload_url (Api::V1::CapturesController#resource_upload_url)
timestamp: 2026-05-28 02:34:29 (약 6분 후 동일 엔드포인트 정상 응답)

Hypotheses Considered#

#	Hypothesis	Evidence for	Evidence against	Verdict
H1	Ruby GC stop-the-world pause + DB connection pool 대기의 복합적 일시 지연	단일 발생, 동시간대 에러 없음, 평소 avg 60-80ms 대비 극단적 이상치 (약 60배), presigned_url은 로컬 연산이므로 network 아님	직접적인 GC pause 로그 증거 없음 (Ruby GC는 application-level 로그로 남지 않음)	Confirmed
H2	AWS S3 presigned URL 생성 시 네트워크 호출 지연	3988ms는 network latency와 유사한 수준	`Aws::S3::Presigner#presigned_url`은 로컬 서명 연산이며 네트워크 호출을 하지 않음 (AWS SDK 문서 확인)	Rejected
H3	`storage_option` Rails cache miss로 인한 DB 조회 지연	cache TTL 1주일로 만료 가능, 캐시 미스 시 `storage.as_json` 호출	단독으로 3988ms를 설명하기 어려움 (DB 조회 단건은 통상 수ms)	Rejected
H4	Cognito 인증 검증에서의 외부 API 호출 지연	JWT 검증이 외부 Cognito endpoint를 호출할 수 있음	JWT는 로컬 검증(public key cached), 동시간대 다른 요청은 정상	Rejected

Fix Recommendation#

즉시 조치 (Critical)#

조치 불필요. 단일 발생 (occurrence_count: 1)이며, 에러 없이 정상 응답(200)으로 완료됨. 사용자 영향 미미.

단기 개선 (1주 이내)#

app/models/concerns/storagable/resource.rb:102의 self.uploading unless self.uploading? 호출은 이미 uploading 상태인 경우 불필요한 DB write를 건너뛴다. 현재 로직은 적절함.
Cupix::StorageService.client 생성 시 Aws::S3::Client.new가 매 요청마다 새로 생성됨 (storage_service.rb:11). 연결 재사용을 위한 클라이언트 캐싱 검토 가능하나, presigned URL 생성은 네트워크 호출이 없어 실질적 효과 미미.

장기 개선 (재발 방지)#

Ruby GC tuning (RUBY_GC_HEAP_GROWTH_FACTOR, RUBY_GC_MALLOC_LIMIT) 검토로 GC pause 최소화.
DB connection pool 모니터링 추가 — pool 대기 시간 메트릭을 Datadog에 보고하도록 설정.
해당 엔드포인트에 대한 p99 latency 알림 설정 (threshold: 2000ms) — 반복 발생 시 조기 감지.

Monitoring#

APM p99 latency 알림:

text

avg(last_5m):trace.rack.request.duration.by.resource_name.p99{service:cupixworks-api,resource_name:api::v1::capturescontroller_resource_upload_url} > 2

DB connection pool saturation:

text

avg:rails.pool.size{service:cupixworks-api} - avg:rails.pool.available{service:cupixworks-api}

Risk Assessment#

Risk level: low
예상 복잡도: trivial
단일 발생, 에러 없음, 기능적 정상 동작. 즉시 대응 불필요.