RCA: Cupix::Errors::System: Mysql2::Error Duplicate entry on facility_permissions unique index

Overview#

What Happened#

cupixworks-api (tesla)에서 POST /api/v1/reviews/{key}/annotations (Api::V1::AnnotationsController#create) 요청 처리 중 Mysql2::Error: Duplicate entry '{facility_id}-User-{accessor_id}' for key 'facility_permissions.idx_facility_permissions_unique_accessor'가 발생해 500 응답으로 이어졌다. 원인은 ReviewPermission#create_facility_permission 콜백의 non-atomic한 check-then-create 패턴이며, 같은 (accessor, facility) 조합으로 두 요청이 동시에 들어올 때 unique index를 위반한다. 16개월 동안 18건으로 저빈도이지만, 명백한 race-condition 결함이다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-04-14 13:22 KST — 커밋 8c3a31015 (TSLA-12368) 로 facility_permissions 등에 unique index (idx_facility_permissions_unique_accessor) 추가 (migration 20260413083342).
2. 2026-04-24 00:18 KST — 최초 발생 (first_seen). unique index 도입 직후부터 중복 insert가 조용히 성공하던 것이 예외로 표면화.
3. 2026-07-25 00:26 KST — Datadog 로그: Duplicate entry '1146-User-2162' (POST /api/v1/reviews/uwokz5/annotations).
4. 2026-08-01 00:05 KST — 최근 발생 (last_seen). Duplicate entry '1146-User-2266' (POST /api/v1/reviews/wdgp1w/annotations).

Error Log#

Datadog Logs

Mysql2::Error: Duplicate entry '1146-User-253' for key 'facility_permissions.idx_facility_permissions_unique_accessor'

Representative Error('1146-User-253')는 이 issue의 first_seen 샘플이다. last_seen(2026-08-01) 근처의 실제 Datadog 로그를 검색한 결과 동일 형태의 최신 occurrence('1146-User-2266', '1146-User-2162')가 확인되었다 — facility_id(1146)는 고정이고 accessor(User-2266 등)만 변한다. 즉 Representative는 accessor id만 다른 variant이며, root cause는 동일하다.

Impact#

• Service: cupixworks-api
• 발생 횟수: 18
• 최초 발생: 2026-04-24 00:18 KST
• 최근 발생: 2026-08-01 00:05 KST

Root Cause Summary#

ReviewPermission은 생성 시 before_create :create_facility_permission 콜백으로 해당 accessor의 FacilityPermission을 보장한다. 이 콜백은 find_by로 존재 여부를 확인한 뒤 없으면 create!하는 non-atomic check-then-create 패턴이다(review_permission.rb:19-31). annotation 생성 등으로 동일 사용자에 대한 ReviewPermission이 짧은 시간에 두 번 이상 동시에 만들어지면, 두 요청이 모두 find_by == nil을 관측한 뒤 각각 create!를 실행 → 나중 트랜잭션이 idx_facility_permissions_unique_accessor unique index를 위반하고 Mysql2::Error: Duplicate entry가 발생한다. 이 예외는 콜백에서 rescue되지 않아 트랜잭션 전체가 실패하고, controller까지 전파되어 Cupix::Errors::System(SYS50000) → 500이 된다. 동일 결함이 annotation_layer_permission.rb, level_permission.rb에도 존재한다. 반면 record_permission.rb와 FacilityPermission#create_workspace_permission은 이미 find_or_create_by! + rescue ActiveRecord::RecordNotUnique + retry로 수정되어 있어 fix 패턴은 이미 팀 내에 존재하지만 일부 모델에 미적용된 상태다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/annotations_controller.rb:27 — create → AnnotationFactory.create!

def create
  @model = factory_instance.create!(params)

  super
end

• annotation 생성은 review context(params[:review_key])에서 이루어지며(annotation_factory.rb:23-25), 이 과정에서 annotating user에 대한 ReviewPermission이 생성/보장된다. ReviewPermission 저장 시 before_create 콜백이 실행된다.

• Failure point: app/models/review_permission.rb:19-31 — non-atomic check-then-create

def create_facility_permission
  facility_permission = ::FacilityPermission.find_by(facility_id: review.facility_id, accessor: accessor)

  if facility_permission.nil?
    facility_permission = ::FacilityPermission.create!(
      facility_id: review.facility_id,
      accessor: accessor,
      permission: 1
    )
  end

  self.facility_permission = facility_permission
end

기대 동작: accessor의 FacilityPermission이 없으면 하나 생성한다. 실제 동작: 두 요청이 동시에 find_by == nil을 관측하면 둘 다 create!를 시도한다. unique index([accessor_id, accessor_type, facility_id])때문에 두 번째 insert가 실패한다.

• unique index 정의:

add_index :facility_permissions,
          [:accessor_id, :accessor_type, :facility_id],
          unique: true,
          name: 'idx_facility_permissions_unique_accessor'

• 이미 존재하는 올바른 패턴 (동일 파일군에서 rescue+retry 적용됨):

def create_facility_permission
  return if record.nil?

  facility_permission = ::FacilityPermission.find_or_create_by!(
    facility_id: record.facility_id,
    accessor: accessor
  ) do |fp|
    fp.permission = 1
  end

  self.facility_permission = facility_permission
rescue ActiveRecord::RecordNotUnique
  Cupix::Logger.warn("[Permission] Duplicate FacilityPermission detected, retrying for #{accessor_type}(#{accessor_id}) on Facility(#{record.facility_id})", class: self.class.name, function: __method__)
  retry
end

FacilityPermission#create_workspace_permission(facility_permission.rb:27-41)도 동일하게 find_or_create_by! + rescue ActiveRecord::RecordNotUnique + retry로 되어 있다. 즉 팀이 이미 채택한 방어 패턴이 review_permission.rb/annotation_layer_permission.rb/level_permission.rb에만 미적용이다.

Log Evidence#

사용한 Datadog 쿼리:

service:cupixworks-api "facility_permissions.idx_facility_permissions_unique_accessor"

핵심 로그 (last_seen 근처의 실제 occurrence):

{
  "timestamp": "2026-08-01 00:05:09",
  "status": "info",
  "message": "[500] POST /api/v1/reviews/wdgp1w/annotations (Api::V1::AnnotationsController#create)",
  "error": {
    "reason": "Mysql2::Error: Duplicate entry '1146-User-2266' for key 'facility_permissions.idx_facility_permissions_unique_accessor'",
    "code": "SYS50000",
    "message": "Mysql2::Error: Duplicate entry '1146-User-2266' for key 'facility_permissions.idx_facility_permissions_unique_accessor'",
    "class": "Cupix::Errors::System"
  }
}

{
  "timestamp": "2026-07-25 00:26:10",
  "status": "info",
  "message": "[500] POST /api/v1/reviews/uwokz5/annotations (Api::V1::AnnotationsController#create)",
  "error": {
    "reason": "Mysql2::Error: Duplicate entry '1146-User-2162' for key 'facility_permissions.idx_facility_permissions_unique_accessor'",
    "code": "SYS50000",
    "message": "Mysql2::Error: Duplicate entry '1146-User-2162' for key 'facility_permissions.idx_facility_permissions_unique_accessor'",
    "class": "Cupix::Errors::System"
  }
}

• 두 로그 모두 Api::V1::AnnotationsController#create 경로, code: SYS50000, class: Cupix::Errors::System으로 일치 → 코드 경로 확인.
• 두 건 모두 facility_id 1146 고정, accessor만 User-2266 / User-2162로 상이 → 같은 facility에 대한 동시 annotation 생성 시 accessor별로 재발하는 패턴.
• 마이그레이션 커밋 시각(git log): 2026-04-14 13:22:12 +0900 8c3a31015 TSLA-12368 add uniqueness validation on permission table → unique index 도입(4/14) 직후 first_seen(4/24)이 시작된 시점 정합성 확인.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• app/models/review_permission.rb:19-31의 create_facility_permission을 record_permission.rb:20-34와 동일하게 find_or_create_by! + rescue ActiveRecord::RecordNotUnique + retry 패턴으로 교체한다. 이미 팀이 채택한 방어 패턴을 그대로 재사용하는 것이므로 리스크가 낮다.
• 동일 결함이 있는 app/models/annotation_layer_permission.rb:18-30, app/models/level_permission.rb:15-30도 함께 동일 패턴으로 수정한다(4개 permission 모델 중 3개가 미적용).

단기 개선 (1주 이내)#

• SYS50000(Cupix::Errors::System)가 ActiveRecord::RecordNotUnique/Mysql2::Error를 그대로 500으로 노출하는 것을 방지하기 위해, 권한 보장 콜백에서 unique violation은 "이미 존재"로 간주해 정상 처리되도록 통일한다(retry로 자연 해소되면 별도 처리 불필요).
• 각 permission 모델의 create_*_permission 콜백을 공통 concern으로 추출해 중복 구현을 제거하고 패턴 일관성을 강제하는 것을 검토한다.

장기 개선 (재발 방지)#

• unique index를 도입할 때 해당 컬럼을 채우는 모든 콜백/서비스가 upsert(find_or_create_by! + rescue) 패턴을 쓰는지 점검하는 체크리스트를 도입한다.
• permission 부여 로직을 단일 서비스 객체로 집약해 여러 모델 콜백에 흩어진 check-then-create를 제거한다.

Monitoring#

권한 unique violation 재발 추이:

service:cupixworks-api "idx_facility_permissions_unique_accessor"

annotation 생성 500 응답 추이:

service:cupixworks-api "AnnotationsController#create" "[500]"

Risk Assessment#

• Risk level: low
• 예상 복잡도: trivial (기존 검증된 패턴을 3개 모델에 복제 적용)

Noise Verdict#

bug — non-atomic한 find_by→create! race condition이 unique index를 위반해 사용자 요청이 500으로 실패하는 명백한 코드 결함이며, 동일 fix 패턴이 이미 record_permission에 적용되어 있어 나머지 모델에도 적용하면 해소된다.