RCA: Api::V1::ClustersController#create (avg 14439ms, max 16562ms)

Overview#

What Happened#

2026-06-25 06:51~07:01 KST 사이에 cupixworks-api의 POST /api/v1/clusters (Api::V1::ClustersController#create) 요청 2건이 평균 14.4초, 최대 16.5초 걸렸다. 같은 시간대에 동일 컨트롤러의 index 액션이 Elasticsearch 호출 도중 10초 timeout을 맞고 502를 반환했고, Pano#_update_document가 NotFound - attributes_in_database warning을 대량으로 출력하고 있었다. cluster create는 모델 저장 직후 Searchable after_commit 콜백이 동기로 ES index를 호출하므로, 같은 ES 지연이 응답 시간에 그대로 누적된 것으로 보인다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-06-25 06:51 KST — 첫 번째 슬로우 ClustersController#create 요청 시작 (cluster first_seen).
2. 2026-06-25 06:54:54 KST — ClusterRepository가 "Operation timed out after 10002 milliseconds with 0 bytes received" error 로깅 (Elasticsearch HTTP timeout).
3. 2026-06-25 06:54:55 KST — Api::V1::ClustersController#index 502 Bad Gateway error on Elasticsearch (BG10002) 응답.
4. 2026-06-25 06:51~07:01 KST — 같은 시간대에 Pano#_update_document의 NotFound - attributes_in_database warning이 분당 수십 건 발생.
5. 2026-06-25 07:01 KST — 두 번째 슬로우 ClustersController#create 요청 (cluster last_seen). 이후 동일 패턴 추가 발견되지 않음.

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::ClustersController#create",
  "service": "cupixworks-api",
  "occurrences": 2,
  "avg_ms": 14439,
  "max_ms": 16562,
  "sample_trace_id": "470544450024522007"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 2
• 최초 발생: 2026-06-25 06:51 KST
• 최근 발생: 2026-06-25 07:01 KST
• 추가 영향: 같은 시간대 ClustersController#index 502 1건 + Pano#_update_document NotFound - attributes_in_database warning 다수 — Elasticsearch 의존 경로 전반의 지연.

Root Cause Summary#

Cluster 모델은 Searchable concern을 통해 after_commit on: :create 콜백에서 _index_document로 Elasticsearch에 동기 index 요청을 보낸다. Api::V1::ClustersController#create → ClusterFactory#create! → BaseFactory#create! → self.model.save! 경로에서 트랜잭션 커밋 직후 ES 호출이 HTTP 응답 시간 안쪽에 포함된다. 인시던트 시간대(2026-06-25 06:51~07:01 KST)에 Elasticsearch가 지연/장애 상태였고 같은 cluster index 액션은 ClusterRepository에서 10초 Curl/Faraday timeout 후 502 BG10002를 반환했다 — 즉 ES 응답이 10초 내외 지연되거나 timeout 후 재시도되는 상황이었다. create 액션은 502로 변환되는 rescue 경로가 없어서 ES 호출이 timeout 직전까지 대기하다 200으로 끝났고, 이것이 평균 14.4초/최대 16.5초의 응답 시간으로 관측되었다. 즉 코드 자체의 버그라기보다 외부 의존(Elasticsearch) 지연이 동기 인덱싱 경로를 통해 사용자 요청 응답 시간에 직접 노출된 latency 인시던트다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/clusters_controller.rb:23-27 — controller create.
• Factory: app/factories/cluster_factory.rb:5-33 — ClusterFactory#create!.
• Save: app/factories/base_factory.rb:124 — self.model.save!.
• Indexing callback: app/models/concerns/searchable.rb:12-14, 34-53 — after_commit on: :create 콜백이 동기로 ES index 호출.
• Failure point (slowness): app/models/concerns/searchable.rb:43 — __elasticsearch__.client.index(...)이 ES 응답을 동기 대기.

def create
  @model = factory_instance.create!(params)

  super
end

def create!(params = {})
  self.model = ::Cluster.new
  # ... parent (capture) lookup ...
  super  # → BaseFactory#create! → model.save!

  if params[:cluster_id].present?
    parent_cluster = ClusterRepository.new(current_user: self.current_user).show(params[:cluster_id])
    self.model.update_attribute(:parent, parent_cluster)
  end

  self.model
end

self.set_parameters(params)

begin
  self.model.save!   # ← after_commit on: :create → _index_document (synchronous ES HTTP)
  self.model
rescue Elasticsearch::Transport::Transport::Errors::BadRequest => e
  raise e
# ... other rescues, none for Faraday::TimeoutError ...
rescue StandardError => e
  raise e if e.is_a?(Cupix::Errors::BaseError)

  raise Cupix::Errors::System.new(code: 'SYS50000', reason: e.message)
end

after_commit on: [:create] do
  _index_document
end

# ...

def _index_document
  return if @skip_index_document == true

  indexed_json = __elasticsearch__.as_indexed_json
  base_request = {
    id: __elasticsearch__.id,
    body: indexed_json
  }

  results = __elasticsearch__.client.index(base_request.merge(index: __elasticsearch__.index_name))
  # NOTE: dual write to tmp_index while reindexing
  if (tmp_index = self.class.fetch_tmp_index_name)
    __elasticsearch__.client.index(base_request.merge(index: tmp_index))
  end
rescue StandardError => e
  Cupix::Logger.error("Index error - #{e.message}", class: self.class.name, function: __method__)
  BulkIndexWorker.perform_async(self.class.name, [id], 'index')
end

기대 동작: 정상 ES 응답 시 index 호출은 수십~수백 ms 내 완료되어 create 액션 전체가 1초 미만으로 끝남. 또한 tmp_index가 설정되어 있으면 같은 동기 경로에서 dual-write가 한 번 더 실행된다.

실제 동작: ES 지연으로 index HTTP 호출이 응답 대기에 머물거나 timeout (Curl 기본 timeout 10초)이 걸리고, rescue가 StandardError로 잡아 BulkIndexWorker로 fallback enqueue 한 뒤 200을 반환했지만 그 시점은 timeout 발생 후. dual-write가 활성화돼 있었다면 같은 timeout이 두 번 누적될 수 있다 (10s + 10s ≈ 20s, 관측된 max 16.5s와 정합적).

Log Evidence#

Datadog query (errors only, 인시던트 윈도우):

service:cupixworks-api status:error
from: 2026-06-24T21:30:00Z to: 2026-06-24T22:15:00Z

Elasticsearch timeout (cluster first_seen 직후, 인시던트 윈도우 내):

{
  "timestamp": "2026-06-25 06:54:54 KST",
  "status": "error",
  "message": "Operation timed out after 10002 milliseconds with 0 bytes received",
  "class": "ClusterRepository"
}

Elasticsearch 502 응답 (1초 뒤, 동일 컨트롤러 index):

{
  "timestamp": "2026-06-25 06:54:55 KST",
  "status": "info",
  "message": "[502] GET /api/v1/clusters (Api::V1::ClustersController#index)",
  "error": {
    "reason": "Bad Gateway error on Elasticsearch",
    "code": "BG10002",
    "class": "Cupix::Errors::BadGateway"
  }
}

Datadog query (warn 레벨 — Pano 인덱싱 이슈, 같은 시간대):

service:cupixworks-api status:(error OR warn)
from: 2026-06-24T21:50:00Z to: 2026-06-24T22:02:00Z

대표 warn (다수 반복):

{
  "timestamp": "2026-06-25 07:01:59 KST",
  "status": "warn",
  "message": "NotFound - attributes_in_database",
  "class": "Pano",
  "function": "_update_document"
}

create 자체는 200으로 끝나서 error/warn 로그 없음 (HTTP access log만 존재). trace_id 470544450024522007/4780489250140447732로 직접 검색 시 Datadog 로그 인덱스에 매칭 결과 없음 — 트레이스 정보는 APM에만 보존되고 로그에는 trace_id 태그가 부착되지 않은 것으로 확인.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 현재 인시던트 자체는 외부(Elasticsearch) 지연이 원인이며 코드 변경 없이 ES가 회복되면 자연 해소된다. 동일 시간대 Pano#_update_document warning 폭주와 ClusterRepository 10s timeout이 함께 발생한 점으로 보아 Elasticsearch 클러스터 상태(node load, indexing queue, GC) 점검을 우선 수행할 것 — 인프라/플랫폼 팀 hand-off 권장.
• 추가 코드 수정 없음.

단기 개선 (1주 이내)#

• Searchable#_index_document (app/models/concerns/searchable.rb:34-53)를 동기 호출 대신 비동기(BulkIndexWorker.perform_async) 기본 경로로 전환하는 옵션을 검토. 현재는 정상 경로가 동기, 실패 시에만 워커로 fallback이라 ES 지연이 응답 시간에 그대로 노출된다. 최소한 Cluster처럼 사용자 응답 path에 있는 모델은 옵트인으로 비동기 indexing을 활성화할 수 있는 토글을 추가.
• ES 클라이언트의 read/connect timeout을 controller 응답 SLA보다 짧게 설정 (예: 23초)하여 ES 장애 시 사용자 응답이 1416초까지 누적되지 않도록 한다. 현재 timeout은 Curl 기본 10초로 추정 (Operation timed out after 10002 milliseconds 로그).
• BaseFactory rescue 체인 (app/factories/base_factory.rb:126-140)에 Faraday::TimeoutError / Elasticsearch::Transport::Transport::Errors::* 분기를 추가해서 ES 실패가 사용자에게 transparent하게 502/202로 전달되도록 정리. 현재는 StandardError가 SYS50000로 raise되어 호출 측에서 ES 원인을 구분하기 어렵다.

장기 개선 (재발 방지)#

• "사용자 요청 path에 들어가는 외부 의존(Elasticsearch, S3, 외부 API)은 비동기/best-effort로 분리"라는 원칙을 정해 모든 after_commit 인덱싱 콜백을 worker enqueue로 통일.
• ES indexing pipeline에 backpressure / circuit breaker 도입 (이미 BaseRepository#search에는 ES 429 회로 차단 로직이 있음 — 동일 패턴을 indexing path에도 적용).
• APM trace에서 Api::V1::ClustersController#create의 child span 중 ES index span 비율을 자동 감시하는 SLO 도입.

Monitoring#

avg/max 지연과 ES 관련 에러를 함께 추적한다. 아래 쿼리는 release dashboard timeseries widget에 그대로 들어갈 수 있다.

avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::clusterscontroller#create}

max:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::clusterscontroller#create}

sum:trace.rack.request.errors{service:cupixworks-api,resource_name:api::v1::clusterscontroller#create}.as_count()

ES timeout / BG10002 발생 추적 (logs 기반 metric):

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

logs("service:cupixworks-api \"BG10002\"").index("*").rollup("count")

Risk Assessment#

• Risk level: medium — 단발성 ES 지연으로 보이지만 동기 indexing 구조 자체가 재현 위험을 만든다. 코드 수정 없이도 ES 회복 시 해소되나, 같은 패턴이 자주 반복되면 사용자 영향이 커진다.
• 예상 복잡도: standard — 즉시 조치는 인프라 hand-off (코드 변경 없음). 단기 개선(비동기 indexing 토글, timeout 단축, rescue 분기 정리)은 standard 난이도, 회귀 위험은 낮으나 모든 Searchable 모델의 인덱싱 타이밍 변화에 대한 통합 테스트 필요.