ES /docs

Api::V1::EditingEntitiesController#index (avg 1046ms, max 1174ms)

RCA: EditingEntitiesController#index Latency (avg 1046ms)

Overview#

What Happened#

2026-05-26 03:33~12:40 UTC 사이 Api::V1::EditingEntitiesController#index 엔드포인트에서 평균 1046ms, 최대 1265ms의 높은 응답 시간이 전 리전(eu-central-1, us-west-2, ap-southeast-1, ap-southeast-2, ap-northeast-1)에서 36회 감지되었다. 500ms 이상의 응답 시간이 지속적으로 관찰되었으며, 최대 스파이크는 13.96초까지 달하는 사례도 있었다.

Quick Facts#

Field Value
resource_name Api::V1::EditingEntitiesController#index
top_frame app/repositories/editing_entity_repository.rb:83
env production (eu-central-1, us-west-2, ap-southeast-1, ap-southeast-2, ap-northeast-1)
avg_duration 1046ms
max_duration 1265ms (cluster), 13.96s (Datadog max metric)

Timeline#

  1. 2026-05-26T03:33:17Z — 최초 500ms 이상 응답 감지
  2. 2026-05-26T12:40:20Z — 마지막 감지 (클러스터 기준)
  3. 2026-05-27 — RCA 분석 완료

Error Log#

Datadog Logs

json
{
  "resource_name": "Api::V1::EditingEntitiesController#index",
  "service": "cupixworks-api",
  "occurrences": 12,
  "avg_ms": 1046,
  "max_ms": 1174,
  "sample_trace_id": "4290164470718717421"
}

Impact#

  • Service: cupixworks-api
  • 발생 횟수: 36
  • 최초 발생: 2026-05-26T03:33:17.380Z
  • 최근 발생: 2026-05-26T12:40:20.583Z
  • 영향 범위: 전 리전(5개) editing entity 목록을 조회하는 모든 사용자

Root Cause Summary#

EditingEntitiesController#index의 높은 응답 시간은 3단계 쿼리 파이프라인의 누적 비용에 기인한다: (1) Elasticsearch 검색에서 복잡한 bool 필터(cycle_state, purged_at, trashed_at 조건)를 포함한 쿼리 실행, (2) ES 결과의 ID 목록으로 PostgreSQL에서 5개 LEFT JOIN(level, record, editing, category, workarea)과 함께 레코드 재조회, (3) 시리얼라이제이션 시 각 엔티티의 association마다 fetch_cache로 Redis를 개별 조회(최대 30 * 6 = 180회). EditingEntity 모델은 cachable?false로 설정되어 자체 캐시가 쓰여지지 않으며, 관련 레코드의 Redis 캐시 미스 시 DB fallback(find_by_id)이 발생하여 응답 시간이 추가로 증가한다.

Technical Analysis#

Code Path#

  • Entry point: app/controllers/api/v1/editing_entities_controller.rb:8
  • ES query construction: lib/cupix/query_option/editing_entity.rb:12lib/cupix/query_option/base.rb:22
  • ES search execution: app/repositories/editing_entity_repository.rb:83
  • DB reload with joins: app/repositories/base_repository.rb:75
  • Serialization with cache lookups: app/controllers/concerns/renderable_controller.rb:90
  • Cache fetch per association: app/models/application_record.rb:84

1단계: ES 쿼리 (editing_entity_repository.rb)

app/repositories/editing_entity_repository.rb:83-88ruby
response = ::EditingEntity.search(
  self.query_option.serializable_hash
).paginate(
  per_page: self.query_option.per_page,
  page: self.query_option.page
)

per_page 기본값은 30개. ES 쿼리는 cycle_state_filter, draft_creation_filter, default_model_filter 등 다수의 bool 조건을 포함한다.

2단계: DB LEFT JOIN 재조회 (base_repository.rb)

app/repositories/base_repository.rb:75-81ruby
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?)
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
app/repositories/editing_entity_repository.rb:98-99ruby
def default_joins(record)
  record.left_joins(:level, :record, :editing, :category, :workarea)
end

ES에서 반환된 ID로 PostgreSQL에서 5개 테이블을 LEFT JOIN하여 다시 조회한다. permission_joinsEditingEntity의 경우 no-op이므로 권한 확인 오버헤드는 없으나, LEFT JOIN 자체가 비용이다.

3단계: 시리얼라이제이션 시 Redis 개별 조회 (application_record.rb)

app/models/application_record.rb:81-95ruby
def belongs_to(name, scope = nil, **options)
  super

  define_method "_#{name}" do |*args, **kwargs, &block|
    if options[:polymorphic]
      fetch_cache(send("#{name}_type"), send("#{name}_id")).merge({
        type: send("#{name}_type")
      }) rescue nil
    else
      model_name = options[:class_name] || name
      model_id = options[:foreign_key] || "#{name}_id"
      fetch_cache(model_name.to_s.classify, send(model_id))
    end
  end
end

EditingEntitySerializer_record, _level, _category, _workarea, _editing, _entity (polymorphic) 6개 attribute를 사용한다. 각각 fetch_cache를 호출하여 Redis에서 캐시를 조회하며, 캐시 미스 시 find_by_id + serialized_json으로 DB fallback이 발생한다.

app/models/concerns/cachable.rb:58-69ruby
def fetch_cache(model_name = self.class.name, model_id = self.id)
  return nil if model_id.blank?

  Rails.cache.fetch(cache_key(model_name, model_id), skip_nil: true, expires_in: self.class.cache_expires_in) do
    if self.respond_to?("serialized_#{model_name.underscore}_json".to_sym)
      self.send("serialized_#{model_name.underscore}_json")
    else
      record = model_name.constantize.find_by_id(model_id)

      record.serialized_json if record.respond_to?(:serialized_json)
    end
  end
end

30개 엔티티 × 6개 association = 최대 180회 Redis 조회. 캐시 미스 비율이 높으면 DB fallback으로 latency가 크게 증가한다.

Log Evidence#

Datadog APM 메트릭 조회:

text
avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::editingentitiescontroller_index}.rollup(avg,3600)

24시간 hourly average 결과 (일부 발췌, 단위: 초):

text
03:00 UTC — 0.410s
09:00 UTC — 0.342s
12:00 UTC — 0.240s
13:00 UTC — 0.554s  ← peak average hour
18:00 UTC — 0.434s
19:00 UTC — 0.834s  ← highest hourly average

Max duration 메트릭에서 확인된 스파이크:

text
max:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::editingentitiescontroller_index}

주요 스파이크 (단위: 초):

text
1779768000 (12:00 UTC) — 2.83s
1779759900 (09:45 UTC) — 3.17s
1779762300 (10:25 UTC) — 4.11s
1779793200 (18:40 UTC) — 5.77s
1779796800 (19:40 UTC) — 6.35s
1779798300 (20:05 UTC) — 13.96s

관련 info 로그 확인 (모두 200 응답):

text
[200] GET /api/v1/editing_entities (Api::V1::EditingEntitiesController#index)

Elasticsearch 에러, DB connection 에러 로그: 해당 시간대 0건 확인됨.

Hypotheses Considered#

# Hypothesis Evidence for Evidence against Verdict
H1 다단계 쿼리 파이프라인(ES→DB JOIN→Redis cache)의 누적 비용이 latency를 유발 APM 메트릭에서 전 리전 일관된 500ms+ 패턴 확인; 코드 분석에서 ES 쿼리 + 5개 LEFT JOIN + 최대 180회 Redis 조회 확인; cachable? = false Confirmed
H2 Elasticsearch 과부하 또는 circuit breaker 코드에 429 에러 핸들링 존재 (base_repository.rb:88) 해당 기간 ES error 로그 0건; 별도 에러 없이 200 응답 반환 Rejected
H3 PostgreSQL connection pool 고갈 고부하 시 connection wait 가능성 ActiveRecord::ConnectionTimeoutError / PG::ConnectionBad 로그 0건 Rejected
H4 특정 리전의 네트워크 지연 일부 리전에서 더 높을 수 있음 5개 전체 리전에서 동일하게 발생 — 단일 리전 이슈 아님 Rejected

Fix Recommendation#

즉시 조치 (Critical)#

  • app/repositories/editing_entity_repository.rb:98-99: default_joins에서 5개 LEFT JOIN을 수행하는데, 시리얼라이제이션이 Redis 캐시(_record, _level 등)를 사용하므로 이 JOIN은 불필요하다. permission_joins도 no-op이므로 default_joins를 제거하거나 최소화하여 DB 쿼리 비용을 줄인다.

단기 개선 (1주 이내)#

  • Redis cache warming: EditingEntitycachable?true로 변경하거나, 시리얼라이제이션 전에 관련 레코드들을 batch로 preload하여 N+1 Redis 호출을 줄인다.
  • Eager loading 패턴 도입: _record, _level 등을 개별 fetch_cache가 아닌 mget(Redis multi-get)으로 한 번에 조회하는 방식으로 변경.
  • per_page 제한 검토: 클라이언트가 불필요하게 큰 per_page를 요청하지 않도록 기본값(30)이 적절한지 확인하고, 필요 시 클라이언트별 요구사항에 맞게 조정.

장기 개선 (재발 방지)#

  • Query pipeline 최적화: ES → DB → Redis 3단계를 ES → Redis(batch)로 줄이거나, ES 결과에 필요한 필드를 이미 포함(_source)시켜 DB 재조회를 제거하는 아키텍처 변경 검토.
  • APM span breakdown 도입: 각 단계(ES query, DB load, serialization)의 개별 span을 Datadog APM에 추가하여 병목 지점을 실시간으로 모니터링.

Monitoring#

  • P95/P99 latency 알림: avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::editingentitiescontroller_index} > 1.0
  • Max duration 알림: max:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::editingentitiescontroller_index} > 5.0
  • Redis cache hit rate 모니터링:
text
avg:trace.redis.command.hits{service:cupixworks-api} / avg:trace.redis.command.total{service:cupixworks-api}

Risk Assessment#

  • Risk level: medium
  • 예상 복잡도: standard
  • 사용자 영향: editing entity 목록 조회 시 1초 이상의 응답 지연. 기능 장애는 아니나 UX 저하 유발.