RCA: Api::V1::AssetsController#download Latency (avg 3427ms)

Overview#

What Happened#

2026-06-04 07:31 KST에 cupixworks-api의 Api::V1::AssetsController#download 엔드포인트에서 3427ms의 응답 지연이 감지되었다. us-west-2 리전에서 발생하였으며, 동일 시간대에 해당 리전 전반에 걸친 API 서버 혼잡이 확인되었다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-06-04 07:07 KST — us-west-2 리전에서 slow download 요청 시작 (첫 번째 >3000ms 요청 감지)
2. 2026-06-04 07:10 KST — 최대 지연 4701ms 기록 (asset hdmyaith3ybf)
3. 2026-06-04 07:31 KST — 본 클러스터의 대표 trace 발생 (3424.9ms, asset 1fnqt8vzwq3h)
4. 2026-06-04 07:52 KST — 관련 NotificationService 에러 발생 (별도 이슈)
5. 2026-06-04 16:04 KST — RCA 수행

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::AssetsController#download",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 3427,
  "max_ms": 3427,
  "sample_trace_id": "2032629982414103838"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 1 (클러스터 기준), 실제로 동일 시간대 50+ slow requests 확인
• 최초 발생: 2026-06-04 07:31 KST
• 최근 발생: 2026-06-04 07:31 KST

Root Cause Summary#

us-west-2 리전의 Rails 워커가 동시간대 PanosController 대량 요청(bulk upload/index, 최대 67,938ms)으로 인해 포화 상태에 빠졌고, 이로 인해 AssetsController#download 요청이 워커 큐에서 대기하며 전체 응답 시간이 3427ms로 증가하였다. DB 쿼리 시간(195.96ms)은 정상 범위이며, view 렌더링 시간(0ms)도 정상이다. 총 소요 시간과 DB 시간의 차이인 ~3230ms는 워커 포화로 인한 큐 대기 시간 및 asset_repository.rb의 13개 이상 JOIN을 포함한 복잡한 permission 쿼리의 실행 지연으로 설명된다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/assets_controller.rb:51 — download action
• before_action chain:
  1. authenticate! → lib/cupix/auth/verification.rb:20 (Cognito JWT 검증, 캐시 미스 시 외부 API 호출)
  2. set_asset → app/controllers/api/v1/assets_controller.rb:62 (permission JOIN 쿼리)
• Failure point: 특정 실패 지점 없음 (latency issue). 주요 지연 구간은 set_asset 의 permission 쿼리 및 서버 혼잡으로 인한 큐 대기.

def download
  resource = @model.resource
  if resource.nil? || resource.revision.zero?
    render_json 404
  else
    redirect_to resource.download_url, allow_other_host: true
  end
end

set_asset은 BaseRepository.show를 호출하여 asset을 조회한다:

def set_asset
  @model = repository_instance.show(params[:key])
end

이 호출은 asset_repository.rb의 permission_joins를 통해 13개 이상의 LEFT JOIN과 GROUP BY를 포함한 복잡한 SQL을 생성한다:

# 9개의 permission subquery LEFT JOIN:
# - review_permissions
# - workspace_permissions
# - facility_permissions
# - team_permissions
# + GROUP BY, GREATEST/IFNULL 조합의 WHERE 절

기대 동작: download 액션은 단순히 asset을 조회하고 S3 presigned URL로 302 redirect하므로, 100-300ms 내에 완료되어야 한다. 실제 동작: DB 시간 195.96ms + 추가 ~3230ms 지연 = 총 3424.9ms 소요. 추가 지연은 워커 큐 대기 시간으로 추정된다.

Log Evidence#

검색에 사용한 Datadog 쿼리:

service:cupixworks-api resource_name:"Api::V1::AssetsController#download" @duration:>1000ms

대표 요청 로그:

{
  "timestamp": "2026-06-03T22:31:13.817Z",
  "resource_name": "Api::V1::AssetsController#download",
  "duration_ms": 3424.9,
  "db_time_ms": 195.96,
  "view_time_ms": 0,
  "http_status": 302,
  "path": "GET /api/v1/assets/1fnqt8vzwq3h/download",
  "region": "us-west-2",
  "host": "ip-10-1-19-190.us-west-2.compute.internal",
  "remote_ip": "44.228.8.68",
  "redirect_location": "https://s3.eu-west-3.amazonaws.com/cupixworks-source-0c24fc2dfb77-euwe3/resources/9cexwe/euwe3/v1",
  "user": "ryan.vaughan@enbridge.com",
  "team_id": 1088,
  "request_id": "fbd0232e-91cc-42d2-92a3-a587bbb10a29"
}

동일 시간대 us-west-2 전체 혼잡 증거:

service:cupixworks-api @duration:>3000ms env:production

PanosController#bulk: 최대 67,938ms
PanosController#index: 최대 35,576ms
JobsController#update: 최대 14,410ms
ReferencesController#index: 31,380ms

리전 간 비교 — ap-southeast-2 동일 시간대:

service:cupixworks-api resource_name:"Api::V1::AssetsController#download" region:ap-southeast-2
→ 모든 요청 27-92ms (정상)

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

즉각적인 코드 수정 필요 없음. 이 latency는 서버 혼잡에 의한 일시적 현상이며, 요청 자체는 성공적으로 완료(HTTP 302)되었다. 모니터링 강화로 재발 감지가 우선이다.

단기 개선 (1주 이내)#

• Puma 워커 수 또는 스레드 수 검토: us-west-2 인스턴스(ip-10-1-19-190)의 워커 설정이 현재 부하를 감당하기에 충분한지 확인. PanosController bulk 요청이 워커를 장시간 점유하여 다른 요청이 대기하는 구조.
• PanosController#bulk에 rate limiting 또는 큐 분리 적용 검토: 대량 처리 요청을 별도 워커 풀로 분리하여 lightweight 엔드포인트(download 등)가 영향받지 않도록 격리.

장기 개선 (재발 방지)#

• Request queuing 메트릭 도입: Datadog APM에서 @http.queue_time 또는 Puma queue latency를 별도 모니터링하여, 워커 포화 시 조기 알림을 받을 수 있도록 설정.
• Auto-scaling 정책: us-west-2 API 서버에 대해 request queue depth 기반 auto-scaling 적용 검토.
• Permission 쿼리 최적화: asset_repository.rb:73-217의 13+ JOIN permission 쿼리를 materialized view나 캐싱으로 개선하여, 서버 부하 시에도 DB 응답 시간을 안정적으로 유지.

Monitoring#

• Puma queue latency 모니터 추가:

avg:trace.rack.queue_time{service:cupixworks-api,region:us-west-2} > 1000

• AssetsController#download P95 duration 알림:

p95:trace.duration{service:cupixworks-api,resource_name:Api::V1::AssetsController#download} > 2000

• 워커 포화 감지 (전체 API slow request 급증):

count:trace.duration{service:cupixworks-api,@duration:>3000ms,region:us-west-2}.rollup(count, 300) > 20

Risk Assessment#

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