ES /docs

Api::V1::MetricsController#index (avg 3849ms, max 3849ms)

RCA: Api::V1::MetricsController#index Slow Response (3849ms)

Overview#

What Happened#

2026-06-04 12:56 KST에 cupixworks-api의 Api::V1::MetricsController#index 엔드포인트에서 3849ms의 응답 지연이 발생했다. 결과가 0건임에도 불구하고 DB에서 2153ms가 소비되었으며, 이는 permission_joins의 11개 LEFT JOIN 권한 쿼리가 DB 부하 상황에서 느려진 것이 원인이다.

Quick Facts#

Field Value
resource_name Api::V1::MetricsController#index
top_frame app/repositories/metric_repository.rb:33-207
runtime Ruby on Rails (cupixworks-api)
deploy production-us-west-2-20260604t0241z0-bfe9a388-cupixworks
env production, us-west-2

Timeline#

  1. 2026-06-04 12:56 KST — MetricsController#index 요청 시작 (facility_key=nvo8k1, team=clark-vdc)
  2. 2026-06-04 12:56 KST — 응답 완료 (200 OK, 3357ms 소요, DB 2153ms)
  3. 2026-06-04 13:29 KST — 동일 호스트에서 PanosController#bulk 15765ms 지연 확인 (호스트 부하 지속)
  4. 2026-06-04 12:59 KST — 다른 호스트에서 동일 엔드포인트 14ms 정상 응답 확인

Error Log#

Datadog Logs

json
{
  "resource_name": "Api::V1::MetricsController#index",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 3849,
  "max_ms": 3849,
  "sample_trace_id": "2146379881440203618"
}

Impact#

  • Service: cupixworks-api
  • 발생 횟수: 1
  • 최초 발생: 2026-06-04 12:56 KST
  • 최근 발생: 2026-06-04 12:56 KST

Root Cause Summary#

MetricsController#index의 permission_joins 메서드가 11개의 LEFT JOIN과 서브쿼리를 포함한 대규모 raw SQL을 실행한다. 해당 시점에 호스트 ip-10-1-19-190이 전반적으로 높은 DB 부하를 경험하고 있었고(동일 호스트에서 여러 느린 요청 발생), 이 상태에서 permission_joins의 복잡한 쿼리가 2153ms의 DB 시간을 소비했다. 결과가 0건임에도 Elasticsearch에서 ID를 조회한 후 MySQL에서 권한 필터링을 수행하는 2단계 쿼리 패턴이 불필요한 DB 부하를 야기했다.

Technical Analysis#

Code Path#

  • Entry point: app/controllers/api/v1/metrics_controller.rb:9
  • SearchableController concern: app/controllers/concerns/searchable_controller.rb:18-42 (QueryOption 구성)
  • Repository search: app/repositories/metric_repository.rb:224-243 (ES 쿼리 실행)
  • Permission filtering: app/repositories/metric_repository.rb:33-207 (11 LEFT JOIN SQL)
  • Serialization: app/controllers/concerns/renderable_controller.rb:86-91

1단계: Elasticsearch 검색 — facility.key 필터로 ES에서 매칭되는 metric ID를 조회한다:

app/repositories/metric_repository.rb:224-243ruby
def _search(query_option)
  # facility_key 필수 검증
  facility_key = query_option.predefined_filter&.dig(:facility_key)
  raise Errors::BadRequestError unless facility_key.present?

  query_option.filter << { term: { 'facility.key': facility_key } }
  response = ::Metric.search(query_option.serializable_hash)
                      .paginate(per_page: query_option.per_page, page: query_option.page)
  # response.records → ES 결과 ID로 MySQL 재조회
end

2단계: Permission JOIN — ES 결과에 대해 11개의 LEFT JOIN으로 권한을 필터링한다:

app/repositories/metric_repository.rb:33-70ruby
def permission_joins(record, user)
  review_id = @review&.id || -1
  user_id = user.id
  team_id = @current_team.id

  record.joins("
    LEFT JOIN (SELECT ...) AS review_public_permissions ON ...
    LEFT JOIN (SELECT ...) AS review_user_permissions ON ...
    LEFT JOIN (SELECT ...) AS review_group_permissions ON ...
    LEFT JOIN (SELECT ...) AS facility_user_permissions ON ...
    LEFT JOIN (SELECT ...) AS facility_group_permissions ON ...
    LEFT JOIN (SELECT ...) AS facility_system_group_permissions ON ...
    LEFT JOIN (SELECT ...) AS workspace_user_permissions ON ...
    LEFT JOIN (SELECT ...) AS workspace_group_permissions ON ...
    LEFT JOIN (SELECT ...) AS team_user_permissions ON ...
    LEFT JOIN (SELECT ...) AS team_group_permissions ON ...
    LEFT JOIN (SELECT ...) AS team_system_group_permissions ON ...
  ")
  .where("GREATEST(IFNULL(...)) >= 1")
  .group(:id)
end

핵심 문제: ES 결과가 0건이더라도, response.records가 ActiveRecord::Relation을 반환하고 이후 permission_joins가 체이닝되어 실행된다. 빈 결과에 대해서도 복잡한 JOIN 쿼리가 DB에 전달될 수 있다.

Log Evidence#

사용한 Datadog 쿼리:

text
service:cupixworks-api @http.url_details.path:"/api/v1/metrics" @duration:>3000000000

해당 요청의 핵심 로그:

json
{
  "timestamp": "2026-06-04T03:56:30.303Z",
  "controller": "Api::V1::MetricsController",
  "action": "index",
  "method": "GET",
  "path": "/api/v1/metrics",
  "status": 200,
  "duration": 3357.78,
  "db_runtime": 2153.7,
  "view_runtime": 0.1,
  "params": {
    "per_page": "100",
    "page": "1",
    "fields": ["id", "key", "name", "position", "unit"],
    "facility_key": "nvo8k1"
  },
  "total_entries": 0,
  "total_pages": 1,
  "user_email": "ginny.choi@cupix.com",
  "team_key": "clark-vdc",
  "host": "ip-10-1-19-190.us-west-2.compute.internal"
}

동일 엔드포인트 정상 응답 비교 (다른 호스트):

json
{
  "timestamp": "2026-06-04T03:59:34.903Z",
  "duration": 14.84,
  "db_runtime": 1.81,
  "total_entries": 0,
  "host": "ip-10-1-144-228.us-west-2.compute.internal"
}

동일 호스트의 다른 느린 요청:

text
2026-06-04T04:29:43Z - PanosController#bulk: 15765ms (host: ip-10-1-19-190)

Hypotheses Considered#

# Hypothesis Evidence for Evidence against Verdict
H1 permission_joins의 11 LEFT JOIN 쿼리가 DB 부하 상황에서 느려짐 DB 시간 2153ms (전체의 64%), 동일 호스트 다른 요청도 느림, 다른 호스트는 동일 쿼리 1.81ms — Confirmed
H2 특정 facility nvo8k1의 데이터 볼륨이 쿼리를 느리게 함 facility_key=nvo8k1 요청에서 발생 total_entries=0 (결과 없음), 데이터 볼륨이 아닌 쿼리 복잡도 문제 Rejected
H3 N+1 쿼리 문제 (serializer 캐시 미스) serializer에서 fetch_cache 사용, 캐시 미스시 개별 쿼리 발생 가능 total_entries=0이므로 serialization 대상 없음, view_runtime 0.1ms Rejected
H4 Elasticsearch 쿼리 자체가 느림 — db_runtime이 대부분 차지 (2153ms), ES 쿼리 시간은 미미 Rejected

Fix Recommendation#

즉시 조치 (Critical)#

  • app/repositories/metric_repository.rb:70-112 (search 메서드 내부): ES 결과가 비어있을 때 permission_joins를 스킵하는 early return 추가. response.records의 ID 목록이 비어있으면 빈 SearchResult를 즉시 반환하여 불필요한 DB 쿼리를 방지한다.

단기 개선 (1주 이내)#

  • permission_joins에서 review_id: -1일 때 review 관련 3개의 LEFT JOIN을 조건부로 제외하여 쿼리 복잡도를 줄인다.
  • base_repository.rb:70-112의 search 메서드에 DB 쿼리 타임아웃(statement_timeout)을 설정하여 극단적 지연을 방지한다.

장기 개선 (재발 방지)#

  • Permission 로직을 Elasticsearch 인덱스에 포함시켜 2단계 쿼리 패턴을 제거하고 단일 ES 쿼리로 권한 필터링까지 처리하는 구조로 변경한다.
  • 또는 permission 결과를 Redis에 캐시하여 매 요청마다 11 JOIN 쿼리를 실행하지 않도록 한다.

Monitoring#

  • Api::V1::MetricsController#index p95 응답 시간 모니터링 추가
  • Datadog 쿼리 예시:
text
avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::metricscontroller_index} by {host}
  • DB 쿼리 시간이 1000ms를 초과하는 요청에 대한 알림 설정:
text
service:cupixworks-api @db_runtime:>1000 @http.url_details.path:"/api/v1/metrics"

Risk Assessment#

  • Risk level: low
  • 예상 복잡도: standard