S3 cross-region metadata queries causing tail latency

RCA: PointcloudsController#check_resource_uploading Latency (avg 1176ms)

Overview#

What Happened#

2026-05-27 13:05 UTC에 cupixworks-api의 Api::V1::PointcloudsController#check_resource_uploading 엔드포인트에서 평균 1176ms 응답 시간이 관측되었다. 동일 시간대에 pointcloud 1109910, 1109912, 1109914에 대한 plane 리소스 업로드 확인 요청이 연속으로 들어왔으며, 모두 800ms~1274ms의 높은 응답 시간을 보였다.

Quick Facts#

Field	Value
resource_name	`Api::V1::PointcloudsController#check_resource_uploading`
top_frame	`app/controllers/concerns/multiple_resourcable_controller.rb:80`
env	production, us-west-2
avg_duration_ms	1176
max_duration_ms	1176

Timeline#

2026-05-27T13:05:05.924Z — 최초 latency 이벤트 감지 (pointcloud 1109910, plane 리소스)
2026-05-27T13:05:21Z — pointcloud 1109912 동일 패턴 발생 (796ms)
2026-05-27T13:05:49Z — pointcloud 1109914 동일 패턴 발생 (1274ms)
2026-05-27 — RCA 분석 수행

Error Log#

Datadog Logs

json

{
  "resource_name": "Api::V1::PointcloudsController#check_resource_uploading",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 1176,
  "max_ms": 1176,
  "sample_trace_id": "2753516916161796567"
}

Impact#

Service: cupixworks-api
발생 횟수: 1 (같은 시간대 유사 요청 3건 추가 확인)
최초 발생: 2026-05-27T13:05:05.924Z
최근 발생: 2026-05-27T13:05:05.924Z
영향 범위: cupix-agent 자동화 클라이언트에서 순차적으로 호출하는 리소스 업로드 확인 워크플로우가 느려짐. 사용자(chan.lee@cupix.com)의 pointcloud 처리 파이프라인 지연 유발.

Root Cause Summary#

check_resource_uploading 엔드포인트의 1176ms 지연은 두 가지 요인의 합산이다: (1) set_pointcloud before action에서 실행되는 15개 LEFT JOIN 권한 조회 쿼리가 ~185ms의 DB 시간을 차지하고, (2) Resource#check_uploading 내부에서 Aws::S3::Object#exists? HEAD 요청이 S3 네트워크 왕복 시간 ~500-800ms를 소비한다. 두 operation이 직렬로 실행되어 합산 1000ms+ 응답 시간이 발생한다.

Technical Analysis#

Code Path#

Entry point: app/controllers/concerns/multiple_resourcable_controller.rb:80
Before action set_pointcloud: app/controllers/api/v1/pointclouds_controller.rb:11 → PointcloudRepository.show
Permission query: app/repositories/pointcloud_repository.rb:40-180
Before action set_multiple_resource: app/controllers/concerns/multiple_resourcable_controller.rb:7
S3 check: app/models/concerns/storagable/resource.rb:163-183
Failure point: 단일 실패 지점이 아닌, 순차적 비용 누적

1. Controller action — 리소스 상태가 :uploading 또는 :missing일 때 check_uploading을 호출하고 결과에 따라 callback을 실행한다:

app/controllers/concerns/multiple_resourcable_controller.rb:80-98ruby

def check_resource_uploading
  case @resource.state_name
  when :uploading, :missing
    callback_uploaded_resource(@resource) if @resource.check_uploading
  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

2. Permission query — set_pointcloud가 실행하는 쿼리는 15개 LEFT JOIN을 사용하여 8개 이상의 권한 테이블을 조인하고 MAX(), GREATEST(), IFNULL() 집계를 수행한다:

app/repositories/pointcloud_repository.rb:44-76ruby

_select = "pointclouds.*,
MAX(pointcloud_user_permissions.permission) AS pointcloud_user_permission,
MAX(review_user_permissions.permission) AS review_user_permission,
MAX(review_group_permissions.permission) AS review_group_permission,
MAX(review_public_permissions.permission) AS review_public_permission,
MAX(record_user_permissions.permission) AS record_user_permission,
MAX(record_group_permissions.permission) AS record_group_permission,
MAX(record_system_group_permissions.permission) AS record_system_group_permission,
MAX(facility_user_permissions.permission) AS facility_user_permission,
MAX(facility_group_permissions.permission) AS facility_group_permission,
MAX(facility_system_group_permissions.permission) AS facility_system_group_permission,
MAX(workspace_user_permissions.permission) AS workspace_user_permission,
MAX(workspace_group_permissions.permission) AS workspace_group_permission,
MAX(team_user_permissions.permission) AS team_user_permission,
MAX(team_group_permissions.permission) AS team_group_permission,
MAX(team_system_group_permissions.permission) AS team_system_group_permission,
MAX(GREATEST(
  IFNULL(pointcloud_user_permissions.permission, 0),
  ...
)) AS applied_permission"

DB 시간 ~185ms는 이 쿼리에 의해 발생한다 (로그에서 확인: DB 184.97ms).

3. S3 HEAD request — check_uploading이 _object.exists?를 호출하여 AWS S3에 HEAD 요청을 보낸다. 이것이 나머지 ~800-1000ms를 차지하는 주요 네트워크 비용이다:

app/models/concerns/storagable/resource.rb:163-183ruby

def check_uploading
  _revision = self.revision
  _object = self.object(_revision + 1)

  if _object.exists?                          # AWS S3 HEAD request (~500-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(...) if resourcable.is_a?(Attachment) && MidasOperation.enabled?

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

4. S3 Object 생성 — Cupix::StorageService.object를 통해 Aws::S3::Object 인스턴스를 생성:

app/models/concerns/storagable/resource.rb:85-99ruby

def object(ver = nil)
  _ver = !ver.nil? ? ver : self.revision
  raise Cupix::Errors::System.new(code: 'SYS10000', reason: "Invalid revision #{ver}") if !_ver.is_a?(Integer) || !(_ver > -1)

  Cupix::StorageService.object(
    storage_option: storage_option,
    bucket_name: storage_option.s3_source_bucket_name,
    key: self.object_key(_ver)
  )
end

Log Evidence#

Datadog 검색 쿼리:

text

service:cupixworks-api *check_resource_uploading*
Time: 2026-05-27T12:00:00Z to 2026-05-27T14:00:00Z

핵심 로그 항목 (동일 시간대 3건):

text

13:05:07.377Z | PUT /api/v1/pointclouds/1109910/resources/plane/check_uploading | 1173.78ms | DB: 184.97ms
13:05:21.803Z | PUT /api/v1/pointclouds/1109912/resources/plane/check_uploading | 796.38ms  | DB: 101.63ms
13:05:49.867Z | PUT /api/v1/pointclouds/1109914/resources/plane/check_uploading | 1273.95ms | DB: 25.86ms

모든 요청의 공통 특성:

json

{
  "user": "chan.lee@cupix.com",
  "user_id": 12697,
  "team": "gad",
  "team_id": 590,
  "user_agent": "cupix-agent",
  "ip": "44.228.8.68",
  "status": 200
}

추가 확인 — 동일 시간대 극단적 지연 요청:

text

service:cupixworks-api @duration:>5000ms
Time: 2026-05-27T13:05:00Z to 2026-05-27T13:06:00Z

13:05:39.859Z | POST /pointclouds/1109910/potree_upload_credentials | 16,665ms

이 16.6초 요청은 S3 presigned URL 생성 과정에서의 추가적인 S3 API 호출 병목을 시사한다.

에러 로그는 없음 (모든 요청 HTTP 200 반환):

text

service:cupixworks-api status:error
Time: 2026-05-27T12:55:00Z to 2026-05-27T13:15:00Z
Result: 0 logs

Hypotheses Considered#

#	Hypothesis	Evidence for	Evidence against	Verdict
H1	S3 HEAD request (`exists?`)가 주 latency 원인	총 응답 1174ms 중 DB가 185ms만 차지 → 나머지 ~990ms가 S3 네트워크 비용. pointcloud 1109914는 DB 26ms인데 총 1274ms → S3가 ~1248ms 소비.	—	Confirmed
H2	15-LEFT-JOIN 권한 쿼리가 주 latency 원인	pointcloud 1109910에서 DB 185ms 측정됨	DB 시간은 전체 latency의 15-16%에 불과. pointcloud 1109914는 DB 26ms인데도 총 1274ms. DB가 주 원인이면 DB 시간과 총 시간이 비례해야 하나 그렇지 않음.	Rejected (보조 요인)
H3	N+1 쿼리 문제	—	단일 pointcloud + 단일 resource 조회이므로 N+1 패턴 없음. DB 쿼리 횟수가 적음.	Rejected
H4	S3 bucket 크로스 리전 접근으로 인한 추가 지연	서버가 us-west-2에 위치하며, 만약 S3 bucket이 다른 리전이면 추가 latency 발생 가능. 같은 시간대 `potree_upload_credentials` 16.6초 timeout도 S3 문제 시사.	버킷 리전 직접 확인 불가 — uncertain	Inconclusive

Fix Recommendation#

즉시 조치 (Critical)#

app/models/concerns/storagable/resource.rb:167 — _object.exists? 호출은 업로드 확인 폴링에서 반복 호출되는 hot path이다. 이 호출에 대한 타임아웃을 설정하여 S3 지연 시 전체 요청이 블로킹되지 않도록 해야 한다.
Cupix::StorageService.object 생성 시 S3 client에 http_open_timeout 및 http_read_timeout을 짧게 설정 (e.g., 3초).

단기 개선 (1주 이내)#

권한 쿼리 캐싱: check_resource_uploading은 cupix-agent가 반복 호출하는 폴링 엔드포인트이다. 동일 사용자+pointcloud 조합에 대한 권한 결과를 짧은 TTL(30-60초)로 캐싱하면 DB 185ms를 절감할 수 있다.
S3 HEAD 요청 결과 캐싱: 업로드 폴링 시 동일 object key에 대해 반복 HEAD 요청이 발생한다. 파일이 아직 존재하지 않는 경우 (:missing 상태), 짧은 negative cache (5-10초)를 도입하여 불필요한 S3 호출을 줄일 수 있다.

장기 개선 (재발 방지)#

이벤트 기반 업로드 확인: S3 Event Notification + SQS/SNS를 활용하여 업로드 완료 시 서버에 알림을 보내는 방식으로 전환. 클라이언트 폴링(check_uploading)을 제거하면 S3 HEAD 요청 자체가 불필요해진다.
권한 쿼리 리팩터링: 15개 LEFT JOIN을 materialized view 또는 별도 permission cache 테이블로 전환하여 단일 pointcloud 조회 시 쿼리 복잡도를 O(1)로 줄인다.

Monitoring#

S3 HEAD request latency를 custom metric으로 추적:

text

service:cupixworks-api resource_name:"Api::V1::PointcloudsController#check_resource_uploading" @duration:>1000ms

권한 쿼리 DB 시간 모니터링:

text

service:cupixworks-api resource_name:"Api::V1::PointcloudsController#check_resource_uploading" @http.status_code:200

S3 API latency를 APM span으로 분리 계측하여 S3 vs DB vs application 시간을 개별 추적.

Risk Assessment#

Risk level: low
예상 복잡도: standard
이유: 기능적 오류가 아닌 성능 이슈로, 모든 요청이 HTTP 200으로 정상 응답하고 있다. 단일 사용자의 자동화 워크플로우에서 발생하며 사용자 체감 영향은 제한적이다. 그러나 동일 패턴이 모든 check_resource_uploading 호출에 적용되므로 부하 증가 시 확대될 수 있다.