RCA: Api::V1::ReferencesController#index Latency

Overview#

What Happened#

2026-05-26 03:22~13:09 UTC 사이에 cupixworks-api 서비스의 Api::V1::ReferencesController#index 엔드포인트에서 평균 1128ms, 최대 1556ms의 응답 지연이 38회 발생했다. 4개 리전(ap-southeast-2, eu-central-1, ap-southeast-1, us-west-2)에서 동시에 관측되었다.

Quick Facts#

Timeline#

1. 2026-05-26T03:22:04Z — 최초 slow trace 감지 (>500ms threshold)
2. 2026-05-26T13:09:15Z — 마지막 slow trace 기록
3. 2026-05-27 — RCA 분석 수행

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::ReferencesController#index",
  "service": "cupixworks-api",
  "occurrences": 13,
  "avg_ms": 1141,
  "max_ms": 1556,
  "sample_trace_id": "50666437399786200"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 38
• 최초 발생: 2026-05-26T03:22:04.361Z
• 최근 발생: 2026-05-26T13:09:15.974Z

Root Cause Summary#

ReferencesController#index의 permission_joins 메서드가 10개의 LEFT JOIN 서브쿼리(capture_permissions, facility_permissions, workspace_permissions, team_permissions × user/group)를 결합한 대형 SQL을 실행한다. 특히 capture_permissions 테이블은 (accessor_id, accessor_type, capture_id)를 결합한 composite index가 없어 풀 스캔에 가까운 조회가 발생하며, Elasticsearch 조회 후 ActiveRecord에서 다시 permission check SQL을 실행하는 이중 조회 구조가 응답 시간을 1초 이상으로 끌어올리고 있다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/references_controller.rb:8 — index action
• repository_instance.search() 호출 → BaseRepository#search (app/repositories/base_repository.rb:70)
• _search(query_option) 호출 → ReferenceRepository#_search (app/repositories/reference_repository.rb:307)
  • capture_id 파라미터가 있으면 CaptureRepository.new(...).show(capture_id) + @capture.panos.untrashed.ids 실행 (N+1 가능성)
  • Elasticsearch ::Reference.search(...).paginate(per_page: 30) 실행
• Failure point: BaseRepository#search line 78-79에서 permission_joins 호출

def search(query_option = nil)
  _search(query_option)

  begin
    if self.review.present?
      contents = self.class.permission_joins(self.class.default_joins(self.response.records), self.current_user, review_id: self.review.id, skip_join: _skip_join?)
    elsif self.capture.present?
      contents = self.class.permission_joins(self.class.default_joins(self.response.records), self.current_user, capture_id: self.capture.id, skip_join: _skip_join?)
    else
      contents = self.class.permission_joins(self.class.default_joins(self.response.records), self.current_user, skip_join: _skip_join?)
    end
    # ...
  end

  SearchResult.new({
    contents: contents.records,  # ← SQL 실행 시점
    # ...
  })
end

permission_joins 메서드는 10개의 LEFT JOIN 서브쿼리를 구성한다:

def self.permission_joins(record, current_user, select: nil, capture_id: -1, **kwargs)
  # ... SELECT with MAX(permission) for 10 permission sources ...

  record.joins("
    LEFT JOIN (
      SELECT capture_id, permission FROM capture_permissions
      WHERE capture_permissions.accessor_id = #{sanitized_user_id}
        AND capture_permissions.accessor_type = 'User'
        AND capture_permissions.capture_id = #{sanitized_capture_id}
    ) AS capture_user_permissions ...

    LEFT JOIN (
      SELECT capture_id, permission FROM capture_permissions
        LEFT JOIN grouped_users ON grouped_users.group_id = capture_permissions.accessor_id
      WHERE capture_permissions.accessor_type = 'Group'
        AND grouped_users.user_id = #{sanitized_user_id}
    ) AS capture_group_permissions ...

    -- 8개 추가 LEFT JOIN (facility_user, facility_group, facility_system_group,
    --   workspace_user, workspace_group, team_user, team_group, team_system_group)
  ").group('id').select(_select).where("GREATEST(...) > 1")
end

기대 동작: ES에서 반환된 최대 30개 reference ID에 대해 빠르게 permission check 수행. 실제 동작: 10개 서브쿼리의 LEFT JOIN + GROUP BY + GREATEST 연산이 결합되며, capture_permissions 테이블에 composite index가 없어 쿼리 실행 시간이 500ms~1500ms에 달함.

Log Evidence#

Datadog에서 확인한 로그:

service:cupixworks-api "ReferencesController#index"
Time range: 2026-05-26T02:00:00Z to 2026-05-26T14:00:00Z

{
  "timestamp": "2026-05-26 22:59:38 KST",
  "status": "info",
  "message": "[200] GET /api/v1/references (Api::V1::ReferencesController#index)"
}

APM metrics에서 확인한 응답 시간 분포 (24시간):

• 평균: 0.350.84초 (350ms840ms)
• 최대 피크: 0.84초 (단일 5분 구간 평균)
• 클러스터에서 포착된 최대 trace: 1556ms

4개 리전에서 동시 발생한 것은 코드/쿼리 수준 문제임을 확인 — 특정 리전 DB 장애가 아닌 구조적 이슈.

DB schema 분석:

# capture_permissions indexes (db/schema.rb:986-989):
- index on [accessor_type, accessor_id]
- index on [capture_id]
- index on [permission]
- index on [record_permission_id]
# 주의: (accessor_id, accessor_type, capture_id) composite index 부재

# facility/workspace/team_permissions (2023-11-07 migration):
- composite index on [*_id, permission, accessor_id, accessor_type] 존재

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• app/repositories/reference_repository.rb:135 — permission_joins 내부의 capture_permissions 서브쿼리에서 사용하는 필터 조건(accessor_id, accessor_type, capture_id)에 맞는 composite index 추가
  • 대상 테이블: capture_permissions
  • 인덱스: (capture_id, accessor_id, accessor_type) 또는 (accessor_id, accessor_type, capture_id)
  • grouped_users JOIN도 포함하므로 (group_id, user_id) 인덱스는 이미 존재 확인

단기 개선 (1주 이내)#

• Reference 모델의 _skip_join? 적용 검토 (base_repository.rb:394): capture_id가 명시적으로 전달될 때는 capture-level permission만 확인하면 충분하므로, 불필요한 facility/workspace/team permission JOIN을 건너뛸 수 있는지 검토
• per_page 기본값(30)이 클라이언트 요청에 비해 과도한 경우 줄이기

장기 개선 (재발 방지)#

• Permission check을 SQL JOIN 방식에서 application-level caching 또는 pre-computed permission 테이블 방식으로 전환
• 현재 ES → MySQL 이중 조회 구조를 ES 인덱스에 permission 정보를 포함하는 방식으로 개선하여 MySQL permission JOIN 제거 검토

Monitoring#

• 추가할 메트릭:
  • ReferencesController#index p95/p99 latency 알림 (threshold: 1000ms)
  • capture_permissions 테이블 slow query 감시

avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::referencescontroller_index} > 1.0

Risk Assessment#

• Risk level: medium
• 예상 복잡도: standard (composite index 추가는 low-risk, permission logic 변경은 medium-risk)