RCA: Api::V1::AnnotationsController#index latency (avg/max 10050ms)

Overview#

What Happened#

2026-06-26 23:12:43 KST에 cupixworks-api의 Api::V1::AnnotationsController#index 요청이 Elasticsearch 호출에서 10초 timeout 에 걸려 502 Bad Gateway (code BG10002) 로 응답했다. 동일 review (v4efud) 에 대한 1ms 뒤 재시도 요청은 122ms 에 정상 완료된 것으로 보아, 쿼리 자체가 무거운 것이 아니라 Elasticsearch 호출이 일시적으로 지연된 단발성 사건이다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-06-26 23:12:33 KST — 클라이언트가 GET /api/v1/reviews/v4efud/annotations 호출 시작.
2. 2026-06-26 23:12:43 KST — Elasticsearch transport 가 10,002 ms 만에 timeout (Operation timed out after 10002 milliseconds with 0 bytes received).
3. 2026-06-26 23:12:43 KST — base_repository.rb#search 가 StandardError 로 catch 하여 Cupix::Errors::BadGateway (code BG10002) 를 raise. 응답 코드 502, 총 소요 10048.24 ms.
4. 2026-06-26 23:12:43 KST — 동일 review/세션의 재시도 요청 (request_id=4c6f617c…) 이 122ms 에 200 으로 성공.

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::AnnotationsController#index",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 10050,
  "max_ms": 10050,
  "sample_trace_id": "3102542776567078022"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 1
• 최초 발생: 2026-06-26 23:12:32 KST
• 최근 발생: 2026-06-26 23:12:32 KST

Root Cause Summary#

Elasticsearch 클라이언트가 초기화 시 transport_options.request.timeout: 10 초로 설정되어 있는데 (config/initializers/elasticsearch.rb:25), 해당 호출이 정확히 그 시점에 timeout 되었다. Datadog request log 에 기록된 db: 10.03 (DB query 10 ms), 그리고 1 ms 뒤 동일 review 에 대한 재시도가 122 ms 에 성공한 사실은 본 쿼리/리뷰의 데이터 양이나 SQL 자체가 무거워서 발생한 latency 가 아니라, Elasticsearch 측 또는 그 사이의 네트워크/커넥션이 일시적으로 응답을 보내지 못한 단발성 stall 임을 보여준다. BulkRepository#search 의 rescue StandardError 는 timeout 도 일반 ES 오류로 묶어 502/BG10002 로 변환한다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/annotations_controller.rb:16-25
• Repository search: app/repositories/annotation_repository.rb → _search 가 ::Annotation.search(query_option.serializable_hash).paginate(...) 호출
• Failure point: app/repositories/base_repository.rb:94-97
• Transport configuration: config/initializers/elasticsearch.rb:17-34 — request.timeout: 10

Controller 는 Elasticsearch 기반 search 만 호출한다.

def index
  annotation_query_option = Cupix::QueryOption::Annotation.new(get_query_option, params)
  annotations = repository_instance.search(annotation_query_option)

  render_api Renderable.new({
    search_result: annotations,
    is_collection: true,
    serializer_option: @serializer_option
  })
end

_search 내부에서 ::Annotation.search 가 Elasticsearch 로 HTTP 요청을 보낸다.

response = ::Annotation.search(
  self.query_option.serializable_hash
).paginate(
  per_page: self.query_option.per_page,
  page: self.query_option.page
)

Elasticsearch client 는 Patron adapter 와 함께 request timeout 10 초로 초기화되어 있다.

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

base_repository.rb#search 는 ES 호출 중 발생한 StandardError 를 모두 Cupix::Errors::BadGateway (BG10002) 로 변환한다. timeout 도 여기서 502 로 응답된다.

def search(query_option = nil)
  _search(query_option)

  begin
    if self.review.present?
      contents = self.class.permission_joins(self.class.default_joins(self.response.records), ...)
    # ...
    end
  rescue Elasticsearch::Transport::Transport::Errors::BadRequest => e
    # ...
  rescue Elasticsearch::Transport::Transport::ServerError => e
    raise unless e.message.start_with?('[429]')
    # ...
  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

기대 동작: ES 일시 지연 시에도 client 가 retry 하거나, 짧은 timeout 으로 빠르게 실패한 후 자동 재시도되어 사용자 경험에 영향이 없어야 한다. 실제 동작: 단일 호출이 10초간 응답을 기다린 뒤 502 로 그대로 사용자에게 반환된다. (동일 review 에 대한 클라이언트/브라우저 재시도는 122ms 에 성공 → ES 자체가 망가진 것이 아닌 단발성 stall.)

Log Evidence#

Datadog query (request log):

service:cupixworks-api AnnotationsController#index @duration:>5000
from 2026-06-26T14:00:00Z to 2026-06-26T14:30:00Z

해당 요청의 request log (요약):

{
  "@timestamp": "2026-06-26T14:12:43.455Z",
  "duration": 10048.24,
  "db": 10.03,
  "http": {
    "status_code": 502,
    "method": "GET",
    "url_details": { "path": "/api/v1/reviews/v4efud/annotations" }
  },
  "controller": "Api::V1::AnnotationsController",
  "action": "index",
  "error": {
    "class": "Cupix::Errors::BadGateway",
    "code": "BG10002",
    "reason": "Bad Gateway error on Elasticsearch",
    "message": "Bad Gateway error on Elasticsearch"
  },
  "team": { "domain": "rogers-obrien", "id": 631 },
  "params": { "per_page": "100", "review_key": "v4efud", "page": "1" },
  "host": { "name": "ip-10-1-80-134.us-west-2.compute.internal" }
}

같은 host 에서 같은 시점에 기록된 error 로그 (Patron transport):

2026-06-26T14:12:43.680Z status:error
"Operation timed out after 10002 milliseconds with 0 bytes received"

0 bytes received 메시지는 ES 가 응답 헤더조차 보내지 않은 채 클라이언트가 timeout 한 케이스 — 즉 ES 측의 query latency 가 아닌 connection-level stall 가능성이 높다.

Datadog query (재시도 확인):

service:cupixworks-api v4efud annotations
from 2026-06-26T14:12:30Z to 2026-06-26T14:12:50Z

동일 review/세션의 두 인접 요청:

ts                          duration  db     status  request_id                              session
2026-06-26T14:12:43.456Z    122.03    13.87  200     4c6f617c-37d7-4d9f-97c1-b5696b499480    684e54bf379b5518...
2026-06-26T14:12:43.455Z    10048.24  10.03  502     43609ac6-e944-4d45-8a3a-ded69103fac5    684e54bf379b5518...

본 timeout 이 산발적임을 확인한 7일 집계:

service:cupixworks-api "Operation timed out after 10002"
from now-7d
=> 20 occurrences spread across 2026-06-19 ~ 2026-06-26, 1~3 per hour at most

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 본 발생 자체는 단발성 (1건) 이고 클라이언트 재시도가 122ms 에 성공 → 별도의 코드 hotfix 불필요. 운영 차원에서 7일간 20건의 ES timeout 추세만 모니터링.
• 만약 BG10002 발생 빈도가 시간당 5건 이상으로 늘어나면 ES 클러스터의 P99 latency, search queue rejection, JVM GC pause 를 우선 점검 (cupix-infrastructure 의 ES 모듈 / OpenSearch 도메인).

단기 개선 (1주 이내)#

• app/repositories/base_repository.rb:94-97 의 rescue StandardError 가 timeout 까지 BG10002 한 가지로 묶고 있어 운영 가시성이 떨어진다. Datadog 에서 timeout 케이스만 분리해 alert/대시보드를 만들 수 있도록 별도 분기를 두는 방향을 검토 (예: Elasticsearch::Transport::Transport::Error 중 timeout 계열은 별도 error code 와 warn 레벨 메트릭 + error.cause 정보 보존). 구현 코드는 본 RCA 범위 외.
• 502 가 사용자에게 그대로 노출되면 UX 가 나쁘므로, 클라이언트 (review 페이지 로딩 흐름) 에 idempotent retry 가 없다면 1회 정도의 client-side retry 를 추가하는 것을 고려 (frontend 영역).

장기 개선 (재발 방지)#

• ES 호출 path 의 SLO 를 명시적으로 설정 (p99 < 1s, timeout error budget). cupixworks-api 의 모든 search controller (annotations, element_traces, editings, ...) 가 동일 transport 를 공유하므로, 같은 stall 영향을 받는다 — 공통 dashboards 와 alerting 을 일원화.
• Elasticsearch transport 의 connection pool 동작과 idle/keepalive 설정을 점검 (Patron + ELB/OpenSearch 의 idle timeout 정렬). 0 bytes received 패턴은 종종 idle 커넥션이 죽은 채 재사용된 경우에 나타난다 — 운영 환경의 LB idle timeout 과 client keepalive 를 정렬할 필요가 있는지 검증 (cupix-infrastructure 측 작업).

Monitoring#

ES timeout 발생 추세 (request log 기반):

service:cupixworks-api "Operation timed out after 10002"

AnnotationsController#index 의 502 발생 빈도:

service:cupixworks-api controller:Api::V1::AnnotationsController action:index @http.status_code:502

ES BG10002 전체 (모든 search controller 공통 ES timeout/error 신호):

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

AnnotationsController#index 의 응답 시간 분포 (10초 timeout 클리프 시각화용):

service:cupixworks-api controller:Api::V1::AnnotationsController action:index @duration:>5000

위 4개 쿼리는 dashboard timeseries widget 의 count aggregation 으로 사용. (writing-datadog-monitoring-queries 가이드에 따라 monitor-only 문법 | stats, count by(...) 등은 사용하지 않음.)

Alerting 임계치 제안: "Operation timed out after 10002" 이 5분간 5건 이상 발생 시 warn, 15분간 10건 이상 시 critical.

Risk Assessment#

• Risk level: low (단발성, 동일 review 의 즉시 재시도 성공, 사용자 영향 1건)
• 예상 복잡도: trivial — 코드 변경 없이 monitoring/dashboard 강화만 권장. 단기 개선 (error code 분리) 은 standard 수준.