RCA: WorkspacePermission with id 114366 not found after 6 retries

Overview#

What Happened#

2026-05-07 16:42 UTC에 cupixworks-worker 서비스의 SavePartialJsonToFileWorker가 WorkspacePermission id 114366, 114368 레코드를 조회하지 못해 6회 재시도 후 에러를 기록했다. 동일 시간대에 ReviewPermission, FacilityPermission 등 다른 permission 모델에서도 같은 패턴이 관찰되어, bulk permission 삭제 작업 중 race condition이 발생한 것으로 판단된다.

Quick Facts#

Affected Teams#

Timeline#

1. 16:42:28.041Z — SavePartialJsonToFileWorker가 WorkspacePermission 114366 조회 시작, 즉시 실패하여 retry 시작
2. 16:42:28~30Z — 6회 exponential backoff retry 수행 (0.1s, 0.2s, 0.4s, 0.8s, 1.6s, 3.2s)
3. 16:42:34.046Z — 최종 실패 에러 기록 (id 114366)
4. 16:42:34~40Z — 동일 패턴으로 id 114368 실패
5. 16:42:40.050Z — 마지막 에러 기록

Error Log#

Datadog Logs

WorkspacePermission with id 114366 not found after 6 retries

Impact#

• Service: cupixworks-worker
• 발생 횟수: 2
• 최초 발생: 2026-05-07T16:42:34.046Z
• 최근 발생: 2026-05-07T16:42:40.050Z

Root Cause Summary#

WorkspacePermission 레코드가 생성된 직후 after_commit on: :create 콜백이 SavePartialJsonToFileWorker를 비동기로 enqueue한다. 그러나 해당 레코드가 bulk permission 작업의 일부로 생성 직후 삭제되면, worker가 실행될 시점에는 레코드가 이미 DB에서 제거된 상태이다. Worker의 6회 retry(총 ~6.3초)는 replication lag을 위한 것이지 삭제된 레코드를 복구할 수 없으므로, 영구적으로 실패한다. 동일 시간대에 WorkspacePermission 2건, ReviewPermission 6건, FacilityPermission 2건이 같은 패턴으로 실패한 점에서 bulk permission 정리 작업이 원인으로 확인된다.

Technical Analysis#

Code Path#

• Entry point: app/models/concerns/data_ware_house/partial_json.rb:6 — after_commit :save_partial_json_to_file_as_created, on: :create
• Enqueue: app/models/concerns/data_ware_house/partial_json.rb:70 — SavePartialJsonToFileWorker.perform_async
• Worker start: app/workers/save_partial_json_to_file_worker.rb:7 — perform(class_name, id, options_json)
• Retry loop: app/workers/save_partial_json_to_file_worker.rb:41-54
• Failure point: app/workers/save_partial_json_to_file_worker.rb:57

1. Create 콜백에서 worker enqueue:

def save_partial_json_to_file_as_created
  if $FORWARD_DATA_CHANGES != true
    Cupix::Logger.debug('Data changes forwarding is disabled', class: self.class, module: 'DataWareHouse', function: 'save_partial_json_to_file_as_created')
    return nil
  end

  Cupix::Logger.debug('Changed data will be forwarded in worker', class: self.class, module: 'DataWareHouse', function: 'save_partial_json_to_file_as_created', id: self.id)

  save_partial_json_to_file_in_worker(operation: '(created)', all_data: true, timestamp: current_timestamp)
end

2. Worker에서 record 조회 시도 (retry 포함):

$MAX_RETRIES.times do |retries|
  model = model_class.find_by_id(id)

  if model.nil?
    delay = 0.1 * (2**retries)
    Cupix::Logger.warn("Retry #{retries + 1} - #{class_name} with id #{id} not found, retrying in #{delay} seconds", class: self.class, function: 'perform')

    sleep(delay)
    next
  else
    break
  end
end

if model.nil?
  Cupix::Logger.error("#{class_name} with id #{id} not found after #{$MAX_RETRIES} retries", class: self.class, function: 'perform')
  return false
end

3. Destroy 콜백은 동기 처리 (worker 미사용):

def save_partial_json_to_file_as_destroyed
  if $FORWARD_DATA_CHANGES != true
    Cupix::Logger.debug('Data changes forwarding is disabled', ...)
    return nil
  end

  Cupix::Logger.debug('Changed data will be forwarded in worker', ..., id: self.id)
  generate_and_save_partial_json('(destroyed)', all_data: false)
end

기대 동작: create 후 worker가 record를 조회하여 전체 데이터를 JSON 파일로 저장. 실제 동작: record가 create 직후 삭제되어 worker 실행 시점에 DB에 존재하지 않음. Retry는 replication lag만 고려하며, 삭제된 레코드는 복구 불가.

4. Cascade destroy 경로 — TeamPermission 삭제 시 연쇄 삭제:

has_many :workspace_permissions, dependent: :destroy

has_many :facility_permissions, dependent: :destroy

Log Evidence#

검색 쿼리:

service:cupixworks-worker status:error "WorkspacePermission"

service:cupixworks-worker "114366"

Retry 타임라인 (id 114366):

2026-05-07T16:42:28.041Z [warn] Retry 1 - WorkspacePermission with id 114366 not found, retrying in 0.1 seconds
2026-05-07T16:42:28.041Z [warn] Retry 2 - WorkspacePermission with id 114366 not found, retrying in 0.2 seconds
2026-05-07T16:42:28.042Z [warn] Retry 3 - WorkspacePermission with id 114366 not found, retrying in 0.4 seconds
2026-05-07T16:42:28.042Z [warn] Retry 4 - WorkspacePermission with id 114366 not found, retrying in 0.8 seconds
2026-05-07T16:42:30.043Z [warn] Retry 5 - WorkspacePermission with id 114366 not found, retrying in 1.6 seconds
2026-05-07T16:42:30.044Z [warn] Retry 6 - WorkspacePermission with id 114366 not found, retrying in 3.2 seconds
2026-05-07T16:42:34.046Z [error] WorkspacePermission with id 114366 not found after 6 retries

동시 발생 패턴 — 같은 시간대에 여러 permission 모델이 동일 에러:

2026-05-07T16:42:34.046Z [error] WorkspacePermission with id 114366 not found after 6 retries (request_id: c6e5bf8bcad1ed6997fa2648)
2026-05-07T16:42:40.050Z [error] WorkspacePermission with id 114368 not found after 6 retries (request_id: dc70f6acfbf28a36358a6606)

동일 시간대에 ReviewPermission (ids: 124801-124806), FacilityPermission (ids: 571071, 571073)도 같은 패턴 확인. 이는 bulk permission 작업이 여러 모델에 걸쳐 레코드를 생성한 후 즉시 삭제했음을 시사한다.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 파일: app/workers/save_partial_json_to_file_worker.rb:56-58
• Worker가 record를 찾지 못했을 때 단순히 에러 로그를 남기는 대신, 해당 상황이 정상적인 시나리오(create 후 즉시 destroy)일 수 있음을 인지하고 warn 레벨로 낮추는 것을 권장. Data warehouse에서 이미 삭제된 레코드의 create 이벤트는 무의미하므로, destroy 이벤트만 정상 처리되면 데이터 정합성에 문제없음.

단기 개선 (1주 이내)#

• save_partial_json_to_file_as_created에서 worker를 enqueue할 때, worker 내부에서 record가 없으면 "(destroyed)" 상태로 간주하고 gracefully 종료하는 로직 추가. 현재 return false는 Sidekiq dead set에 쌓이지 않지만 (retry: false), 불필요한 에러 로그가 모니터링 노이즈를 유발한다.

장기 개선 (재발 방지)#

• Data warehouse 변경 추적 아키텍처를 이벤트 소싱 방식으로 전환 검토. after_commit 시점에 변경 데이터를 인라인으로 직렬화하여 worker에 payload로 전달하면, worker가 DB를 재조회할 필요가 없어진다. Destroy 콜백은 이미 이 패턴(동기 inline 저장)을 사용하고 있으므로, create/update도 동일하게 적용 가능.

Monitoring#

• 현재 에러 로그를 warn으로 전환 후, 아래 쿼리로 빈도 추적:

service:cupixworks-worker "not found after 6 retries" status:warn

• 특정 임계치(예: 1시간 내 50건 이상) 초과 시 알림 설정으로 bulk 작업 이상 감지.

Risk Assessment#

• Risk level: low
• 예상 복잡도: trivial
• Data warehouse에 일부 create 이벤트가 누락되지만, 해당 레코드는 이미 삭제된 상태이므로 최종 정합성에는 영향 없음. Destroy 이벤트는 동기 처리로 정상 기록됨.