Api::V1::FacilityTypesController#index (avg 13606ms, max 13606ms)
RCA: Api::V1::FacilityTypesController#index latency (avg 13606ms)
Overview#
What Happened#
2026-07-06 14:56:39 KST 에 cupixworks-api (ap-southeast-2, tenant cupix) 에서 Api::V1::FacilityTypesController#index 트레이스가 13606ms 소요되어 latency cluster 로 감지되었다. 지난 14일 동안 동일 endpoint 에서 3s 이상 소요된 요청이 다수의 tenant (endeavourgroup, toyoeng, forida-demo, qatest2, webuild 등) 에서 반복적으로 관측되고 있으며, 최대 75363ms 까지 기록되었다. 에러/실패는 없고 모두 HTTP 200 응답이다.
Quick Facts#
| Field | Value |
|---|---|
| resource_name | Api::V1::FacilityTypesController#index |
| service | cupixworks-api |
| top_frame | app/repositories/facility_type_repository.rb:112 (Elasticsearch search) + app/repositories/facility_type_repository.rb:126-309 (permission_joins) |
| avg_duration_ms | 13606 |
| max_duration_ms | 13606 (cluster 대표) / 75363 (14일 최대, forida-demo) |
| env | production, ap-southeast-2 |
| tenant | cupix (대표 트레이스) |
| sample_trace_id | 2203852587658987718 |
Affected Teams#
Datadog service:cupixworks-api "FacilityTypesController" @duration:>3000 (지난 14일) 로부터 도메인별 slow request 관찰:
| Team / Domain | Slow Requests (>3s, 14d) | Max Duration | Notes |
|---|---|---|---|
| forida-demo | 1 | 75363ms | serialization 51810ms 지배 |
| toyoeng | 2 | 57539ms | ES 결과 0건인데도 db 8-10s 소요 |
| qatest2 | 2 | 22276ms | serialization 15274ms |
| webuild | 1 | 20321ms | — |
| scs-assetfuture | 2 | 21110ms | — |
| endeavourgroup | 1 | 10399ms | db 1820ms |
| cupix | 2 | 6747ms | — |
| updatedemo, exyte, buildforpeople, performance, solarturbines, ikukbo | 각 1-2 | 3-6s | — |
문제는 특정 tenant 에 국한되지 않고 여러 도메인에서 재현됨 → tenant-specific data anomaly 가 아닌 endpoint 자체의 시스템적 성능 이슈로 판단.
Timeline#
- 2026-07-06 14:56:39 KST — 대표 트레이스 (
2203852587658987718) 13606ms, ap-southeast-2 에서 발생 (cluster first_seen) - 2026-07-06 14:56:53 KST — 동일 endpoint 정상 요청 (60ms, endeavourgroup team=180, 결과 3건) — 즉시 회복
- 2026-07-06 15:03:41 KST — 동일 user (
emily.holmes@edg.com.au, endeavourgroup) 재시도 10399ms (db 1820ms, entries=1) - 2026-07-06 14:56:39 KST — status board 가 sibling cluster
1201b35e-...와 함께svc:cupixworks-api::unknown인시던트 자동 생성 후 05:56:39.309Z (=14:56:39 KST) 에 즉시 resolve 처리
Error Log#
{
"resource_name": "Api::V1::FacilityTypesController#index",
"service": "cupixworks-api",
"occurrences": 1,
"avg_ms": 13606,
"max_ms": 13606,
"sample_trace_id": "2203852587658987718"
}
Impact#
- Service:
cupixworks-api - 발생 횟수: 1 (이 cluster) / 14일 동안
duration:>3000이 25건 이상 관찰됨 - 최초 발생: 2026-07-06 14:56:39 KST
- 최근 발생: 2026-07-06 14:56:39 KST
- 사용자 영향:
/api/v1/facility_types는 Facility 리스트 페이지, 필터 dropdown 등 여러 UI 초기 로드 경로에서 호출되는 endpoint. 10s+ 응답은 UI 초기 페인트 지연/타임아웃을 유발함.
Root Cause Summary#
FacilityTypesController#index 는 세 단계로 요청을 처리하는데 각 단계가 team/facility 규모에 대해 비효율적으로 스케일한다: (1) FacilityTypeRepository#_search 가 Elasticsearch 로 후보를 뽑고, (2) BaseRepository#search 가 결과를 ActiveRecord 로 hydrate 한 뒤 FacilityTypeRepository.permission_joins 에서 11개 LEFT JOIN + GROUP BY 로 권한을 재계산하며, (3) FacilityTypeSerializer 가 각 row 마다 FacilityType#facilities_count 를 호출해 별도의 SQL COUNT 를 실행한다 (N+1). Datadog request log 상 db 시간과 serialization 시간이 team 규모/facility 수에 비례해 증가하고 (forida-demo: serialization 51810ms, qatest2: 15274ms, toyoeng: db 9969ms), 결과가 0건인 tenant 조차도 permission_joins 만으로 8-10s 를 소비한다. 별도의 예외 없이 200 응답이므로 이는 트래픽/데이터 스파이크가 아닌 endpoint 구조 자체에서 오는 지속적 성능 문제로 판단된다.
Technical Analysis#
Code Path#
Entry point: app/controllers/api/v1/facility_types_controller.rb:6-14
def index
facility_types = repository_instance.search(Cupix::QueryOption::FacilityType.new(get_query_option, params.merge(include_default: true)))
render_api Renderable.new({
search_result: facility_types,
is_collection: true,
serializer_option: @serializer_option
})
end
repository_instance.search 는 BaseRepository#search (line 70) 로 위임되어 다음 순서로 실행된다.
Step 1 — FacilityTypeRepository#_search 가 Elasticsearch 쿼리를 조립하고 페이지네이션 (per_page: 100, page: 1 관찰) 수행:
response = ::FacilityType.search(
self.query_option.serializable_hash
).paginate(
per_page: self.query_option.per_page,
page: self.query_option.page
)
set_response(response)
Step 2 — BaseRepository#search 가 hits 를 .records 로 ActiveRecord hydrate 한 뒤 permission_joins 에 넘김:
def search(query_option = nil)
_search(query_option)
begin
if self.review.present?
# ...
else # = self.review_id.nil?
contents = self.class.permission_joins(self.class.default_joins(self.response.records), self.current_user, skip_join: _skip_join?)
end
Failure point 1 — permission_joins (권한 재계산 매크로 쿼리): 11개의 LEFT JOIN 서브쿼리 (review/facility/workspace/team × user/group/system_group/public) 를 걸고 GROUP BY facility_types.id 로 집계하며 마지막에 IFNULL/GREATEST 로 permission 을 계산:
LEFT JOIN facility_types AS sub_facility_types
ON sub_facility_types.ancestry = facility_types.id
LEFT JOIN facilities AS accessible_facilities
ON accessible_facilities.cycle_state IN ('created', 'archiving', 'archived')
AND (
accessible_facilities.facility_type_id = facility_types.id
OR accessible_facilities.facility_type_id = facility_types.ancestry
OR accessible_facilities.facility_type_id = sub_facility_types.id
)
").group('facility_types.id').select(_select).where("
GREATEST(
IFNULL(review_user_permissions.permission, 0),
IFNULL(review_group_permissions.permission, 0),
IFNULL(review_public_permissions.permission, 0)
) > 0
OR
...
GREATEST(
IFNULL(facility_user_permissions.permission, 0),
...
) > 1
")
accessible_facilities join 은 OR 조건 3개로 facility ↔ facility_type/parent/sub_type 을 매치하기 때문에 index 를 활용하기 어렵고 team 이 크면 explode 한다. ES 결과가 0건인 toyoeng team 도 이 쿼리로 db 9969ms 를 소비함이 관찰됨 (records 가 비어도 permission_joins 는 각 subquery 를 실행).
Failure point 2 — FacilityTypeSerializer 가 각 record 에 대해 facilities_count 를 호출하는데, 모델 메서드가 매번 라이브 COUNT SQL 을 실행:
class FacilityTypeSerializer
include CupixSerializer
attribute :id
attribute :name
attribute :parent, &:_parent
attribute :team, &:_team
attribute :cycle_state
attribute :created_at
attribute :updated_at
attribute :facilities_count
end
def facilities_count
return self[:facilities_count] if self[:facilities_count].present?
if main_type?
# Main Type: include self and all Sub Types
::Facility.untrashed.where(facility_type_id: subtree_ids, team_id: team_id).count
else
# Sub Type: count only self
::Facility.untrashed.where(facility_type_id: id, team_id: team_id).count
end
end
self[:facilities_count] 는 permission_joins 의 select 목록에 없으므로 항상 nil → SQL COUNT 로 fallback 한다. Elasticsearch 인덱스는 facilities_count 를 저장하지만 (app/models/concerns/searchable/facility_type.rb:60, 65-83), hydrate 시 AR 인스턴스로 대체되면서 ES 필드가 유실된다. Main type 의 경우 subtree_ids 로 계층 전체를 조회하므로 sub-type 수에 따라 비용이 증가한다.
기대 동작 vs 실제 동작:
- 기대: 100건 이하 결과에 대해 O(1) permission check + cached count → <500ms
- 실제:
permission_joins(records 유무와 무관하게 subquery 실행) + N ×facilities_count(main_type 은 subtree join) → 3-75s 관찰
Log Evidence#
Datadog query (재현용):
service:cupixworks-api "FacilityTypesController" @duration:>3000
Representative slow requests (지난 14일):
2026-07-06T06:03:41.396Z dur=10399ms db=1820ms serialization=253ms team=endeavourgroup entries=1 user=emily.holmes@edg.com.au params={per_page:100,page:1,fields:[id,name,parent,created_at,updated_at,facilities_count]}
2026-07-03T08:54:56.510Z dur=52506ms db=7809ms serialization=0ms team=toyoeng entries=0 user=reiko.miki@toyo-eng.com
2026-07-03T08:54:12.437Z dur=57539ms db=9969ms serialization=0ms team=toyoeng entries=0
2026-06-29T09:19:05.571Z dur=22276ms db=11832ms serialization=15274ms team=qatest2 entries=14 user=integration@cupix.com
2026-06-26T01:55:51.766Z dur=75363ms db=15056ms serialization=51810ms team=forida-demo entries=4 user=venus.kwok@forida.com.hk
2026-06-26T01:43:27.679Z dur=20321ms db=? team=webuild entries=0
주요 관찰:
- 결과 0건에도 db 8-10s 소요 (toyoeng) → ES 후보 hydrate 이후 실행되는
permission_joins서브쿼리 비용.records가 비어도 11개 LEFT JOIN 서브쿼리들 자체는 실행됨. - entries=4 인 forida-demo 가 serialization 51810ms → row 당 12.9s 소요, N ×
facilities_count(SQL COUNT with subtree) 의 지문과 일치. main_type row 가 다수 포함되어 subtree_ids scan 이 반복됨으로 추정. - 에러 없음 —
service:cupixworks-api resource_name:"Api::V1::FacilityTypesController#index" status:error(14d) → 0 hits.
Sample fast request (같은 tenant/user, 60ms):
{
"@timestamp": "2026-07-06T05:56:53.794Z",
"duration": 60.48,
"db": 38.55,
"serialization": {"duration": 17},
"pagination": {"total_entries": 3},
"team": {"domain": "endeavourgroup", "id": 180},
"user": {"email": "emily.holmes@edg.com.au"}
}
동일 사용자/tenant 도 결과 수가 적으면 60ms 로 반환되므로, 문제는 요청 자체가 아니라 team 의 facility_type/facility 규모 및 결과 row 특성 (main_type vs sub_type 비율) 에 있음.
Hypotheses Considered#
| # | Hypothesis | Evidence for | Evidence against | Verdict |
|---|---|---|---|---|
| H1 | permission_joins 의 11개 LEFT JOIN + GROUP BY 가 결과 수와 무관하게 큰 비용을 유발 |
toyoeng team: entries=0 이지만 db=7809-9969ms (app/repositories/facility_type_repository.rb:190-278) |
— | Confirmed |
| H2 | Serializer 가 매 row 마다 FacilityType#facilities_count 를 호출하여 N+1 SQL COUNT 발생 (main_type 은 subtree scan) |
forida-demo: entries=4 → serialization 51810ms (row 당 ~13s), app/models/facility_type.rb:20-30 은 항상 SQL COUNT (ES 인덱스의 facilities_count 는 AR hydrate 시 유실) |
— | Confirmed |
| H3 | 특정 tenant 의 데이터 이상 (거대한 ancestry chain 등) 이 원인 | endeavourgroup, toyoeng, forida-demo, qatest2, webuild, cupix 등 다수 tenant 에서 재현 | Slow request 가 12+ 도메인에 걸침 → tenant-specific 이 아님 | Rejected |
| H4 | Elasticsearch 클러스터 자체가 느림 | ES 관련 에러/circuit-breaker 로그 없음 (Cupix::Logger.error("Elasticsearch circuit breaker") app/repositories/base_repository.rb:91 미검출) |
fast 요청 (60ms) 이 동일 시간대에 성공. db/serialization 이 지배적이며 ES 부분은 미미 | Rejected |
| H5 | 최근 배포로 인한 회귀 | 대표 트레이스 버전 production-ap-southeast-2-20260706t0513z0-13e7c827-cupixworks 관측 |
6월 24일까지 거슬러 올라가는 slow 요청 다수 → 최소 2주 이상 지속되어 온 pre-existing 이슈 | Rejected |
| H6 | 외부 dependency 장애 | status-board scope=svc:cupixworks-api::unknown, active=null (dep:* 아님) |
— | Rejected |
Fix Recommendation#
즉시 조치 (Critical)#
-
facilities_count를 hydrated record 에서 재계산하지 않도록 우회- 대상:
app/serializers/facility_type_serializer.rb:11,app/models/facility_type.rb:20-30 - 방향: (a)
permission_joins의_select목록에facilities_count를 추가하여 ES 인덱스 값 또는 미리 계산된 subquery 결과를 컬럼으로 실어보내거나, (b)#index액션에서 결과 record 들에 대해 batch preload 로 team+facility_type_id 별 count 를 한 번의 GROUP BY 쿼리로 계산해 record 에 주입. Serializer 는 그 캐시를 소비. - 근거: forida-demo 케이스에서 serialization 51810ms 는 row 당 12.9s COUNT — 단일 batch 로 해결 시 O(1) 로 축소 가능.
- 대상:
-
결과가 0건인 경우
permission_joinsskip- 대상:
app/repositories/base_repository.rb:70-82 - 방향:
self.response.records가 비면 즉시 빈 SearchResult 를 반환. toyoeng 사례처럼 결과 0건에도 permission_joins 로 db 8-10s 를 태우는 낭비를 제거. - 근거:
permission_joins는 record 필터링 목적인데 record 가 없으면 실행할 이유가 없음.
- 대상:
단기 개선 (1주 이내)#
permission_joinsLEFT JOIN 재구성app/repositories/facility_type_repository.rb:126-309의accessible_facilitiesOR 조건 join 은 index 를 활용하기 어려움. facility ↔ facility_type 매칭을 UNION ALL + IN () 로 재작성하거나, 사전 CTE 로(facility_id, matched_facility_type_id)를 만들고 이를 join.
FacilityType#facilities_count를 ES 인덱스 값 우선 사용- Elasticsearch mapping 에
facilities_count필드가 이미 존재 (app/models/concerns/searchable/facility_type.rb:60). hydrate 대신 ES_source를 그대로 활용하는 경량 path 를 추가하거나,as_indexed_json이 최신값이라는 전제 하에 record.assign_attributes(facilities_count: es_source.facilities_count) 로 채워넣기. - 단, ES 색인 지연 시 stale count 위험 → 허용 가능한 정확도 정책 확인 필요 (facilities_count 는 UI 표시용 근사치이므로 대부분 허용됨).
- Elasticsearch mapping 에
장기 개선 (재발 방지)#
- APM slow trace SLO 도입:
resource:Api::V1::FacilityTypesController#indexp95 > 2s 시 alert. 회귀를 조기 감지. - 권한 검사와 검색 분리 리팩터:
permission_joins처럼 매 read 요청마다 대형 JOIN 을 재실행하는 패턴이 다른 리포지토리에도 존재할 수 있음. materialized view 또는 별도 permission service 로 이전 검토. - Serializer 에 lazy N+1 감지 hook: 개발/스테이징에서 serialization 중 SQL COUNT 등이 발생하면 실패시키는 spec/observer 를 추가해 회귀 방지.
Monitoring#
Datadog 쿼리 (dashboard timeseries 위젯용):
avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::facilitytypescontroller#index}
p95:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::facilitytypescontroller#index}
sum:trace.rack.request.hits{service:cupixworks-api,resource_name:api::v1::facilitytypescontroller#index}.as_rate()
Log 기반 slow request 카운트 (참고용, monitor 로 등록 시 아래 쿼리 사용):
service:cupixworks-api "FacilityTypesController" @duration:>5000
임계값 제안: p95 > 2000ms 5분 지속 시 warn, > 5000ms 5분 지속 시 alert.
Risk Assessment#
- Risk level: medium
- 사용자 impact: UI 초기 로드 지연 (facility list 화면). 에러는 아니지만 UX 저하 및 잠재적 gateway timeout 위험 (75s 관찰됨).
- 재현성: 다수 tenant 에서 지속 관찰, 결정론적 성능 이슈로 재현 용이.
- 예상 복잡도: standard
- 즉시 조치 (facilities_count preload, 빈 records skip) 는 국소 변경.
- 단기 개선 (permission_joins 재구성) 는 SQL/스키마 이해가 필요한 표준 refactor.