RCA: ES doc_missing after max retries

Overview#

What Happened#

2026-05-22 04:0108:23 UTC 동안 cupixworks-worker 서비스의 DocMissingRetryWorker에서 1,012건의 에러가 발생했다. Elasticsearch partial update 시 document_missing_exception이 반환되어 5분/10분/20분 간격으로 3회 재시도했으나, 최종 시도에서도 문서가 존재하지 않아 에러로 기록된 것이다. 주로 ElementTrace 모델의 editing_id 필드 업데이트에서 발생했으며, 수백수천 개의 문서 ID가 영향을 받았다.

Quick Facts#

Timeline#

1. 2026-05-17 — TSLA-12839 커밋: BulkPartialIndexWorker + DocMissingRetryWorker + BulkPartialIndexDeadWorker 파이프라인 추가
2. 2026-05-19 09:20 UTC — deploy 3e770a15 완료 (TSLA-12839 포함)
3. 2026-05-22 04:01 UTC — 최초 에러 발생 (retry attempt 3 실패)
4. 2026-05-22 08:23 UTC — 최종 에러 발생 (4시간 22분 지속)

Error Log#

Datadog Logs

ES doc_missing after max retries

Impact#

• Service: cupixworks-worker
• 발생 횟수: 1,012
• 최초 발생: 2026-05-22T04:01:48.901Z
• 최근 발생: 2026-05-22T08:23:19.397Z
• 영향 범위: ElementTrace 문서의 ES 인덱스에 editing_id 필드가 반영되지 않음. 검색/필터 시 해당 ElementTrace가 올바른 editing session에 매핑되지 않을 수 있음. editing_id 1115585, 1115651, 1115652 등 다수 editing session 영향.

Root Cause Summary#

_stamp_editing_id_on_elements 메서드가 DB에서 update_all로 editing_id를 설정한 직후, BulkPartialIndexWorker를 통해 ES partial update({ doc: { editing_id: X } })를 큐에 넣는다. 그런데 대상 ElementTrace 레코드가 아직 ES에 full-document로 인덱싱되지 않은 상태(새로 생성되었거나 BulkIndexWorker가 아직 처리하지 못한 경우)에서 partial update가 먼저 실행되면 document_missing_exception이 발생한다. DocMissingRetryWorker가 5분→10분→20분 간격으로 재시도하지만, 총 35분 이내에도 원본 문서가 인덱싱되지 않으면 최종 실패한다.

Technical Analysis#

Code Path#

Entry point: SQA finalization 중 editing merge/split 시 _stamp_editing_id_on_elements 호출

eligible_et_ids.each_slice(STAMP_BATCH_SIZE) { |batch| ::ElementTrace.where(id: batch).update_all(editing_id: editing.id) }
BulkIndexWorker.perform_async('ElementTrace', eligible_et_ids, 'update')
BulkSavePartialJsonToFileWorker.perform_async('ElementTrace', eligible_et_ids, { operation: '(updated)' }.to_json)

TSLA-12839에서 위 BulkIndexWorker 호출이 BulkPartialIndexWorker로 교체됨:

 eligible_et_ids.each_slice(1000) do |slice|-  batch = slice.map { |id| { update: { _id: id, data: { doc: { editing_id: editing.id } } } } }-  ::ElementTrace.__elasticsearch__.client.bulk(index: ::ElementTrace.index_name, body: batch)+  BulkPartialIndexWorker.perform_async('ElementTrace', slice, { 'editing_id' => editing.id })   BulkPartialSaveJsonToFileWorker.perform_async('ElementTrace', slice, { editing_id: editing.id }.to_json) end

BulkPartialIndexWorker — ES bulk API를 호출하고 응답을 파싱:

body = ids.map { |id| { update: { _id: id, data: { doc: fields } } } }
response = model_class.__elasticsearch__.client.bulk(
  index: model_class.index_name, body: body
)

return true unless response.is_a?(Hash) && response['errors']

doc_missing_ids = []
failed_items = []

Array(response['items']).each do |item|

document_missing_exception인 ID를 DocMissingRetryWorker로 전달:

if doc_missing_ids.any?
  DocMissingRetryWorker.perform_in(
    5.minutes, model_name, doc_missing_ids, fields, 1
  )
end

Failure point: DocMissingRetryWorker attempt 3에서 여전히 missing인 경우:

if attempt < MAX_ATTEMPTS
  delay = (5 * (2**attempt)).minutes
  DocMissingRetryWorker.perform_in(
    delay, model_name, still_missing, fields, attempt + 1
  )
else
  dead_items = still_missing.map { |id| { 'id' => id, 'type' => 'document_missing_exception' } }
  BulkPartialIndexDeadWorker.perform_async(
    model_name, dead_items, fields, 'doc_missing_after_max_retries'
  )
  Cupix::Logger.error('ES doc_missing after max retries',
                      class: self.class.name, function: 'perform',
                      model_name: model_name,
                      attempt: attempt,
                      missing_count: still_missing.size,
                      sample_ids: still_missing.first(5))
end

Race condition의 핵심:

• DB에서 ElementTrace 레코드가 생성됨 → BulkIndexWorker가 full-doc 인덱싱을 큐에 넣음
• 동시에 SQA finalization이 같은 레코드에 editing_id를 스탬프하고 BulkPartialIndexWorker로 partial update를 큐에 넣음
• Sidekiq 큐 경합 또는 높은 큐 latency로 인해 partial update가 full-doc 인덱싱보다 먼저 실행됨
• ES에 문서가 없으므로 document_missing_exception 발생
• 35분(5+10+20)의 retry window 내에도 full-doc이 인덱싱되지 않으면 최종 실패

Log Evidence#

Datadog 쿼리 (에러 로그):

service:cupixworks-worker status:error "ES doc_missing after max retries" @environment:production

에러 로그 샘플 (attempt 3, max):

{
  "message": "ES doc_missing after max retries",
  "class": "DocMissingRetryWorker",
  "function": "perform",
  "model_name": "ElementTrace",
  "attempt": 3,
  "missing_count": 166,
  "sample_ids": [115812675, 115812676, 115812677, 115812678, 115812679],
  "fields_keys": ["editing_id"],
  "host": "ip-10-1-18-233.us-west-2.compute.internal",
  "version": "production-us-west-2-20260519T0920Z0-3e770a15-cupixworks"
}

Retry attempt 2 (warn-level, 아직 재시도 중):

service:cupixworks-worker "doc_missing" -status:error @environment:production

{
  "message": "ES doc_missing still missing (scheduling next retry)",
  "class": "DocMissingRetryWorker",
  "attempt": 2,
  "still_missing_count": 1000,
  "next_attempt": 3,
  "delay_minutes": 20,
  "max_attempts": 3
}

Companion dead-letter 로그:

service:cupixworks-worker status:error "ES bulk partial index dead" @environment:production

{
  "message": "ES bulk partial index dead",
  "class": "BulkPartialIndexDeadWorker",
  "function": "perform",
  "model_name": "ElementTrace",
  "reason": "doc_missing_after_max_retries",
  "failed_count": 166,
  "fields": { "editing_id": 1115651 }
}

영향받은 editing_id: 1115585, 1115651, 1115652. Missing document ID 범위: 115812675~115814966 (ElementTrace).

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• doc_missing_retry_worker.rb:62 — MAX_ATTEMPTS를 3에서 5로 증가하고, delay 계산을 (5 * (2**attempt)).minutes에서 초기 delay를 10분으로 늘려 총 재시도 시간을 ~150분으로 확대
• 또는 DocMissingRetryWorker의 마지막 시도에서 partial update 대신 BulkIndexWorker.perform_async(model_name, still_missing, 'index')로 full-doc 인덱싱을 시도하는 fallback 추가

단기 개선 (1주 이내)#

• _stamp_editing_id_on_elements에서 BulkPartialIndexWorker 호출 전에, 대상 ID가 ES에 이미 존재하는지 확인하는 guard 추가. 미존재 ID는 즉시 BulkIndexWorker로 라우팅하여 full-doc 인덱싱 후 partial update 시도
• BulkPartialIndexWorker에서 doc_missing 비율이 전체의 50% 이상이면, 해당 batch를 partial update 대신 full-doc BulkIndexWorker로 fallback하는 로직 추가

장기 개선 (재발 방지)#

• ElementTrace 생성 시점에 ES 인덱싱 완료를 보장하는 메커니즘 도입 (예: 인덱싱 완료 이벤트 발행 후 downstream 작업 시작)
• Partial update 파이프라인에 "upsert" 모드 지원 추가: doc_as_upsert: true를 사용하면 문서가 없을 때 자동 생성되어 race condition 자체를 제거할 수 있음

Monitoring#

• DocMissingRetryWorker attempt 3 도달률 모니터링:

service:cupixworks-worker "ES doc_missing after max retries" @environment:production

• Datadog gauge tesla.es_bulk_partial.dead.count by model_name + reason 태그 모니터
• Sidekiq 큐 latency 알림: default 큐가 5분 이상 지연 시 경고

Risk Assessment#

• Risk level: medium
• 예상 복잡도: standard
• ES 인덱스 데이터 정합성 영향이 있으나, 검색/필터 기능에만 영향. DB 데이터는 정상. backfill rake task로 복구 가능.