RCA: ES bulk partial index dead

Overview#

What Happened#

2026-06-26 03:48–03:49 KST 사이 cupixworks-worker (us-west-2, production)에서 BulkPartialIndexDeadWorker가 3건의 ES bulk partial index dead 에러를 기록했다. Editing split 후 새로운 editing_id로 Element 도큐먼트에 partial-update를 적용하려 했으나, DocMissingRetryWorker가 5/10/20분 backoff로 최대 3회까지 재시도해도 Elasticsearch가 해당 Element id (4472223, 4472197)를 찾지 못해 dead-letter 로직(reason: doc_missing_after_max_retries)에 의해 영구 실패 처리되었다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-06-26 03:11 KST — Editing 1189985가 waiting → ready 상태로 전이 (cupixworks-worker info log).
2. 2026-06-26 03:14 KST — Editing 1190003가 waiting → ready 상태로 전이.
3. ~03:13 KST (T0, 추정) — BulkPartialIndexWorker가 Element partial-update 시도, ES bulk 응답에 document_missing_exception 발생. DocMissingRetryWorker를 5분 뒤로 스케줄(attempt=1).
4. 2026-06-26 03:28 KST — attempt=2 실행 후 여전히 missing (id 4472223), 20분 backoff로 attempt=3 스케줄.
5. 2026-06-26 03:29 KST — attempt=2 실행 후 여전히 missing (id 4472223, 4472197), 20분 backoff로 attempt=3 스케줄.
6. 2026-06-26 03:48 KST — attempt=3 실행 후에도 doc 없음 → BulkPartialIndexDeadWorker 호출, dead-letter 기록 (1건, id 4472223, editing 1189985).
7. 2026-06-26 03:49 KST — attempt=3 실행 후에도 doc 없음 → BulkPartialIndexDeadWorker 호출, dead-letter 기록 (2건, id 4472223 + 4472197, editing 1190003).

Error Log#

Datadog Logs

ES bulk partial index dead

대표 로그 페이로드 (Datadog raw):

{
  "message": "ES bulk partial index dead",
  "status": "error",
  "class": "BulkPartialIndexDeadWorker",
  "function": "perform",
  "model_name": "Element",
  "reason": "doc_missing_after_max_retries",
  "failed_count": 2,
  "fields": { "editing_id": 1190003 },
  "sample": [
    { "id": "4472223", "type": "document_missing_exception" },
    { "id": "4472197", "type": "document_missing_exception" }
  ],
  "@timestamp": "2026-06-25T18:49:43.711Z",
  "environment": "production",
  "service": "cupixworks-worker"
}

Impact#

• Service: cupixworks-worker
• 발생 횟수: 3
• 최초 발생: 2026-06-26 03:48 KST
• 최근 발생: 2026-06-26 03:49 KST
• 데이터 영향: Element 2개(4472223, 4472197)의 editing_id 필드가 Elasticsearch에 반영되지 않음. RDS와 ES 사이의 stale 상태. 향후 동일 editing(1189985, 1190003)에 대한 ES 기반 검색이나 집계에서 이 element들이 빠질 수 있음.
• 사용자 영향: 인지 가능한 사용자 에러는 없음 (HTTP 에러나 작업 실패로 이어지지 않음). 단, editing split 결과 ES view가 부분적으로 불일치.

Root Cause Summary#

EditingSplitService가 새 editing으로 element들을 재할당한 뒤 BulkPartialIndexWorker.perform_async('Element', slice, { 'editing_id' => new_editing.id })로 ES partial-update를 큐잉했지만, Element 4472223과 4472197은 해당 시점에 Elasticsearch 인덱스에 존재하지 않았다. DocMissingRetryWorker가 5/10/20분 backoff로 3회 재시도(코드 의도: "cupixworks ingestion has not finished indexing the new doc when tesla tries to partial-update")해도 여전히 document_missing_exception이 반환되어 dead-letter로 보내졌다.

Revision 1 (2026-06-26) 시점 Kibana 직접 조회로 확인된 사실:

• elements 인덱스에서 id 4472223, 4472197은 0건 ({"term":{"id":4472223}}, {"term":{"id":4472197}}, {"terms":{"id":[4472223,4472197]}} 모두 hits 0).
• 같은 ID 범위(4472190–4472230) 내 다른 20개 id는 모두 cycle_state: "created" 상태로 정상 존재.
• soft-delete된 element(cycle_state: "deleted")는 ES 인덱스에 그대로 남는다 (예: id 4472008, 4472013이 deleted 상태로 조회됨). 즉 정상적 cycle_state 흐름으로 삭제됐다면 deleted 문서로 발견되어야 한다.

→ 4472223/4472197은 cycle_state flow로 삭제된 것이 아니라, 비표준 경로로 elements 인덱스에서 제거된 상태이다. 단순한 ingestion 지연이 아니라, 재시도 가능 윈도우(약 35분) 안에도 ES elements 인덱스에 해당 Element 도큐먼트가 존재하지 않았던 상태가 root cause이다.

Revision 2 (2026-06-26) 추가 조사로 다음을 확정:

• element_traces 인덱스에 element.id: 4472223을 참조하는 ET 75건, 4472197을 참조하는 ET 66건이 존재하며, 각 ET의 element 서브도큐먼트가 완전히 denormalize되어 있다 (name: "Direct Shape", category.name: "Steel", level.name: "LEVEL 0", bim.name: "CDHRP_NIIK_STEEL_MAIN-MODEL.rvt", guid, bim_object_id 등). 이 denormalize 값들은 indexer가 실제 Element 행을 읽어 채우는 필드이므로, Element 4472223 / 4472197는 과거에 RDS에 commit된 상태로 존재했다.
• 가장 오래된 ET 행의 created_at은 2025-11-04로, dead-letter 시점(2026-06-25)보다 약 8개월 앞선다. 즉 Element는 사건 발생 한참 전부터 안정적으로 존재했으며, "이번 editing-split 직전 transaction이 rollback되어 한 번도 commit되지 않았다"는 가설은 성립하지 않는다.

남는 가능성은 (a) elements 인덱스가 부분적으로 reindex/rebuild될 때 두 id가 누락된 경우 (예: incremental reindex window 밖에 있던 도큐먼트), (b) ES level에서 직접 delete by id (또는 cleanup 작업)가 수행되어 도큐먼트만 사라진 경우 — Element 자체가 commit되지 않은 케이스가 아니다. 두 경우 모두 Element.__elasticsearch__ 인덱스 lifecycle의 무결성 문제이며, dead-letter는 의도된 안전망(TSLA-12839)으로 정상 동작했다.

Technical Analysis#

Code Path#

Entry — Editing split이 deferred jobs로 partial-update를 enqueue하는 지점:

deferred_jobs << lambda do
  BulkIndexWorker.perform_async('EditingEntity', ee_ids, 'index') if ee_ids.any?
  et_ids.each_slice(1000) do |slice|
    BulkPartialIndexWorker.perform_async('ElementTrace', slice, { 'editing_id' => new_editing.id })
    BulkPartialSaveJsonToFileWorker.perform_async('ElementTrace', slice, { editing_id: new_editing.id }.to_json)
  end
  element_ids.each_slice(1000) do |slice|
    BulkPartialIndexWorker.perform_async('Element', slice, { 'editing_id' => new_editing.id })
    BulkPartialSaveJsonToFileWorker.perform_async('Element', slice, { editing_id: new_editing.id }.to_json)
  end
end

BulkPartialIndexWorker가 client.bulk 응답을 파싱하여 document_missing_exception은 DocMissingRetryWorker로, 그 외 에러는 dead-letter로 분기:

Array(response['items']).each do |item|
  op = item.values.first
  next unless op.is_a?(Hash) && op['error']

  if op.dig('error', 'type') == 'document_missing_exception'
    doc_missing_ids << op['_id']
  else
    failed_items << { 'id' => op['_id'], 'type' => op.dig('error', 'type'), 'reason' => op.dig('error', 'reason') }
  end
end

if doc_missing_ids.any?
  DocMissingRetryWorker.perform_in(
    5.minutes, model_name, doc_missing_ids, fields, 1
  )
  Cupix::Logger.warn('ES bulk partial index doc_missing (scheduling retry)',
                     class: self.class.name, function: 'perform',
                     model_name: model_name,
                     doc_missing_count: doc_missing_ids.size, ...

DocMissingRetryWorker가 3회까지 5/10/20분 backoff로 재시도. 마지막 attempt에서도 missing이면 BulkPartialIndexDeadWorker에 doc_missing_after_max_retries reason으로 전달:

if attempt < MAX_ATTEMPTS
  delay = (5 * (2**attempt)).minutes
  DocMissingRetryWorker.perform_in(
    delay, model_name, still_missing, fields, attempt + 1
  )
  Cupix::Logger.warn('ES doc_missing still missing (scheduling next retry)', ...)
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', ...)
end

Failure point — dead-letter 로그가 기록되는 위치:

def perform(model_name, failed_items, fields_hash, reason = 'unknown')
  return if failed_items.blank?
  return unless model_name.is_a?(String)

  Cupix::Logger.error('ES bulk partial index dead',
                      class: self.class.name, function: 'perform',
                      model_name: model_name,
                      reason: reason,
                      failed_count: failed_items.size,
                      fields: fields_hash,
                      sample: failed_items.first(10))

  DogstatsdMetricWorker.histogram(
    'tesla.es_bulk_partial.dead.count',
    failed_items.size,
    tags: ["model_name:#{model_name}", "reason:#{reason}"]
  )

기대 동작: BulkPartialIndexWorker가 partial-update를 큐잉할 때, 대상 Element 도큐먼트는 이미 ES에 indexing되어 있어야 한다(또는 5/10/20분 backoff 내에 indexing 완료). 그러면 partial-update가 성공한다.

실제 동작: 35분의 retry 윈도우(5 + 10 + 20분)가 끝날 때까지 ES에 Element 4472223, 4472197 도큐먼트가 존재하지 않아 partial-update 시도가 모두 document_missing_exception으로 실패. dead-letter 처리됨.

Log Evidence#

Datadog 쿼리 (dead-letter 발생):

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

Datadog 쿼리 (retry 흐름 trace):

service:cupixworks-worker "doc_missing"

3회 retry 후에도 missing이 남아 dead-letter로 분기된 직전 단계(attempt=2, next_attempt=3):

{
  "message": "ES doc_missing still missing (scheduling next retry)",
  "status": "warn",
  "class": "DocMissingRetryWorker",
  "model_name": "Element",
  "attempt": 2,
  "next_attempt": 3,
  "max_attempts": 3,
  "delay_minutes": 20,
  "still_missing_count": 2,
  "still_missing_ids": ["4472223", "4472197"],
  "fields_keys": ["editing_id"],
  "@timestamp": "2026-06-25T18:29:39.338Z"
}

최종 dead-letter (reason: doc_missing_after_max_retries):

{
  "message": "ES bulk partial index dead",
  "status": "error",
  "class": "BulkPartialIndexDeadWorker",
  "model_name": "Element",
  "reason": "doc_missing_after_max_retries",
  "failed_count": 2,
  "fields": { "editing_id": 1190003 },
  "sample": [
    { "id": "4472223", "type": "document_missing_exception" },
    { "id": "4472197", "type": "document_missing_exception" }
  ],
  "@timestamp": "2026-06-25T18:49:43.711Z"
}

editing 1189985 케이스(개별 dead-letter):

{
  "message": "ES bulk partial index dead",
  "reason": "doc_missing_after_max_retries",
  "failed_count": 1,
  "fields": { "editing_id": 1189985 },
  "sample": [{ "id": "4472223", "type": "document_missing_exception" }],
  "@timestamp": "2026-06-25T18:48:47.651Z"
}

상태 전이 로그(editing이 ready로 전환된 시각):

2026-06-26 03:11:27 KST — state has transitioned from waiting to ready on Editing 1189985
2026-06-26 03:14:16 KST — state has transitioned from waiting to ready on Editing 1190003

— 추정 T0 (BulkPartialIndexWorker 최초 호출): 3회 retry 완료까지 5+10+20=35분 소요, 마지막 dead-letter가 03:4803:49 KST이므로 T0 ≈ **03:1303:14 KST**, 즉 editing이 ready로 전환된 직후. (uncertain — needs verification: 초기 ES bulk partial index doc_missing (scheduling retry) 로그가 검색에서 발견되지 않았다. retry 스케줄 시각은 attempt=2의 delay_minutes=20과 dead-letter 시각으로부터 역산.)

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 데이터 정합성 검증 (Revision 1·2에서 ES 측 확정): Revision 1에서 elements 인덱스에 두 id가 어떤 cycle_state 값으로도 없음을 확인했고, Revision 2에서 element_traces 인덱스의 denormalized element 필드(141건)로 Element가 과거에 commit되어 존재했음을 확정. 따라서 "RDS에 없음 / rollback phantom id" 케이스는 제외되며, 남는 시나리오는 RDS에는 행이 존재하나 elements ES 인덱스에서만 누락된 상태다. 운영 조치는 Rails console에서 Element.find([4472223, 4472197]).each { |e| e.__elasticsearch__.index_document }로 강제 재인덱싱 후, 필요시 editing_id 갱신을 수동 적용.
• 즉시 코드 변경은 권장하지 않음. dead-letter 로그가 의도대로 작동했고, 실제 데이터 손상은 partial-update 누락 2건에 국한.

단기 개선 (1주 이내)#

• dead-letter 후속 처리 정의: 현재 BulkPartialIndexDeadWorker는 로그/메트릭만 남기고 종료한다 (app/workers/bulk_partial_index_dead_worker.rb:7 주석 "operators consume it via Datadog logs / metrics"). 운영자가 수동으로 처리하는 흐름이 명문화/자동화되어 있지 않다면, dead-letter 항목을 모아 일 1회 reindex 시도하는 후속 워커 또는 알림(Slack/PagerDuty)을 추가하는 방향을 검토.
• Editing split → ES indexing 순서 보장: EditingSplitService가 새 Element를 생성하거나 새 editing을 만든 직후, ES partial-update를 enqueue하기 전에 해당 Element 도큐먼트가 ES에 존재하는지 보장하는 흐름이 있는지 점검. 도입할 곳은 app/services/cupix/editing_split_service.rb:815 부근의 deferred_jobs lambda.

장기 개선 (재발 방지)#

• RDS ↔ ES 인덱싱 보장 메커니즘: cupixworks ingestion / Element indexing 파이프라인의 SLA(예: "Element 생성 후 N초 내 ES 인덱싱 완료")를 명시하고, 미달 시 dead-letter가 아닌 자동 reindex 트리거로 자가치유.
• doc_missing 비율 모니터링: tesla.es_bulk_partial.dead.count 메트릭이 이미 존재 (bulk_partial_index_dead_worker.rb:24-28). reason별로 분리된 알람과 baseline을 설정하면 ingestion latency 회귀를 조기에 발견 가능.

Monitoring#

대시보드/위젯에 그대로 들어갈 timeseries queries:

sum:tesla.es_bulk_partial.dead.count{reason:doc_missing_after_max_retries}.as_count()

sum:tesla.es_bulk_partial.dead.count{*} by {reason,model_name}.as_count()

doc_missing warn 로그(retry 진행 중) 추세:

logs("service:cupixworks-worker @class:DocMissingRetryWorker status:warn").index("*").rollup("count").by("model_name")

dead-letter 절대수:

logs("service:cupixworks-worker @class:BulkPartialIndexDeadWorker status:error").index("*").rollup("count").by("@reason,@model_name")

Risk Assessment#

• Risk level: low — dead-letter 자체는 의도된 안전망으로 정상 동작했고, 사용자에게 노출되는 에러나 작업 실패 없음. 영향은 Element 2건의 ES editing_id 필드 stale 상태.
• 예상 복잡도: standard — root cause 자체는 데이터/인덱싱 정합성 확인 작업이며, 코드 수정보다는 운영적 조치(reindex + dead-letter 후속 처리 정책 수립)가 우선.
• 재발 가능성: medium — Element 인덱싱 latency가 35분을 초과하는 케이스가 다른 editing에서도 재현될 수 있음. cupixworks-worker::unknown 스코프로 같은 서비스에 최근 3건의 incident가 있었음(상태 보드 기준, 모두 resolved). 동일 근본 원인인지는 별도 RCA 비교 필요.

Revision History#

Revision 1#

Feedback: "kibana 에서 해당 element 가 실제로 삭제된건지 확인좀. cycle_state 를 확인하면 됨" — Element 4472223/4472197이 정말 삭제됐는지 Kibana cycle_state 필드로 확인 요청.

판정:

변경 사항:

• ## Root Cause Summary: Revision 1 Kibana 조회 결과를 추가하고, "정상 cycle_state 삭제가 아님"을 명시. 남은 가능성을 (a) ES indexing 누락 (b) 비표준 경로 삭제로 정정.
• ## Hypotheses Considered:
  • H1 Evidence란에 Kibana 조회 결과를 추가 (Confirmed 유지, 근거 강화).
  • H4 재서술: 기존 "id가 잘못 전달됨" 가설을 "cycle_state soft-delete로 사라진 가설"로 좁히고 Rejected 처리. 근거는 deleted 문서는 인덱스에 남는다는 관찰.
• ## Fix Recommendation → ### 즉시 조치: Kibana 측 확인은 완료된 것으로 표시하고, 남은 작업을 Rails console RDS 조회로 한정. ES indexing 누락 케이스(Element.find(id).__elasticsearch__.index_document)를 우선 시나리오로 명시.

추가 조사 내용:

• 도구: searching-kibana skill, bun .claude/skills/searching-kibana/scripts/search-kibana.ts -e prod -i elements.
• 검증 쿼리:
  • --id 4472223 / --id 4472197 → hits 0.
  • --term "editing_id:1190003" → 998 hits, 모두 cycle_state:"created" (예: 4906943, 4907060, 4907096). 같은 editing의 다른 element들은 정상 indexing되어 editing_id가 갱신됨 → editing-split의 partial-update가 broad failure가 아니라 특정 id에만 국한된 문제임을 재확인.
  • --range "id:4472190-4472230" → 22 hits, 4472197 / 4472223 만 빠져 있음.
  • cycle_state:"deleted" AND id:4472000-4473000 → 정상 hits, soft-delete 문서가 인덱스에 보존됨을 확인.

Revision 2#

Feedback: "그러면 아예 commit 되지 않고, rollback 됐을 가능성" — Element 4472223/4472197을 만든 RDS transaction이 commit되지 못하고 rollback되어, 한 번도 RDS에 존재하지 않은 phantom id에 partial-update를 시도한 케이스일 가능성.

판정:

변경 사항:

• ## Root Cause Summary: rollback 가설을 부정하는 Revision 2 증거 단락 추가. 남는 가능성을 (a) elements 인덱스 reindex/rebuild 시 누락, (b) ES-level delete by id / cleanup으로 좁힘.
• ## Hypotheses Considered: 신규 H6 (rollback phantom id) 추가, Rejected 처리. ET denormalized 필드 + BulkableFactory#bulk! 코드 경로 증거 명시.
• ## Fix Recommendation → ### 즉시 조치: "RDS에 없음 → stale id" 분기 제거. "RDS에는 행이 존재하나 elements ES 인덱스에서만 누락"으로 시나리오 단일화하고, Element.find([4472223, 4472197]).each { |e| e.__elasticsearch__.index_document }를 권장 조치로 명시.

추가 조사 내용:

• 신규 탐색: element_traces 인덱스 (이전 revision은 elements 인덱스만 봄).
• 쿼리:
  • bun .claude/skills/searching-kibana/scripts/search-kibana.ts -e prod -i element_traces --term "element.id:4472223" --size 3 → 75 hits, 첫 행 ET id 69398061, element.name:"Direct Shape", element.bim.id:13453.
  • 동일 쿼리 raw → element.guid, element.bim_object_id, element.level.id:47975, element.facility:11971(jfwiz0) 등 fully populated.
  • --term "element.id:4472197" → 66 hits, 첫 행 ET id 78881232.
• 코드 경로 재확인:
  • app/factories/bulkable_factory.rb:43-69 — bulk!의 transaction 경계와 enqueue 시점.
  • app/services/cupix/editing_split_service.rb:155-220 — deferred_jobs는 각 group의 split transaction 안에서 array에 push되지만 .each(&:call)은 line 220 (모든 transaction commit 후) 에서 실행. split transaction이 rollback되면 lambda는 array에 남지만, lambda body의 element_ids는 외부 변수로 캡처돼 있어 여전히 호출되긴 함 — 단, 이 lambda 내부는 BulkPartialIndexWorker.perform_async만 수행하므로 Element 자체를 생성하지 않음. Element 생성과는 별개 경로.
  • db/migrate/20240401084915_create_element_traces.rb:10 — t.references :element, index: true만 있고 FK 제약 없음. 다만 본 케이스에서는 ET의 denormalized payload로 Element 실재성이 이미 입증돼 FK 부재는 이번 판정과 무관.