RCA: Editing split failed: Waited 7 sec, 0/10 available

Overview#

What Happened#

2026-06-17 07:44:42 KST에 production cupixworks-worker (us-west-2) 의 EditingSplitWorker#perform 가 Elasticsearch client connection pool 고갈로 실패했다. 같은 4초 구간에 ES _index_document 요청 8건이 10초 timeout 으로 동시 실패하면서 size=10 ES pool 의 모든 connection 이 점유됐고, split 작업이 ES client 를 7초간 대기한 뒤 ConnectionPool::TimeoutError("Waited 7 sec, 0/10 available") 로 raise 됐다. 동시 시점에 CreateSitetrackEditingEntitiesWorker 와 Feed#_index_document 도 동일 메시지로 실패했다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-06-17 07:44:32 KST 부근 — Elasticsearch cluster 응답 지연 시작 (10s request.timeout 도달 시점에서 역산)
2. 2026-06-17 07:44:40 KST — Feed#_index_document 첫 ES pool wait 실패: Index error - Waited 7 sec, 0/10 available
3. 2026-06-17 07:44:42 KST — EditingSplitWorker#perform 실패 (Editing split failed: Waited 7 sec, 0/10 available) + CreateSitetrackEditingEntitiesWorker 동시 실패 (sitetrack_id 19563)
4. 2026-06-17 07:44:42–07:44:44 KST — ES 측 timeout 8건 (Operation timed out after 10002 ms) 폭주
5. 2026-06-17 07:44:44 KST 이후 — 더 이상 동일 에러 없음 (incident self-cleared, ES 회복)
6. 2026-06-17 08:16:57 KST 이후 — EditingSplitWorker 정상 동작 (수십 건 Starting editing split / Editing split finished 로그 확인)

Error Log#

Datadog Logs

Editing split failed: Waited 7 sec, 0/10 available

Impact#

• Service: cupixworks-worker
• 발생 횟수: 1
• 최초 발생: 2026-06-17 07:44:42 KST
• 최근 발생: 2026-06-17 07:44:42 KST
• 1건의 editing split job 실패. Sidekiq retry (retry: 2)로 자동 복구 가능. 그러나 동일 root cause 로 같은 4초 구간에 sitetrack assignment 1건 + ES indexing 9건이 함께 실패 → siteinsights 도메인 일부 데이터의 splitting/indexing 이 일시 지연됐다.

Root Cause Summary#

근본 원인은 Elasticsearch cluster 의 응답 지연이다. ES request timeout: 10 초로 설정된 ES client 가 size=10 의 ConnectionPool::Wrapper (wait timeout: 7 sec) 를 통해 공유되는데, 다수의 ES 요청이 동시에 10초 timeout 에 걸리면 size=10 pool 이 연속 점유된다. 이 시점에 EditingSplitWorker (내부적으로 Cupix::ElementTraceGeoGroupingService 가 ES search 를 3회 호출) 가 ES client checkout 을 시도했으나 7초 wait 후 풀에 가용 connection 이 없어 ConnectionPool::TimeoutError("Waited 7 sec, 0/10 available") 가 raise → EditingSplitWorker rescue 블록이 그 메시지를 그대로 로그로 남겼다. bug 가 아닌, ES 인프라 latency spike 로 인한 down‑stream pool starvation.

Technical Analysis#

Code Path#

Sidekiq job 진입 → ES 호출 → pool 고갈 발생 시 raise 지점:

class EditingSplitWorker
  include Sidekiq::Worker
  sidekiq_options queue: :default, retry: 2

  def perform(editing_id)
    Cupix::Logger.info('Starting editing split', class: self.class.name, function: __method__, editing_id: editing_id)

    ::Cupix::EditingSplitService.new(editing_id: editing_id).split!

    Cupix::Logger.info('Editing split finished', class: self.class.name, function: __method__, editing_id: editing_id)
  rescue StandardError => e
    Cupix::Logger.error("Editing split failed: #{e.message}", class: self.class.name, function: __method__, editing_id: editing_id)
    raise
  end
end

split! 은 compute_split_groups → group_tasks_by_geo 를 거쳐 ElementTraceGeoGroupingService 를 호출한다:

def group_tasks_by_geo(task_ids, element_to_tasks)
  geo_service = ::Cupix::ElementTraceGeoGroupingService.new(
    facility_id: editing.facility_id, category_id: editing.category_id,
    level_id: editing.level_id, task_ids: task_ids
  )

  geo_result = geo_service.group_element_traces

ElementTraceGeoGroupingService 는 ES search 를 직접 호출한다 (3 곳에서 execute_search 실행):

def execute_search(query)
  response = ::ElementTrace.__elasticsearch__.client.search(
    ...
  )
rescue ::Elasticsearch::Transport::Transport::Error, ::Faraday::Error => e

ES client 는 application 전역에서 size=10 connection_pool 로 공유된다 — 이 풀이 이번 인시던트의 critical resource:

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
      }
    }
  ) ...
}

기대 동작: 정상 시 ES search 가 < 1초 안에 완료 → checkout/checkin 이 빠르게 회전 → size=10 으로 충분.

실제 동작: ES 가 느려져 각 thread 가 최대 10초 동안 connection 을 hold. Sidekiq concurrency=30 (config/sidekiq.yml) 환경에서 10개를 초과한 thread 들이 7초 wait 후 ConnectionPool::TimeoutError 로 실패. 7초 wait < 10초 request timeout 이므로, ES 가 끝까지 응답하지 못하면 풀이 회복되지 않고 wait 측에서 먼저 무너지는 구조.

Failure point: connection_pool gem 의 pop (Waited 7 sec, 0/10 available 메시지) — application 코드가 아닌 client checkout 단계.

EditingSplitWorker 자체는 retry: 2 이므로 후속 retry 에서 ES 가 회복되면 자동 복구된다 (실제로 같은 시간대 다른 split job 들은 이후 정상 실행됨, 아래 Log Evidence 참조).

Log Evidence#

Datadog query (재현용):

service:cupixworks-worker "Waited 7 sec, 0/10 available"

service:cupixworks-worker status:error
(time: 2026-06-16T22:40:00Z ~ 2026-06-16T22:50:00Z)

같은 4초 구간 (UTC 22:44:4044, KST 07:44:4044) 의 worker error 폭주:

2026-06-17 07:44:42  EditingSplitWorker#perform     Editing split failed: Waited 7 sec, 0/10 available
2026-06-17 07:44:42  CreateSitetrackEditingEntitiesWorker#perform  error on sitetrack_id: 19563 - Waited 7 sec, 0/10 available
2026-06-17 07:44:40  Feed#_index_document           Index error - Waited 7 sec, 0/10 available
2026-06-17 07:44:42  Feed#_index_document           Index error - Operation timed out after 10002 milliseconds with 0 bytes received
2026-06-17 07:44:44  Feed#_index_document           Index error - Operation timed out after 10001 milliseconds with 0 bytes received
2026-06-17 07:44:44  Feed#_index_document           Index error - Operation timed out after 10002 milliseconds with 0 bytes received  (×6)

총 8건의 Operation timed out after ~10002 ms (10s ES request timeout 도달) + 3건의 Waited 7 sec, 0/10 available (ES pool checkout 실패). 두 종류는 정확히 같은 4초 윈도우에 발생했고, 그 이후로 동일 에러는 사라진다 (Datadog service:cupixworks-worker @class:EditingSplitWorker 검색 결과: 22:44 이후 30+ 건의 Editing split finished 정상 종료 로그).

ES 한 건의 timeout 메시지 원문 (대표):

{
  "timestamp": "2026-06-17 07:44:44",
  "status": "error",
  "message": "Index error - Operation timed out after 10002 milliseconds with 0 bytes received",
  "class": "Feed",
  "function": "_index_document"
}

이는 size=10 pool 이 10초 동안 동시에 점유됐고, 7초 wait 한도 내에서 풀 회복이 일어나지 않았음을 보여준다.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

없음. 단발 인시던트(occurrence_count=1) 이고, ES cluster 일시 latency 가 자체 회복되어 후속 재발이 없다. Sidekiq retry: 2 로 자동 재처리됨. 우선 ES 측 latency 원인 (스로틀링, GC pause, hot shard, slow query 등)을 인프라 팀에서 검토할 것을 권고.

단기 개선 (1주 이내)#

• ES request timeout 과 pool wait timeout 의 정합성 검토: config/initializers/elasticsearch.rb:17 의 ES request timeout: 10 초 vs pool timeout: 7 초. request timeout (10s) > pool wait (7s) 이므로 ES 가 끝까지 응답 못 할 때 pool wait 측이 먼저 무너진다. 두 수치를 정렬(예: pool wait ≥ request timeout) 하면 ES 가 응답을 끝낸 직후의 회복 기회를 놓치지 않는다. 다만 wait 시간을 늘리면 worker 응답성도 함께 늘어나므로 ES SLA 와 함께 결정해야 한다.
• ES pool size 와 Sidekiq concurrency 의 비율 검토: config/sidekiq.yml production concurrency=30, ES pool size=10. ES 가 1초 이상 느려질 때 항상 starvation 위험. pool size 를 concurrency 와 비슷한 수준(예: 20~30)으로 키우거나, ES 호출이 많은 워커를 별도 큐/concurrency 로 분리.
• EditingSplitWorker 로깅 강화: 현재 e.message 만 로그 (editing_split_worker.rb:12). exception class, backtrace, ES latency context 를 함께 기록하면 추후 동일 패턴 식별이 쉬워진다 (코드 변경 본 보고서 범위 외 — direction only).

장기 개선 (재발 방지)#

• ES cluster capacity / hot shard / slow query 에 대한 alerting 강화.
• ES indexing path (Feed#_index_document) 와 search path (worker side) 를 다른 client/pool 로 분리하여 indexing latency 가 search 워커를 정지시키지 않도록 격리.
• ES 호출 회로 차단기(circuit breaker) 도입 검토 — ES latency 가 임계치 초과 시 ES-의존 워커 자동 backoff.

Monitoring#

다음 Datadog timeseries 쿼리로 동일 패턴 재발을 감지한다 (release dashboard widget 호환):

logs("service:cupixworks-worker \"Waited\" \"available\"").index("*").rollup("count").by("@class")

logs("service:cupixworks-worker \"Operation timed out\"").index("*").rollup("count").by("@class")

logs("service:cupixworks-worker @class:EditingSplitWorker status:error").index("*").rollup("count")

추가 메트릭 권고:

• ES request latency (p95, p99) 메트릭 — avg:trace.elasticsearch.query.duration{service:cupixworks-worker-elasticsearch} (datadog tracing 설정에 의존)
• ES connection_pool checkout wait time custom metric (pool.wait_ms histogram을 client wrapper 에 emit)

Risk Assessment#

• Risk level: low — single occurrence, self-cleared, Sidekiq retry 로 자동 복구. ES infra 측 latency 가 1차 원인이며 application bug 가 아니다.
• 예상 복잡도: standard — 코드 fix 자체는 즉시 필요 없음. 다만 ES pool / Sidekiq concurrency 비율 조정은 운영팀과 ES capacity planning 협의 필요.