ES /docs

MaskableRepository — InnoDB row lock contention on concurrent pano updates

RCA: PanosController#mask_upload_url Latency (1815ms)

Overview#

What Happened#

2026-05-27 11:44:09 UTC에 cupixworks-api 서비스의 Api::V1::PanosController#mask_upload_url 엔드포인트에서 1815ms의 응답 지연이 발생했다. cupix-agent 클라이언트가 12개 이상의 pano mask upload URL 요청을 동시에 전송하는 burst 패턴에서, 첫 번째 배치(~11:44:10)는 정상(100-350ms)이었으나 두 번째 배치(~11:44:12)에서 1700-3200ms로 급증했다.

Quick Facts#

Field Value
resource_name Api::V1::PanosController#mask_upload_url
top_frame app/controllers/concerns/maskable_controller.rb:28
env production, us-west-2
deploy production-us-west-2-20260527t0524z0-650f3601-cupixworks

Timeline#

  1. 2026-05-27T11:44:10Z — 첫 번째 배치 요청 도착 (7개, pano 86026458-86026469), 정상 응답 (100-350ms)
  2. 2026-05-27T11:44:12Z — 두 번째 배치 요청 도착 (5개), 지연 응답 (1700-3200ms)
  3. 2026-05-27T11:44:12.817Z — 대표 trace (ID: 1047593615445870707, pano 86026468) 1813ms 응답
  4. 2026-05-27T11:48:20Z — 동일 사용자의 후속 요청에서도 2065ms 지연 재현

Error Log#

Datadog Logs

json
{
  "resource_name": "Api::V1::PanosController#mask_upload_url",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 1815,
  "max_ms": 1815,
  "sample_trace_id": "1047593615445870707"
}

Impact#

  • Service: cupixworks-api
  • 발생 횟수: 1 (클러스터 기준, 실제 동시간대 5건 이상)
  • 최초 발생: 2026-05-27T11:44:09.407Z
  • 최근 발생: 2026-05-27T11:44:09.407Z
  • 영향 사용자: findorff 팀 (user_id: 38891, cupix-agent 사용)
  • 기능 영향: mask upload URL 생성 지연으로 cupix-agent의 mask 업로드 워크플로우 지연. HTTP 200 정상 응답했으므로 데이터 손실 없음.

Root Cause Summary#

cupix-agent가 12개 이상의 mask_upload_url 요청을 동시에 전송하면서 DB row lock contention이 발생했다. mask_upload_url 엔드포인트는 find_or_create_mask (SELECT + 잠재적 INSERT) → mask.uploading (UPDATE) → @model.uploading_mask_state! (UPDATE)으로 최대 3개의 write operation을 수행한다. 동일 pano의 mask 테이블과 pano 모델의 state 컬럼에 대한 동시 쓰기가 row-level lock 대기를 유발하며, 첫 배치가 lock을 점유하는 동안 두 번째 배치가 대기하면서 1700-3200ms로 지연되었다. DB time 자체는 82ms로 낮지만, 이는 lock 획득 후의 실제 쿼리 시간만 측정한 것이고 lock 대기 시간은 포함되지 않는다.

Technical Analysis#

Code Path#

  • Entry point: app/controllers/concerns/maskable_controller.rb:16
  • before_action set_pano: pano를 DB에서 로드 (permission joins + Pundit 인가)
  • Line 27-28: repository_instance.mask_upload_url(_mask_type) 호출
  • Repository: app/repositories/concerns/maskable_repository.rb:51-62
  • Model: app/models/concerns/maskable.rb:42-57find_or_create_mask
  • Serializer: app/serializers/mask_serializer.rb:13-19 — S3 presigned URL 생성 트리거
  • S3 URL: app/models/concerns/storagable/mask.rb:37-44

1. Controller action (entry point)

app/controllers/concerns/maskable_controller.rb:16-34ruby
def mask_upload_url
  if params[:review_key].present?
    review_repository_instance = ReviewRepository.new(current_user: current_user)
    review = review_repository_instance.show(params[:review_key])

    pano = PanoRepository.new(current_user: current_user, review: review).show(params[:id])
    if !review_repository_instance._capture_ids.include?(pano.capture_id) || !review_repository_instance._level_ids.include?(pano.level_id)
      raise Cupix::Errors::NotFound.new(code: 'ARG10002', reason: 'Pano not found with review', review: { key: params[:review_key] }, pano: { id: params[:id] })
    end
  end

  _mask_type = params[:mask_type].presence || 'custom'
  mask = repository_instance.mask_upload_url(_mask_type)

  render_api Renderable.new({
    contents: mask,
    serializer: MaskSerializer
  })
end

2. Repository — DB write operations (contention point)

app/repositories/concerns/maskable_repository.rb:51-62ruby
def mask_upload_url(mask_type)
  _mask_type = mask_type.presence || 'custom'
  mask = @model.find_or_create_mask(_mask_type)  # SELECT + potential INSERT

  if %i[missing created uploaded].include?(mask.state_name)
    mask.uploading  # UPDATE masks SET state = 'uploading'
  end

  @model.uploading_mask_state!  # UPDATE panos SET mask_state = 'uploading'

  mask
end

기대 동작: 각 요청이 독립적인 pano에 대해 mask를 생성/갱신하므로 병렬 처리 가능해야 함. 실제 동작: 동시 요청 시 masks 테이블의 INSERT와 panos 테이블의 UPDATE가 겹치면서 DB connection pool 경합 및 row lock 대기 발생.

3. find_or_create_mask — 비원자적 패턴

app/models/concerns/maskable.rb:42-57ruby
def find_or_create_mask(mask_type = CUSTOM_TYPE)
  mask = masks.find_by_mask_type(mask_type)

  if mask.nil?
    mask = ::Mask.new

    mask.maskable_id = id
    mask.maskable_type = self.class.name
    mask.mask_type = mask_type
    mask.team_id = self.team_id

    mask.save!  # INSERT — row lock on masks table
  end

  mask
end

4. S3 presigned URL 생성

app/models/concerns/storagable/mask.rb:37-44ruby
def mask_upload_url(params = {})
  _mask_revision = params[:mask_revision].presence || mask_upload_revision
  mask_object(mask_type: params[:mask_type], mask_revision: _mask_revision).presigned_url(
    :put,
    bucket: hosting_bucket_name,
    expires_in: $AWS[:s3][:put_presigned_url_expires_in].to_i,
    acl: 'bucket-owner-full-control'
  )
end

S3 presigned URL 생성은 일반적으로 로컬 암호화 연산이지만, AWS credential이 만료되어 instance metadata 또는 STS에서 갱신이 필요한 경우 추가 네트워크 지연이 발생할 수 있다.

Log Evidence#

Datadog에서 사용한 쿼리:

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

대표 trace (ID: 1047593615445870707)의 로그:

text
2026-05-27T11:44:12.817Z [200] POST /api/v1/panos/86026468/mask_upload_url (Api::V1::PanosController#mask_upload_url)
  duration: 1813.35ms, db_time: 82.43ms
  host: ip-10-1-144-228
  user_id: 38891, team: findorff, session: 455ad67ca73a66bdb602d3bb3fc0f90a5cdec03d

동시간대 관련 로그:

text
2026-05-27T11:44:10.595Z Published event - failed_record_count: 0 / 1 (class: Cupix::EventService)
2026-05-27T11:44:10.595Z world_transformation set as [...] (class: Pano, function: set_world_transformation_from_meta)
2026-05-27T11:44:10.595Z Set a storage on Mask using default storage on uswe2 (class: Mask, function: set_storage)

지연 패턴 비교:

text
# 첫 번째 배치 (~11:44:10) - 정상
pano 86026461: 354ms (db: 61ms)
pano 86026460: 198ms (db: 77ms)
pano 86026458: 136ms (db: 30ms)
pano 86026459: 103ms (db: 19ms)

# 두 번째 배치 (~11:44:12) - 지연
pano 86026465: 3204ms (db: 118ms)
pano 86026466: 1782ms (db: 81ms)
pano 86026468: 1813ms (db: 82ms) ← 대표 trace
pano 86026467: 1776ms (db: 30ms)
pano 86026463: 1760ms (db: 25ms)

핵심 관찰: DB time(25-118ms)과 total duration(1700-3200ms) 간 큰 격차는 lock 대기 또는 connection pool 대기 시간이 Rails 계측에서 DB time으로 측정되지 않음을 의미한다.

Hypotheses Considered#

# Hypothesis Evidence for Evidence against Verdict
H1 DB row lock contention from concurrent mask state updates 동시 12개 요청 burst; 첫 배치 정상, 두 번째 배치 지연; total duration >> db_time (lock 대기 미계측); repository에서 3개 write operation 순차 수행 각 pano가 별도 row이므로 pano 간 직접적 row lock은 없어야 함 — 그러나 masks 테이블 INSERT와 connection pool 경합은 발생 가능 Confirmed
H2 AWS S3 credential refresh latency presigned URL 생성 시 credential 만료 시 STS 호출 필요; 배포 직후(05:24Z) 새 인스턴스에서 첫 credential fetch 가능 credential refresh는 한 번만 발생하고 캐시됨, 같은 호스트의 첫 배치는 정상 응답 Rejected
H3 Application server request queueing (Puma thread exhaustion) 3개 서버(ip-10-1-80-134, ip-10-1-144-228, ip-10-1-19-190)에 분산됨에도 모두 지연; burst 요청이 available thread를 모두 점유 가능 3개 서버 모두 동시에 thread 고갈은 12개 요청으로는 불가능 (일반적으로 Puma는 16-32 thread) Rejected
H4 DB connection pool exhaustion under concurrent write load 동시 12개 요청이 각각 3개 DB operation 수행 = 최대 36개 concurrent DB connection 필요; pool size 초과 시 대기 발생; db_time에 pool 대기는 미포함 connection pool size 미확인 — uncertain Likely contributing

Fix Recommendation#

즉시 조치 (Critical)#

  • 해당 없음 — HTTP 200 정상 응답했으며 기능적 장애가 아닌 latency 이슈. 즉시 조치 불필요.

단기 개선 (1주 이내)#

  • app/repositories/concerns/maskable_repository.rb:51-62: find_or_create_mask와 state transition을 하나의 DB transaction으로 묶어 lock 점유 시간 최소화. find_or_create_by 패턴 사용으로 race condition 방지.
  • app/models/concerns/maskable.rb:42-57: find_or_create_mask에서 find_or_create_by!를 사용하여 SELECT → INSERT 간의 race condition 제거.
  • cupix-agent 측에서 동시 요청 수를 제한하는 rate limiting 또는 request batching 적용 검토.

장기 개선 (재발 방지)#

  • mask_upload_url 엔드포인트에 bulk API 제공: 하나의 요청으로 여러 pano의 mask upload URL을 동시에 생성할 수 있도록 하여 N개의 HTTP 요청을 1개로 줄임.
  • DB connection pool size 모니터링 및 적정 수준 확인. concurrent write 부하에 맞게 pool size 조정.

Monitoring#

  • mask_upload_url 엔드포인트 p95/p99 latency 알림 추가:
text
avg(last_5m):trace.rack.request.duration{service:cupixworks-api, resource_name:api::v1::panoscontroller#mask_upload_url} > 1000
  • DB connection pool 사용률 메트릭 추가 (ActiveRecord pool checkout wait time)
  • cupix-agent burst 패턴 감지를 위한 request rate 모니터링

Risk Assessment#

  • Risk level: low
  • 예상 복잡도: standard
  • 사유: 기능 장애 없이 latency만 증가하는 이슈. HTTP 200 정상 응답하며 데이터 손실 없음. 특정 클라이언트(cupix-agent)의 burst 패턴에서만 재현되며, 일반 사용자에게는 영향 없음.