ES /docs

Api::V1::VideosController#check_uploading (avg 1111ms, max 1250ms)

RCA: Api::V1::VideosController#check_uploading Latency (avg 1111ms)

Overview#

What Happened#

2026-05-26 10:38~10:51 UTC 사이에 cupixworks-api 서비스의 Api::V1::VideosController#check_uploading 엔드포인트에서 평균 1111ms, 최대 1250ms의 응답 지연이 9회 발생했다. nhc-sa 팀의 모바일 클라이언트(Dart/3.11)가 36개 비디오를 순차적으로 벌크 업로드하는 과정에서 발생했으며, 핵심 병목은 S3 HEAD 요청(_object.exists?)의 네트워크 지연이다.

Quick Facts#

Field Value
resource_name Api::V1::VideosController#check_uploading
top_frame app/models/concerns/storagable/resource.rb:167
env production, us-west-2
avg_duration 1111ms
max_duration 1250ms

Affected Teams#

Team / Domain Error Count Impact
nhc-sa (team_id: 828) 9 비디오 업로드 확인 지연 — 36개 비디오 벌크 업로드 시 누적 지연 약 10초

Timeline#

  1. 2026-05-26T10:38:23Z — 첫 번째 고지연 trace 감지 (nhc-sa 벌크 업로드 시작)
  2. 2026-05-26T10:51:03Z — 마지막 고지연 trace (벌크 업로드 종료)
  3. 2026-05-26T10:52:00Z — 정상 응답 시간 복구

Error Log#

Datadog Logs

json
{
  "resource_name": "Api::V1::VideosController#check_uploading",
  "service": "cupixworks-api",
  "occurrences": 9,
  "avg_ms": 1111,
  "max_ms": 1250,
  "sample_trace_id": "1653695293901843325"
}

Impact#

  • Service: cupixworks-api
  • 발생 횟수: 9
  • 최초 발생: 2026-05-26T10:38:23.475Z
  • 최근 발생: 2026-05-26T10:51:03.912Z

Root Cause Summary#

check_uploading 엔드포인트의 핵심 로직은 S3에 HEAD 요청을 보내 파일 업로드 완료를 검증하는 것이다(Aws::S3::Object#exists?). 이 동기식 S3 네트워크 호출이 요청당 600~800ms를 소비하며 전체 응답 시간의 70%를 차지한다. 추가로 before_action :set_video에서 실행되는 12개 LEFT JOIN permission 쿼리(200400ms)와, resources 연관이 eager load되지 않아 발생하는 N+1 쿼리가 나머지 지연을 구성한다. nhc-sa 모바일 클라이언트가 resource_state 필드를 응답에 요청하면서 추가 S3 조회가 발생하여 데스크톱 클라이언트(191ms) 대비 5배 이상 느린 응답(1025ms)을 보인다.

Technical Analysis#

Code Path#

1. Entry point — Controller action

app/controllers/api/v1/videos_controller.rb:47-52ruby
def check_uploading
  video = repository_instance.check_uploading
  render_api Renderable.new({
    contents: @model
  })
end

before_action :set_video(line 5)가 먼저 실행되어 @model을 로드한다.

2. before_action — set_video (permission + default_joins 실행)

app/controllers/api/v1/videos_controller.rb:63-65ruby
def set_video
  @model = repository_instance.show(params[:id])
end

BaseRepository.showdefault_joins + permission_joins를 적용하여 비디오를 조회한다. permission_joins는 12개 LEFT JOIN sub-query로 user/group/system 레벨 권한을 집계하며, 약 200~400ms 소요.

3. default_joins — resources eager load 누락

app/repositories/video_repository.rb:27-36ruby
def self.default_joins(record)
  record.includes(:storage).joins("
    LEFT JOIN facilities ON facilities.id = videos.facility_id
    LEFT JOIN records ON records.id = videos.record_id
    LEFT JOIN captures ON captures.id = videos.capture_id
    LEFT JOIN cameras ON cameras.id = captures.camera_id
    LEFT JOIN workspaces ON workspaces.id = videos.workspace_id
    LEFT JOIN levels ON levels.id = captures.level_id
    LEFT JOIN capture_types ON capture_types.id = captures.capture_type_id
  ").joins(:facility, :capture).select(...)
end

:storage만 includes하고 :resources는 포함하지 않아 이후 resource 호출 시 N+1 쿼리 발생.

4. Repository — check_uploading 호출

app/repositories/video_repository.rb:305-314ruby
def check_uploading
  case @model.state_name
  when :resource_uploading, :resource_missing, :created
    raise Cupix::Errors::Resource.new(code: 'RESC10000', reason: 'Resource does not uploaded') unless @model.check_resource_uploading
  else
    raise Cupix::Errors::InvalidState.new(code: 'STAT10000', reason: "Invalid state: #{@model.state}")
  end
  @model
end

5. Video concern — N+1 쿼리 트리거

app/models/concerns/resourcable/video.rb:28-36ruby
def check_resource_uploading
  if resource.check_uploading
    self.done
    true
  else
    self.resource_missing
    false
  end
end

resource 메서드 호출로 별도 DB 쿼리 발생:

app/models/concerns/resourcable.rb:56-57ruby
def resource
  self.resources.where(kind: nil).first
end

6. Failure point — S3 HEAD 요청 (핵심 병목)

app/models/concerns/storagable/resource.rb:163-183ruby
def check_uploading
  _revision = self.revision
  _object = self.object(_revision + 1)

  if _object.exists?  # S3 HEAD 요청 — 600~800ms 소요
    self.etag = _object.etag.gsub('"', '') rescue nil
    self.size = _object.size
    self.content_type = _object.content_type rescue nil

    return false if self.size.blank? || self.size.zero?

    MidasOperation.record_attachment_upload(attachment: resourcable, file_size: self.size) if resourcable.is_a?(Attachment) && MidasOperation.enabled?

    self.increase_revision
    self.done
    true
  else
    self.missing
    false
  end
end

_object.exists?Aws::S3::Object의 HEAD 요청으로, S3 API 네트워크 라운드트립에 600~800ms 소요된다. 이후 .etag, .size, .content_type 접근 시 추가 HEAD 또는 캐시된 응답을 사용한다.

Log Evidence#

Datadog에서 사용한 쿼리:

text
service:cupixworks-api resource_name:"Api::V1::VideosController#check_uploading" env:production @duration:>500ms

검색 결과 (71건 중 고지연 패턴):

text
Team: nhc-sa | Avg Duration: 1025ms | DB time: 24ms | Client: Dart/3.11
Team: ellisdon | Avg Duration: 191ms | DB time: 15ms | Client: CupixConnect/4.6.9 (Electron)

nhc-sa 팀 요청의 필드 분석:

text
fields=["id", "name", "state", "meta", "location", "capture", "upload_url", "resource_state"]

ellisdon 팀 요청 (resource_state 미포함):

text
fields=["id", "name", "state", "meta", "location"]

resource_state 필드 포함 시 추가 S3 조회가 발생하여 응답 시간이 5배 증가하는 패턴 확인됨. DB 시간은 모든 팀에서 15~30ms로 일정하여 데이터베이스는 병목이 아님을 확인.

Hypotheses Considered#

# Hypothesis Evidence for Evidence against Verdict
H1 S3 HEAD 요청(_object.exists?)의 네트워크 지연이 주요 병목 DB time 24ms인데 total 1111ms → 미설명 시간 ~1000ms가 S3 네트워크 호출과 일치. ellisdon(resource_state 미요청)은 191ms Confirmed
H2 N+1 쿼리로 인한 DB 병목 resources가 eager load되지 않아 별도 쿼리 발생 (resourcable.rb:57) DB time 24ms로 전체 지연의 2%에 불과 — N+1은 존재하나 주요 원인은 아님 Partially confirmed (minor contributor)
H3 Permission joins의 복잡한 쿼리가 주요 병목 12개 LEFT JOIN sub-query 존재 (video_repository.rb:59-229) DB time 24ms에 이미 포함되어 있으며, 전체 대비 미미함 Rejected
H4 특정 호스트의 리소스 부족 (CPU/메모리) 3개 호스트 모두 동일 지연 분포, 고지연이 특정 호스트에 집중되지 않음 Rejected
H5 resource_state 필드 직렬화 시 추가 S3 호출 nhc-sa(resource_state 요청) 1025ms vs ellisdon(미요청) 191ms — 5배 차이 resource_state 직렬화 로직 미확인 (uncertain — needs verification) Inconclusive

Fix Recommendation#

즉시 조치 (Critical)#

이 지연은 check_uploading 엔드포인트의 설계상 S3 HEAD 요청이 필수적이므로 완전 제거는 불가하다. 그러나 다음으로 영향을 줄일 수 있다:

  • app/repositories/video_repository.rb:28includes(:storage):resources 추가하여 N+1 쿼리 제거
  • latency 임계값 조정 — 현재 500ms 이상을 이상으로 감지하는데, 이 엔드포인트는 S3 호출이 본질적이므로 1500ms 이상으로 상향 검토

단기 개선 (1주 이내)#

  • resource_state 필드 직렬화 최적화 — 모바일 클라이언트가 resource_state를 요청할 때 추가 S3 조회가 발생하는지 확인하고, 불필요한 경우 직렬화에서 제외하거나 캐시 적용
  • S3 exists? 호출에 timeout 설정 — 현재 기본 SDK timeout 사용 중이므로, 명시적으로 2초 timeout 설정하여 극단적 지연 방지

장기 개선 (재발 방지)#

  • 비동기 업로드 확인 패턴 도입 — 클라이언트가 폴링하는 대신 S3 Event Notification → SQS → Worker로 업로드 완료 시 자동 상태 전환하여 동기식 S3 호출 제거
  • Permission joins 캐싱 — 빈번하게 호출되는 엔드포인트에서 permission 계산 결과를 단기 캐시하여 DB 부하 경감

Monitoring#

  • APM에서 check_uploading P95/P99 지연 시간 추적:
text
service:cupixworks-api resource_name:"Api::V1::VideosController#check_uploading" env:production
  • S3 호출 지연 별도 계측 (custom span 추가 권장):
text
service:cupixworks-api operation:s3.head_object @duration:>1000ms
  • 팀별 응답 시간 분포 모니터링 (resource_state 필드 요청 여부별):
text
service:cupixworks-api resource_name:"Api::V1::VideosController#check_uploading" @http.fields:*resource_state*

Risk Assessment#

  • Risk level: low
  • 예상 복잡도: standard