ES /docs

Bulk index partial failure

RCA: Bulk index partial failure

Overview#

What Happened#

2026-06-10 13:37 KST, cupixworks-api (production, ap-southeast-1)에서 Capture#bulk_operation!이 Elasticsearch bulk update를 호출했지만 부분 실패가 발생했다. 실패 원인은 ES [parent] Data too large (circuit_breaking_exception, HTTP 429) — 클러스터 heap 사용량이 7.7GB로 parent breaker limit 7.5GB(8160437862 bytes)를 초과한 상태였다. 동일 시간대(13:37:10–13:37:56)에 같은 ES 클러스터를 사용하는 다수의 모델(Capture, Pano, EditingEntity, Admin::EditingRepository)에서 429 circuit-breaking 에러가 동시 다발했고, 일부 요청은 결국 Faraday timeout(10s)으로 500을 반환했다.

Quick Facts#

Field Value
exception.class Elasticsearch::Transport::Transport::Errors::TooManyRequests (logged via partial-failure handler)
exception.message Bulk index partial failure (1 of 1 items failed with circuit_breaking_exception)
top_frame app/models/concerns/searchable.rb:232
runtime Rails / elasticsearch-ruby client
deploy production-ap-southeast-1-20260609T0227Z0-4aed8e74-cupixworks
env production / ap-southeast-1

Affected Teams#

Team / Domain Error Count Impact
Search / Indexing (Capture) 1 (this cluster) Capture 2514 ES document update missed — index drift
Search / Indexing (Pano, EditingEntity, Admin::EditingRepository) 19+ in the same minute 동일 ES 클러스터 heap 압박으로 다수 indexing 실패
API consumers of PUT /api/v1/jobs, POST /api/v1/panos 다수 500 응답 (SYS50000) — job 진행/pano 생성 실패

Timeline#

  1. 2026-06-10 13:37:10 KST — ES parent breaker가 7.6–7.9GB 영역에서 반복적으로 trip (Pano#_update_document 등 다수 모델에서 429 시작)
  2. 2026-06-10 13:37:40 KST — Capture 2514 가 processing → done 전이. Capture#bulk_operation! 호출, ES bulk update가 partial failure (1/1 fail, status 429) 반환 → Bulk index partial failure 로깅 (이 클러스터)
  3. 2026-06-10 13:37:42 KST — 동일 request_id 컨텍스트에서 후속 Capture#_update_document 가 429 반환 (bulk 와 달리 raise 됨)
  4. 2026-06-10 13:37:52 KSTEditingEntity#_index_document 가 Faraday timeout(10002ms) → PUT /api/v1/jobs/9287 가 500 응답
  5. 2026-06-10 13:37:56 KST — request_id 8c00491c 트레이스 종료

Error Log#

Datadog Logs

text
Bulk index partial failure
json
{
  "message": "Bulk index partial failure",
  "class": "Capture",
  "function": "bulk_operation!",
  "operation": "update",
  "total": 1,
  "failed_count": 1,
  "failed_sample": [
    {
      "id": "2514",
      "status": 429,
      "error": {
        "type": "circuit_breaking_exception",
        "reason": "[parent] Data too large, data for [indices:data/write/bulk[s]] would be [8314793078/7.7gb], which is larger than the limit of [8160437862/7.5gb], real usage: [8314778240/7.7gb], new bytes reserved: [14838/14.4kb], usages [request=0/0b, fielddata=2051/2kb, in_flight_requests=14838/14.4kb, model_inference=0/0b, eql_sequence=0/0b, accounting=574695688/548mb]",
        "bytes_wanted": 8314793078,
        "bytes_limit": 8160437862,
        "durability": "PERMANENT"
      }
    }
  ],
  "request_id": "8c00491c-67d1-4b93-a34d-8cc89cc6b645",
  "environment": "production",
  "deploy": "production-ap-southeast-1-20260609T0227Z0-4aed8e74-cupixworks"
}

Impact#

  • Service: cupixworks-api
  • 발생 횟수: 1 (이 fingerprint), 단 동일 분 내 동일 ES 클러스터 원인의 429/timeout 에러는 20+ 건 발견됨
  • 최초 발생: 2026-06-10 13:37:40 KST
  • 최근 발생: 2026-06-10 13:37:40 KST

Root Cause Summary#

ap-southeast-1 production Elasticsearch 클러스터의 parent circuit breaker 가 limit (7.5GB / 8160437862 bytes)을 초과하여 다수의 indexing 요청을 HTTP 429 (circuit_breaking_exception, durability PERMANENT)로 거절하고 있었다. 이 클러스터 fingerprint 의 실패는 그 중 한 건으로, Capture 2514 의 processing → done 상태 전이가 트리거한 Capture.bulk_operation!('update') 가 한 건짜리 bulk request 를 보냈는데 ES heap 압박으로 거절된 것이다. bulk_operation! 의 partial-failure 처리 경로(searchable.rb:225-238)는 실패를 로깅만 하고 raise/retry 하지 않는다 — 따라서 Capture 2514 의 ES 문서는 갱신되지 않은 상태로 남고, BulkIndexWorker 의 sidekiq retry(retry: 5) 도 트리거되지 않는다. 즉, 이 에러는 (a) ES 클러스터 heap 부족이라는 인프라 원인과, (b) bulk path 가 partial-failure 를 swallow 하는 코드 경로의 결합으로 발생한다.

Technical Analysis#

Code Path#

  • Entry point (worker path): app/workers/bulk_index_worker.rb:14model_name.classify.constantize.bulk_operation!(ids, operation, refresh_cached)
  • Inline path: Capture 의 state transition 내에서 bulk_operation! 또는 _update_document 직접 호출
  • ES request: app/models/concerns/searchable.rb:223self.__elasticsearch__.client.bulk(...)
  • Failure point: app/models/concerns/searchable.rb:225-238 — partial-failure handler
app/models/concerns/searchable.rb:194-238ruby
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'
    raise Cupix::Errors::Argument.new(code: 'ARG10000', reason: 'ids should be an array') unless ids.is_a?(Array)

    ids.each do |id|
      batch_for_bulk.push({ delete: { _id: id } })
    end
  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

  raise Cupix::Errors::System.new(code: 'SYS10000', reason: 'empty batch_for_bulk') if batch_for_bulk.blank?

  begin
    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
app/workers/bulk_index_worker.rb:1-26ruby
class BulkIndexWorker
  include Sidekiq::Worker
  sidekiq_options queue: :default, retry: 5

  sidekiq_retry_in do |count|
    # retry 300, 600, 1200, 2400, 2400 seconds
    [300 * (2**count), 2400].min
  end

  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
end

기대 동작 vs 실제 동작:

  • 기대: bulk request 의 일부 항목이 실패하면 예외를 raise 하여 BulkIndexWorker 의 sidekiq retry (최대 5회, 5분/10분/20분/40분/40분 backoff) 가 동작 — ES 부담 완화 후 재시도되어 index drift 방지
  • 실제: partial failure 는 Cupix::Logger.error 로 로깅 후 정상 흐름으로 진행. Capture 2514 의 ES document 는 갱신되지 않은 채 남고, retry 도 발생하지 않음. 이후 검색/필터 결과가 stale 상태가 됨.

Log Evidence#

사용한 Datadog 쿼리:

text
service:cupixworks-api status:error @environment:production "Bulk index partial failure"
text
service:cupixworks-api "circuit_breaking_exception"
text
service:cupixworks-api @request_id:8c00491c-67d1-4b93-a34d-8cc89cc6b645

같은 분(13:37:10–13:37:56 KST) 동안 발생한 다른 ES 429 에러 (다른 모델/path):

json
{
  "timestamp": "2026-06-10 13:37:42 KST",
  "class": "Capture",
  "function": "_update_document",
  "message": "ElasticsearchError - [429] ... circuit_breaking_exception ... bytes_wanted: 8381901248, bytes_limit: 8160437862"
}
json
{
  "timestamp": "2026-06-10 13:37:53 KST",
  "class": "Admin::EditingRepository",
  "message": "[429] ... circuit_breaking_exception ... bytes_wanted: 8386082832, bytes_limit: 8160437862"
}

같은 request_id 의 trace 결과 — Job 9287 update 가 결국 timeout 으로 500 응답:

json
{
  "timestamp": "2026-06-10 13:37:52 KST",
  "message": "[500] PUT /api/v1/jobs/9287 (Api::V1::JobsController#update)",
  "error": [
    "Faraday::TimeoutError",
    "Operation timed out after 10002 milliseconds with 0 bytes received"
  ]
}

ES 클러스터 heap 사용량(파싱한 값들):

시각 (KST) 호출 path bytes_wanted bytes_limit 비율
13:37:10 Pano#_update_document 8,295,426,008 8,160,437,862 101.7%
13:37:23 Pano#_update_document 8,176,891,430 8,160,437,862 100.2%
13:37:40 Capture#bulk_operation! (this) 8,314,793,078 8,160,437,862 101.9%
13:37:42 Capture#_update_document 8,381,901,248 8,160,437,862 102.7%
13:37:53 Admin::EditingRepository 8,386,082,832 8,160,437,862 102.8%

accounting 값은 일관되게 ~548MB 로 fielddata/request 사용량은 작고, 대부분의 heap 점유는 일반 JVM 객체 (segments, query cache 등) 임을 시사.

Hypotheses Considered#

# Hypothesis Evidence for Evidence against Verdict
H1 ES 클러스터 parent circuit breaker (heap 한계 초과)로 인한 indexing 거절 동일 분에 다수 모델/path 에서 [parent] Data too large 429 다발 (bytes_wanted 가 일관되게 bytes_limit=8160437862 초과). 클러스터 fingerprint failure 항목의 error.reason 도 동일 메시지. Confirmed
H2 페이로드가 너무 커서 request circuit breaker (단일 request 한계) 가 trip failed_sample 의 bytes_wanted<http_request> / indices:data/write/bulk[s] context 에서 7.7+ GB — 이는 단일 요청 크기가 아니라 클러스터 전체 heap 누적치 (parent breaker). single bulk body 는 total: 1 로 매우 작음 (14.4kb new bytes reserved). request=0/0b, accounting=548mb 로 단일 request 자체는 작음 Rejected
H3 서비스 측 코드 버그 (bulk_operation! 가 잘못된 payload 생성) total: 1, failed_count: 1 — 그러나 실패 원인은 ES 측에서 명시한 circuit_breaking_exception 같은 코드 경로가 H1 의 다른 모델들에서도 동일한 429 를 받음 → 인프라 원인 Rejected
H4 bulk_operation! 의 partial-failure handler 가 swallow 하여 retry 가 안 됨 (보조 root cause) searchable.rb:225-238 에서 Cupix::Logger.error 만 호출하고 raise 하지 않음. BulkIndexWorker (retry: 5) 의 sidekiq retry 가 트리거되지 않음. 결과적으로 Capture 2514 의 ES document 가 stale bulk_operation_with_response 등 다른 entry 도 raise 안 함 — 의도적 design 가능성도 있음 Confirmed (contributing)
H5 Faraday timeout (10s) 가 진짜 root cause timeout 은 같은 trace 의 후속 단계에서 발생 — heap 압박으로 ES 응답 지연 timeout 메시지 자체에 circuit_breaking_exception 언급 없음 Rejected (timeout 은 H1 의 결과)

Fix Recommendation#

즉시 조치 (Critical)#

  • ES 클러스터 heap 압박 완화 (인프라 팀): ap-southeast-1 production ES 클러스터의 heap 사용량이 일관되게 95–103% 영역. 다음 중 하나 이상 필요
    • 노드 추가 / heap size 증설 (현재 limit 7.5GB → 12GB+ 검토)
    • 큰 인덱스의 shard re-balance 또는 오래된/사용 안 하는 index 정리 (segment count 감소)
    • indices.breaker.total.limit 설정값과 실제 heap 의 비율 점검 (default 95%)
    • JVM heap dump / _nodes/stats/breaker 로 어떤 component 가 heap 을 점유 중인지 확인 (단, accounting 만 548MB 이고 나머지는 unreserved heap → segment/query cache 의심)
  • 영향받은 record 의 indexing 일관성 복구: BulkIndexWorker.perform_async('Capture', [2514], 'update') 로 재indexing (또는 Capture.bulk_operation('update', [2514])). 동일 시간대 다른 모델(Pano, EditingEntity 등) 도 같이 점검.

단기 개선 (1주 이내)#

  • app/models/concerns/searchable.rb:225-238 의 partial-failure handler 가 retryable 한 실패(429 circuit_breaking_exception, 503 등)를 만났을 때 raise 하도록 수정 검토. 그래야 BulkIndexWorker 의 sidekiq retry: 5 백오프 (5분→40분) 가 동작하여 ES 회복 후 자동 복구됨.
  • 비-retryable 영구 에러(예: mapping conflict, illegal_argument)는 raise 하지 말고 별도 dead-letter 로 보내는 분기 추가.
  • _update_document, _index_document 등 동기 single-doc path 도 429 시 BulkIndexWorker 큐로 fallback 시켜 retry 보장.

장기 개선 (재발 방지)#

  • ES indexing 을 항상 BulkIndexWorker 경유로 표준화 (controller 동기 indexing 제거) — request latency 분리 + retry 일원화.
  • ES 메트릭 + 알림: parent breaker trip 빈도, heap usage > 85%, indexing rejected count 모니터링 (아래 참조).
  • ES capacity planning 프로세스: 인덱스 growth 추적 + 자동 rollover/ILM 도입.
  • Index 일관성 검증 잡(주기적 reconciliation) 으로 partial-failure 로 누락된 document 자동 복구.

Monitoring#

  • ES rejection / circuit-breaker trip 빈도 (이 인시던트의 1차 신호)
text
sum:trace.rack.request.errors{service:cupixworks-api,resource_name:* ,error_type:Elasticsearch.Transport.Transport.Errors.TooManyRequests}.as_count()
  • API 측 429/500 logs from ES (시계열로 빈도 확인):
text
logs("service:cupixworks-api \"circuit_breaking_exception\"").index("*").rollup("count").by("@class").last("1d")
  • Bulk index partial failure 로그 발생 빈도:
text
logs("service:cupixworks-api \"Bulk index partial failure\"").index("*").rollup("count").by("@class").last("7d")
  • ES JVM heap usage(Datadog ES integration metric):
text
avg:elasticsearch.jvm.mem.heap_in_use{env:production,region:ap-southeast-1} by {host}
  • 권장 알림:
    • ES breaker.parent.tripped rate > 0 (지속 5m) → page on-call
    • heap_in_use_pct > 85% (지속 10m) → warn
    • logs "Bulk index partial failure" count > 5 / 5m → warn (현재 partial-failure swallow 로 재indexing 안 되므로 데이터 일관성 위험 신호)

Risk Assessment#

  • Risk level: high — ES 클러스터가 한계 헤더를 반복적으로 trip 하고 있고, 코드 경로가 partial-failure 를 swallow 하여 ES document 가 stale 상태로 남는다. 검색/필터링 정확도, capture/pano lifecycle, job 진행 모두에 영향.
  • 예상 복잡도: standard (코드 변경) + critical (인프라 capacity 변경 / ES 클러스터 운영). 코드 수정 자체는 작지만(searchable.rb 의 partial-failure 분기 raise), root cause 인 heap 압박 해결은 ES 클러스터 운영 작업이 필요.