RCA: Api::V1::ReferencesController#create slow response (12080ms)

Overview#

What Happened#

2026-06-25 06:50 KST, cupixworks-api의 POST /api/v1/references 엔드포인트에서 단일 요청이 12.08초 동안 처리된 latency 클러스터가 감지되었다 (us-west-2, tenant cupix). 응답 자체는 HTTP 200으로 성공했지만 서비스의 일반 응답 분포 대비 매우 느렸다. 동일 시점에 active 인시던트는 없었고 같은 endpoint 의 인접 요청들은 정상 응답 속도였다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-06-25 01:45 KST — svc:cupixworks-api::unknown 인시던트 #1 시작 (별도 클러스터들). 23:00 KST 무렵 resolved.
2. 2026-06-25 06:50:04 KST — 본 클러스터 단일 trace 발생 (12080ms, HTTP 200 응답).
3. 2026-06-25 06:50:08 ~ 06:50:20 KST — 동일 endpoint 의 후속 요청들 정상 응답.

직전 incident가 06:45 KST 경 종료되었고, 본 클러스터는 그 이후 isolated 단발 latency 로 보인다 — 별도 service degradation 의 잔여 영향인지, References 도메인 고유의 worst-case path 인지는 단일 샘플로 단정할 수 없다 (uncertain — needs verification).

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::ReferencesController#create",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 12080,
  "max_ms": 12080,
  "sample_trace_id": "1796802385058709023"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 1
• 최초 발생: 2026-06-25 06:50 KST
• 최근 발생: 2026-06-25 06:50 KST
• Region: us-west-2
• Tenant: cupix

Root Cause Summary#

Api::V1::ReferencesController#create 의 worst-case 처리 경로는 (1) ReferenceFactory#create! 에서 Reference 본체 저장, (2) ReferenceRepository#add_reference_sources 에서 클라이언트가 보낸 모든 source ID 종류(pano/capture/pointcloud/mesh/floorplan/bim)를 종류별로 따로 쿼리하고, ID마다 한 건씩 존재 여부 확인 + 한 건씩 insert 하는 N+1 패턴, (3) 각 Reference 와 ReferenceSource 의 after_commit on: [:create] 에서 동기적으로 Elasticsearch indexing 호출 (EntityIndexable#_entity_index_document) 이 결합된 형태이다. 본 trace 는 충분히 큰 source ID 집합과/또는 ES 응답 지연이 겹쳐 12초까지 늘어난 것으로 추정되며, 수집된 정보(단일 trace, span breakdown 미수집) 만으로는 어느 단계가 지배적이었는지 확정할 수 없다 — code path 가 가진 구조적 worst-case 는 명확하다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/references_controller.rb:20-24
• Factory: app/factories/reference_factory.rb:5-41
• N+1 source 추가: app/repositories/reference_repository.rb:27-92
• 동기 ES indexing: app/models/concerns/entity_indexable.rb:42-45, 160-170

Controller 진입점은 단순히 factory 호출 후 super 로 렌더만 한다:

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

  super
end

Factory 는 부모(facility) 결정 → super (BaseFactory 의 model.save!) → 그 후 다시 add_reference_sources 호출:

self.model.facility = self.parent

super

reference_repository = ReferenceRepository.new(model: self.model)

if params[:capture_ids].present? || params[:pano_ids].present? || params[:mesh_ids].present? || params[:floorplan_ids].present? || params[:pointcloud_ids].present? || params[:bim_ids].present?
  reference_repository.add_reference_sources(
    capture_ids: params[:capture_ids],
    pano_ids: params[:pano_ids],
    mesh_ids: params[:mesh_ids],
    floorplan_ids: params[:floorplan_ids],
    pointcloud_ids: params[:pointcloud_ids],
    bim_ids: params[:bim_ids]
  )
end

if params[:capture_id].present?
  reference_repository.add_reference_sources(capture_ids: [params[:capture_id]])
end

add_reference_sources 는 6 종류 source 를 동일 패턴으로 처리한다. pano 경로만 보면:

def add_reference_sources(opts = {})
  unless opts[:pano_ids].blank?
    panos = PanoRepository.where(id: opts[:pano_ids])

    panos.each do |pano|
      next if @model.reference_sources.where(reference_sourcable: pano).exists?

      result = @model.reference_sources.create(reference_sourcable: pano)
      raise Cupix::Errors::Entity.new(code: 'ENT10004', reason: 'Failed to add reference source with errors') unless result.valid?
    end
  end

N 개의 source ID 마다 (a) 중복 여부 SELECT, (b) reference_sources.create 의 INSERT, (c) ReferenceSource 모델의 after_commit 콜백이 추가로 발생한다. 같은 패턴이 capture/pointcloud/mesh/floorplan/bim 6 회 반복된다 (동일 파일 27-92 라인).

Reference 모델은 EntityIndexable 을 include 한다 — 따라서 본체 save 와 그 이후 source 생성 양쪽에서 동기 ES indexing 이 트리거된다:

included do
  after_commit :_entity_index_document, on: [:create]
  after_commit :_entity_update_document, on: [:update]
  after_commit :_entity_delete_document, on: [:destroy]
end

def _entity_index_document
  return if @skip_index_document == true

  Elasticsearch::Model.client.index(
    index: self.class.entity_index_name,
    id: entity_document_id,
    body: as_entity_indexed_json
  )
rescue StandardError => e
  Cupix::Logger.error("Entity index error - #{e.message}", class: self.class.name, function: __method__)
end

as_entity_indexed_json 내부의 _entity_ancestry 는 team/workspace/facility/record/capture/level/bim/review/annotation_layer 의 ancestor 이름까지 매번 DB 조회로 채운다 (entity_indexable.rb:108-158). 즉 reference 1건 + source N 건 → DB 조회 + ES POST 가 (1 + N) 회 동기 발생.

기대 동작: source ID 다건은 한 번의 bulk 처리 + 비동기 indexing. 실제 동작: source ID 마다 round-trip 2 회(SELECT, INSERT) + 동기 ES POST.

Log Evidence#

service:cupixworks-api "ReferencesController" "create"

service:cupixworks-api "1796802385058709023"

이 trace ID 키워드 검색은 0 건 반환했다 — 본 cluster 는 APM trace 만 잡혔고 logs-side 매칭 entry 가 없음. 응답 완료 access log 만 다음과 같이 남았다:

{
  "timestamp": "2026-06-25 06:50:04",
  "status": "info",
  "message": "[200] POST /api/v1/references (Api::V1::ReferencesController#create)"
}

같은 시점 (06:48 ~ 06:50 KST) 의 동일 endpoint 호출 분포는 정상으로, 14건 모두 HTTP 200 으로 응답:

06:48:46 [200] POST /api/v1/references
06:48:46 [200] POST /api/v1/references
06:48:47 [200] POST /api/v1/references
06:48:48 [200] POST /api/v1/references (x3)
06:48:50 [200] POST /api/v1/references
06:50:00 [200] POST /api/v1/references
06:50:01 [200] POST /api/v1/references
06:50:04 [200] POST /api/v1/references (x2)  ← 본 cluster 포함
06:50:08 [200] POST /api/v1/references
06:50:16 [200] POST /api/v1/references
06:50:20 [200] POST /api/v1/references

ES indexing 실패 흔적도 없음:

service:cupixworks-api status:error "Entity index error"

Found 0 logs.

따라서 ES 호출 자체는 모두 성공했고, 문제는 호출 횟수 × 동기 대기 시간이 누적된 worst-case 라는 가설과 일관된다. span breakdown(trace.activerecord.duration, trace.elasticsearch.request.duration 등 per-trace 분해)이 메트릭으로 노출되지 않아 단계별 점유 시간은 본 RCA 시점에서 확정 불가 (uncertain — needs verification: 동일 trace 의 APM flame graph 확인 필요).

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 별도 hotfix 가 시급한 사용자 영향은 없음 (단일 occurrence, HTTP 200). monitoring 강화 우선.
• cupixworks-api 의 Api::V1::ReferencesController#create 에 대해 p95/p99 latency 알림을 임계 (예: p99 > 5s 5분 지속) 으로 추가하고, 추가 발생 시 APM flame graph 에서 DB / ES 점유 비중을 확정한다.

단기 개선 (1주 이내)#

• ReferenceRepository#add_reference_sources (reference_repository.rb:27-92) 의 6 종류 분기를 bulk 처리로 전환:
  • 종류별로 where(reference_sourcable_type: ..., reference_sourcable_id: ids).pluck(:reference_sourcable_id) 한 번에 기존 매핑 조회
  • 차집합만 한 번의 insert_all 또는 reference_sources.create 배열로 처리
  • 이 변경만으로 N → 1 round-trip 으로 축소되어, source 가 많은 요청의 worst-case 시간이 가장 크게 줄어든다.
• EntityIndexable (entity_indexable.rb:42-45) 의 after_commit indexing 을 비동기 (Sidekiq job) 로 분리하고, request path 에서는 enqueue 만 하도록 변경한다 — Reference 자체에 우선 적용하고, 다른 EntityIndexable include 모델로 점진 확대.

장기 개선 (재발 방지)#

• "단일 controller action 안에서 N개 자식 레코드 생성 + 자식마다 동기 외부 호출" 패턴을 codebase 전반에서 식별하고, repository layer 에 bulk insert / 비동기 indexing 의 공통 helper 를 도입.
• APM custom span 으로 add_reference_sources 와 _entity_index_document 를 wrap 해 latency 분해를 항상 표시 (현재는 trace 가 발생해도 어느 단계가 지배적인지 RCA 단계에서 즉시 알 수 없음).

Monitoring#

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

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

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

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

알림 권고:

• max:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::referencescontroller#create} 가 5 분 동안 5s 를 초과하면 warn
• sum:trace.rack.request.hits{...,resource_name:api::v1::referencescontroller#create}.as_count() 가 0 으로 떨어지면 (정상 트래픽 시간대 기준) 별도 service 가용성 알림과 cross-check

Risk Assessment#

• Risk level: low (단일 occurrence, 응답 성공, 동시간 이웃 요청 정상)
• 예상 복잡도: standard (bulk insert 전환은 표준 Rails 리팩터링, 비동기 indexing 은 모델 콜백 정리 + Sidekiq job 추가로 standard 범위)