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#
- 2026-05-26T03:33:17Z — 최초 500ms 이상 응답 감지
- 2026-05-26T12:40:20Z — 마지막 감지 (클러스터 기준)
- 2026-05-27 — RCA 분석 완료
Error Log#
{
"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:12→lib/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)
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)
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
def default_joins(record)
record.left_joins(:level, :record, :editing, :category, :workarea)
end
ES에서 반환된 ID로 PostgreSQL에서 5개 테이블을 LEFT JOIN하여 다시 조회한다. permission_joins는 EditingEntity의 경우 no-op이므로 권한 확인 오버헤드는 없으나, LEFT JOIN 자체가 비용이다.
3단계: 시리얼라이제이션 시 Redis 개별 조회 (application_record.rb)
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이 발생한다.
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 메트릭 조회:
avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::editingentitiescontroller_index}.rollup(avg,3600)
24시간 hourly average 결과 (일부 발췌, 단위: 초):
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 메트릭에서 확인된 스파이크:
max:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::editingentitiescontroller_index}
주요 스파이크 (단위: 초):
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 응답):
[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:
EditingEntity의cachable?를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 모니터링:
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 저하 유발.