ES /docs

EntityParameterable#entity_parameters N+1 queries — sequential hierarchy traversal

RCA: SitetracksController#entity_parameters Slow Response (avg 4491ms)

Overview#

What Happened#

2026-06-04 07:16~07:22 KST 사이에 cupixworks-api 서비스의 Api::V1::SitetracksController#entity_parameters 엔드포인트가 평균 4491ms, 최대 4496ms의 응답 시간을 기록했다. 2건의 요청(sitetrack ID 18803, 18804)이 모두 200 OK로 응답했으나, 정상 응답 시간(수백 ms 이하)을 크게 초과했다.

Quick Facts#

Field Value
resource_name Api::V1::SitetracksController#entity_parameters
top_frame app/models/concerns/entity_parameterable.rb:15-32
env production, us-west-2

Affected Teams#

Team / Domain Error Count Impact
cupixworks-api (Siteinsights) 2 Sitetrack entity_parameters 조회 시 사용자 대기 시간 4.5초

Timeline#

  1. 2026-06-04 06:20 KST — Sitetrack 18803, 18804 자동 생성 (Capture 131171 처리 시작)
  2. 2026-06-04 07:16 KST — Sitetrack 18804 entity_parameters 요청 (4486ms)
  3. 2026-06-04 07:22 KST — Sitetrack 18803 entity_parameters 요청 (4496ms)
  4. 2026-06-04 07:35 KST — 동일 패턴이 다른 컨트롤러(Captures, Panos, Pointclouds)에서도 관측됨

Error Log#

Datadog Logs

json
{
  "resource_name": "Api::V1::SitetracksController#entity_parameters",
  "service": "cupixworks-api",
  "occurrences": 2,
  "avg_ms": 4491,
  "max_ms": 4496,
  "sample_trace_id": "2504960596352756117"
}

Impact#

  • Service: cupixworks-api
  • 발생 횟수: 2
  • 최초 발생: 2026-06-04 07:16 KST
  • 최근 발생: 2026-06-04 07:22 KST

Root Cause Summary#

EntityParameterable#entity_parameters 메서드가 부모 모델 계층(Sitetrack → Facility → Workspace → Team)을 순회하며 각 레벨에서 개별 eager_load + WHERE 쿼리를 실행하는 N+1 패턴을 사용한다. Sitetrack의 경우 총 5~7개의 독립적인 DB 쿼리가 순차 실행되며, 각 쿼리마다 entity_parameter_groups 테이블에 대한 JOIN이 포함된다. 또한 before_action :set_sitetrack에서 permission_joins가 11개의 LEFT JOIN을 포함한 복잡한 권한 체크 쿼리를 먼저 실행한다. 이 두 가지가 합산되어 4.5초의 응답 지연이 발생한다.

Technical Analysis#

Code Path#

  • Entry point: app/controllers/api/v1/sitetracks_controller.rb:6 (before_action :set_sitetrack)
  • Permission check: app/repositories/sitetrack_repository.rb:53-226 (11개 LEFT JOIN 포함한 permission_joins)
  • Action: app/controllers/concerns/entity_parameterable_controller.rb:16 (entity_parameters action)
  • Repository call: app/repositories/entity_parameterable_repository.rb:2-18 (sitetrack 조회 후 .entity_parameters 호출)
  • Core logic: app/models/concerns/entity_parameterable.rb:15-33 (부모 모델 계층 순회)
  • Failure point: app/models/concerns/entity_parameterable.rb:19-22 (반복적 DB 쿼리 + 메모리 내 배열 비교)

1단계: Permission Check (set_sitetrack)

app/repositories/sitetrack_repository.rb:53-60ruby
def self.permission_joins(record, current_user, select: nil, review_id: -1, **kwargs)
  # ... 11개의 LEFT JOIN: facility_permissions, workspace_permissions,
  # team_permissions, review_permissions 등
  record.joins("
    LEFT JOIN (...) AS review_public_permissions ...
    LEFT JOIN (...) AS facility_user_permissions ...
    LEFT JOIN (...) AS workspace_user_permissions ...
    LEFT JOIN (...) AS team_user_permissions ...
  ").group('id').select(_select).where(...)
end

2단계: entity_parameters 메서드 (핵심 병목)

app/models/concerns/entity_parameterable.rb:15-32ruby
def entity_parameters
  _entity_params = entity_parameter  # Query 1: eager_load + WHERE entity = self

  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
    # Query 2,3,4: 각 부모 모델에 대해 개별 쿼리
    _entity_params += self.send(model_name).entity_parameter.where.not(name: _entity_params.map(&:name))
  end

  # Query 5: system parameters
  _system_params = system_entity_parameter.where.not(name: _entity_params.map(&:name))
  # Query 6: default parameters
  _default_params = default_entity_parameter.where.not(name: _entity_params.map(&:name) + _system_params.map(&:name))

  _entity_params + _system_params + _default_params
end

기대 동작: entity_parameters 조회가 수백 ms 이내에 완료되어야 함.

실제 동작: 부모 모델 계층 순회(Facility → Workspace → Team)와 각 레벨에서의 개별 쿼리 실행으로 인해 4.5초 소요. 특히:

  • _entity_params.map(&:name) 호출 시 이전 쿼리 결과를 메모리에 모두 로드
  • .where.not(name: ...) 절에 배열을 전달하여 NOT IN (...) SQL 생성
  • eager_load(:entity_parameter_group) 매번 JOIN 발생

3단계: 부모 모델 순회 (재귀)

app/models/concerns/entity_parameterable.rb:41-48ruby
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

Sitetrack의 경우 parent_model 체인: ::Facility::Workspace::Team. 세 모델 모두 applied_entity_parameter? = true이므로, 3개의 추가 쿼리가 순차 실행된다.

Log Evidence#

검색에 사용한 Datadog 쿼리:

text
service:cupixworks-api "SitetracksController" "entity_parameters"
Time range: 2026-06-03T21:00:00Z to 2026-06-03T23:30:00Z

핵심 로그 항목:

json
{
  "timestamp": "2026-06-04 07:22:22",
  "status": "info",
  "message": "[200] GET /api/v1/sitetracks/18803/entity_parameters (Api::V1::SitetracksController#entity_parameters)"
}
json
{
  "timestamp": "2026-06-04 07:16:08",
  "status": "info",
  "message": "[200] GET /api/v1/sitetracks/18804/entity_parameters (Api::V1::SitetracksController#entity_parameters)"
}

동일 패턴이 다른 컨트롤러에서도 확인됨 (같은 EntityParameterable concern 사용):

text
service:cupixworks-api "entity_parameters" @duration:>2000
json
{
  "timestamp": "2026-06-04 07:34:12",
  "message": "[200] GET /api/v1/captures/707047/entity_parameters (Api::V1::CapturesController#entity_parameters)"
}
json
{
  "timestamp": "2026-06-04 07:33:58",
  "message": "[200] GET /api/v1/panos/86974962/entity_parameters (Api::V1::PanosController#entity_parameters)"
}

에러는 없고 (status:error 0건), warn도 0건. 모두 200 OK 응답이나 APM 기준 duration이 4.5초를 기록.

Hypotheses Considered#

# Hypothesis Evidence for Evidence against Verdict
H1 EntityParameterable#entity_parameters의 N+1 쿼리 패턴 (부모 모델 계층 순회 시 5-7개 순차 쿼리) 코드 분석: entity_parameterable.rb:15-32에서 루프 내 개별 쿼리 + eager_load + map + where.not 패턴 확인. 동일 concern 사용하는 다른 컨트롤러에서도 동일한 지연 관측. Confirmed
H2 permission_joins의 11-table LEFT JOIN 쿼리가 주요 병목 코드 분석: sitetrack_repository.rb:53-226에서 11개 LEFT JOIN 확인. set_sitetrack before_action에서 매 요청마다 실행. show 액션은 동일 permission check를 수행하지만 entity_parameters만큼 느리지 않음 (show 로그에서 지연 미관측). permission check는 기여 요인이나 주요 원인은 아님. Contributing factor
H3 DB connection pool 고갈 또는 일시적 DB 부하 동일 시간대 2건 모두 동일한 지연 패턴 다른 엔드포인트(show, captures)는 같은 시간대에 정상 응답. 에러 로그 없음. Rejected

Fix Recommendation#

즉시 조치 (Critical)#

  • 파일: app/models/concerns/entity_parameterable.rb:15-33
  • 방향: entity_parameters 메서드를 단일 쿼리로 리팩토링. 현재 부모 모델 계층을 순회하며 개별 쿼리를 실행하는 대신, 모든 관련 entity_parameter_group을 한 번의 쿼리로 조회하도록 변경.
    • 모든 관련 entity IDs (self, facility, workspace, team)를 미리 수집
    • 하나의 EntityParameter.eager_load(:entity_parameter_group).where(entity_parameter_groups: { entity: [self, facility, workspace, team] OR is_system_group OR is_default_group }) 쿼리로 통합
    • Ruby 측에서 우선순위에 따라 name 중복 제거 (entity → parents → system → default 순)

단기 개선 (1주 이내)#

  • 결과를 Rails cache에 저장 (entity_parameters 결과를 Rails.cache.fetch로 감싸기). entity_parameter 변경 시 캐시 무효화.
  • EntityParameterSerializer에서 사용하는 필드만 SELECT하여 메모리 사용량 최소화.

장기 개선 (재발 방지)#

  • entity_parameterable concern이 적용된 모든 컨트롤러(Captures, Panos, Pointclouds, Facilities 등)에 동일 문제가 존재하므로, concern 레벨에서 근본적으로 해결 필요.
  • materialized view 또는 denormalized entity_parameters 테이블 도입을 검토하여, 계층 순회 없이 단일 조회로 완료되도록 설계.

Monitoring#

  • APM duration 모니터링 추가:
text
avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::sitetrackscontroller#entity_parameters} > 2000
  • 동일 concern 사용하는 다른 엔드포인트도 모니터링:
text
avg:trace.rack.request.duration{service:cupixworks-api,resource_name:*entity_parameters*} > 2000

Risk Assessment#

  • Risk level: medium
  • 예상 복잡도: standard (concern 레벨 쿼리 최적화, 영향 범위가 넓으나 로직은 명확)