ES /docs

Operation timed out after 10001 milliseconds with 0 bytes received

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

Error Log#

Datadog Logs

text
Operation timed out after 10001 milliseconds with 0 bytes received

Impact#

  • Service: cupixworks-api
  • 발생 횟수: 2
  • 최초 발생: 2026-04-06T22:27:42.243Z
  • 최근 발생: 2026-04-06T23:50:08.330Z

Root Cause Summary#

ClusterRepository#_search 메서드에서 Elasticsearch 검색 요청 시 Patron(libcurl) HTTP 클라이언트가 10초 timeout을 초과하여 에러가 발생했습니다. Elasticsearch 클라이언트의 transport_options.request.timeout이 10초로 설정되어 있으며(config/initializers/elasticsearch.rb:24-26), Elasticsearch 클러스터가 해당 시점에 검색 요청에 10초 이상 응답하지 못해 Patron이 Operation timed out after 10001 milliseconds with 0 bytes received 에러를 발생시켰습니다. 이 에러는 2개의 서로 다른 API 서버 인스턴스(ip-10-1-19-190, ip-10-1-144-228)에서 약 1시간 22분 간격으로 발생하여, 특정 서버 문제가 아닌 Elasticsearch 클러스터 측의 일시적 성능 저하(slow query 또는 부하 증가)가 원인으로 판단됩니다.

Technical Analysis#

Code Path#

  • Entry point: app/controllers/api/v1/clusters_controller.rb:14 — ClustersController#index에서 repository_instance.search(cluster_query_option) 호출
ruby
# app/controllers/api/v1/clusters_controller.rb:12-21
def index
  cluster_query_option = Cupix::QueryOption::Cluster.new(get_query_option(enable_current_team: false), params)
  clusters = repository_instance.search(cluster_query_option)

  render_api Renderable.new({
    search_result: clusters,
    is_collection: true,
    serializer_option: @serializer_option
  })
end
  • app/repositories/base_repository.rb:70-71 — BaseRepository#search가 _search(query_option) 호출
ruby
# app/repositories/base_repository.rb:70-92
def search(query_option = nil)
  _search(query_option)

  begin
    if self.review.present?
      contents = self.class.permission_joins(...)
    # ...
  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')
  end
end
  • app/repositories/cluster_repository.rb:95-100 — ClusterRepository#_search에서 ::Cluster.search() Elasticsearch 호출 수행
ruby
# app/repositories/cluster_repository.rb:95-103
response = ::Cluster.search(
  self.query_option.serializable_hash
).paginate(
  per_page: self.query_option.per_page,
  page: self.query_option.page
)

set_response(response)
  • Failure point: config/initializers/elasticsearch.rb:17-27 — Elasticsearch 클라이언트가 Patron(libcurl) adapter를 사용하며, timeout이 10초로 설정됨
ruby
# config/initializers/elasticsearch.rb:1,17-27
require 'patron'

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|
    # ...
  end
}

기대 동작: ::Cluster.search() 호출 시 Elasticsearch가 10초 이내에 검색 결과를 반환해야 합니다.

실제 동작: Elasticsearch가 10초 이내에 응답하지 못해 Patron(libcurl)이 Patron::TimeoutError를 발생시킵니다. 이 에러는 base_repository.rb:88의 rescue StandardError에서 캐치되어 Cupix::Logger.error로 로깅(class: ClusterRepository)된 후 Cupix::Errors::BadGateway로 re-raise됩니다. 클라이언트는 502 Bad Gateway 응답을 받습니다.

Log Evidence#

사용한 Datadog 쿼리:

text
service:cupixworks-api status:error "Operation timed out after 10001 milliseconds with 0 bytes received"
Time range: 2026-04-06T21:27:00Z to 2026-04-07T00:50:00Z
text
service:cupixworks-api status:error @class:ClusterRepository
Time range: 2026-04-06T00:00:00Z to 2026-04-07T01:00:00Z

첫 번째 발생 (2026-04-06T22:27:42.243Z):

json
{
  "timestamp": "2026-04-06T22:27:42.243Z",
  "status": "error",
  "message": "Operation timed out after 10001 milliseconds with 0 bytes received",
  "class": "ClusterRepository",
  "method": "search",
  "request_id": "9da4c280-6be9-4104-ba14-585c17a6dc71",
  "host": "ip-10-1-19-190.us-west-2.compute.internal",
  "pid": 3964393,
  "version": "production-us-west-2-20260406T1237Z0-7ff48a81-cupixworks"
}

두 번째 발생 (2026-04-06T23:50:08.330Z):

json
{
  "timestamp": "2026-04-06T23:50:08.330Z",
  "status": "error",
  "message": "Operation timed out after 10002 milliseconds with 0 bytes received",
  "class": "ClusterRepository",
  "method": "search",
  "request_id": "07424743-c4ba-4852-96ce-a5bda471838c",
  "host": "ip-10-1-144-228.us-west-2.compute.internal",
  "pid": 1811984,
  "version": "production-us-west-2-20260406T1223Z0-7ff48a81-cupixworks"
}

핵심 관찰:

  • 두 에러 모두 method: "search", class: "ClusterRepository"로 동일한 코드 경로에서 발생
  • 서로 다른 API 서버 인스턴스에서 발생 (ip-10-1-19-190 vs ip-10-1-144-228) — 특정 서버 문제 아님
  • timeout 값이 10001ms와 10002ms로 설정된 10초 timeout과 정확히 일치 (1-2ms는 libcurl 내부 오차)
  • 0 bytes received — Elasticsearch가 partial response도 보내지 못한 완전한 timeout
  • 해당 기간(약 1.5시간) 동안 ClusterRepository 에러는 이 2건만 발생 — 간헐적 이슈

Fix Recommendation#

즉시 조치 (Critical)#

현재 에러율이 낮으므로(2건/1.5시간) 즉각적인 코드 변경은 불필요합니다. 다만, Elasticsearch 클러스터의 상태를 점검해야 합니다:

  • Elasticsearch slow query log 확인하여 해당 시간대의 느린 쿼리 파악
  • Elasticsearch 클러스터 CPU, memory, disk I/O 메트릭 확인
  • ClusterRepository#_search의 쿼리가 accessible_clusters.pluck(:id) (cluster_repository.rb:89)로 대량의 ID를 terms query에 포함시키는 구조이므로, 특정 사용자의 권한 범위가 매우 클 경우 쿼리가 비효율적일 수 있음

단기 개선 (1주 이내)#

  • config/initializers/elasticsearch.rb:24-26의 timeout을 검색 API용으로 적절히 조정하거나, 검색 요청에 별도의 timeout 옵션을 적용하는 것을 검토
  • ClusterRepository#_search (cluster_repository.rb:89)에서 accessible_clusters.pluck(:id)의 결과가 매우 클 경우를 대비한 보호 로직 추가 검토 — 예: terms query의 ID 수 제한, 또는 Elasticsearch의 terms_lookup으로 전환
  • base_repository.rb:88-91의 rescue StandardError에서 Patron::TimeoutError를 별도로 처리하여 timeout-specific한 에러 메시지 및 응답 코드(504 Gateway Timeout)를 반환하는 것을 검토

장기 개선 (재발 방지)#

  • Elasticsearch 검색 쿼리에 대한 Datadog APM trace를 통해 slow query를 체계적으로 모니터링
  • ClusterRepository의 permission 기반 검색 쿼리 최적화 — 현재 permission_joins가 12개 LEFT JOIN을 수행하며(cluster_repository.rb:150-270), 이것이 Elasticsearch 검색과 결합되어 전체 응답 시간에 영향을 줄 수 있음

Monitoring#

  • Elasticsearch timeout 에러 모니터링:
text
service:cupixworks-api status:error "Operation timed out" @class:ClusterRepository
  • Elasticsearch 응답 시간 메트릭:
text
avg:elasticsearch.query.time{service:cupixworks-api}
  • 검색 API 전체 에러율:
text
service:cupixworks-api status:error "Bad Gateway error on Elasticsearch"

Risk Assessment#

  • Risk level: low
  • 예상 복잡도: standard
  • 사유: 발생 빈도가 낮고(2건/1.5시간), 간헐적 Elasticsearch timeout으로 사용자에게 502 응답이 반환되지만 데이터 손실이나 상태 불일치는 없음. 사용자가 재시도하면 정상 동작할 가능성이 높음.