RCA: Api::V1::AssetsController#download 92s latency

Overview#

What Happened#

2026-06-26 10:51 KST 시각에 cupixworks-api (ap-southeast-2, tenant cupix) 의 Api::V1::AssetsController#download 요청 한 건이 92.9초 동안 지연되었다. 동일 시간대에 같은 region/tenant 의 다른 엔드포인트들이 ActiveRecord::LockWaitTimeout (Mysql2 lock wait timeout 50초) 으로 502 응답을 다수 반환하고 있었으며, 본 latency 클러스터는 같은 DB lock contention 사건의 일부로 보인다. status board 도 본 클러스터를 2026-06-26-svc-cupixworks-api--unknown-1 인시던트에 묶고 있다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-06-26 10:25 KST — Parent incident 2026-06-26-svc-cupixworks-api--unknown-1 시작 (Api::V1::PanosController#update 41.5s latency, cluster 943fdcb4).
2. 2026-06-26 10:46 KST 이후 — panos 테이블 대상 Mysql2::Error::TimeoutError: Lock wait timeout exceeded 502 응답 다수 발생 (check_tile_uploading, check_mask_uploading, mask_upload_url). duration ≈ 50087ms = innodb_lock_wait_timeout 기본값.
3. 2026-06-26 10:51:49 KST — Api::V1::AssetsController#download 92945ms (≈ lock wait timeout 1회 + 추가 대기) 후 응답 (trace 1226871822661237507). 본 클러스터 first_seen / last_seen.
4. 2026-06-26 10:53 KST 이후 — 추가 502 LockWaitTimeout 발생 후 parent incident 의 다른 cluster 들이 같은 패턴으로 분류됨.

Error Log#

Datadog Logs

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

Impact#

• Service: cupixworks-api
• 발생 횟수: 1
• 최초 발생: 2026-06-26 10:51 KST
• 최근 발생: 2026-06-26 10:51 KST

Root Cause Summary#

Api::V1::AssetsController#download 엔드포인트 자체는 set_asset (1회 DB lookup) → resource.download_url (S3 presigned URL 생성) → 302 redirect 의 단순 흐름이며 정상 응답은 수십 ms 이내에 끝난다. 그러나 사건 시각 ap-southeast-2 / tenant cupix 의 production DB 에서 panos 테이블을 둘러싼 광범위한 InnoDB row-lock 경합이 발생하여 50초 innodb_lock_wait_timeout 으로 502 를 반환하는 요청이 다수 누적되고 있었다. 본 요청은 같은 DB / connection pool 을 공유하기 때문에 set_asset 단계의 DB SELECT 또는 그 외 before_action 단계 (예: check_team_license, ApplicationRecord lookup) 에서 lock 또는 connection 대기로 묶여 92.9초 지연되었다. 본 클러스터는 단독 root cause 가 아니라 parent incident (2026-06-26-svc-cupixworks-api--unknown-1) 의 부수 피해이다.

Technical Analysis#

Code Path#

download 액션 자체는 redirect 외 비즈니스 로직이 거의 없다:

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

@model 은 before_action :set_asset 에서 채워지며, 이 단계가 DB 를 한 번 친다:

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

resource.download_url 은 Storagable::Resource#download_url 로, 외부 호출이 없고 S3 presigned URL 만 만드는 in-memory 연산이다:

def download_url(opts = {})
  ver = opts[:ver] || self.revision

  raise Cupix::Errors::Resource.new(code: 'ENT10011', reason: "Resource does not uploaded: #{ver}") if ver.zero?

  filename = opts[:filename].presence || self.name

  case opts[:distribution]
  when 'cloudfront'
    _rcd = CGI.escape("attachment; filename=#{filename}")
  else
    if !opts[:exp].blank?
      exp = opts[:exp]
    else
      exp = 3.hours.to_i
    end

    self.object(ver).presigned_url(:get, expires_in: exp, response_content_disposition: "filename=#{CGI.escape(filename) rescue nil}")
  end
end

• Entry point: app/controllers/api/v1/assets_controller.rb:51
• DB hit (의심 stall 지점): app/controllers/api/v1/assets_controller.rb:62-64 의 set_asset 및 상위 Api::V1::ApiController before_action 체인 (check_team_license, set_app_id, set_updated_since)
• Presigned URL 생성: app/models/concerns/storagable/resource.rb:203 — 외부 I/O 없음

기대 동작: DB SELECT 1회 + 메모리 연산으로 수십 ms 이내 302 응답. 실제 동작: 92945ms 후 응답. before_action / set_asset 단계에서 MySQL connection 또는 row-lock 대기로 묶인 것으로 추정. 코드 자체에는 본 latency 를 유발하는 결함이 없다.

Log Evidence#

같은 시간대 같은 region 의 DB lock 경합을 보여주는 로그를 Datadog 에서 조회.

쿼리:

service:cupixworks-api "Lock wait timeout"
시간 범위: 2026-06-26T01:25:00Z ~ 2026-06-26T02:00:00Z

대표 로그 (raw, region/tenant 태그 포함):

{
  "service": "cupixworks-api",
  "host": "ip-10-1-83-103.ap-southeast-2.compute.internal",
  "tenant": "cupix",
  "team": { "domain": "crossriverrail", "id": 72 },
  "controller": "Api::V1::PanosController",
  "action": "check_mask_uploading",
  "duration": 50087.91,
  "error": {
    "message": "Mysql2::Error::TimeoutError: Lock wait timeout exceeded; try restarting transaction",
    "class": "ActiveRecord::LockWaitTimeout"
  }
}

같은 시간 창 (10:46~10:53 KST) 에서 다수 502 응답이 모두 50087ms 부근에서 끊김 — MySQL InnoDB innodb_lock_wait_timeout (기본 50s) 의 정확한 일치:

2026-06-26 10:46:39 [502] PUT /api/v1/panos/14131474/check_tile_uploading  ActiveRecord::LockWaitTimeout
2026-06-26 10:46:43 [502] PUT /api/v1/panos/14132644/check_tile_uploading  ActiveRecord::LockWaitTimeout
2026-06-26 10:46:47 [502] PUT /api/v1/panos/14131939/check_tile_uploading  ActiveRecord::LockWaitTimeout
2026-06-26 10:47:28 [502] PUT /api/v1/panos/14132652/check_tile_uploading  ActiveRecord::LockWaitTimeout
2026-06-26 10:47:29 [502] PUT /api/v1/panos/14132647/check_tile_uploading  ActiveRecord::LockWaitTimeout
2026-06-26 10:47:34 [502] PUT /api/v1/panos/14131474/check_tile_uploading  ActiveRecord::LockWaitTimeout
2026-06-26 10:47:42 [502] PUT /api/v1/panos/14131939/check_tile_uploading  ActiveRecord::LockWaitTimeout
2026-06-26 10:48:41 [502] PUT /api/v1/panos/14131939/check_tile_uploading  ActiveRecord::LockWaitTimeout
2026-06-26 10:53:28 [502] POST /api/v1/panos/14133747/mask_upload_url      ActiveRecord::LockWaitTimeout
2026-06-26 10:53:29 [502] PUT /api/v1/panos/14133757/check_mask_uploading  ActiveRecord::LockWaitTimeout

본 클러스터의 다운로드 trace (10:51:49 KST) 는 위 두 502 폭주 구간 사이에 위치하며, status board 가 본 cluster 를 묶은 parent incident 의 다른 cluster 들은 모두 Api::V1::PanosController#* 의 long-duration trace 다 (예: 943fdcb4 Api::V1::PanosController#update 41.5s, 10:25:34 KST 발생).

성공한 동일 엔드포인트의 정상 응답 시간 (참고 — 평소 패턴):

2026-06-26 10:58:39 [302] GET /api/v1/assets/9u5tqsh6o66a/download         (Api::V1::AssetsController#download)
2026-06-26 10:58:17 [302] GET /api/v1/reviews/pa3nl4/assets/.../download   (Api::V1::AssetsController#download)

이 정상 trace 들의 access log 한 줄로 끝난다 (= 빠른 응답). 92s 지연은 본 한 건만 관측된 outlier.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 본 cluster 는 단독 코드 결함이 아닌 parent incident 의 부수 피해이므로 코드 변경 불필요. parent incident 2026-06-26-svc-cupixworks-api--unknown-1 의 root cause (panos 테이블 row-lock 경합) 처리에 합류한다.
• DB lock 경합의 직접 원인 (어떤 transaction 이 row-lock 을 장기 보유했는가) 은 다음 위치에서 추적해야 한다:
  • Api::V1::PanosController#update, #check_tile_uploading, #check_mask_uploading, #mask_upload_url 의 transaction 경계 (app/controllers/api/v1/panos_controller.rb 및 PanoRepository)
  • 같은 capture/cluster 의 pano upload 처리가 동시에 다발하면서 같은 row 또는 동일 부모 record 의 lock 을 잡는지 확인. crossriverrail team (team.id=72) 의 capture 45578 부근 trace 를 별도 RCA 로 추적할 것.

단기 개선 (1주 이내)#

• Api::V1::AssetsController#download 처럼 단순 redirect/refresh 엔드포인트는 가능한 한 짧은 read-only DB transaction 으로 동작하도록, primary 대신 replica 에서 SELECT 하거나 statement timeout 을 짧게(예: 5s) 두어 lock 경합 시 빠르게 fail-fast 하도록 고려.
• set_asset 의 repository.show(params[:key]) 가 read-only 쿼리임을 보장 (현재 코드상 select 만 수행 — 추가 transaction 시작 여부 확인).

장기 개선 (재발 방지)#

• panos write 경로의 transaction 범위 축소: lock 보유 시간이 긴 transaction 을 찾아 분할.
• ap-southeast-2 production DB 의 innodb_lock_wait_timeout 단축 (현재 50s 추정) — read-heavy API 경로에 영향이 크므로 30s 이하로 검토하고, 동시에 long-running write 를 줄이는 작업과 병행.
• DB connection pool 가용성 / pool_wait 모니터링: lock 경합 시 connection 회수가 막혀 본 download 같은 무관 엔드포인트까지 막히는 cascading 패턴 감지.

Monitoring#

sum:trace.rack.request.duration.by_resource_service.errors{service:cupixworks-api,env:production,region:ap-southeast-2}.as_count()

avg:trace.rack.request.duration{service:cupixworks-api,env:production,resource_name:api::v1::assetscontroller#download}

sum:mysql.innodb.row_lock_waits{service:cupixworks-api,env:production,region:ap-southeast-2}.as_rate()

max:mysql.innodb.row_lock_time{service:cupixworks-api,env:production,region:ap-southeast-2}

추가 권장:

• ActiveRecord::LockWaitTimeout 카운트 Datadog Logs 기반 metric:
  textCopy

  logs("service:cupixworks-api @error.class:ActiveRecord::LockWaitTimeout env:production").index("*").rollup("count").by("region")
  

• region 별 p99 응답 시간을 endpoint 별로 비교하여 ap-southeast-2 만 튀는 패턴을 조기 감지.

Risk Assessment#

• Risk level: medium (단일 trace 의 사용자 영향은 한정적이나, 같은 parent incident 의 cluster 다수가 동시에 발생 — DB 광범위 영향).
• 예상 복잡도: standard — 코드 결함은 없고, parent incident (panos write 경로 lock 분석) 와 연계 작업 필요.