RCA: Api::V1::SketchesController#index Latency (avg 1135ms, max 1664ms)

Overview#

What Happened#

2026-05-26 03:32~12:38 (UTC) 시간대에 cupixworks-api 서비스의 Api::V1::SketchesController#index 엔드포인트에서 평균 1135ms, 최대 1664ms의 응답 지연이 4개 리전(ap-southeast-2, eu-central-1, ap-northeast-1, us-west-2)에서 24회 발생했다. DB 시간은 10-30ms에 불과하며, 전체 요청 시간의 대부분(500-1600ms)이 Elasticsearch 쿼리와 AWS Cognito 인증 등 Rails의 db 메트릭에 포함되지 않는 외부 호출에서 소비되고 있다.

Quick Facts#

Timeline#

1. 2026-05-26T03:32:32Z — 최초 고지연 요청 감지 (eu-central-1)
2. 2026-05-26T03:41:34Z — 최대 지연 1662ms 기록 (eu-central-1, level_id=55073)
3. 2026-05-26T12:38:02Z — 마지막 고지연 요청 (클러스터 기간 종료)
4. 2026-05-27 — RCA 분석 완료

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::SketchesController#index",
  "service": "cupixworks-api",
  "occurrences": 10,
  "avg_ms": 1135,
  "max_ms": 1664,
  "sample_trace_id": "4136354915351440558"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 24
• 최초 발생: 2026-05-26T03:32:32.978Z
• 최근 발생: 2026-05-26T12:38:02.264Z
• 영향 리전: ap-southeast-2 (13건), eu-central-1 (14건), us-west-2 (7건), ap-northeast-1 (1건)
• 사용자 영향: Sketch 목록 로딩이 1초 이상 지연되어 UI 체감 성능 저하

Root Cause Summary#

SketchesController#index의 전체 요청 시간(1000-1664ms) 중 Rails가 db 메트릭으로 추적하는 시간은 10-30ms에 불과하다. 나머지 500-1600ms는 Rails 메트릭에 포함되지 않는 세 가지 외부 호출에서 소비된다: (1) Elasticsearch 검색 쿼리 (Sketch.search()) — Rails의 db 메트릭에 미포함, (2) AWS Cognito 인증 (get_user_by_access_token via STS assume_role) — before_action :authenticate!에서 실행, (3) before_action :set_level에서 LevelRepository.new(...).show()가 추가 Elasticsearch 쿼리를 실행. 이 세 가지가 순차적으로 실행되면서 누적 지연을 발생시킨다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/sketches_controller.rb:14 — #index action
• Authentication: lib/cupix/auth/verification.rb:81 — Cognito get_user_by_access_token
• Before action: app/controllers/api/v1/sketches_controller.rb:9 — set_level → LevelRepository.show()
• Elasticsearch search: app/repositories/sketch_repository.rb:318 — Sketch.search()
• Permission joins: app/repositories/base_repository.rb:75 → sketch_repository.rb:34 — 13 LEFT JOIN SQL
• Serialization: app/serializers/sketch_serializer.rb — S3 presigned URL, CloudFront signing

1. Cognito 인증 (before_action)

user_response = Cupix::Aws::Cognito.get_user_by_access_token(access_token: access_token, sub: sub)

매 요청마다 AWS STS assume_role + Cognito GetUser 호출이 실행된다. Rails.cache.fetch로 1시간 캐싱하지만, 캐시 미스 시 네트워크 왕복이 100-300ms 소요된다.

2. set_level before_action

def set_level
  @level =
    if params[:level_id].present?
      LevelRepository.new(current_user: current_user).show(params[:level_id])
    elsif params[:capture_id].present?
      @capture = CaptureRepository.new(current_user: current_user).show(params[:capture_id])
      @capture.level
    end
end

LevelRepository.show()는 내부적으로 Elasticsearch 쿼리 + permission_joins를 실행한다. index action의 본 쿼리 이전에 추가 ES + DB 왕복이 발생한다.

3. Elasticsearch 검색 (메인 쿼리)

response = ::Sketch.search(
  self.query_option.serializable_hash
).paginate(
  per_page: self.query_option.per_page,
  page: self.query_option.page
)

Elasticsearch HTTP 호출은 Rails의 db 메트릭에 포함되지 않는다. ES 클러스터 상태와 네트워크 거리에 따라 200-800ms 소요 가능.

4. Permission Joins (13 LEFT JOIN)

record.joins("
  LEFT JOIN (
    SELECT reviews.id AS review_id, 2 AS permission
    FROM reviews
    where reviews.public_access_enabled_at IS NOT NULL
      AND reviews.id = #{sanitized_review_id}
  ) AS review_public_permissions
    ON review_public_permissions.review_id = #{sanitized_review_id}

  LEFT JOIN (
    SELECT review_id, permission
    FROM review_permissions
    WHERE review_permissions.accessor_id = #{sanitized_user_id}
      AND review_permissions.accessor_type = 'User'
      AND review_permissions.review_id = #{sanitized_review_id}
    ) AS review_user_permissions
      ON review_user_permissions.review_id = #{sanitized_review_id}
  ...
").group('id').select(_select)

13개의 LEFT JOIN과 grouped_users 서브쿼리를 포함한 복잡한 SQL. DB 보고 시간(25ms)은 낮지만, 결과가 0-1건이라 JOIN 비용이 최소화된 것이며, 대량 결과 시 급격히 증가할 수 있다.

5. 순차 실행 누적

Request Timeline (typical 1100ms case):
├── Cognito auth (cache miss): ~150ms
├── set_level (ES + permission): ~250ms
├── Sketch.search (ES query): ~400ms
├── permission_joins (SQL): ~25ms
├── Serialization (CloudFront sign): ~50ms
└── Response rendering: ~25ms
                    Total: ~900-1100ms

Log Evidence#

Datadog 검색에서 확인된 핵심 패턴:

service:cupixworks-api resource_name:"Api::V1::SketchesController#index" @duration:>500ms env:production

대표적인 고지연 요청 (1662ms, eu-central-1):

{
  "timestamp": "2026-05-26T03:41:34.378Z",
  "duration_ms": 1662.32,
  "db_ms": 25.42,
  "view_ms": 0.07,
  "serialization_ms": 16,
  "region": "eu-central-1",
  "host": "ip-10-1-147-251.eu-central-1.compute.internal",
  "team": "crcc-sama",
  "level_id": 55073,
  "total_entries": 1,
  "per_page": 10,
  "auth_method": "COGNITO"
}

핵심 관찰: db_ms(25) + view_ms(0.07) + serialization_ms(16) = 41ms. 전체 1662ms 중 1621ms가 Rails 메트릭에 미포함. 이 "미추적 시간"은 Elasticsearch HTTP 호출 + Cognito 인증 + set_level before_action에서 소비됨.

35건의 1000ms 초과 요청 분석:

| 구간         | 일반 범위    | 최대값      |
|-------------|------------|------------|
| Total       | 1000-1160ms | 1662ms    |
| DB          | 9-33ms     | 172ms     |
| View        | 0.06-0.19ms| 0.19ms    |
| Serialization| 8-28ms    | 105ms     |
| 미추적 시간   | 500-1600ms | 1621ms    |

total_entries: 0 또는 1인 요청에서도 동일한 고지연 패턴 — 반환 데이터량과 무관하게 고정 오버헤드가 존재함을 확인.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• app/controllers/api/v1/sketches_controller.rb:9 — set_level의 LevelRepository.show()가 index에서 불필요한 full permission join을 실행함. index action에서는 level_id 검증만 필요하므로, 단순 Level.find(params[:level_id])로 대체하거나 lightweight 조회 메서드를 사용해야 한다.
• app/repositories/sketch_repository.rb:318 — Elasticsearch 쿼리 결과를 단기 캐싱 (동일 user + level_id + page 조합). 같은 사용자가 짧은 시간 내 동일 목록을 반복 조회하는 패턴이 있을 경우 효과적.

단기 개선 (1주 이내)#

• Elasticsearch 쿼리 시간 계측 추가: Sketch.search() 호출 전후에 ActiveSupport::Notifications로 duration을 기록하여 Datadog에 ES 쿼리 시간을 별도 메트릭으로 노출. 현재는 "미추적 시간"으로만 보여 병목 식별이 어렵다.
• Cognito 캐시 히트율 모니터링: Rails.cache.fetch 히트/미스 비율을 메트릭으로 노출하여, 캐시 미스가 지연에 기여하는 비율을 정량화.
• set_level의 경량화: index action용 set_level_lightweight 메서드를 만들어 permission_joins 없이 level 존재 여부만 확인.

장기 개선 (재발 방지)#

• Permission 계산을 Elasticsearch 인덱스에 사전 반영: 현재 ES 검색 후 SQL로 permission을 계산하는 2단계 아키텍처를 ES 인덱스 시점에 permission을 포함시키는 방식으로 전환. 이렇게 하면 permission_joins의 13 LEFT JOIN이 제거됨.
• 인증 결과의 request-level 캐싱: 동일 요청 내에서 set_level과 본 쿼리가 각각 Cognito/permission을 중복 계산하지 않도록 request context에 캐싱.

Monitoring#

• ES 쿼리 duration을 custom metric으로 추가:

service:cupixworks-api resource_name:"Api::V1::SketchesController#index" @http.status_code:200 @duration:>500ms

• Cognito cache hit/miss 비율 모니터링:

service:cupixworks-api @message:"Cognito cache" @cache_status:(hit OR miss)

• set_level 소요 시간 분리 계측:

service:cupixworks-api @class:"SketchesController" @method:"set_level" @duration:>100ms

Risk Assessment#

• Risk level: medium
• 예상 복잡도: standard — set_level 경량화는 단순 변경이나, permission 아키텍처 전환은 대규모 리팩토링 필요