ES /docs

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#

  1. 2026-07-06 14:56:39 KST — 대표 트레이스 (2203852587658987718) 13606ms, ap-southeast-2 에서 발생 (cluster first_seen)
  2. 2026-07-06 14:56:53 KST — 동일 endpoint 정상 요청 (60ms, endeavourgroup team=180, 결과 3건) — 즉시 회복
  3. 2026-07-06 15:03:41 KST — 동일 user (emily.holmes@edg.com.au, endeavourgroup) 재시도 10399ms (db 1820ms, entries=1)
  4. 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#

Datadog Traces

text
{
  "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

app/controllers/api/v1/facility_types_controller.rb:6-14ruby
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.searchBaseRepository#search (line 70) 로 위임되어 다음 순서로 실행된다.

Step 1FacilityTypeRepository#_search 가 Elasticsearch 쿼리를 조립하고 페이지네이션 (per_page: 100, page: 1 관찰) 수행:

app/repositories/facility_type_repository.rb:112-119ruby
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 2BaseRepository#search 가 hits 를 .records 로 ActiveRecord hydrate 한 뒤 permission_joins 에 넘김:

app/repositories/base_repository.rb:70-82ruby
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 1permission_joins (권한 재계산 매크로 쿼리): 11개의 LEFT JOIN 서브쿼리 (review/facility/workspace/team × user/group/system_group/public) 를 걸고 GROUP BY facility_types.id 로 집계하며 마지막에 IFNULL/GREATEST 로 permission 을 계산:

app/repositories/facility_type_repository.rb:190-199ruby
  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
    )
app/repositories/facility_type_repository.rb:279-308ruby
").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 2FacilityTypeSerializer 가 각 record 에 대해 facilities_count 를 호출하는데, 모델 메서드가 매번 라이브 COUNT SQL 을 실행:

app/serializers/facility_type_serializer.rb:1-12ruby
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
app/models/facility_type.rb:20-30ruby
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_joinsselect 목록에 없으므로 항상 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 (재현용):

text
service:cupixworks-api "FacilityTypesController" @duration:>3000

Representative slow requests (지난 14일):

text
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):

json
{
  "@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_joins skip

    • 대상: app/repositories/base_repository.rb:70-82
    • 방향: self.response.records 가 비면 즉시 빈 SearchResult 를 반환. toyoeng 사례처럼 결과 0건에도 permission_joins 로 db 8-10s 를 태우는 낭비를 제거.
    • 근거: permission_joins 는 record 필터링 목적인데 record 가 없으면 실행할 이유가 없음.

단기 개선 (1주 이내)#

  • permission_joins LEFT JOIN 재구성
    • app/repositories/facility_type_repository.rb:126-309accessible_facilities OR 조건 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 표시용 근사치이므로 대부분 허용됨).

장기 개선 (재발 방지)#

  • APM slow trace SLO 도입: resource:Api::V1::FacilityTypesController#index p95 > 2s 시 alert. 회귀를 조기 감지.
  • 권한 검사와 검색 분리 리팩터: permission_joins 처럼 매 read 요청마다 대형 JOIN 을 재실행하는 패턴이 다른 리포지토리에도 존재할 수 있음. materialized view 또는 별도 permission service 로 이전 검토.
  • Serializer 에 lazy N+1 감지 hook: 개발/스테이징에서 serialization 중 SQL COUNT 등이 발생하면 실패시키는 spec/observer 를 추가해 회귀 방지.

Monitoring#

Datadog 쿼리 (dashboard timeseries 위젯용):

text
avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::facilitytypescontroller#index}
text
p95:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::facilitytypescontroller#index}
text
sum:trace.rack.request.hits{service:cupixworks-api,resource_name:api::v1::facilitytypescontroller#index}.as_rate()

Log 기반 slow request 카운트 (참고용, monitor 로 등록 시 아래 쿼리 사용):

text
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.