RCA: Api::V1::CapturesController#index Latency (avg 2376ms, max 3527ms)

Overview#

What Happened#

2026-05-26 04:26~06:07 UTC 사이에 cupixworks-api의 CapturesController#index 엔드포인트에서 평균 2376ms, 최대 3527ms의 응답 지연이 8건 발생했다. us-west-2와 ap-southeast-2 두 리전에서 관측되었으며, 주요 원인은 AccessibleEntities::Cache 권한 캐시 미스 시 발생하는 다단계 permission 쿼리이다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-05-26 04:26:38Z — 최초 발생 (ap-southeast-2)
2. 2026-05-26 06:07:15Z — 마지막 발생 (us-west-2)
3. 2026-05-26 — error-sweeper 감지 및 RCA 수행

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::CapturesController#index",
  "service": "cupixworks-api",
  "occurrences": 8,
  "avg_ms": 2376,
  "max_ms": 3527,
  "sample_trace_id": "4479250235366130310"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 8
• 최초 발생: 2026-05-26T04:26:38.387Z
• 최근 발생: 2026-05-26T06:07:15.447Z

Root Cause Summary#

CapturesController#index의 Elasticsearch 쿼리 빌드 단계에서 current_user.readable_record_ids와 current_user.directly_accessible_capture_ids를 호출한다. 이 메서드들은 AccessibleEntities::Cache를 통해 Redis에 캐시되지만, 캐시 미스 시 다단계 permission 테이블 조인 쿼리를 실행하여 17002100ms의 DB 시간을 소비한다. 이후 Elasticsearch 결과에 대해 추가로 15개 LEFT JOIN permission_joins를 수행하여 총 응답 시간이 23003500ms에 달한다. us-west-2에서 DB 시간이 ap-southeast-2보다 4~5배 높은 것은 해당 리전의 permission 테이블 크기가 더 크거나 DB 인스턴스 부하가 높기 때문으로 판단된다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/captures_controller.rb:22 — index action
• ES 쿼리 빌드: app/repositories/capture_repository.rb:662-680 — permission ID 로드
• 캐시 조회: app/models/concerns/accessible_entities/cache.rb:65-78 — _readable_record_ids
• 캐시 미스 시 쿼리: app/models/concerns/accessible_entities.rb:57-75 — readable_records (4단계 OR 조인)
• Capture 권한 캐시: app/models/concerns/accessible_entities/directly_accessible.rb:61-67 — directly_accessible_capture_ids
• Permission JOIN: app/repositories/capture_repository.rb:279-505 — 15개 LEFT JOIN SQL
• Failure point: 캐시 미스 시 readable_records와 directly_permitted_items 실행이 1700-2100ms 소요

1단계: Elasticsearch 쿼리 빌드 시 permission ID 로드

if self.current_user.present?
  self.query_option.query[:bool][:must] += [
    {
      bool: {
        should: [
          {
            terms: {
              "record.id": self.current_user.readable_record_ids
            }
          },
          {
            terms: {
              id: self.current_user.directly_accessible_capture_ids
            }
          }
        ]
      }
    }
  ]
end

readable_record_ids와 directly_accessible_capture_ids는 캐시 히트 시 즉시 반환되지만, 캐시 미스 시 아래 쿼리를 실행한다.

2단계: 캐시 미스 시 permission 계산

def _readable_record_ids(visibility = Cyclable.visibility[:UNTRASHED])
  Rails.cache.fetch({
    cached_permission: {
      user_id: id,
      model: 'Record',
      min_permission: 2,
      t: cached_permission_timestamp
    }
  }, expires_in: DEFAULT_PERMISSION_CACHE_EXPIRES_IN) do
    Cupix::Logger.info("Flushing readable_record_ids on user #{id}", ...)
    readable_records(visibility).pluck(:id)
  end
end

캐시 미스 시 readable_records가 실행되며, 이는 Team/Workspace/Facility/Record 4단계 OR 쿼리를 수행한다:

def readable_records(visibility = Cyclable.visibility[:UNTRASHED])
  scope = ::Record.visibility_scope(visibility)

  RecordRepository.where(
    team: directly_permitted_items(::Team, visibility, min_permission: 2)
  ).or(
    RecordRepository.where(
      workspace: directly_permitted_items(::Workspace, visibility, min_permission: 2)
    )
  ).or(
    RecordRepository.where(
      facility: directly_permitted_items(::Facility, visibility, min_permission: 2)
    )
  ).or(
    RecordRepository.where(
      id: directly_permitted_item_ids(::Record, visibility, min_permission: 2)
    )
  ).distinct.merge(scope)
end

3단계: SQL permission_joins (15+ LEFT JOIN)

def self.permission_joins(record, current_user, select: nil, review_id: -1, **kwargs)
  return record if kwargs[:skip_join]

  _select = "MAX(review_user_permissions.permission) AS review_user_permission,
    MAX(review_group_permissions.permission) AS review_group_permission,
    MAX(review_public_permissions.permission) AS review_public_permission,
    MAX(capture_user_permissions.permission) AS capture_user_permission,
    MAX(record_user_permissions.permission) AS record_user_permission,
    MAX(record_group_permissions.permission) AS record_group_permission,
    MAX(record_system_group_permissions.permission) AS record_system_group_permission,
    MAX(facility_user_permissions.permission) AS facility_user_permission,
    ...
    MAX(GREATEST(...)) AS applied_permission"
end

Log Evidence#

Datadog에서 모든 8개 trace를 조회한 결과, 공통 패턴을 확인했다.

service:cupixworks-api resource_name:"Api::V1::CapturesController#index" @duration:>2000000000 env:production

us-west-2 trace 예시 (trace_id: 4282859805962577851):

{
  "resource_name": "Api::V1::CapturesController#index",
  "duration_ms": 2890,
  "db_ms": 1854,
  "team": "fgip-pkg1",
  "entries": 51,
  "region": "us-west-2"
}

ap-southeast-2 trace 예시 (trace_id: 4479250235366130310):

{
  "resource_name": "Api::V1::CapturesController#index",
  "duration_ms": 1074,
  "db_ms": 379,
  "team": "endeavourgroup",
  "entries": 5,
  "region": "ap-southeast-2"
}

AccessibleEntities::Cache flush 로그 (모든 trace에서 공통 관측):

"Flushing readable_record_ids on user {id}" — module: AccessibleEntities::Cache
"Flushing directly_permitted_items on user {id}, model: Record, min_permission: 2" — module: AccessibleEntities::Cache
"Flushing directly_permitted_items on user {id}, model: Capture, min_permission: 1" — module: AccessibleEntities::Cache

핵심 패턴:

• us-west-2: DB 시간 1700~2100ms (결과 수와 무관 — 0건 반환 시에도 1740ms)
• ap-southeast-2: DB 시간 90420ms (같은 로직이지만 45배 빠름)
• 모든 slow trace에서 AccessibleEntities::Cache "Flushing" 로그 존재 → 캐시 미스 확인

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• app/repositories/capture_repository.rb:662-680 — Elasticsearch 쿼리 빌드 시 readable_record_ids와 directly_accessible_capture_ids를 병렬로 실행하거나, 쿼리 방식을 변경하여 전체 ID 목록 대신 서버사이드 필터링으로 전환 검토
• app/models/concerns/accessible_entities/cache.rb:6-12 — cached_permission_timestamp가 admin 팀 사용자에 대해 매번 SecureRandom.hex(10)을 반환하여 캐시를 무효화하는지 확인. admin 사용자가 아닌 일반 사용자도 timestamp 만료로 인한 cache miss가 발생할 수 있음

단기 개선 (1주 이내)#

• readable_record_ids 캐시 TTL을 리전별 DB 부하에 맞게 조정하거나, 캐시 워밍 전략 도입 (로그인 시 비동기 워밍)
• us-west-2의 permission 관련 테이블 (record_permissions, facility_permissions, workspace_permissions, team_permissions, grouped_users)에 대한 쿼리 성능 분석 및 인덱스 최적화
• readable_records 메서드의 4단계 OR 쿼리를 단일 optimized 쿼리로 재작성 검토

장기 개선 (재발 방지)#

• Permission 모델을 역정규화(denormalize)하여 user별 accessible record/capture ID를 materialized view 또는 별도 테이블로 관리하는 방안 검토
• Elasticsearch 쿼리에서 ID 목록 기반 필터링 대신 Elasticsearch 인덱스에 permission 정보를 포함하여 서버사이드 필터링 구현 (ID 목록이 수천 개를 초과하면 ES terms 쿼리 성능도 저하됨)
• 리전 간 DB 성능 차이 조사 (us-west-2 RDS 인스턴스 사양/부하 확인)

Monitoring#

• CapturesController#index 응답 시간 P95/P99 메트릭 알림:

avg(last_5m):trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::capturescontroller#index} > 2000000000

• AccessibleEntities::Cache flush 빈도 모니터링:

service:cupixworks-api "Flushing readable_record_ids" | stats count by @usr.id

• us-west-2 DB 시간 모니터링 (permission 쿼리 격리):

service:cupixworks-api resource_name:"Api::V1::CapturesController#index" @http.status_code:200 | stats avg(@duration), avg(@db_time) by @region

Risk Assessment#

• Risk level: medium
• 예상 복잡도: standard — 캐시 워밍 및 쿼리 최적화는 기존 아키텍처 내에서 수행 가능하나, permission 모델 재설계는 대규모 변경 필요