RCA: Api::V1::CapturesController#update_meta_by_key latency (avg 51.5s, max 53.9s)

Overview#

What Happened#

2026-07-01 10:47 KST ~ 10:54 KST 사이에 cupixworks-api 의 Api::V1::CapturesController#update_meta_by_key 요청 4건이 평균 51.5초, 최대 53.9초로 지연되었다. 지연의 원인은 endpoint 자체가 아니라 MySQL InnoDB row lock 대기이며, 동일 시간대에 다수의 pano/capture/job endpoint 가 Mysql2::Error::TimeoutError: Lock wait timeout exceeded (기본 innodb_lock_wait_timeout=50s 와 정확히 일치) 로 502 를 반환하고 있다. 이 클러스터는 status-board incident 2026-07-01-svc-cupixworks-api--unknown-1 의 일부로, 최근 7일간 유사 사고가 8회 반복 발생했다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-07-01 10:43 KST — status-board incident 2026-07-01-svc-cupixworks-api--unknown-1 open (첫 클러스터 3f1c828f-...).
2. 2026-07-01 10:43:27 KST — 마지막 정상 응답: [200] PUT /api/v1/jobs/1165311/actions/postprocessor/complete.
3. 2026-07-01 10:47:17 KST — 첫 502: PUT /api/v1/jobs/1165311/actions/postprocessor/complete LockWaitTimeout.
4. 2026-07-01 10:47:35 KST — 본 클러스터 최초 발생 (first_seen) — capture 724756 update_meta_by_key 51초 지연.
5. 2026-07-01 10:50:58 ~ 10:55:00 KST — Lock wait timeout 폭발적으로 확산 (pano/capture/job 여러 endpoint).
6. 2026-07-01 10:54:09 KST — 본 클러스터 마지막 발생 (last_seen).
7. 2026-07-01 10:55:53 KST — capture 724756 meta/prop PUT 정상 성공 (200) — 락 경합 해소 시작.
8. 2026-07-01 10:56:07 KST — capture 724756 publish PUT 200. 이후 reconstruction 큐잉 정상 진행.
9. 2026-07-01 11:02:16 KST — status-board incident 마지막 이벤트 (8cbb9d23-...).

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::CapturesController#update_meta_by_key",
  "service": "cupixworks-api",
  "occurrences": 4,
  "avg_ms": 51498,
  "max_ms": 53938,
  "sample_trace_id": "1537825686223368602"
}

대표적인 502 로그 (동일 endpoint, capture 724756):

{
  "timestamp": "2026-07-01T01:54:08.686Z",
  "status": "info",
  "message": "[502] PUT /api/v1/captures/724756/meta/prop (Api::V1::CapturesController#update_meta_by_key)",
  "error": {
    "message": "Mysql2::Error::TimeoutError: Lock wait timeout exceeded; try restarting transaction",
    "class": "ActiveRecord::LockWaitTimeout"
  }
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 4 (본 클러스터). 인시던트 전체적으로는 15+ 개 endpoint 에서 lock timeout 502 발생.
• 최초 발생: 2026-07-01 10:47 KST
• 최근 발생: 2026-07-01 10:54 KST

Root Cause Summary#

update_meta_by_key 는 MetableController#update_meta_by_key 에서 @model.meta[key] = ...; @model.save 형태로 captures 테이블의 단일 row 를 UPDATE 한다. 문제의 시각에는 동일 Capture 724756 및 인근 record 를 대상으로 여러 워크플로우 — postprocessor complete_action (job 1165311), pano stitched/check_uploading/check_mask_uploading 콜백, publish 파이프라인 — 가 동시에 트랜잭션을 열고 있었다. Rails 모델 Capture 는 75개 이상의 concern (Cyclable, Publishable, Statable, Metable, EntityIndexable, Notifiable, 3D reconstruction 관련 등) 을 include 하고 있어 단순 save 도 여러 callback 및 counter_culture 갱신을 트랜잭션 안에서 수행한다. 그 결과 captures row 및 관련 counter row 에 대한 InnoDB row lock 이 장시간 유지되어, 다른 트랜잭션들이 기본 innodb_lock_wait_timeout=50s 를 넘겨 Mysql2::Error::TimeoutError 로 fail 했다. 본 클러스터의 51-53초 latency 는 MySQL 이 50초 lock wait 후 timeout 을 반환한 시간과 정확히 일치한다. 근본 원인은 endpoint 개별 버그가 아니라 captures (및 관련 pano/job) 테이블에서 발생한 트랜잭션 경합 이며, 재발 빈도(7일간 8회)를 볼 때 특정 이벤트 유발이 아닌 정상 트래픽에서 병목이 반복 노출 되는 구조적 문제다.

Technical Analysis#

Code Path#

Entry point — controller action:

def update_meta_by_key
  if !@model.updatable_by?(current_user) && (@review.present? && !@review.updatable_by?(current_user))
    raise Cupix::Errors::PermissionDenied.new(code: 'PERM10000', reason: 'Permission denied')
  end

  begin
    parsed_meta = JSON.parse(request.raw_post)
    @model.meta[params[:meta_key]] = parsed_meta
    @model.skip_entrypoint_flush = true if @model.respond_to?(:skip_entrypoint_flush)
    @model.save
    ...

Failure point — @model.save (line 51). @model 은 Capture 인스턴스이며, save 시 수많은 concern 콜백이 동일 트랜잭션 내에서 실행된다:

class Capture < ApplicationRecord
  include RecordEntity::Capture
  include EntityIndexable
  include ::Statable::Capture
  include ::Cyclable::Capture
  include Metable
  include Publishable::Capture
  include Notifiable::Capture
  include ::Eventable::Capture
  include EntityUpdates::Child
  include ::DogstatsdMetric::Capture
  # ... 75+ concerns
  has_many :clusters, dependent: :destroy
  has_many :videos, dependent: :destroy
  has_many :nodes, dependent: :destroy
  has_many :pointclouds, dependent: :destroy
  ...
  counter_culture :record,
                  column_name: proc { |model| model.untrashed? && !model.skip_counter_culture? ? 'captures_count' : nil },
                  column_names: { ::Capture.untrashed => :captures_count },
                  execute_after_commit: true
  counter_culture :level,
                  column_name: proc { |model| model.untrashed? && !model.skip_counter_culture? ? 'captures_count' : nil },
                  column_names: { ::Capture.untrashed => :captures_count }
  has_paper_trail
end

기대 동작: 단일 컬럼(meta JSON) UPDATE 는 밀리초 단위로 끝나야 한다. 실제 동작: 동일 Capture row (또는 부모 record/level counter row) 에 대한 다른 트랜잭션(publish 파이프라인, postprocessor complete, pano callback) 이 이미 X-lock 을 보유 중이었고, 본 요청의 UPDATE 는 50초간 대기 후 timeout 되거나 (실패한 3건) 대기 끝에 성공했다 (본 클러스터의 51.5초 span).

동일 시각 경합 상대 — postprocessor complete_action:

2026-07-01T01:43:27Z [200] PUT /api/v1/jobs/1165311/actions/postprocessor/complete
2026-07-01T01:47:17Z [502] LockWaitTimeout  (재시도 1)
2026-07-01T01:48:13Z [502] LockWaitTimeout  (재시도 2)
2026-07-01T01:49:13Z [502] LockWaitTimeout  (재시도 3)
2026-07-01T01:50:14Z [502] LockWaitTimeout  (재시도 4)
2026-07-01T01:51:24Z [502] LockWaitTimeout  (재시도 5)
2026-07-01T01:51:04Z [Job] state changed from stopping to stopped on Job 1165311

complete_action 은 actionable_controller 를 통해 job → capture 로 상태 전파를 수행하며, Capture 모델의 state machine callback 을 트리거하여 동일 row 에 UPDATE 를 발생시킨다.

Log Evidence#

Datadog query 1 — update_meta_by_key 관련 로그:

service:cupixworks-api "CapturesController#update_meta_by_key"
from=2026-07-01T01:40:00Z to=2026-07-01T02:00:00Z

핵심 결과 (capture 724756 대상 반복 재시도, 5회 중 3회 502, 마지막 1회 성공):

2026-07-01T01:53:16.541Z [502] PUT /api/v1/captures/724756/meta/prop  LockWaitTimeout
2026-07-01T01:54:08.686Z [502] PUT /api/v1/captures/724756/meta/prop  LockWaitTimeout
2026-07-01T01:54:41.520Z [200] PUT /api/v1/captures/724524/meta/prop
2026-07-01T01:55:00.821Z [502] PUT /api/v1/captures/724756/meta/prop  LockWaitTimeout
2026-07-01T01:55:53.209Z [200] PUT /api/v1/captures/724756/meta/prop

Datadog query 2 — 동일 시간대 전체 락 대기 timeout 분포:

service:cupixworks-api "Lock wait timeout"
from=2026-07-01T01:40:00Z to=2026-07-01T02:10:00Z

결과: 42건 발견. 영향 endpoint 요약:

Api::V1::CapturesController#update_meta_by_key   (본 클러스터)
Api::V1::PanosController#stitched
Api::V1::PanosController#check_uploading
Api::V1::PanosController#check_tile_uploading
Api::V1::PanosController#check_mask_uploading
Api::V1::JobsController#complete_action
Api::V1::JobsController#update

Datadog query 3 — capture 724756 관련 전체 활동:

service:cupixworks-api "724756"
from=2026-07-01T01:30:00Z to=2026-07-01T02:00:00Z

publish 파이프라인이 락 해소 직후 진행됨을 확인:

2026-07-01T01:55:53Z [200] PUT /api/v1/captures/724756/meta/prop
2026-07-01T01:56:07Z [200] PUT /api/v1/captures/724756/publish
2026-07-01T01:56:21Z start validation for 3D reconstruction. capture_id: 724756
2026-07-01T01:56:25Z Reconstruction job is created for capture 724756. job_id: 1165386
2026-07-01T01:56:49Z reconstruction_state has transitioned from none to queued on Capture 724756
2026-07-01T01:56:53Z reconstruction_state has transitioned from queued to processing on Capture 724756

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 락 홀더 트랜잭션 식별을 위한 관측성 강화

  • RDS Performance Insights 또는 performance_schema.data_locks / data_lock_waits 로 사고 재발 시 blocking transaction 을 캡처하는 절차 문서화.
  • 위치: 운영 런북 (코드 변경 아님).
  • 근거: H5 가 Inconclusive 인 이유는 애플리케이션 로그만으로는 lock holder 를 특정할 수 없기 때문. 다음 재발 (지난 7일 8회) 을 놓치지 않도록 사전 준비 필요.

• update_meta_by_key 에서 unrelated callback 우회

  • 위치: app/controllers/concerns/metable_controller.rb:42-69
  • 접근: 이미 skip_entrypoint_flush = true 로 일부 콜백을 건너뛰고 있음. 유사하게 meta 컬럼만 변경할 때는 update_columns(meta: ...) 로 콜백/트랜잭션을 우회하거나, has_paper_trail skip, counter_culture skip 을 전면 검토.
  • 근거: 단순 meta JSON UPDATE 가 Capture 의 75+ concern callback 을 모두 트리거할 이유가 없다. Capture#save 트랜잭션 범위를 줄이면 lock hold 시간이 감소한다.

단기 개선 (1주 이내)#

• Api::V1::JobsController#complete_action / postprocessor callback 트랜잭션 축소

  • 위치: app/controllers/concerns/actionable_controller.rb, app/models/concerns/actionable.rb
  • 접근: state machine transition 과 outbound 알림(SQS enqueue, Slack, ES reindex) 을 동일 트랜잭션 안에서 수행하는지 확인. after_commit 으로 분리하거나 SQL update 를 세분화.
  • 근거: complete_action 이 락 홀더 후보이며, 재시도가 5회 반복 실패했다. 트랜잭션 축소는 재발 빈도를 낮추는 가장 직접적 조치.

• row-level lock 경합 예방을 위한 순서 정규화

  • 위치: Capture#save 관련 concerns (특히 Publishable::Capture, Cyclable::Capture, Statable::Capture)
  • 접근: 동일 Capture 에 대해 publish, meta/*, postprocessor complete 가 순차 처리되도록 서비스 계층에서 advisory lock (e.g. SELECT GET_LOCK("capture:#{id}")) 도입 검토.
  • 근거: MySQL row lock 은 예측 불가 순서로 대기하여 fair scheduling 을 보장하지 않으므로, 애플리케이션 레벨에서 순서 강제가 필요.

장기 개선 (재발 방지)#

• Capture 모델 concern 다이어트: 75+ concern 을 리팩터링 없이 유지하면 save latency 는 계속 증가한다. 도메인별 (state, meta, storage, notification) 서비스 객체로 분리하여 필요할 때만 로직 실행.
• hot capture pattern 감지 대시보드: 하나의 capture 에 대해 pano callback / job callback / meta update 가 동시에 몰리는 패턴은 특정 워크플로우 (publish 직전) 에서 반복된다. write hotspot 모니터링 필요.
• svc:cupixworks-api::unknown 반복 재발 근본 조사 태스크 발행: 7일 8회 재발은 만성 문제이며, 개별 클러스터 RCA 로는 해결 불가. 별도 워크스트림 (Jira epic) 필요.

Monitoring#

Datadog 쿼리 예시 — release dashboard 에 timeseries widget 으로 그대로 사용 가능:

• lock wait timeout 발생 빈도:

sum:trace.rack.request.errors{service:cupixworks-api,error_type:ActiveRecord::LockWaitTimeout}.as_count()

• update_meta_by_key p95/p99 latency:

p95:trace.rack.request{service:cupixworks-api,resource_name:api::v1::capturescontroller#update_meta_by_key}
p99:trace.rack.request{service:cupixworks-api,resource_name:api::v1::capturescontroller#update_meta_by_key}

• captures 테이블 lock 관련 MySQL 지표:

avg:mysql.innodb.row_lock_time{service:cupixworks-api}
avg:mysql.innodb.row_lock_current_waits{service:cupixworks-api}

• 알림: resource_name:*captures*update_meta_by_key p95 > 5s 지속 5분 시 warning.

Risk Assessment#

• Risk level: high — 사용자향 API 502, 다중 endpoint 확산, 7일 8회 재발.
• 예상 복잡도: critical — 근본 fix 는 Capture 모델 및 write path 리팩터링 필요. 즉시 조치는 관측성 강화 + update_meta_by_key narrow-update 로 가능하나, 근본 해결은 아키텍처 수준.