RCA: Api::V1::PointcloudsController#entity_parameters (avg 33888ms, max 33888ms)

Overview#

What Happened#

2026-07-16 19:53 KST 프로덕션 cupixworks-api 에서 GET /api/v1/pointclouds/1224014/entity_parameters 요청 한 건이 약 33.9초 만에 200 응답으로 완료됐다. 동일 endpoint 의 정상 응답은 서비스 전체 p99 (~1.5s) 를 크게 넘지 않았고, 이번 outlier 는 새로 업로드된 pointcloud(id=1224014, facility=15950)의 상승 요청 흐름 중 처음 호출된 entity_parameters 요청에서만 관측됐다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-07-16 19:50:45 KST — pointcloud 1224014 생성 (facility 15950, user 37878). Cachable::ReviewLoad cache 무효화.
2. 2026-07-16 19:50:51 KST — pointcloud state initializing → queued.
3. 2026-07-16 19:53:08 KST — GET /api/v1/pointclouds/1224014/entity_parameters 요청 시작 (span first_seen).
4. 2026-07-16 19:53:42 KST — 동 요청 [200] 응답 로그 기록. 총 33888ms.
5. 2026-07-16 19:54:43 KST — pointcloud state queued → done, publish_on_finish 트리거.

Error Log#

Datadog Logs

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

Impact#

• Service: cupixworks-api
• 발생 횟수: 1
• 최초 발생: 2026-07-16 19:53 KST
• 최근 발생: 2026-07-16 19:53 KST

정상 응답(HTTP 200)이며 유저 노출 에러는 없다. 다만 클라이언트 관점에서 30초 이상 응답 지연은 UX 저하 및 upstream(ALB/LB idle-timeout, 클라이언트 재시도) 리스크가 있다. 동일 요청 패턴은 pointcloud 업로드 완료 직후 반복 호출되는 workflow 의 일부라 재발 시 blast radius 는 클 수 있다.

Root Cause Summary#

Api::V1::PointcloudsController#entity_parameters 는 EntityParameterableController#entity_parameters (app/controllers/concerns/entity_parameterable_controller.rb:16-29) 로 위임되며, 최종적으로 Pointcloud 인스턴스의 EntityParameterable#entity_parameters (app/models/concerns/entity_parameterable.rb:15-33) 를 호출한다. 이 메서드는 self → parent_model 체인 (Pointcloud → Record → Facility → Workspace → Team, applied_entity_parameter? 를 리턴하는 모델만) 을 재귀적으로 순회하며 각 단계에서 EntityParameter.eager_load(:entity_parameter_group).where(...).where.not(name: ...) 쿼리를 별도로 실행한다. 이번 outlier 는 이 chained lookup 이 pointcloud 1224014 (facility 15950) 컨텍스트에서 유일하게 33.8s 로 소요됐으며, 동시간대 (10:52:30–10:54:00 UTC) 서비스 p99 는 1.5s 수준, MySQL/RDS CPU 는 정상(~17-23%)이었다. 즉 광범위 인프라 장애가 아니라 이 요청 개별의 slow-path (parent chain 순회 × N+1 형태의 eager_load 쿼리 + where.not(name: [...]) 배열 확장) 로 인한 request-level outlier 로 판단된다. 단, 33.8s 는 순수 쿼리 시간만으로는 재현되기 어려운 크기이므로 그 순간의 GC pause / connection pool acquisition / 순간적 DB slow query 요인이 겹쳤을 가능성이 남는다 (uncertain — needs verification via APM trace flame graph on trace_id 1353218467795904081).

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/pointclouds_controller.rb:1
• Concern dispatch: app/controllers/concerns/entity_parameterable_controller.rb:16
• Repository dispatch: app/repositories/entity_parameterable_repository.rb:2
• Traversal hotspot: app/models/concerns/entity_parameterable.rb:15
• Failure point (latency hotspot): app/models/concerns/entity_parameterable.rb:19-22 (parent-chain iteration)

Controller entry:

def entity_parameters
  _results = repository_instance.entity_parameters(params)

  render_api Renderable.new({
    contents: _results,
    is_collection: true,
    serializer: EntityParameterSerializer,
    serializer_option: {
      fields: {
        entity_parameter: @fields
      }
    }
  })
end

Repository looks up the group entity (a Pointcloud in this case) via repository_class.show(id) and delegates to the model:

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

The concern that produces the parameter list:

def entity_parameter
  EntityParameter.eager_load(:entity_parameter_group).where(entity_parameter_groups: { entity: self })
end

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

Parent chain resolution (recursive collection of ancestors that respond applied_entity_parameter? == true):

def entity_parameter_models(current_model_class)
  return [] if current_model_class.nil?
  return [current_model_class] if current_model_class == ::Team

  _current_model_class = current_model_class.respond_to?(:applied_entity_parameter?) && current_model_class.applied_entity_parameter? ? [current_model_class] : []
  current_model_class = current_model_class.parent_model if current_model_class.respond_to?(:parent_model)
  _current_model_class + entity_parameter_models(current_model_class)
end

Pointcloud 의 조상 체인은 Pointcloud → Record (applied) → Facility (applied) → Workspace → Team (applied) 로 정의된다:

def self.parent_model
  ::Record
end

def self.parent_model
  ::Facility
end

def self.parent_model
  ::Workspace
end

included do
  include EntityParameterable
  def self.applied_entity_parameter?
    true
  end
end

기대 동작: 각 반복은 이미 획득한 이름을 WHERE name NOT IN (...) 로 제외하므로, entity_parameter_group_id 및 name 인덱스가 존재하는 상태에서 각 SQL 은 O(수십ms) 수준으로 완료되고 총합도 수백ms 이내여야 한다. 동시간대 다른 pointcloud 들의 동일 요청은 초 단위 이내로 완료됨(19:53:42 이후 19:54:11, 19:54:14, 19:54:50 등 로그 참조).

실제 동작: pointcloud 1224014 요청은 33888ms 소요. 정상 요청 대비 30배 이상. where.not(name: [...]) 의 IN 리스트는 각 iteration 마다 _entity_params.map(&:name) 을 다시 계산해 넘기므로 배열이 커지면 파라미터 바인딩과 planner 비용이 증가한다 (단, 지속적으로 slow 하지 않은 것을 보면 이 자체만으로 33s 를 유발했다고 단정하기 어렵다 — GC / conn-pool acquisition / 특정 순간의 DB slow lookup 이 겹쳤을 가능성이 큼).

Log Evidence#

Datadog 쿼리 (사용):

service:cupixworks-api "PointcloudsController" "entity_parameters"

service:cupixworks-api "1224014"

동일 pointcloud (1224014) 흐름의 관련 로그 (KST):

2026-07-16 19:50:45  info  Cachable::ReviewLoad | Invalidated facility review cache on create | model=Pointcloud | model_id=1224014 | facility_id=15950
2026-07-16 19:50:51  info  pointcloud state changed from initializing to queued. id: 1224014 (StateMachines::Machine)
2026-07-16 19:53:04  info  [200] PUT /api/v1/pointclouds/1224014 (Api::V1::PointcloudsController#update)
2026-07-16 19:53:04  info  [302] GET /api/v1/pointclouds/1224014/download (Api::V1::PointcloudsController#download_single_resource)
2026-07-16 19:53:42  info  [200] GET /api/v1/pointclouds/1224014/entity_parameters (Api::V1::PointcloudsController#entity_parameters)
2026-07-16 19:54:43  info  pointcloud state changed from queued to done. id: 1224014

정상 응답 대비(같은 endpoint, 동일 시간대):

2026-07-16 19:53:42  [200] .../1224014/entity_parameters      (요청 시작 10:53:08 UTC → 총 33888ms)
2026-07-16 19:54:11  [200] .../1224016/entity_parameters      (초 단위 이내 완료)
2026-07-16 19:54:14  [200] .../1224018/entity_parameters      (초 단위 이내 완료)
2026-07-16 19:54:50  [200] .../1224024/entity_parameters      (초 단위 이내 완료)

동시간대 서비스 전체 지표 (동 시각 근접):

p99:trace.rack.request{service:cupixworks-api}  ≈ 0.9 ~ 1.6s
max:aws.rds.cpuutilization{*}                    ≈ 17-23%

ThrottlingException / AccessDenied 에러 로그가 동시간대 다수 존재하나 이는 별도 소스(CloudWatch Logs FilterLogEvents 권한/쓰로틀 — arn:aws:logs:...) 로, entity_parameters request path 와는 무관하다.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• APM trace 1353218467795904081 의 flame graph 를 열어 33.8s 가 어떤 span (SQL / GC / connection wait) 에 소진됐는지 확증한다. 이 데이터 없이는 (H1) 의 sub-cause 를 특정할 수 없음. Datadog APM UI 에서 trace_id 검색 필요.
• 재발 여부 모니터링: 아래 Monitoring 섹션의 쿼리를 대시보드/모니터에 추가한다. 단발성이 아니라 반복 outlier 라면 코드 개선 우선순위 상승.

단기 개선 (1주 이내)#

• app/models/concerns/entity_parameterable.rb:15-33 의 iteration 을 리팩터하여, parent chain 순회 결과를 단일 join 쿼리(또는 entity_parameter_group_id 목록에 대한 IN 쿼리 한 번)로 대체하는 방향을 검토한다. 현재 구조는:
  • 각 iteration 마다 _entity_params.map(&:name) 을 Ruby-side 로 재계산
  • 각 iteration 마다 EntityParameter.eager_load(:entity_parameter_group).where(entity_parameter_groups: { entity: X }).where.not(name: [...]) SQL 발행 이 patterns 은 chain 이 깊을수록 N+1 유사한 read 부하를 만든다. 목표: Pointcloud → Team 까지의 조회를 1-2 회 SQL 로 축약.
• where.not(name: _entity_params.map(&:name) + _system_params.map(&:name)) 처럼 큰 IN 리스트가 발생하는 경우, MySQL 쿼리 플래너가 range scan 대신 full scan 을 택할 수 있다. entity_parameters.name 인덱스는 이미 존재(index_entity_parameters_on_name — db/schema.rb:1851)하나 selectivity 확인 필요.

장기 개선 (재발 방지)#

• entity_parameter 조회 결과를 Rails cache 로 감싸는 것을 검토. Cachable::ReviewLoad 처럼 create/update 시 invalidate 하는 훅을 사용하면 동일 facility 의 반복 조회를 상수 시간에 서비스할 수 있다 (특히 pointcloud 업로드 완료 flow 처럼 짧은 시간에 같은 chain 을 다수 호출하는 경우 효과가 큼).
• APM 상 이 endpoint 에 대한 SLO (예: p99 < 2s) 를 정의하고 위반 시 알림을 걸어 outlier 를 개별 트래킹.

Monitoring#

• 이 endpoint 의 outlier 를 상시 감시하고 위 request-level slow-path 재발 여부를 확인.

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

service:cupixworks-api "PointcloudsController#entity_parameters"

APM 지표 (release dashboard timeseries widget 용):

avg:trace.rack.request{service:cupixworks-api}

p99:trace.rack.request{service:cupixworks-api}

max:aws.rds.cpuutilization{*}

Risk Assessment#

• Risk level: low (단일 발생, 정상 200 응답, 유저 노출 에러 없음)
• 예상 복잡도: standard (short-term: SQL 리팩터, long-term: cache 도입)