RCA: PointcloudsController#entity_parameters 22s Latency

Overview#

What Happened#

2026-05-30 20:04 KST에 cupixworks-api 서비스의 Api::V1::PointcloudsController#entity_parameters 엔드포인트가 pointcloud ID 1117093에 대해 22,264ms(약 22초)의 응답 시간을 기록했다. 동일 시간대 같은 호스트에서 3개의 element_traces/refresh 대량 배치 작업이 동시에 실행 중이었으며, 이로 인한 리소스 경합이 근본 원인이다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-05-30 19:50~20:00 KST — clark-vdc 사용자가 record_id 130699에 대해 element_traces/refresh 3건 동시 요청
2. 2026-05-30 20:04:16 KST — accoes 사용자가 pointcloud 1117093의 entity_parameters 요청 (host ip-10-1-80-134)
3. 2026-05-30 20:04:40 KST — entity_parameters 응답 완료 (22,160ms 소요, DB 7,536ms)
4. 2026-05-30 20:04:42 KST — 동일 호스트에서 NotFound - attributes_in_database 경고 다수 발생
5. 2026-05-30 20:30 KST — RCA 분석 시작

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::PointcloudsController#entity_parameters",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 22264,
  "max_ms": 22264,
  "sample_trace_id": "3349885339038374516"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 1
• 최초 발생: 2026-05-30 20:04 KST
• 최근 발생: 2026-05-30 20:04 KST

Root Cause Summary#

호스트 ip-10-1-80-134에서 3개의 element_traces/refresh 요청(각 12분+, 333 배치 × 500 레코드 처리)이 동시에 실행되며 DB connection pool과 Ruby GVL(Global VM Lock)을 독점했다. 이 상태에서 entity_parameters 요청이 같은 호스트로 라우팅되어 DB connection 대기(7.5초)와 CPU/스레드 스케줄링 대기(14.7초)가 발생했다. 정상 상태에서 동일 엔드포인트는 37~65ms에 응답하므로, 코드 자체의 문제가 아닌 리소스 경합에 의한 일시적 성능 저하이다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/pointclouds_controller.rb:11 (before_action :set_pointcloud)
• Permission query: app/controllers/api/v1/pointclouds_controller.rb:74-76
• Action: app/controllers/concerns/entity_parameterable_controller.rb:16-29
• Repository: app/repositories/entity_parameterable_repository.rb:2-18
• Core logic: app/models/concerns/entity_parameterable.rb:15-33

Step 1: before_action에서 permission query 실행

def set_pointcloud
  @model = repository_instance.show(params[:pointcloud_id] || params[:id])
end

show 메서드는 12개 이상의 LEFT JOIN으로 구성된 permission query를 실행한다.

Step 2: entity_parameters 액션에서 동일 permission query 재실행

def entity_parameters(params = {})
  _id_or_key = params[:id] || params[:key]
  if _id_or_key.present?
    if self.class.current_class == ::Review
      review = ::Review.find_by(key: _id_or_key) || (raise Cupix::Errors::Parameter.new(code: 'ARG10001', reason: 'Invalid id or key'))
      _group_entity = review.facility
    else
      _group_entity = self.class.current_class.repository_class.new(current_user: current_user, current_team: current_team).show(_id_or_key)
    end
  elsif self.class.current_class == ::Team
    _group_entity = current_team
  else
    raise Cupix::Errors::Parameter.new(code: 'ARG10001', reason: 'Invalid group entity')
  end

  _group_entity.entity_parameters
end

Line 9에서 .show(_id_or_key)가 다시 호출되어 동일한 12-LEFT-JOIN permission query가 두 번째 실행된다.

Step 3: entity_parameters 모델 로직 — 순차 쿼리 다수 실행

def entity_parameters
  _entity_params = entity_parameter

  parent = self.class.parent_model if self.class.respond_to?(:parent_model)
  entity_parameter_models(parent).each do |model_class|
    model_name = model_class.name.downcase
    _entity_params += self.send(model_name).entity_parameter.where.not(name: _entity_params.map(&:name))
  end

  _system_params = system_entity_parameter.where.not(
    name: _entity_params.map(&:name)
  )

  _default_params = default_entity_parameter.where.not(
    name: _entity_params.map(&:name) + _system_params.map(&:name)
  )

  _entity_params + _system_params + _default_params
end

이 메서드는 Pointcloud → Record → Facility → Workspace → Team 계층을 순차적으로 탐색하며, 각 레벨에서 belongs_to 로드 + eager_load JOIN 쿼리를 실행한다. 총 약 13개 SQL 쿼리가 순차적으로 발생한다.

정상 시: 각 쿼리가 1-3ms로 총 37~65ms에 완료된다. 장애 시: DB connection pool 고갈로 각 쿼리 앞에서 connection 대기가 발생하여 총 7,536ms DB time이 소요되었고, 나머지 14.7초는 Ruby GVL/스레드 스케줄링 대기로 소모되었다.

Log Evidence#

검색 쿼리 1: 동일 엔드포인트의 정상/비정상 비교

service:cupixworks-api (PointcloudsController OR entity_parameters)
Time: 2026-05-30 10:00Z ~ 12:00Z

결과 비교:

동일 호스트(ip-10-1-80-134)의 이전 요청(1117087)은 65ms로 정상 응답하여, 문제가 특정 시간대에만 발생함을 확인.

검색 쿼리 2: 동일 호스트의 동시 실행 작업

service:cupixworks-api @host.name:ip-10-1-80-134* @duration:>10000
Time: 2026-05-30 10:00Z ~ 12:00Z

결과 (element_traces/refresh):

{
  "resource_name": "Api::V1::ElementTracesController#refresh",
  "duration_ms": 760319,
  "db_time_ms": 19775,
  "user": "quinton.robinson@clarkconstruction.com",
  "team": "clark-vdc",
  "record_id": 130699
}

3건의 refresh 요청이 각각 1213분간 실행되며, 333개 배치(각 500 레코드)를 순차 처리. 26초 구간 동안 배치 #204#272가 처리됨.

검색 쿼리 3: 호스트 활동 로그 (장애 시점)

service:cupixworks-api @host.name:ip-10-1-80-134*
Time: 2026-05-30 11:04:16Z ~ 11:04:42Z

26초 동안 해당 호스트에서 100개 로그 항목 발생 — 84개는 ElementTrace batch processing(custom 로그), 16개만 HTTP 요청. 호스트가 배치 작업에 의해 리소스가 독점된 상태 확인.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

이 건은 일시적 리소스 경합에 의한 단발성 이벤트로, 즉각적인 코드 수정은 불필요하다. 그러나 element_traces/refresh 요청의 리소스 독점 방지를 위한 대응이 필요하다:

• app/controllers/api/v1/element_traces_controller.rb의 refresh 액션에 동시 실행 제한(concurrency limit) 또는 rate limiting 적용을 검토
• 동일 record_id에 대한 중복 refresh 요청 방지(deduplication) 로직 추가 검토

단기 개선 (1주 이내)#

• app/repositories/entity_parameterable_repository.rb:9에서 중복 show 호출 제거 — set_pointcloud before_action에서 이미 로드된 @model을 재사용하도록 변경
• element_traces/refresh를 비동기 Worker(Sidekiq)로 이관하여 Rails 프로세스 자원 독점 방지

장기 개선 (재발 방지)#

• 대량 배치 작업(333 batches × 500 records)은 별도 인프라(dedicated worker pool)에서 실행하도록 아키텍처 분리
• Rails 프로세스 수준에서 단일 요청의 DB connection 점유 시간에 상한(timeout) 설정
• Load balancer에서 호스트별 active connection 수 기반 라우팅(least-connections) 적용 검토

Monitoring#

• element_traces/refresh 요청의 duration이 5분 초과 시 알림:

service:cupixworks-api resource_name:"Api::V1::ElementTracesController#refresh" @duration:>300000

• 호스트별 평균 응답 시간 이상 탐지:

avg:trace.rack.request.duration{service:cupixworks-api} by {host} > 5000

• entity_parameters 엔드포인트 P99 latency 모니터링:

service:cupixworks-api resource_name:"Api::V1::PointcloudsController#entity_parameters" @duration:>5000

Risk Assessment#

• Risk level: low
• 예상 복잡도: standard
• 단발성 리소스 경합 이벤트로 재현 빈도는 낮으나, element_traces/refresh의 동시 실행이 반복되면 다른 엔드포인트에서도 동일 현상 발생 가능