RCA: Faraday::TimeoutError: Operation timed out after 10001 milliseconds with 0 bytes received

Overview#

What Happened#

tesla (cupixworks-api)의 Elasticsearch 트랜스포트 호출이 설정된 10초 request timeout 을 초과하여 Faraday::TimeoutError("Operation timed out after 10001 milliseconds with 0 bytes received")가 발생했다. 이 에러는 Datadog APM 의 cupixworks-elasticsearch instrumentation span 에 기록된 것으로, 실제 앱 서비스는 tesla 이다. ES 클러스터가 10초 안에 단 1바이트도 응답하지 못한 transient 지연 상황으로, 약 33개월간 52건(하루 1건 미만)만 관측되었다.

Quick Facts#

Affected Teams#

Timeline#

1. 2023-10-27 09:58 KST — 최초 발생 (first_seen)
2. 2026-07-21 13:07 KST — 최근 발생 (last_seen)
3. 2026-08-04 — RCA 수행. Datadog 로그 검색 결과 0건(retention 14일 초과, last_seen이 14일 밖)

Error Log#

Datadog Logs

Operation timed out after 10001 milliseconds with 0 bytes received

Impact#

• Service: cupixworks-elasticsearch (APM adapter span; 실제 앱은 tesla / cupixworks-api)
• 발생 횟수: 52
• 최초 발생: 2023-10-27 09:58 KST
• 최근 발생: 2026-07-21 13:07 KST

Root Cause Summary#

cupixworks-elasticsearch 는 실제 서비스가 아니라 Datadog APM 의 Elasticsearch instrumentation span 이름이다(config/initializers/datadog.rb:44 c.tracing.instrument :elasticsearch, service_name: global_service_name + '-elasticsearch'). 실제 앱은 tesla 이다. tesla 의 ES 클라이언트는 config/initializers/elasticsearch.rb:23-26에서 transport_options: { request: { timeout: 10 } }로 10초 request timeout 을 갖도록 구성되어 있고, HTTP 전송은 faraday 0.17.5 + patron(libcurl) adapter 를 사용한다. ES 클러스터가 10초 안에 응답 바이트를 하나도 반환하지 못하면 patron 의 Patron::TimeoutError 가 faraday/adapter/patron.rb:40에서 Faraday::TimeoutError("...after 10001 milliseconds with 0 bytes received")로 재-raise 되며, 이 시점의 span 에 에러로 기록된다. 즉 이 에러는 코드 결함이 아니라 ES 클러스터의 transient 지연/응답 지연이 설정된 10초 캡에 걸린 것이다. 10001ms는 설정된 10초 timeout 그 자체이고 0 bytes received는 서버가 응답을 시작조차 못했음을 뜻한다.

Technical Analysis#

Code Path#

• Entry point: ES 클라이언트 구성 — config/initializers/elasticsearch.rb:17-34
• Timeout 설정: config/initializers/elasticsearch.rb:25
• 재-raise 지점: faraday-0.17.5/lib/faraday/adapter/patron.rb:40 (라이브러리)
• Read 경로 처리: app/repositories/base_repository.rb:70-98
• Write 경로 처리: app/models/concerns/searchable.rb:112-121

ES 클라이언트는 10초 request timeout 과 함께 생성된다. patron 이 libcurl 백엔드로 실제 소켓 통신을 담당한다.

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

10초 안에 응답이 시작되지 않으면 patron adapter 가 Patron::TimeoutError 를 잡아 Faraday::TimeoutError 로 변환한다. 이 메시지가 바로 대표 에러 문자열이다.

rescue ::Patron::TimeoutError => err
  raise Faraday::TimeoutError, err.message

기대 동작 vs 실제 동작: tesla 는 이미 이 예외를 두 경로에서 인지하고 처리한다.

Write(색인) 경로 — Faraday::TimeoutError 를 명시적으로 rescue 하여 로그를 남기고 BulkIndexWorker 로 async 재색인한다. 사용자 요청은 실패하지 않는다.

    rescue Faraday::TimeoutError => e
      Cupix::Logger.error("TimeoutError - #{e.message}", class: self.class.name, function: __method__)
      BulkIndexWorker.perform_async(self.class.name, [id], 'index')
    rescue Elasticsearch::Transport::Transport::Error => e
      Cupix::Logger.error("ElasticsearchError - #{e.message}", class: self.class.name, function: __method__)
      BulkIndexWorker.perform_async(self.class.name, [id], 'index')
    rescue StandardError => e
      Cupix::Logger.error("StandardError - #{e.message}", class: self.class.name, function: __method__)
      BulkIndexWorker.perform_async(self.class.name, [id], 'index')

Read(검색) 경로 — search 는 BadRequest/ServerError(429) 를 개별 처리하고, 그 외는 rescue StandardError(line 94)로 잡아 Cupix::Errors::BadGateway BG10002 로 감싸 502 를 반환한다. Faraday::TimeoutError < Faraday::ClientError < Faraday::Error < StandardError 이고 Elasticsearch::Transport::Transport::Error 의 하위가 아니므로 이 경로에서는 line 94 에 도달한다.

    rescue Elasticsearch::Transport::Transport::ServerError => e
      raise unless e.message.start_with?('[429]')
      Cupix::Logger.error("Elasticsearch circuit breaker: #{e.message}", class: self.class.name, method: __method__)
      raise Cupix::Errors::System.new(code: 'SYS20000', reason: 'Elasticsearch circuit breaker triggered (too many requests)')
    rescue StandardError => e
      Cupix::Logger.error(e.message.to_s, class: self.class.name, method: __method__)
      raise Cupix::Errors::BadGateway.new(code: 'BG10002', reason: 'Bad Gateway error on Elasticsearch')

어느 경로든 raw Faraday::TimeoutError 가 그대로 상위로 전파되어 요청을 무한정 중단시키지 않는다. Datadog Error Tracking 에 남는 것은 앱의 rescue 이전에 ES span 에 기록된 transport-level 에러다.

Log Evidence#

Datadog 로그 검색(대표 에러가 last_seen 2026-07-21 로 14일 retention 밖) — 모두 0건. et: 이슈는 Error Tracking 에만 남고 검색 가능한 로그가 없다.

사용한 쿼리:

service:cupixworks-elasticsearch "Faraday::TimeoutError"

"Operation timed out after 10001 milliseconds"

"Faraday::TimeoutError"

"Operation timed out after" "bytes received"

결과:

Found 0 logs

증거는 코드/구성으로 확정된다. Gemfile.lock 이 트랜스포트 스택과 timeout 근원을 확인해 준다.

elasticsearch-transport (7.5.0)
  faraday (>= 0.14, < 1)
faraday (0.17.5)
patron (0.13.3)
  faraday (>= 0.9.0, <= 1.10.0)

APM span 이름의 근원:

c.tracing.instrument :elasticsearch, service_name: global_service_name + '-elasticsearch'

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 없음. 이것은 ES 클러스터의 transient 지연에 대한 정상적 timeout 이며 코드 결함이 아니다. write/read 양 경로 모두 이미 이 예외를 처리한다.

단기 개선 (1주 이내)#

• (선택) 관측성 개선: read 경로(app/repositories/base_repository.rb:88-97)에서 Faraday::TimeoutError(및 Faraday::Error)를 rescue StandardError 이전에 별도 rescue 하여, transient ES timeout 을 예상 가능한 warn + BG10002 로 명확히 분류하면 알람 노이즈와 원인 진단이 쉬워진다. write 경로(searchable.rb:112) 는 이미 이 패턴을 갖고 있어 read 경로에 정렬시키는 정도의 소폭 변경이다.

장기 개선 (재발 방지)#

• ES 클러스터 측 지연 근원 모니터링: slow query, GC pause, 노드 포화 등 took/노드 지표를 관측(초기화 코드가 이미 elasticsearch.duration span tag 를 설정하므로 이를 대시보드화). 지속적으로 10초를 넘기면 timeout 상향이 아니라 클러스터 용량/쿼리 최적화로 접근한다.
• 산발적 빈도(하루<1)이므로 별도 재시도 래퍼 도입은 과잉. 현재의 async 재색인(write) + 502 변환(read) 으로 충분하다.

Monitoring#

• ES transport timeout 추세(앱 로그 기준, read 경로 개선 후):

service:cupixworks-api "Bad Gateway error on Elasticsearch"

• write 경로 timeout 후 async 재색인 트리거 추세:

service:cupixworks-api "TimeoutError -"

• ES 호출 지연 span 분포(APM span 기반, span 이 지연을 태그하는 경우):

service:cupixworks-elasticsearch

Risk Assessment#

• Risk level: low
• 예상 복잡도: trivial (권장 조치는 관측성 목적의 선택 사항이며, 필수 코드 수정 없음)

Noise Verdict#

noise — ES 클러스터의 일시적 지연이 설정된 10초 request timeout 에 걸려 발생한 transient network/latency 이슈이며, write/read 양 경로가 이미 async 재색인과 502 변환으로 정상 처리하므로 코드 결함이 아니다.