RCA: Editing split failed: Couldn't find Editing with 'id'=1204740

Overview#

What Happened#

cupixworks-worker의 EditingSplitWorker가 방금 생성된 신규 Editing 레코드를 조회하지 못하고 ActiveRecord::RecordNotFound로 실패했다. 2026-07-02 하루 동안 최소 20건 이상 동일 패턴(각기 다른 editing_id)이 반복되며 SQA(siteinsights) editing 자동 분할 파이프라인이 부분적으로 중단됐다. 표본으로 잡힌 id=1204740 케이스에서는 동일 시각(15:31:50 KST)에 여러 후속 워커(LogEditingStateWorker, SavePartialJsonToFileWorker) 도 같은 id를 찾지 못하고 실패했다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-07-02 15:31:50 KST — EditingEntity#create_editing_with_geo_bucket가 Editing 1204740 생성 (set geo_bucket_key on editing 1204740).
2. 2026-07-02 15:31:50 KST — 동일 초에 LogEditingStateWorker.perform이 editing not found: 1204740 로그. EditingSplitWorker.perform이 Editing split failed: Couldn't find Editing with 'id'=1204740로 raise (occurrence 1).
3. 2026-07-02 15:31:50 KST — SavePartialJsonToFileWorker가 Retry 1 시작, 이후 exponential backoff (0.1s → 3.2s) 로 총 6회 재시도.
4. 2026-07-02 15:31:56 KST — SavePartialJsonToFileWorker가 Editing with id 1204740 not found after 6 retries로 최종 실패.
5. 2026-07-02 16:47:01 KST — 같은 fingerprint의 마지막 발생 (id=1205007, cluster last_seen).

Error Log#

Datadog Logs

Editing split failed: Couldn't find Editing with 'id'=1204740

Impact#

• Service: cupixworks-worker
• 발생 횟수: 6 (24h 유사 패턴은 20+ 건)
• 최초 발생: 2026-07-02 15:31:50 KST
• 최근 발생: 2026-07-02 16:47:01 KST

Root Cause Summary#

EditingSplitService#initialize는 ::Editing.find(editing_id)을 즉시 호출하는데, EditingSplitWorker를 enqueue하는 두 지점(EditingEntity#_stamp_editing_id_on_elements line 455, CreateSitetrackEditingEntitiesWorker#perform line 84)은 모두 신규 Editing을 방금 생성한 뒤 동일 실행 컨텍스트 안에서 perform_async를 호출한다. Sidekiq worker가 이 job을 pick하는 시점에 새 Editing 레코드가 아직 primary DB 커밋 전(=enclosing transaction 미커밋) 이거나, 커밋 직후 read replica 로 propagate 되기 전이면 find(editing_id)가 RecordNotFound를 raise한다. 같은 시각 다중 워커(LogEditingStateWorker blank 처리, SavePartialJsonToFileWorker 6회 backoff)에서도 동일 id를 못 찾는 사실은 개별 워커 문제가 아니라 write-read visibility 지연이 공통 원인임을 시사한다. SavePartialJsonToFileWorker는 이미 이 상황을 방어하기 위해 6회 retry 로직을 갖고 있지만 EditingSplitWorker는 최초 라인에서 곧바로 raise한다.

Technical Analysis#

Code Path#

• Entry point: app/workers/editing_split_worker.rb:5 — Sidekiq perform.
• Enqueue sites:
  • app/models/concerns/finalization/editing_entity.rb:455 — _stamp_editing_id_on_elements 내부, 신규 winner editing 생성 직후.
  • app/workers/create_sitetrack_editing_entities_worker.rb:84 — editing_entity.assign_editing_to_editing_entity 직후.
• Failure point: app/services/cupix/editing_split_service.rb:13 — @editing = ::Editing.find(editing_id).

Worker는 진입 즉시 EditingSplitService.new(...).split!을 호출하며, initialize가 find를 사용해 미존재시 예외를 던진다.

def perform(editing_id)
  Cupix::Logger.info('Starting editing split', class: self.class.name, function: __method__, editing_id: editing_id)

  ::Cupix::EditingSplitService.new(editing_id: editing_id).split!

  Cupix::Logger.info('Editing split finished', class: self.class.name, function: __method__, editing_id: editing_id)
rescue StandardError => e
  Cupix::Logger.error("Editing split failed: #{e.message}", class: self.class.name, function: __method__, editing_id: editing_id)
  raise
end

def initialize(editing_id:, current_user: nil)
  @editing = ::Editing.find(editing_id)                     # RecordNotFound 여기서 raise
  @current_user = current_user || @editing.editor || @editing.user
end

_stamp_editing_id_on_elements가 SQA + geo grouping 경로에서 신규 editing 생성/스탬핑을 마친 뒤 splitworker를 enqueue한다. 이 코드 블록은 after_ready_state :assign_editing_to_editing_entity state-machine 콜백 안에서 실행되므로 enclosing transaction이 아직 열려 있을 가능성이 높다.

if SQA_GEO_GROUPING_ENABLED && editing.editing_type == 'siteinsights' &&
   (counts_by_editing[editing.id] || 0) > ::Cupix::EditingSplitService::MAX_ELEMENTS_PER_EDITING
  ::EditingSplitWorker.perform_async(editing.id)             # transactional 컨텍스트 안에서 즉시 enqueue
end

동일한 문제 인지에 대응해 SavePartialJsonToFileWorker는 exponential backoff retry를 갖는다. EditingSplitWorker는 해당 방어가 없다.

$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", ...)
    sleep(delay)
    next
  else
    break
  end
end

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

EditingSplitWorker는 sidekiq_options queue: :default, retry: 2 (line 3) 로 Sidekiq 자체 retry가 2회로 제한되어 있어 replica lag가 있을 때 원본 exception 로그가 항상 남는다.

기대 동작: enqueue 시점의 editing_id가 커밋 완료된 뒤 worker가 pick해 정상 조회. 실제 동작: worker가 트랜잭션 커밋 전(또는 replica propagation 완료 전) job을 pick → find 실패.

Log Evidence#

Datadog 쿼리 (재현):

service:cupixworks-worker "1204740"

동일 초 내 여러 워커가 같은 id를 못 찾은 로그 (raw):

{"timestamp":"2026-07-02 15:31:50","status":"info","message":"set geo_bucket_key on editing 1204740","class":"EditingEntity","function":"create_editing_with_geo_bucket"}
{"timestamp":"2026-07-02 15:31:50","status":"info","message":"state has transitioned from waiting to ready on Editing 1204740"}
{"timestamp":"2026-07-02 15:31:50","status":"info","message":"editing not found: 1204740","class":"LogEditingStateWorker","function":"perform"}
{"timestamp":"2026-07-02 15:31:50","status":"error","message":"Editing split failed: Couldn't find Editing with 'id'=1204740","class":"EditingSplitWorker","function":"perform"}
{"timestamp":"2026-07-02 15:31:50","status":"warn","message":"Retry 1 - Editing with id 1204740 not found, retrying in 0.1 seconds","class":"SavePartialJsonToFileWorker"}
{"timestamp":"2026-07-02 15:31:50","status":"warn","message":"Retry 2 - Editing with id 1204740 not found, retrying in 0.2 seconds","class":"SavePartialJsonToFileWorker"}
{"timestamp":"2026-07-02 15:31:50","status":"warn","message":"Retry 3 - Editing with id 1204740 not found, retrying in 0.4 seconds","class":"SavePartialJsonToFileWorker"}
{"timestamp":"2026-07-02 15:31:50","status":"warn","message":"Retry 4 - Editing with id 1204740 not found, retrying in 0.8 seconds","class":"SavePartialJsonToFileWorker"}
{"timestamp":"2026-07-02 15:31:52","status":"warn","message":"Retry 5 - Editing with id 1204740 not found, retrying in 1.6 seconds","class":"SavePartialJsonToFileWorker"}
{"timestamp":"2026-07-02 15:31:54","status":"warn","message":"Retry 6 - Editing with id 1204740 not found, retrying in 3.2 seconds","class":"SavePartialJsonToFileWorker"}
{"timestamp":"2026-07-02 15:31:56","status":"error","message":"Editing with id 1204740 not found after 6 retries","class":"SavePartialJsonToFileWorker","function":"perform"}

Datadog 쿼리 (24h 스캔):

service:cupixworks-worker status:error "Editing split failed"

24시간 내 동일 fingerprint의 서로 다른 editing_id (일부):

2026-07-02 16:47:01  id=1205007
2026-07-02 16:44:15  id=1204991
2026-07-02 16:20:08  id=1204935
2026-07-02 16:03:49  id=1204867
2026-07-02 16:01:39  id=1204857
2026-07-02 15:31:50  id=1204740   (representative)
2026-07-01 20:55:43  id=65781
2026-07-01 20:43:53  id=65773
...

동일 클래스/함수 (EditingSplitWorker#perform)에서 각기 다른 신규 id로 반복 실패 → 특정 record의 데이터 문제가 아니라 enqueue-timing 패턴임.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

1. app/workers/editing_split_worker.rb:5 — worker perform 진입 시 SavePartialJsonToFileWorker.perform와 동일한 short exponential backoff (예: 6회, 0.1s → 3.2s) 로 Editing.find_by(id: editing_id)를 재시도한 뒤에도 nil이면 warn 로그 남기고 조용히 종료. 이유: replica/commit-visibility race 를 즉시 완화하고, 진짜 삭제된 editing의 경우에도 error → warn 으로 severity를 낮춰 Datadog 오탐을 줄인다.
2. app/services/cupix/editing_split_service.rb:13 — find 대신 find_by로 바꾸고 nil 응답 시 Cupix::Logger.warn("Split skipped (editing not found)", ...) 후 return []. EditingSplitWorker 상위에서도 RecordNotFound를 별도로 rescue해 raise하지 않는 방향 검토.
3. 두 enqueue 지점(editing_entity.rb:455, create_sitetrack_editing_entities_worker.rb:84)을 after_commit (또는 ActiveRecord::Base.connection.after_commit_transaction) 훅으로 이동해 커밋 직후에만 job이 큐에 들어가도록 변경. 이 방향이 근본적 해결책이며, LogEditingStateWorker/SavePartialJsonToFileWorker의 동일 증상도 동시에 해소된다.

단기 개선 (1주 이내)#

• Sidekiq middleware 레벨에서 perform_async를 after_commit으로 자동 지연시키는 helper (예: perform_async_after_commit) 도입. ElementTrace, EditingEntity, Editing 등 write 직후 fan-out 되는 job이 많아 재발 위험이 크다.
• _stamp_editing_id_on_elements 트랜잭션 소요 시간을 측정하는 Datadog metric 추가(tesla.editing.stamp_duration_ms). 6s+ 소요 케이스가 확인되면 배치 단위 분해 또는 트랜잭션 분리 검토.

장기 개선 (재발 방지)#

• Sidekiq/ActiveRecord 통합 표준화: 모든 perform_async 호출이 아래 셋 중 하나에 위치하도록 규칙화 — (a) 트랜잭션 밖, (b) after_commit_callback, (c) middleware 자동 지연. RuboCop 커스텀 cop 또는 lint 검토.
• 신규 workflow 설계 시 "write → enqueue → immediate read" 파이프라인 안티패턴 리뷰 체크리스트 항목 추가.

Monitoring#

• 추가 알림 대상: 24h 발생 건수 급증 시 알림.

sum:trace.sidekiq.job.errors{service:cupixworks-worker,resource_name:EditingSplitWorker}.as_count()

• Editing 조회 실패로 인해 조기 종료되는 케이스 트래킹 (fix 배포 후 warn 로 다운그레이드된 뒤 유용):

sum:logs{service:cupixworks-worker,@class:EditingSplitWorker,status:warn} by {@message}.as_count()

• SavePartialJsonToFileWorker의 6-retry 소진 실패 (동일 root cause 지표):

sum:logs{service:cupixworks-worker,@class:SavePartialJsonToFileWorker,@message:"not found after 6 retries"}.as_count()

Risk Assessment#

• Risk level: medium — SQA(siteinsights) 자동 split이 반복 실패 시 editing이 MAX_ELEMENTS 초과 상태로 남아 UI/작업자 성능 저하 가능. 데이터 손실은 없음(Sidekiq retry로 결국 성공하거나, 후속 trigger로 재분할 가능).
• 예상 복잡도: standard — worker 진입부 방어 로직(작음) + enqueue 지점 after_commit 이동(중간). 회귀 위험을 낮추기 위해 두 단계를 분리 배포 권장.