RCA: StandardError - Waited 7 sec, 0/10 available

Overview#

What Happened#

2026-04-24 20:10 UTC에 cupixworks-api의 POST /api/v1/panos/82417652/mask_upload_url 엔드포인트에서 Elasticsearch connection pool이 고갈되어 ConnectionPool::TimeoutError가 발생했다. 요청 총 소요 시간이 약 34.8분(2,087,601ms)으로 비정상적으로 길었으며, 해당 호스트의 Elasticsearch connection pool(size: 10) 전체가 소진된 상태에서 7초 대기 후 timeout이 발생했다.

Quick Facts#

Timeline#

1. 2026-04-24 ~19:35 UTC — 동일 호스트에서 요청 시작 (추정, 총 소요시간 ~34.8분 역산)
2. 2026-04-24 20:10:01.285Z — ConnectionPool::TimeoutError 발생, 502 응답 반환
3. 2026-04-25 — Error Sweeper 수집 및 RCA 수행

Error Log#

Datadog Logs

StandardError - Waited 7 sec, 0/10 available

Impact#

• Service: cupixworks-api
• 발생 횟수: 1
• 최초 발생: 2026-04-24T20:10:01.285Z
• 최근 발생: 2026-04-24T20:10:01.285Z
• 영향 사용자: Scott Johnson (scott.johnson@bnbuilders.com), Team: bnbuilders (ID 630)
• 영향 범위: mask_upload_url API 호출 실패 → pano mask 업로드 불가 (cupix-agent 클라이언트)

Root Cause Summary#

Elasticsearch connection pool(size: 10, timeout: 7초)이 완전히 고갈된 상태에서 Pano#_update_document가 pool에서 connection을 획득하지 못해 ConnectionPool::TimeoutError가 발생했다. 해당 요청은 총 34.8분(2,087,601ms)이 소요되었고 DB 시간만 2.1분(128,571ms)이었는데, 이는 동일 호스트(ip-10-1-144-228)에서 다수의 Elasticsearch 요청이 장시간 connection을 점유하면서 pool이 고갈된 것을 의미한다. after_commit hook에서 동기적으로 Elasticsearch update를 수행하는 구조 때문에, 한 번 pool이 포화되면 대기 중인 모든 요청이 연쇄적으로 지연된다.

Technical Analysis#

Code Path#

• Entry point: Api::V1::PanosController#mask_upload_url — maskable_controller.rb:16에서 정의된 controller action

def mask_upload_url(mask_type)
  _mask_type = mask_type.presence || 'custom'
  mask = @model.find_or_create_mask(_mask_type)

  if %i[missing created uploaded].include?(mask.state_name)
    mask.uploading
  end

  @model.uploading_mask_state!  # Pano 저장 → after_commit 트리거

  mask
end

• Trigger: @model.uploading_mask_state!가 Pano record를 update → after_commit on: [:update] hook 실행

after_commit on: [:update] do
  _update_document  # 동기적으로 Elasticsearch update 호출
end

• Failure point: _update_document에서 __elasticsearch__.client.update() 호출 시 connection pool에서 connection 획득 실패

begin
  request = {
    id: __elasticsearch__.id,
    body: { doc: attributes },
    retry_on_conflict: 5
  }
  request.merge!(type: __elasticsearch__.document_type) if __elasticsearch__.document_type

  results = __elasticsearch__.client.update(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.update(request.merge(index: tmp_index))
  end

• Pool configuration: ConnectionPool::Wrapper.new(size: 10, timeout: 7) — 전체 프로세스에서 공유하는 글로벌 Elasticsearch client

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
}

• Error handling: _update_document의 rescue StandardError 블록에서 에러를 로깅한 후 raise e로 재전파

rescue StandardError => e
  Cupix::Logger.error("StandardError - #{e.message}", class: self.class.name, function: __method__)
  raise e
end

기대 동작: uploading_mask_state! 저장 후 _update_document가 Elasticsearch에 변경사항을 동기적으로 반영하고 정상 응답. 실제 동작: Pool의 10개 connection이 모두 사용 중이어서 7초 대기 후 ConnectionPool::TimeoutError 발생 → StandardError rescue에서 잡혀 502 응답 반환.

Log Evidence#

Datadog 검색 쿼리:

service:cupixworks-api status:error "Waited 7 sec" @environment:production

에러 발생 시점의 application log:

{
  "timestamp": "2026-04-24T20:10:01.285Z",
  "service": "cupixworks-api",
  "host": "ip-10-1-144-228.us-west-2.compute.internal",
  "pid": 2614224,
  "class": "Pano",
  "function": "_update_document",
  "message": "StandardError - Waited 7 sec, 0/10 available",
  "request_id": "34227f90-80e6-4423-b650-fb80ec2dd5aa",
  "tenant": "cupix"
}

동일 request_id의 request log:

{
  "timestamp": "2026-04-24T20:10:01.207Z",
  "error_class": "ConnectionPool::TimeoutError",
  "error_message": "Waited 7 sec, 0/10 available",
  "method": "POST",
  "path": "/api/v1/panos/82417652/mask_upload_url",
  "controller": "Api::V1::PanosController#mask_upload_url",
  "status": 502,
  "duration": 2087601.03,
  "db_runtime": 128571.67,
  "user": "scott.johnson@bnbuilders.com",
  "team": "bnbuilders",
  "remote_ip": "44.228.8.68",
  "user_agent": "cupix-agent",
  "auth_method": "COGNITO"
}

요청 소요 시간 2,087,601.03ms (약 34.8분)는 비정상적으로 길며, 이는 해당 프로세스가 이미 상당 시간 동안 pool 고갈 상태에서 대기하고 있었음을 시사한다.

동일 시간대 warn 로그 검색 (service:cupixworks-api status:warn @host:ip-10-1-144-228):

service:cupixworks-api status:warn "pool"
→ 0건 (pool 관련 사전 경고 없음)

service:cupixworks-api status:warn @host:ip-10-1-144-228
→ "NotFound - attributes_in_database" 다수 발생 (20:39-20:40Z)
→ pool 고갈 전 사전 warning 없이 바로 exhaustion 발생

다른 서비스 cross-check:

status:error "0/10 available"
→ cupixworks-api 1건만 발견, cupixworks-worker 등 다른 서비스 해당 없음

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• config/initializers/elasticsearch.rb:17 — connection pool size를 10에서 25~50으로 증가시킨다. production 환경의 동시성을 고려하면 현재 10은 너무 작다. timeout도 7초에서 15초로 늘려 일시적 부하에 대한 tolerance를 높인다.

단기 개선 (1주 이내)#

• app/models/concerns/searchable.rb:16-18 — after_commit on: [:update]에서 _update_document를 동기 호출하는 대신, background job(Sidekiq 등)으로 비동기 처리하도록 변경한다. 이렇게 하면 HTTP 요청 처리 중에 connection pool을 점유하지 않으며, pool 고갈이 사용자 응답에 영향을 주지 않는다.
• maskable_repository.rb:59 — uploading_mask_state! 호출 시 @model.skip_index_document!를 먼저 설정하여 mask state 변경만으로는 ES 동기 update를 트리거하지 않도록 한다. mask state 변경은 ES 인덱스에 즉시 반영할 필요가 낮다.

장기 개선 (재발 방지)#

• Elasticsearch update를 모든 model에서 비동기로 전환하는 아키텍처 변경을 검토한다. after_commit → async job 패턴으로 전환하면 connection pool 압력을 근본적으로 해소할 수 있다.
• Connection pool 사용량에 대한 모니터링을 추가하여 pool 포화 전에 알림을 받을 수 있도록 한다.
• dual write(tmp_index) 로직이 활성화되는 reindexing 시점에는 pool size를 동적으로 확장하거나, reindex 전용 client를 분리하는 것을 고려한다.

Monitoring#

• Elasticsearch connection pool checkout 대기 시간 및 pool 사용률 메트릭 추가
• Datadog 쿼리로 pool 고갈 에러 모니터링:

service:cupixworks-api status:error "available" "Waited"

• 요청 duration 이상 감지:

service:cupixworks-api @duration:>60000

Risk Assessment#

• Risk level: medium — 단일 발생이지만, pool size가 작아 동시성 증가 시 재발 가능성 높음
• 예상 복잡도: standard — pool size 증가는 설정 변경만으로 가능하나, 비동기 전환은 테스트 필요