ES /docs

Api::V1::AssetsController#index (avg 1507ms, max 2528ms)

RCA: Api::V1::AssetsController#index Latency

Overview#

What Happened#

2026-05-26 03:32 ~ 12:31 UTC 동안 cupixworks-api 서비스의 Api::V1::AssetsController#index 엔드포인트에서 평균 1457ms, 최대 3782ms의 높은 응답 시간이 43건 관측되었다. 5개 리전(ap-southeast-2, us-west-2, ap-southeast-1, eu-central-1, ap-northeast-1) 전체에서 발생하여 글로벌 이슈로 확인된다.

Quick Facts#

Field Value
resource_name Api::V1::AssetsController#index
top_frame app/repositories/asset_repository.rb:271
env production (ap-southeast-2, us-west-2, ap-southeast-1, eu-central-1, ap-northeast-1)

Timeline#

  1. 2026-05-26 03:32 UTC — 최초 slow trace 감지 (>500ms threshold)
  2. 2026-05-26 12:31 UTC — 마지막 slow trace 기록
  3. 2026-05-27 — RCA 분석 완료

Error Log#

Datadog Logs

json
{
  "resource_name": "Api::V1::AssetsController#index",
  "service": "cupixworks-api",
  "occurrences": 19,
  "avg_ms": 1507,
  "max_ms": 2528,
  "sample_trace_id": "891803863076975420"
}

Impact#

  • Service: cupixworks-api
  • 발생 횟수: 43
  • 최초 발생: 2026-05-26T03:32:30.031Z
  • 최근 발생: 2026-05-26T12:31:35.480Z
  • 영향 범위: 5개 production 리전의 asset 목록 조회 API 사용자 전체. review 기반 asset 조회 시 응답 지연으로 UX 저하.

Root Cause Summary#

AssetsController#index의 review 기반 조회 경로에서 ReviewRepository._capture_ids 호출 시 Redis 캐시 miss가 빈번하게 발생하여 latency가 급증했다. 캐시 키에 포함된 facility.entity_updates_hexdigest가 facility 내 10개 엔티티 타입(level, capture, record 등) 중 하나라도 업데이트되면 변경되어, 활성 facility에서 캐시가 사실상 무효화된다. 캐시 miss 시 _level_ids → _record_ids → accessible_captures (ES query, size: 10000) → _capture_ids 순서로 3회의 Elasticsearch 쿼리가 순차 실행되고, 이후 permission_joins에서 9개의 LEFT JOIN + GROUP BY를 포함한 복잡한 SQL이 실행되어 총 latency가 1-3초에 달한다.

Technical Analysis#

Code Path#

  1. Entry point: app/controllers/api/v1/assets_controller.rb:15-25 — index 액션이 repository_instance.search를 호출
app/controllers/api/v1/assets_controller.rb:15-25ruby
def index
  assets = repository_instance.search(
    Cupix::QueryOption::Asset.new(get_query_option, params)
  )

  render_api Renderable.new(
    search_result: assets,
    is_collection: true,
    serializer_option: @serializer_option
  )
end
  1. BaseRepository.search: app/repositories/base_repository.rb:70-112 — _search 호출 후 permission_joins + default_joins 적용
app/repositories/base_repository.rb:70-81ruby
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.review_id.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?)
    # ...
  end
end
  1. AssetRepository._search (핵심 병목): app/repositories/asset_repository.rb:262-274 — review가 있으면 ReviewRepository._capture_ids를 호출하여 ES terms 쿼리에 사용
app/repositories/asset_repository.rb:262-274ruby
elsif review.present?
  self.query_option.query[:bool][:must] += [
    {
      term: {
        "assetable.type": 'Capture'
      }
    },
    {
      terms: {
        "assetable.id": ReviewRepository.new(model: review)._capture_ids
      }
    }
  ]
end
  1. 캐시 키 생성: app/repositories/concerns/cachable_repository/review.rb:90-103 — facility.entity_updates_hexdigest가 캐시 키에 포함됨
app/repositories/concerns/cachable_repository/review.rb:90-103ruby
def cache_key(cache_type)
  default_key = {
    self: {
      id: model.id,
      class: model.class.name,
      updated_at: model.updated_at
    },
    cache: cache_type,
    facility_hex_digest: model.facility.entity_updates_hexdigest
  }
  default_key.merge!({ drafted_at: model.drafted_at }) if model.marked_as_draft?

  default_key
end
  1. entity_updates_hexdigest 계산: app/models/concerns/entity_updates.rb:25-27 — 10개 엔티티의 최신 updated_at을 합산한 SHA1 해시
app/models/concerns/entity_updates.rb:10-27ruby
def entity_updates
  Rails.cache.fetch(entity_updates_cache_key, expires_in: DEFAULT_ATTRIBUTE_CACHE_EXPIRES_IN) do
    entities.each_with_object({}) do |entity, hash|
      hash[entity] =
        begin
          entity.to_s.classify.safe_constantize.where(self.class.name.downcase => self).order(:updated_at).last.try(:updated_at)
        rescue StandardError
          nil
        end
      hash
    end
  end
end

def entity_updates_hexdigest
  Digest::SHA1.hexdigest(entity_updates.to_s)
end
  1. 캐시 miss 시 실행 경로: _capture_ids → accessible_captures → 3회 ES query (level, record, capture 각각 size: 10000) → capture IDs 수집
app/repositories/concerns/accessible_entities_repository/review.rb:124-155ruby
def accessible_captures(level_ids: nil, record_ids: nil, visibility: Cyclable.visibility[:UNTRASHED])
  raise Cupix::Errors::PermissionDenied.new(code: 'PERM10000', reason: 'Permission denied') if @current_user.present? && !@model.readable_by?(@current_user)

  query_option = Cupix::QueryOption::Capture.new(visibility: visibility)
  # ... facility filter, level_ids filter, record_ids filter ...

  search_results = ::Capture.search(query_option.serializable_hash.merge(size: 10000)).records
  Cupix::Logger.info("accessible_entity_count: #{search_results.results.size}", class: self.class.name, function: __method__)
  search_results
end
  1. permission_joins (SQL 병목): app/repositories/asset_repository.rb:73-217 — 9개의 LEFT JOIN subquery로 권한 계산
app/repositories/asset_repository.rb:55-71ruby
def self.default_joins(record)
  record.includes(:child_assets, :storage).joins("
    LEFT JOIN workspaces ON workspaces.id = assets.workspace_id
    LEFT JOIN users ON users.id = assets.user_id
    LEFT JOIN teams ON teams.id = assets.team_id
    LEFT JOIN captures ON captures.id = assets.assetable_id AND assets.assetable_type = 'Capture'
  ").select('
    assets.*,
    workspaces.name AS workspace_name,
    users.firstname AS user_firstname,
    users.lastname AS user_lastname,
    users.email AS user_email,
    teams.name AS team_name,
    captures.level_id AS capture_level_id,
    captures.record_id AS capture_record_id
  ')
end

Log Evidence#

캐시 miss 로그 — review p8dwh3에서 6초 내 8회 cache flush 발생:

text
Datadog query: service:cupixworks-api "Flushing" "review p8dwh3" from 2026-05-26T12:57:00Z to 2026-05-26T12:58:00Z
text
2026-05-26 21:57:29 KST - Flushing level_ids on review p8dwh3 (ReviewRepository._level_ids)
2026-05-26 21:57:29 KST - Flushing record_ids on review p8dwh3 (ReviewRepository._record_ids)
2026-05-26 21:57:31 KST - Flushing capture_ids on review p8dwh3 (ReviewRepository._capture_ids)
2026-05-26 21:57:32 KST - Flushing annotation_layer_ids on review p8dwh3 (ReviewRepository._annotation_layer_ids)
2026-05-26 21:57:33 KST - Flushing capture_ids on review p8dwh3 (ReviewRepository._capture_ids)
2026-05-26 21:57:33 KST - Flushing floorplan_ids on review p8dwh3 (ReviewRepository._floorplan_ids)
2026-05-26 21:57:33 KST - Flushing capture_ids on review p8dwh3 (ReviewRepository._capture_ids)
2026-05-26 21:57:35 KST - Flushing capture_ids on review p8dwh3 (ReviewRepository._capture_ids)

review 7m19uw에서도 동일 패턴 (빈번한 접근 시 반복적 cache miss):

text
Datadog query: service:cupixworks-api "Flushing" "review 7m19uw" from 2026-05-26T12:53:00Z to 2026-05-26T12:55:30Z
text
2026-05-26 21:54:28 KST - Flushing capture_ids on review 7m19uw (ReviewRepository._capture_ids)
2026-05-26 21:55:15 KST - Flushing capture_ids on review 7m19uw (ReviewRepository._capture_ids)
2026-05-26 21:55:18 KST - Flushing capture_ids on review 7m19uw (ReviewRepository._capture_ids)

APM metric data (최근 4시간) — 간헐적으로 응답 시간이 1-2초로 치솟는 spike 패턴:

text
Datadog query: avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::assetscontroller_index}
text
Spike examples (seconds):
  2.054274, 2.066484, 1.881035, 1.622865, 1.608819, 1.583653, 1.389905, 1.377524, 1.363984, 1.346084
Normal baseline: 0.05-0.15 seconds

Hypotheses Considered#

# Hypothesis Evidence for Evidence against Verdict
H1 entity_updates_hexdigest 기반 캐시 키가 활성 facility에서 빈번하게 무효화되어 ES 쿼리 반복 실행 동일 review에 대해 수초 내 반복적 cache flush 로그 발생 (p8dwh3: 6초 내 8회); entity_updates는 10개 엔티티의 최신 updated_at을 집계하므로 활성 facility에서 거의 항상 변경됨 — Confirmed
H2 Elasticsearch 클러스터 자체의 성능 저하 (circuit breaker 등) — "Elasticsearch circuit breaker" 또는 "Bad Gateway" 에러 로그 0건; ES metric에 이상 없음 Rejected
H3 permission_joins의 9개 LEFT JOIN SQL이 단독으로 병목 DB 쿼리 자체가 복잡함 (9 subquery joins + GROUP BY) 캐시 hit 시 정상 응답 (50-150ms baseline); 병목은 캐시 miss로 인한 ES 쿼리 + SQL 조합에서 발생 Rejected (단독 원인 아님, 복합 요인)
H4 accessible_captures의 size: 10000 설정으로 대량 결과 반환 시 느림 실제 로그에서 capture count 1-6건으로 적음. 단, 대형 facility에서는 더 클 수 있음 현재 로그에서는 소규모 결과만 확인됨 Inconclusive

Fix Recommendation#

즉시 조치 (Critical)#

  • 파일: app/repositories/concerns/cachable_repository/review.rb:90-103
  • 방향: 캐시 키에서 facility_hex_digest 제거 또는 변경 빈도가 낮은 대안으로 교체. model.updated_at만으로도 review 자체의 변경을 감지할 수 있으며, facility-level 변경은 별도의 명시적 캐시 무효화 이벤트로 처리해야 한다.

단기 개선 (1주 이내)#

  • _capture_ids 호출 경로 최적화: asset_repository.rb:271에서 호출되는 ReviewRepository._capture_ids가 캐시 miss 시 _level_ids → _record_ids 순차 호출을 유발한다. 이 3단계 ES 쿼리 체인을 단일 ES 쿼리로 통합하거나, capture_ids를 review 모델에 직접 저장하는 materialized 접근 방식 검토.
  • entity_updates 계산 비용 절감: entity_updates.rb:12-16에서 10개 테이블에 ORDER BY updated_at DESC LIMIT 1 쿼리를 실행한다. 이를 DB trigger 또는 callback 기반 incremental update로 교체.

장기 개선 (재발 방지)#

  • Permission 모델 리팩토링: 9개 LEFT JOIN subquery 기반의 permission_joins를 materialized permission table이나 Redis 기반 permission bitmap으로 대체. 현재 구조는 record 수가 증가할수록 O(N * joins) 비용이 선형 증가한다.
  • Cache invalidation 전략 개선: facility 전체를 무효화하는 현재 방식 대신, 변경된 엔티티 타입에 한정한 selective invalidation 도입. 예: capture 추가 시 capture_ids 캐시만 무효화.

Monitoring#

  • _capture_ids cache hit ratio 모니터링 추가
  • 다음 Datadog 쿼리로 cache flush 빈도 추적:
text
service:cupixworks-api "Flushing capture_ids" | stats count by @review_key | top 10
  • APM duration spike 알림:
text
avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::assetscontroller_index} > 1.0

Risk Assessment#

  • Risk level: medium
  • 예상 복잡도: standard (캐시 키 변경은 간단하나 invalidation 정합성 검증 필요)