RCA: Index error - Waited 7 sec, 0/10 available

Overview#

What Happened#

2026-05-22 06:57~07:00 UTC에 cupixworks-worker(us-west-2)에서 Elasticsearch connection pool이 완전 고갈되어 Feed#_index_document와 EditingSplitWorker#perform에서 연쇄적으로 실패가 발생했다. 동일 호스트에서 총 8건의 connection pool timeout 에러가 기록되었으며, 그 중 일부는 Sidekiq 재시도 소진 후 death handler에 도달했다.

Quick Facts#

Timeline#

1. 06:54~06:57 UTC — 대량 indexing 작업 진행 (CreateSitetrackEditingEntitiesWorker, BulkPartialIndexWorker, bulk_partial_save_to_file)
2. 06:57:46 UTC — EditingSplitWorker에서 최초 connection pool timeout 발생 (editing_id: 1115084, 1115090)
3. 06:58:16~06:58:54 UTC — EditingSplitWorker 반복 실패, Sidekiq death handler 발동
4. 06:59:32~06:59:58 UTC — Feed#_index_document에서도 동일 에러 발생 (이 클러스터의 대표 에러)

Error Log#

Datadog Logs

Index error - Waited 7 sec, 0/10 available

Impact#

• Service: cupixworks-worker
• 발생 횟수: 2 (이 클러스터), 총 8건 (동일 시간대 관련 에러 포함)
• 최초 발생: 2026-05-22T06:59:32.208Z
• 최근 발생: 2026-05-22T06:59:58.213Z
• 영향 범위: Elasticsearch indexing 실패로 검색 데이터 동기화 지연. 단, _index_document 실패 시 BulkIndexWorker로 재시도하므로 최종 데이터 유실 가능성은 낮음. EditingSplitWorker는 death handler까지 도달하여 editing_id 1115084, 1115090의 split 처리가 완전 실패.

Root Cause Summary#

Elasticsearch connection pool(size: 10, timeout: 7초)이 동시 다발적인 indexing 작업으로 완전히 고갈되었다. 동일 호스트(ip-10-1-18-233)에서 CreateSitetrackEditingEntitiesWorker, BulkPartialIndexWorker 등의 대량 bulk indexing이 동시에 실행되면서 10개의 커넥션이 모두 점유되었고, 이후 Feed#_index_document와 EditingSplitWorker가 7초 동안 커넥션을 획득하지 못해 ConnectionPool::TimeoutError가 발생했다.

Technical Analysis#

Code Path#

• Entry point: config/initializers/elasticsearch.rb:17 — ConnectionPool 초기화 (size: 10, timeout: 7)
• Failure point: app/models/concerns/searchable.rb:43 — __elasticsearch__.client.index() 호출 시 pool에서 connection checkout 실패
• Error handler: app/models/concerns/searchable.rb:50-52 — rescue 후 에러 로깅 및 BulkIndexWorker 재시도 enqueue

Pool 설정 (size: 10, timeout: 7초):

Elasticsearch::Model.client = ConnectionPool::Wrapper.new(size: 10, timeout: 7) {
  Elasticsearch::Client.new(
    host: ENV.fetch('RAILS_ES_HOST') { 'localhost' },
    port: ENV.fetch('RAILS_ES_PORT') { DEFAULT_RAILS_ES_PORT },
    user: ENV['RAILS_ES_USER'],
    password: ENV['RAILS_ES_PASSWORD'],
    transport_options: {
      request: {
        timeout: 10
      }
    }
  ) do |faraday|
    if Rails.env.development?
      faraday.response :logger, Logger.new($stdout, level: :info)
    end
  end
}

ConnectionPool::Wrapper는 pool size만큼의 Elasticsearch client 인스턴스를 유지하며, with 블록이나 method_missing을 통해 connection을 checkout한다. Sidekiq concurrency가 pool size를 초과하면 timeout이 발생한다.

에러 발생 지점 — _index_document:

def _index_document
  return if @skip_index_document == true

  indexed_json = __elasticsearch__.as_indexed_json
  base_request = {
    id: __elasticsearch__.id,
    body: indexed_json
  }

  results = __elasticsearch__.client.index(base_request.merge(index: __elasticsearch__.index_name))
  Cupix::Logger.debug(results.to_json, class: self.class.name, function: __method__)

  # NOTE: dual write to tmp_index while reindexing
  if (tmp_index = self.class.fetch_tmp_index_name)
    __elasticsearch__.client.index(base_request.merge(index: tmp_index))
  end
rescue StandardError => e
  Cupix::Logger.error("Index error - #{e.message}", class: self.class.name, function: __method__)
  BulkIndexWorker.perform_async(self.class.name, [id], 'index')
end

__elasticsearch__.client는 ConnectionPool::Wrapper 인스턴스로, .index() 호출 시 내부적으로 pool.checkout을 수행한다. Pool이 고갈되면 timeout 후 ConnectionPool::TimeoutError 예외가 발생하고, 이것이 rescue에서 잡혀 "Index error - Waited 7 sec, 0/10 available" 메시지로 로깅된다.

Exception stack trace (Sidekiq death handler에서 확인):

connection_pool-2.5.0/lib/connection_pool/timed_stack.rb:78:in `block (2 levels) in pop'
<internal:kernel>:187:in `loop'
connection_pool-2.5.0/lib/connection_pool/timed_stack.rb:70:in `block in pop'
connection_pool-2.5.0/lib/connection_pool/timed_stack.rb:69:in `synchronize'
connection_pool-2.5.0/lib/connection_pool/timed_stack.rb:69:in `pop'
connection_pool-2.5.0/lib/connection_pool.rb:125:in `checkout'
connection_pool-2.5.0/lib/connection_pool.rb:107:in `block in with'
connection_pool-2.5.0/lib/connection_pool.rb:106:in `handle_interrupt'
connection_pool-2.5.0/lib/connection_pool.rb:106:in `with'
connection_pool-2.5.0/lib/connection_pool/wrapper.rb:14:in `with'

Log Evidence#

사용한 Datadog 쿼리:

service:cupixworks-worker status:error @environment:production "Waited 7 sec, 0/10 available"

service:cupixworks-worker status:error @environment:production (elasticsearch OR index OR "connection pool")

service:cupixworks-worker @environment:production host:ip-10-1-18-233.us-west-2.compute.internal

핵심 에러 로그 (Feed#_index_document):

{
  "timestamp": "2026-05-22T06:59:58.213Z",
  "status": "error",
  "message": "Index error - Waited 7 sec, 0/10 available",
  "class": "Feed",
  "function": "_index_document",
  "host": "ip-10-1-18-233.us-west-2.compute.internal",
  "pid": 3114827,
  "request_id": "b9f6bf88c0cf65d1000f3e1f"
}

EditingSplitWorker death handler (재시도 소진):

{
  "timestamp": "2026-05-22T06:58:54.203Z",
  "message": "Sidekiq job died after all retries",
  "error.msg": "Waited 7 sec, 0/10 available",
  "class": "EditingSplitWorker",
  "function": "perform",
  "editing_id": 1115084,
  "request_id": "cf64c18621d96c585cc25f58"
}

동시 실행 중이던 bulk indexing 작업 (에러 직전 info 로그):

06:54~06:57 UTC - CreateSitetrackEditingEntitiesWorker: creating editing entities for sitetrack_id 18275
06:54~06:57 UTC - BulkPartialIndexWorker: multiple "ES bulk partial index response" calls
06:54~06:57 UTC - Element/ElementTrace: bulk_partial_save_to_file operations

이 대량 작업들이 동일 호스트에서 동시에 실행되면서 10개의 ES connection을 모두 점유했음을 보여준다.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• config/initializers/elasticsearch.rb:17: Connection pool size를 Sidekiq concurrency에 맞게 증가. 현재 size: 10인데, Sidekiq 워커가 10개 이상의 스레드를 사용하면 pool 고갈이 필연적이다. size: ENV.fetch('ES_POOL_SIZE', 25).to_i와 같이 환경 변수로 설정 가능하게 변경 권장.

단기 개선 (1주 이내)#

• Sidekiq concurrency 설정과 ES pool size를 연동하여, pool size가 항상 concurrency 이상이 되도록 설정. Sidekiq.options[:concurrency] + 5 정도의 여유를 두는 것이 일반적.
• BulkPartialIndexWorker와 같은 대량 작업에 Sidekiq queue 분리 또는 rate limiting 적용하여 동시 실행 수 제한.

장기 개선 (재발 방지)#

• Elasticsearch connection pool 사용량 모니터링 추가 (checkout 대기 시간, pool 사용률).
• Bulk indexing 작업에 backpressure 메커니즘 도입: pool 사용률이 높을 때 새 bulk 작업 enqueue를 지연.
• connection_pool gem의 timeout을 적절히 조정하거나, timeout 시 즉시 재시도하지 않고 exponential backoff 적용.

Monitoring#

• ES connection pool checkout 대기 시간 메트릭 추가
• Datadog 알림 쿼리:

service:cupixworks-worker status:error "0/10 available"

• Pool 사용률 커스텀 메트릭:

avg:elasticsearch.connection_pool.utilization{service:cupixworks-worker} > 0.8

Risk Assessment#

• Risk level: medium
• 예상 복잡도: standard — pool size 변경은 설정 1줄이지만, 적정 크기 결정과 부하 테스트 필요. Queue 분리는 Sidekiq 설정 변경과 배포 필요.