RCA: CapturesController#update Lock Wait Timeout (50s)

Overview#

What Happened#

2026-05-29 10:58 KST, eu-central-1 리전에서 Api::V1::Admin::CapturesController#update 요청이 MySQL InnoDB lock wait timeout(50초)에 도달하여 502 응답을 반환했다. 동일 시간대에 EditingsController#update에서도 반복적인 lock wait timeout이 발생하고 있어, 동시 트랜잭션 간 row-level lock 경합이 원인으로 확인되었다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-05-29 10:22 KST — Capture 37119에 대해 3D Reconstruction invoked on publish
2. 2026-05-29 10:24 KST — Capture 37119 unpublish 수행
3. 2026-05-29 10:34 KST — Editing 121538에서 lock wait timeout 시작 (EditingsController#update)
4. 2026-05-29 10:45 KST — Editing 121538 lock wait timeout 반복 종료 (13+ 건)
5. 2026-05-29 10:59 KST — Admin::CapturesController#update capture 37119 요청 → lock wait timeout (50s), 502 반환
6. 2026-05-29 11:02 KST — 동일 요청 재시도 → 동일 lock wait timeout (50s), 502 반환
7. 2026-05-29 11:02 KST — error-sweeper 감지

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::Admin::CapturesController#update",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 50048,
  "max_ms": 50048,
  "sample_trace_id": "841204706254257661"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 2 (동일 사용자 재시도 포함)
• 최초 발생: 2026-05-29 10:58 KST
• 최근 발생: 2026-05-29 11:02 KST

Root Cause Summary#

MySQL InnoDB의 innodb_lock_wait_timeout(기본값 50초)에 도달한 것이 직접 원인이다. Admin::CaptureRepository#update에서 @model.save!를 호출할 때, 해당 row(capture 37119)에 대한 exclusive lock을 획득하려 했으나, 동일 시간대에 editing 121538의 상태 전환을 처리하는 장기 실행 트랜잭션이 관련 row에 대한 lock을 보유하고 있었다.

핵심 메커니즘: state_machines-activerecord gem은 after_transition 콜백을 트랜잭션 내부에서 실행한다 (gem 소스 callback order: after_save → after_transition → end transaction → after_commit). Editing의 done_state! 이벤트가 트랜잭션을 열고, after_transition 콜백 체인에서 EditingEntity → Capture로 cascading state transition이 발생하며, 각 Capture row에 exclusive lock을 획득한다. 모든 콜백이 완료될 때까지 트랜잭션이 유지되므로, editing_entities가 많을수록 lock 보유 시간이 선형 증가한다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/admin/captures_controller.rb:22-25
• Repository update: app/repositories/admin/capture_repository.rb:34-40
• Base permission check: app/repositories/base_repository.rb:131-143
• Parameter setting: app/concerns/parameter/admin/capture.rb:12-25
• Failure point: app/repositories/admin/capture_repository.rb:38 (@model.save!)

Controller에서 repository.update를 호출:

def update
  @model = repository.new(model: @model, current_user: current_user).update(params)
  super
end

Repository에서 parameter 설정 후 save 호출 — 이 지점에서 lock 대기 발생:

def update(params = {})
  super
  set_parameters(params)
  @model.save!  # ← Lock wait timeout 발생 지점
  @model
end

BaseRepository의 super 호출에서 permission 확인 후 model attribute 설정:

def update(params = {}, current_user = nil)
  raise Cupix::Errors::PermissionDenied.new(code: 'PERM10000', reason: 'Permission denied') unless @model.updatable_by?(@current_user)
  # ...
  check_updatable_by_billing_state!
  set_params(params)
  @model.last_updated_user = self.current_user if @model.respond_to?(:last_updated_user)
end

@model.save!는 MySQL에서 UPDATE captures SET ... WHERE id = 37119를 실행하며, 이때 해당 row에 대한 exclusive lock을 요청한다. 동시에 다른 트랜잭션(editing state machine)이 동일 row 또는 관련 row의 lock을 보유하고 있어 50초간 대기 후 timeout.

Lock Holding Chain (after_transition inside transaction)#

state_machines-activerecord gem (v0.8.0)의 callback 실행 순서 — gem 소스에서 확인:

# Callback Order (from gem documentation):
# * (-) save
# * (-) begin transaction (if enabled)    ← 트랜잭션 시작
# * (1) *before_transition*
# * (4) before_save
# * (-) create/update
# * (7) after_save
# * (8) *after_transition*                ← 여기서 cascade 발생 (아직 트랜잭션 내부)
# * (-) end transaction (if enabled)      ← 트랜잭션 종료
# * (9) after_commit                      ← 트랜잭션 외부

기본 설정 use_transactions: true (line 421):

@defaults = {:action => :save, use_transactions: true}

done_state! 호출 시 after_transition 콜백 체인 (모두 동일 트랜잭션 내부에서 실행):

Editing#done_state! (transaction BEGIN)
  ├─ after_transition → FORCE_APPLY_ENTITIES_STATUSES (line 141-145)
  │   └─ editing_entities.untrashed.each { |entity| entity.done_state! }
  │       └─ EditingEntity#done_state! (nested save)
  │           ├─ after_transition → sync_entity_state(:done) (line 67-71)
  │           │   └─ entity.public_send("done_editing_state!")  ← Capture row LOCK
  │           │       └─ Capture#done_editing_state! (nested save → UPDATE captures SET editing_state='done')
  │           │           └─ CaptureEditingStateProxy.after_transition (line 141)
  │           │               └─ record.update_capture_editing_state → Record row LOCK
  │           └─ after_transition → set_editing_done_at (line 58-60)
  │               └─ entity.stat_editing_done_at, entity.log_state_change
  ├─ after_transition → :done → log_trace_event('preview_finished') (line 158-163)
  ├─ after_transition → :done → start_sitetrack (line 165-167)
  │   └─ SitetrackFactory.create! (DB writes)
  ├─ after_transition → :done/:rejected → sync_review_completion (line 171-175)
  │   └─ reviewer state change + origin.done_state! (재귀!)
  └─ after_transition → :done/:rejected → review.update!(state:) (line 183-197)
(transaction COMMIT) ← 여기서야 모든 lock 해제

핵심 코드 — EditingEntity의 sync_entity_state가 Capture에 cascading:

def sync_entity_state(state)
  return if self.entity.blank?
  return unless self.entity.respond_to?("#{state}_editing_state!")
  return if self.entity.editing_state == self.state

  return if self.editing&.editing_type == 'refinement'

  self.entity.public_send("#{state}_editing_state!")  # ← Capture row exclusive lock 획득
end

Editing의 after_transition → FORCE_APPLY_ENTITIES_STATUSES에서 모든 entity를 순회:

after_transition from: any, to: FORCE_APPLY_ENTITIES_STATUSES do |model, transition|
  # Force to update editing entities state
  model.editing_entities.untrashed.each do |entity|
    entity.public_send("#{transition.to_name}_state!")  # ← N개 entity 각각 state machine 전환
  end
end

추가로, Editing 모델의 before_update 콜백 set_assigned_at도 capture row를 직접 업데이트:

::Capture.where(id: capture_entity_ids).update_all(
  editor_id: editor_id,
  updated_at: DateTime.now
)

Log Evidence#

Datadog에서 확인된 lock timeout 요청:

service:cupixworks-api @http.url_details.path:"/api/v1/admin/captures/37119" @http.method:PUT

첫 번째 요청 (10:59 KST):

{
  "timestamp": "2026-05-29T01:59:06.702Z",
  "request_id": "97129594-b4d5-4746-9aee-213b1ca4cc42",
  "resource_name": "Api::V1::Admin::CapturesController#update",
  "http.status_code": 502,
  "duration": 50046.11,
  "db_time": 50016.72,
  "host": "ip-10-1-16-73.eu-central-1.compute.internal",
  "user": "finn.lee@cupix.com",
  "user_agent": "insomnia/2022.4.2",
  "error": "ActiveRecord::LockWaitTimeout: Mysql2::Error::TimeoutError: Lock wait timeout exceeded; try restarting transaction"
}

두 번째 요청 (11:02 KST, 사용자 재시도):

{
  "timestamp": "2026-05-29T02:02:16.768Z",
  "request_id": "7c04640a-d965-4fdd-907d-4188e8af87e8",
  "duration": 50095.34,
  "db_time": 50017.79,
  "http.status_code": 502
}

동일 시간대 editing 121538 lock timeout 패턴 (10:34~10:45 KST):

service:cupixworks-api @http.url_details.path:"/api/v1/editings/121538" status:error

{
  "resource_name": "Api::V1::EditingsController#update",
  "timestamps": "01:34:53 ~ 01:45:13 UTC (13+ occurrences)",
  "duration": "~50s each",
  "db_time": "~50s each",
  "error": "ActiveRecord::LockWaitTimeout",
  "hosts": ["ip-10-1-16-73", "ip-10-1-81-53"]
}

Lock 보유 트랜잭션의 근거 — editing 121538 상태 전환 로그:

"state has transitioned from editing to done on Editing 121538"

이 메시지가 lock timeout 발생 시간대에 반복 출현하여, editing state machine의 after_transition 콜백이 장기 트랜잭션을 실행하며 capture row에 대한 lock을 점유했음을 시사한다.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical) — FORCE_APPLY_ENTITIES_STATUSES를 비동기 Worker로 분리#

목표: N개 entity를 순회하며 cascading state transition을 수행하는 heavy operation만 Sidekiq worker로 분리하여, 트랜잭션 내 lock 보유 시간 최소화.

대상 콜백 (app/models/concerns/statable/editing.rb):

구현 방법:

기존 EditingStateChangeWorker 패턴을 참고하여 전용 worker 생성:

class ApplyEntitiesStateWorker
  include Sidekiq::Worker
  sidekiq_options queue: :default, retry: 3

  def perform(editing_id, state)
    editing = ::Editing.find_by(id: editing_id)
    return if editing.nil?

    editing.editing_entities.untrashed.each do |entity|
      entity.public_send("#{state}_state!")
    end
  end
end

after_transition from: any, to: FORCE_APPLY_ENTITIES_STATUSES do |model, transition|
  ApplyEntitiesStateWorker.perform_async(model.id, transition.to_name.to_s)
end

참고 — 기존 유사 Worker:

class EditingStateChangeWorker
  include Sidekiq::Worker
  sidekiq_options queue: :default, retry: 1

  def perform(classname, ids, state)
    records = classname.constantize.where(id: ids)
    records.each do |record|
      record.fire_events!((state + '_editing_state').to_sym)
    end
  end
end

주의사항:

• Worker 실패 시 자동 rollback 불가 → 멱등성(idempotency) 보장 필요 (entity의 현재 state 체크 후 전환)
• retry: 3으로 일시적 lock 경합 시 재시도 허용
• Worker 실행 전 editing이 삭제/상태 변경된 경우 방어 처리 (find_by + nil check)

추가: Capture retry (방어 조치)

• app/repositories/admin/capture_repository.rb:38 — @model.save! 호출 시 ActiveRecord::LockWaitTimeout 예외에 대한 1-2회 재시도 추가 (lock 보유측 개선과 병행).

단기 개선 (1주 이내)#

• EditingEntity#sync_entity_state (editing_entity.rb:85-93) — 개별 entity마다 save!를 호출하는 대신, 상태값만 모아서 Capture.where(id: ids).update_all(editing_state: state)로 일괄 업데이트하면 lock 보유 시간을 N → 1로 줄일 수 있음.
• Capture update 시 innodb_lock_wait_timeout을 session 레벨에서 더 짧게 설정(예: 10초)하고 빠른 실패 + 재시도 전략 적용. 50초 대기는 사용자 경험에 치명적.

장기 개선 (재발 방지)#

• Editing-Capture 간 상태 전환에서 row-level lock 의존도를 줄이기 위해 optimistic locking(lock_version) 도입 검토.
• 장기 실행 트랜잭션 모니터링 — innodb_trx 테이블을 주기적으로 조회하여 30초 이상 실행 트랜잭션 알림.
• Admin API에 request timeout(30초)을 application 레벨에서 설정하여 50초 대기를 방지.

Monitoring#

• Lock wait timeout 발생 횟수 모니터링:

service:cupixworks-api "Lock wait timeout exceeded"

• EU 리전 DB lock 경합 추적:

service:cupixworks-api @duration:>30000 env:production @http.url_details.path:/api/v1/admin/captures/*

• MySQL innodb_row_lock_waits 메트릭을 Datadog custom metric으로 수집하여 lock 경합 빈도 추적.

Risk Assessment#

• Risk level: medium
• 예상 복잡도: standard (retry 로직은 trivial이나, editing state machine 콜백 분리는 영향 범위 확인 필요)

Revision History#

Revision 1#

Feedback: Editing state machine의 after_transition 콜백에서 capture row 업데이트를 별도 트랜잭션으로 분리하거나, after_commit 콜백으로 이동하여 lock 보유 시간 최소화. 이쪽으로 다시 조사.

판정:

변경 사항:

• ## Root Cause Summary — lock 메커니즘에 대한 상세 설명 추가 (gem callback order, cascading 체인)
• ### Lock Holding Chain 신규 섹션 추가 — after_transition 콜백의 전체 실행 트리 시각화, gem 소스 코드 증거 포함
• ## Fix Recommendation — 즉시 조치를 "after_transition → after_commit 이동"으로 구체화, 대상 콜백 4개를 line 번호와 함께 명시, 구현 방법 2가지(after_commit + saved_change_to_state?, 비동기 worker) 제시, 주의사항(멱등성, sync_review_completion 예외) 추가

추가 조사 내용:

• state_machines-activerecord gem (v0.8.0) 소스 코드 직접 확인 — callback order, transaction wrapping 메커니즘
• app/models/concerns/statable/editing.rb — 전체 after_transition 콜백 체인 분석 (5개 콜백)
• app/models/concerns/statable/editing_entity.rb:85-93 — sync_entity_state의 capture lock 획득 경로
• app/models/concerns/quality_assurancable/editing_element.rb:141 — CaptureEditingStateProxy.after_transition 연쇄 호출
• app/models/capture_editing_state_proxy.rb — record.update_capture_editing_state 호출로 Record row 추가 lock
• app/concerns/parameter/editing.rb:90 — done_state! 트리거 지점 확인
• app/models/editing.rb:32-86 — before_update :set_assigned_at의 bulk capture update (update_all) 확인

Revision 2#

Feedback: "apply_entities_state 이것만 worker 에서 실행할 수 있게 해주고, 나머지는 heavy operation 이 아니라서 지금 상태로 유지"

판정:

변경 사항:

• ## Fix Recommendation 즉시 조치를 "4개 콜백 모두 after_commit 이동" → "FORCE_APPLY_ENTITIES_STATUSES만 비동기 Worker 분리"로 축소
• 대상 콜백 테이블에 "사유" 컬럼 추가하여 heavy/lightweight 구분 명시
• 구현 방법을 ApplyEntitiesStateWorker 전용 worker 생성으로 구체화, 기존 EditingStateChangeWorker 패턴 참조 추가
• 나머지 3개 콜백은 "현행 유지" 판정으로 변경

추가 조사 내용:

• app/workers/editing_state_change_worker.rb — 기존 entity state 전환 async worker 패턴 확인 (Sidekiq, queue: default, retry: 1)
• statable/editing.rb:148-167 — 나머지 3개 콜백의 실제 operation 복잡도 재확인 (모두 단일 record 처리)