RCA: EditingsController#list_editing_entities Latency (avg 1055ms)

Overview#

What Happened#

2026-05-26 06:34~11:02 UTC 사이 cupixworks-api 서비스의 Api::V1::Admin::EditingsController#list_editing_entities 엔드포인트에서 평균 1055ms, 최대 1099ms의 응답 지연이 발생했다. Datadog 로그 분석 결과, 해당 시간대에 500ms 이상 지연된 요청이 74건 확인되었으며, 특히 ap-southeast-2 리전에 집중되었다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-05-26T06:34:40Z — 최초 지연 감지 (1060ms, ap-southeast-2)
2. 2026-05-26T11:02:01Z — 마지막 지연 발생
3. 2026-05-27 — RCA 수행

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::Admin::EditingsController#list_editing_entities",
  "service": "cupixworks-api",
  "occurrences": 3,
  "avg_ms": 1055,
  "max_ms": 1099,
  "sample_trace_id": "7765153272627207643"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 74건 (500ms 초과), 클러스터 기준 3건 (1000ms 초과)
• 최초 발생: 2026-05-26T06:34:40.504Z
• 최근 발생: 2026-05-26T11:02:01.534Z

Root Cause Summary#

list_editing_entities 엔드포인트의 serialization 과정에서 각 EditingEntity 레코드마다 6개 association (record, level, category, workarea, editing, entity)에 대해 개별 Redis fetch_cache 호출이 발생한다. DB 시간은 평균 37ms에 불과하지만, 총 응답 시간과의 차이(600~1100ms)는 Redis cache lookup 및 cache miss 시 개별 SQL 쿼리가 누적된 결과이다. left_joins가 사용되지만 이는 데이터를 메모리에 preload하지 않으므로, serialization 시점에 association 데이터가 없어 매번 캐시/DB를 조회하게 된다. ap-southeast-2 리전에 집중된 이유는 해당 리전의 Redis 지연 또는 cache miss 비율이 높기 때문으로 추정된다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/concerns/has_editing_entity_controller.rb:7
• Elasticsearch 검색: app/repositories/editing_entity_repository.rb:83-88
• SQL 로드 + left_joins: app/repositories/base_repository.rb:75-81 → editing_entity_repository.rb:98-99
• Serialization: app/serializers/editing_entity_serializer.rb:8-13
• Cache fetch per association: app/models/concerns/cachable.rb:58-69

1. Controller action — Elasticsearch 쿼리 시작

def list_editing_entities
  editing_entity_query_option = Cupix::QueryOption::EditingEntity.new(get_query_option(enable_current_team: false), params)
  editing_entity_query_option.editing_ids = [@model.id]
  editing_entities = ::EditingEntityRepository.new(current_user: current_user).search(editing_entity_query_option)

  render_api Renderable.new({
    search_result: editing_entities,
    is_collection: true,
    serializer: EditingEntitySerializer,
    serializer_option: {
      fields: {
        editing_entity: @fields
      }
    }
  })
end

2. Repository — Elasticsearch 검색 후 SQL로 레코드 로드

def search(query_option = nil)
  _search(query_option)

  begin
    # ...
    contents = self.class.permission_joins(self.class.default_joins(self.response.records), self.current_user, skip_join: _skip_join?)
    # ...
  end

  SearchResult.new({
    contents: contents.records,
    # ...
  })
end

3. default_joins — left_joins는 preload하지 않음 (핵심 병목)

def default_joins(record)
  record.left_joins(:level, :record, :editing, :category, :workarea)
end

left_joins는 SQL JOIN만 수행하고 ActiveRecord association 캐시에 데이터를 적재하지 않는다. 따라서 serialization 시점에 각 association 접근 시 다시 개별 조회가 필요하다.

4. Serializer — 레코드당 6회 cache fetch

class EditingEntitySerializer
  include CupixSerializer

  attribute :id
  attribute :record, &:_record
  attribute :level, &:_level
  attribute :category, &:_category
  attribute :workarea, &:_workarea
  attribute :editing, &:_editing
  attribute :entity, &:_entity
  # ...
end

각 _record, _level 등은 fetch_cache를 호출한다.

5. fetch_cache — Redis miss 시 개별 SQL 실행

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

per_page=300일 때 최대 1800회 Redis 조회 (300 레코드 x 6 associations). Cache miss 시 각각 개별 SQL 쿼리 발생.

Log Evidence#

사용한 Datadog 쿼리:

service:cupixworks-api "list_editing_entities" @duration:>500

74건의 slow request 중 대표 로그 (최고 지연):

{
  "timestamp": "2026-05-26T06:56:52Z",
  "duration_ms": 1117.83,
  "db_ms": 16.18,
  "view_ms": 0.24,
  "region": "ap-southeast-2",
  "host": "ip-10-1-145-251.ap-southeast-2",
  "user": "digitexx+mason@cupix.io",
  "params": {"per_page": "300", "id": "189745", "fields": ["id", "entity", "editing"]},
  "user_agent": "Retool/2.0"
}

핵심 패턴 — 총 응답 시간 대비 DB/View 시간이 극히 작음:

Duration: 1117.83ms | DB: 16.18ms | View: 0.24ms | Unaccounted: ~1101ms
Duration: 1097.50ms | DB: 44.39ms | View: N/A   | Unaccounted: ~1053ms
Duration: 1077.42ms | DB: 181.66ms| View: N/A   | Unaccounted: ~896ms
Duration: 1060.17ms | DB: 42.88ms | View: N/A   | Unaccounted: ~1017ms

리전 분포:

ap-southeast-2: 57건 (77%)
us-west-2:      13건 (18%)
eu-central-1:    4건 (5%)

73/74건이 Retool/2.0 User-Agent — Admin 대시보드 폴링에 의한 반복 호출.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• app/repositories/editing_entity_repository.rb:98-99 — left_joins를 includes 또는 preload로 변경하여 association 데이터를 batch로 preload
• 이렇게 하면 serialization 시 fetch_cache 호출 시점에 이미 메모리에 로드된 association을 사용하거나, 최소한 batch SQL(6건)로 처리됨

단기 개선 (1주 이내)#

• Serializer에서 _record, _level 등 cache method 대신 preload된 association을 직접 사용하는 경로 추가. 이미 includes로 로드된 경우 Redis를 거치지 않도록 분기 처리
• Retool 대시보드의 per_page=300 설정을 적절한 값(30~50)으로 제한하거나, 필요한 fields만 요청하도록 조정

장기 개선 (재발 방지)#

• BaseRepository#search 패턴 전반에서 left_joins 사용을 검토하여, preload가 필요한 경우 includes로 교체
• Elasticsearch index에 이미 serialized 데이터가 포함되어 있으므로, admin 조회 시 ES 응답을 직접 반환하는 경로 추가를 검토 (SQL round-trip 제거)

Monitoring#

• list_editing_entities 엔드포인트 p95 latency 추적:

service:cupixworks-api resource_name:"Api::V1::Admin::EditingsController#list_editing_entities" @duration:>500ms

• Redis fetch_cache hit/miss ratio 모니터링 (특히 ap-southeast-2)
• Retool 폴링 빈도 확인 및 rate limit 고려

Risk Assessment#

• Risk level: low
• 예상 복잡도: standard — left_joins를 includes로 변경하는 것은 단순하나, serializer의 cache 경로와의 상호작용을 테스트해야 함