ES /docs

Bulk index partial failure

RCA: Bulk index partial failure

Overview#

What Happened#

2026-06-29 07:28 KST 경에 cupixworks-worker Sidekiq 잡이 BimRevision 레코드에 대한 Elasticsearch bulk update를 실행하다가 bim_revisions 인덱스에서 일부 문서가 존재하지 않아 document_missing_exception(404) 을 반환했다. 같은 분 안에 eu-central-1, ap-southeast-2 두 리전에서 한 번씩 발생했고, 한 배치당 total: 300failed_count: 45 (~15%) 가 실패했다. 워커는 예외를 raise하지 않고 에러 로그만 남겼기 때문에 잡은 정상 종료되었고 후속 배치는 계속 처리되었다.

Quick Facts#

Field Value
exception.class (없음 — Cupix::Logger.error 만 호출)
exception.message Bulk index partial failure
top_frame app/models/concerns/searchable.rb:232
runtime Ruby on Rails (Sidekiq worker), Elasticsearch bulk API
deploy bfdc5ebd (production-eu-central-1-20260628T2222Z0, production-ap-southeast-2-20260628T2222Z0)
env production, regions: eu-central-1, ap-southeast-2

Affected Teams#

Team / Domain Error Count Impact
cupixworks-worker / BimRevision indexing 2 (각 배치당 45건 문서 누락) Elasticsearch bim_revisions 인덱스에서 일부 BimRevision 문서가 갱신되지 않아 검색/리스팅 결과의 최신성이 떨어질 수 있음. DB 데이터는 영향 없음.

Timeline#

  1. 2026-06-29 07:22 KST — 두 리전(eu-central-1, ap-southeast-2)에 동일 빌드 bfdc5ebd 배포 완료 (Datadog 로그의 dd.version 필드 기준).
  2. 2026-06-29 07:28:47 KST — ap-southeast-2 worker: update - id: 1 - 311 로그 후 즉시 Bulk index partial failure (failed_count: 45, total: 300, IDs 1..6 등이 document_missing).
  3. 2026-06-29 07:28:49 KST — eu-central-1 worker: update - id: 1 - 300 로그 후 동일한 Bulk index partial failure (failed_count: 45, total: 300).
  4. 2026-06-29 07:28:53 KST 이후 — 같은 워커가 다음 batch (id: 312 - 611, 612 - 911, ...) 처리. 이후 partial failure 로그는 더 이상 발생하지 않음 (낮은 ID 구간에서만 실패).

Error Log#

Datadog Logs

text
Bulk index partial failure

Full attributes (eu-central-1 instance, 2026-06-28T22:28:49.647Z):

Datadog log attributesjson
{
  "message": "Bulk index partial failure",
  "class": "BimRevision",
  "function": "bulk_operation!",
  "operation": "update",
  "total": 300,
  "failed_count": 45,
  "failed_sample": [
    { "id": "2", "status": 404,
      "error": { "type": "document_missing_exception",
                 "reason": "[_doc][2]: document missing",
                 "index": "bim_revisions",
                 "index_uuid": "qrm3SQPiQV-hN9rArFbENg",
                 "shard": "2" } },
    { "id": "3", "status": 404,
      "error": { "type": "document_missing_exception",
                 "reason": "[_doc][3]: document missing",
                 "index": "bim_revisions", "shard": "3" } },
    { "id": "4", "status": 404,
      "error": { "type": "document_missing_exception",
                 "reason": "[_doc][4]: document missing",
                 "index": "bim_revisions", "shard": "3" } },
    { "id": "5", "status": 404,
      "error": { "type": "document_missing_exception",
                 "reason": "[_doc][5]: document missing",
                 "index": "bim_revisions", "shard": "1" } },
    { "id": "6", "status": 404,
      "error": { "type": "document_missing_exception",
                 "reason": "[_doc][6]: document missing",
                 "index": "bim_revisions", "shard": "4" } }
  ]
}

Impact#

  • Service: cupixworks-worker
  • 발생 횟수: 2
  • 최초 발생: 2026-06-29 07:28:47 KST
  • 최근 발생: 2026-06-29 07:28:49 KST
  • 영향 범위: 각 리전당 BimRevision 최저 ID 구간(약 45/300 문서)이 Elasticsearch에서 갱신되지 않음. DB는 정상. 워커는 raise하지 않고 다음 배치로 진행하므로 잡 자체는 성공 처리됨.

Root Cause Summary#

BimRevision.bulk_operation!(ids, 'update') 가 Elasticsearch bulk API에 update 액션을 보내는데, 대상 ID(예: 1, 2, 3, 4, 5, 6 등 낮은 ID 구간)의 문서가 bim_revisions 인덱스에 존재하지 않아 ES가 항목별로 document_missing_exception (404) 을 반환했다. update 액션은 문서가 이미 존재한다고 가정하므로, 인덱스가 새로 만들어졌거나, 해당 문서가 과거에 삭제되었거나, DB에는 존재하지만 ES에 한 번도 색인된 적이 없는 레코드인 경우 모두 이 예외가 발생한다. 두 리전이 거의 동시에 같은 ID 범위(1~)에서 실패한 점, ID가 작은 쪽에 집중된 점, 같은 배포(bfdc5ebd) 직후라는 점을 종합하면 배포 후 또는 정기 reconcile/migration이 id 오름차순으로 첫 batch(1..300) 를 update 로 시도한 시나리오와 일치한다 (소스 상의 후보: lib/cupix/migrate/bim_revision.rb#migrate_revision_version, lib/tasks/tesla/migrate.rake#migrate_cycle_state). 어느 트리거가 정확히 이번 호출을 만들었는지는 추가 정황이 없어 uncertain — needs verification 로 남겨둔다.

Technical Analysis#

Code Path#

Entry point는 Searchable concern의 클래스 메서드 bulk_operation! 이다. update operation을 받으면 각 ID에 대해 ES bulk update payload를 생성하고 단일 bulk 호출을 수행한다.

app/models/concerns/searchable.rb:194-242ruby
def bulk_operation!(ids, operation = 'index', refresh_cached = false)
  raise Cupix::Errors::Argument.new(code: 'ARG10000', reason: 'ids is required') if ids.blank?

  batch_for_bulk = []
  if operation == 'delete'
    # ...
  else
    records = self.eager_loaded.where(id: ids)

    records.find_each do |record|
      record.update_all if refresh_cached && record.respond_to?(:update_all) && record.has_attribute?(:cached)
      data_hash = record.as_indexed_json

      case operation
      when 'index'
        batch_for_bulk.push({ index: { _id: record.id, data: data_hash } })
      when 'update'
        batch_for_bulk.push({ update: { _id: record.id, data: { doc: data_hash } } })
      end
    end
  end

  # ...
  results = self.__elasticsearch__.client.bulk(index: index_name, body: batch_for_bulk)

  if results.is_a?(Hash) && results['errors']
    failed_items = (results['items'] || []).filter_map do |item|
      op = item.values.first
      next unless op.is_a?(Hash) && op['error']

      { id: op['_id'], status: op['status'], error: op['error'] }
    end
    Cupix::Logger.error('Bulk index partial failure',
                        class: self.name, function: __method__,
                        operation: operation,
                        total: batch_for_bulk.size,
                        failed_count: failed_items.size,
                        failed_sample: failed_items.first(5))
  end

update 액션은 ES에 이미 존재하는 문서만 갱신할 수 있다. 문서가 없으면 ES는 항목 단위로 404 document_missing_exception 을 돌려주는데, 전체 호출은 200으로 끝나지만 응답 본문에 errors: true 가 들어 있다. 이 코드는 이를 감지해서 에러 로그만 남기고 예외는 raise하지 않는다 — 그래서 호출자(bulk_operation, BulkIndexWorker) 입장에서는 "성공"으로 처리된다.

가능한 호출 경로 — BimRevision 에서 update 작업으로 들어오는 코드 위치:

lib/cupix/migrate/bim_revision.rb:8-23ruby
def migrate_revision_version
  name = 'V9'
  version = 9
  Cupix::Logger.info('start bim_revision version migration')
  loop do
    invalid_name = name.next
    version += 1
    valid_name = "V#{version}"
    bim_revisions = BimRevision.where(name: invalid_name)

    break if bim_revisions.empty?

    Cupix::Logger.info("Migrate bim_revision version from #{invalid_name} to #{valid_name}", class: self.name, function: __method__, bim_revision_ids: bim_revisions.pluck(:id))
    bim_revisions.update_all(name: valid_name)
    bim_revisions.pluck(:id).each_slice(300) do |ids|
      ::BimRevision.bulk_operation(ids, 'update')
    end

    name = invalid_name
  end
end

migrate_cycle_state rake task 도 update 액션으로 모든 Cyclable 모델을 일괄 동기화한다 — BimRevisionCyclable 을 include 하고 있으면 동일 경로다:

lib/tasks/tesla/migrate.rake:574-581ruby
_relation = model.where(cycle_state: nil)
_relation.in_batches(of: _batch_size).each_with_index do |relation, batch_index|
  message = "[#{DateTime.now}][migrate_cycle_state] Processing uninitialized #{model.name}: batch ##{batch_index} started"
  Cupix::Slack.post('backend-migration', "#{$SLACK_REGION_USER_NAME} [#{Rails.env}]", message, icon_emoji: SLACK_REGION_ICON)
  Cupix::Logger.info(message)
  relation.update_all(cycle_state: 'created')
  model.bulk_operation(relation.pluck(:id), 'update') if model.respond_to?(:bulk_operation)
end

호출자 측 wrapper — 워커는 bulk_operation! 의 예외를 잡지만, partial failure는 raise가 아니라 로그만 남기므로 retry로 전달되지 않는다:

app/workers/bulk_index_worker.rb:10-25ruby
def perform(model_name, ids, operation = 'index', refresh_cached = false)
  return if ids.blank?
  return unless model_name.is_a?(String)

  model_name.classify.constantize.bulk_operation!(ids, operation, refresh_cached)
rescue Cupix::Errors::System => e
  if e.message.include?('empty batch_for_bulk')
    Cupix::Logger.warn("Empty batch_for_bulk - skipping (model: #{model_name}, ids: #{ids})",
                       class: self.class.name, function: __method__)
    return
  end
  raise e
rescue Elasticsearch::Transport::Transport::ServerError => e
  Cupix::Logger.error("ServerError - #{e.message}", class: self.class.name, function: __method__)
  raise e
end

기대 동작 vs 실제 동작:

  • 기대: 대상 ID 모두 ES에 존재 → bulk update 성공, 모든 문서가 최신 상태로 갱신.
  • 실제: ID 1..6 등 낮은 ID 문서가 ES에 없어 항목당 document_missing_exception 반환. ES bulk 호출 자체는 부분 성공(errors: true), 워커는 로그만 남기고 종료. 누락 문서는 재색인되지 않음.

Failure point — update 작업이 document_missing_exception 을 만났을 때 자동 복구(예: index 로 fallback 후 재시도) 가 없는 지점:

app/models/concerns/searchable.rb:225-238ruby
if results.is_a?(Hash) && results['errors']
  failed_items = (results['items'] || []).filter_map do |item|
    op = item.values.first
    next unless op.is_a?(Hash) && op['error']

    { id: op['_id'], status: op['status'], error: op['error'] }
  end
  Cupix::Logger.error('Bulk index partial failure',
                      class: self.name, function: __method__,
                      operation: operation,
                      total: batch_for_bulk.size,
                      failed_count: failed_items.size,
                      failed_sample: failed_items.first(5))
end

Log Evidence#

Datadog 쿼리:

text
service:cupixworks-worker "Bulk index partial failure"
text
service:cupixworks-worker @class:BimRevision

배치 진행 패턴 — update 가 ID 1 부터 오름차순으로 진행됨 (배포 직후 첫 배치만 실패):

text
2026-06-29 07:28:47 KST  info   update - id: 1 - 311       BimRevision.bulk_operation!  (ap-southeast-2)
2026-06-29 07:28:47 KST  error  Bulk index partial failure BimRevision.bulk_operation!  total=300 failed=45
2026-06-29 07:28:49 KST  info   update - id: 1 - 300       BimRevision.bulk_operation!  (eu-central-1)
2026-06-29 07:28:49 KST  error  Bulk index partial failure BimRevision.bulk_operation!  total=300 failed=45
2026-06-29 07:28:53 KST  info   update - id: 312 - 611     BimRevision.bulk_operation!  (정상)
2026-06-29 07:28:59 KST  info   update - id: 612 - 911     BimRevision.bulk_operation!  (정상)
2026-06-29 07:29:00 KST  info   update - id: 1 - 300       BimRevision.bulk_operation!  (정상; 다른 리전 두 번째 시도)

핵심 관찰:

  • 실패한 ID는 모두 한 자리수 (1, 2, 3, 4, 5, 6) — 가장 오래된/이미 삭제된 레코드 영역.
  • 두 리전 모두 같은 deploy SHA bfdc5ebd 직후 (07:22 KST 배포 → 07:28 KST 실패).
  • 각 리전의 ES index_uuid 가 다름 (qrm3SQPiQV-hN9rArFbENg, _NnbYS_ORoyL8QTNU46DoQ) — 리전별 독립 인덱스이므로 두 실패는 동일 트리거가 양쪽에서 발생한 것이지 cross-region 영향이 아님.
  • failed_count: 45 / total: 300 이 두 리전에서 동일 — 같은 ID 범위 (1..300) 중 동일 비율이 ES에 없음.
  • "Bulk operation failed" (cluster e00d4025, us-west-2) 는 이 partial failure 와는 별개 (raise 되는 예외 경로). 여기에서는 다루지 않음.

Hypotheses Considered#

# Hypothesis Evidence for Evidence against Verdict
H1 update 작업이 ES에 존재하지 않는 문서 ID를 대상으로 호출되었다 (DB에는 있지만 ES에 색인 안 됨, 또는 ES에서 삭제됨) failed_sample 의 모든 항목이 document_missing_exception (404) 이고 _doc][1..6] 등 가장 낮은 ID에 집중. searchable.rb:215update payload 는 문서 존재를 전제. Confirmed
H2 Elasticsearch 클러스터 자체의 장애/네트워크 문제 같은 시간대에 다른 모델 (@class:BimRevision 외) 의 ES 에러가 폭증했어야 함. 두 리전 모두 동시에 같은 ES 클러스터 문제일 확률 낮음. 실제 응답은 정상 bulk response (errors: true 의 정상 형식). Faraday::TimeoutError 같은 transport 예외 없음. Rejected
H3 새 배포 bfdc5ebdas_indexed_json 또는 eager_loaded 스코프를 변경해 문서가 깨졌다 배포(07:22 KST) 후 6분 만에 실패 발생, 두 리전 동시. 실패는 ES document_missing 이지 매핑/직렬화 에러가 아님. 그리고 이미 색인된 문서는 같은 호출에서 정상 갱신됨 (total=300 중 255 는 성공). Rejected
H4 정기 reindex/migration 잡 (Cupix::Migrate::BimRevision.migrate_revision_version 또는 migrate_cycle_state rake task) 가 ID 오름차순으로 update 를 발행 update - id: 1 - 311, update - id: 312 - 611 등 ID 오름차순 batch 가 분 단위로 연속. 둘 다 each_slice(300) 또는 in_batches(of: 2000) 패턴과 일치. 정확한 호출자 식별 가능한 starter 로그(Slack [migrate_cycle_state] Processing BimRevision begin 등) 가 Datadog 14일 retention 내에서 시간/리전 매치되지 않음 — uncertain. Confirmed (broad path); 정확한 트리거는 uncertain — needs verification
H5 bulk_operation 자체가 race condition 으로 인해 미생성 문서를 갱신하려 했다 (예: BimRevision 생성 직후 update 가 먼저 도달) 매우 낮은 ID(1..6)는 race일 수 없음 — 한참 전에 생성된 레코드. Rejected

Fix Recommendation#

즉시 조치 (Critical)#

즉시 production-impacting 한 사고는 아니다 (잡 자체는 진행되고 DB는 정상). 다만 ES에 누락된 BimRevision 문서(낮은 ID 영역) 의 검색 가시성이 떨어진 상태일 수 있으므로:

  • 운영 작업: 각 리전(eu-central-1, ap-southeast-2)에서 BimRevision.where(id: 1..400) 정도 (실패 ID 분포 기준) 에 대해 BulkIndexWorker.perform_async('BimRevision', ids, 'index') 를 한 번 실행해 누락 문서를 새로 색인. update 가 아닌 index 액션이어야 한다 (app/models/concerns/searchable.rb:213). 코드 변경 불필요, ops-only.
  • 검증: 위 작업 후 service:cupixworks-worker "Bulk index partial failure" @class:BimRevision 가 비어 있는지 확인.

단기 개선 (1주 이내)#

Searchable#bulk_operation! 의 partial failure 처리에 자동 fallback 또는 분류된 에러 처리를 추가:

  • app/models/concerns/searchable.rb:225-238 부분에서 실패 항목의 error.type == 'document_missing_exception' 만 골라 같은 ID 집합에 대해 index 액션으로 재시도하는 경로 추가. 다른 에러(매핑 충돌, version conflict 등) 는 그대로 로그만 남기고 raise하지 않는 동작 유지.
  • 또는 Cupix::Migrate::BimRevision.migrate_revision_version 등 알려진 migration 호출부에서 update 대신 index 를 사용하도록 정책 정리 (이 변경은 DB와 ES 일관성에 더 안전 — update 는 doc 가 있다는 가정을 두지만 인덱스가 새로 만들어지거나 오래된 문서가 purge 된 환경에서는 항상 깨진다).
  • bulk_operation! 가 partial failure 시 어떤 호출자 컨텍스트(어떤 worker, 어떤 잡 ID) 에서 왔는지 알 수 있도록 caller_locations(1, 2) 또는 Sidekiq.current_job 정보를 로그에 포함.

장기 개선 (재발 방지)#

  • 모델별 ES 색인 상태에 대한 reconcile 잡 추가: 정기적으로 DB의 ID 분포와 ES의 _count / _search 결과를 비교해 누락 문서를 자동으로 index 작업으로 재색인.
  • updateindex 의 의미 차이를 abstract 한 단일 메서드 (예: upsert_index!) 로 정리해 호출자가 의도치 않게 update 를 선택하지 않도록 함. 호출처 30+ 군데 (lib/cupix/migrate/*.rb, app/repositories/*.rb, rake task) 가 모두 'update' 리터럴 문자열로 호출 중이라 휴먼 에러 가능성이 높다.
  • Datadog 에 Bulk index partial failure 메트릭화 + failed_count 누적 알람.

Monitoring#

추가할 Datadog 모니터링 쿼리 (release dashboard timeseries widget 용):

text
sum:logs{service:cupixworks-worker,@message:"Bulk index partial failure"}.as_count()

모델별 failed_count 추이:

text
sum:logs{service:cupixworks-worker,@message:"Bulk index partial failure"} by {@class}.as_count()

document_missing_exception 분리 추적 (failed_sample 첫 항목 기준):

text
sum:logs{service:cupixworks-worker,@message:"Bulk index partial failure",@failed_sample.error.type:document_missing_exception}.as_count()

알람 임계치 제안: 1시간에 Bulk index partial failure 가 5건 이상이면 경보 (이번 사례는 2건 / 5분이지만 동일 ID 영역 반복이라 이벤트 자체는 미흡).

Risk Assessment#

  • Risk level: low — 잡 실패 아님, DB 데이터 영향 없음, 검색 인덱스에서 일부 오래된 ID 의 신선도만 영향.
  • 예상 복잡도: standard — fallback 재색인 로직 추가는 단일 concern 파일(searchable.rb) 수정이며, 호출처 전반에 미치는 영향 작음. 운영 reindex 는 일회성 작업.