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#
- 2026-06-04 06:20 KST — Sitetrack 18803, 18804 자동 생성 (Capture 131171 처리 시작)
- 2026-06-04 07:16 KST — Sitetrack 18804
entity_parameters요청 (4486ms) - 2026-06-04 07:22 KST — Sitetrack 18803
entity_parameters요청 (4496ms) - 2026-06-04 07:35 KST — 동일 패턴이 다른 컨트롤러(Captures, Panos, Pointclouds)에서도 관측됨
Error Log#
{
"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_parametersaction) - 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)
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 메서드 (핵심 병목)
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단계: 부모 모델 순회 (재귀)
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 쿼리:
service:cupixworks-api "SitetracksController" "entity_parameters"
Time range: 2026-06-03T21:00:00Z to 2026-06-03T23:30:00Z
핵심 로그 항목:
{
"timestamp": "2026-06-04 07:22:22",
"status": "info",
"message": "[200] GET /api/v1/sitetracks/18803/entity_parameters (Api::V1::SitetracksController#entity_parameters)"
}
{
"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 사용):
service:cupixworks-api "entity_parameters" @duration:>2000
{
"timestamp": "2026-06-04 07:34:12",
"message": "[200] GET /api/v1/captures/707047/entity_parameters (Api::V1::CapturesController#entity_parameters)"
}
{
"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_parameterableconcern이 적용된 모든 컨트롤러(Captures, Panos, Pointclouds, Facilities 등)에 동일 문제가 존재하므로, concern 레벨에서 근본적으로 해결 필요.- materialized view 또는 denormalized entity_parameters 테이블 도입을 검토하여, 계층 순회 없이 단일 조회로 완료되도록 설계.
Monitoring#
- APM duration 모니터링 추가:
avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::sitetrackscontroller#entity_parameters} > 2000
- 동일 concern 사용하는 다른 엔드포인트도 모니터링:
avg:trace.rack.request.duration{service:cupixworks-api,resource_name:*entity_parameters*} > 2000
Risk Assessment#
- Risk level: medium
- 예상 복잡도: standard (concern 레벨 쿼리 최적화, 영향 범위가 넓으나 로직은 명확)