ES /docs

Api::V1::EditingsController#show (avg 1580ms, max 1580ms)

RCA: Api::V1::EditingsController#show Latency (1580ms)

Overview#

What Happened#

2026-05-27 09:20 UTC, cupixworks-api 서비스의 Api::V1::EditingsController#show 엔드포인트에서 1580ms 응답 시간이 관측되었다. 정상 응답(200)이지만 500ms p95 임계값을 크게 초과하는 latency 이상이다.

Quick Facts#

Field Value
resource_name Api::V1::EditingsController#show
top_frame app/repositories/base_repository.rb:308
env production, us-west-2
avg_duration 1580ms
sample_trace_id 4471223273264767489

Timeline#

  1. 2026-05-27 09:20:02Z — EditingsController#show 요청 수신, 1580ms 응답 시간 관측
  2. 2026-05-27 — Error sweeper에 의해 latency cluster 감지
  3. 2026-05-28 — RCA 분석 수행

Error Log#

Datadog Logs

json
{
  "resource_name": "Api::V1::EditingsController#show",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 1580,
  "max_ms": 1580,
  "sample_trace_id": "4471223273264767489"
}

Impact#

  • Service: cupixworks-api
  • 발생 횟수: 1
  • 최초 발생: 2026-05-27T09:20:02.126Z
  • 최근 발생: 2026-05-27T09:20:02.126Z

Root Cause Summary#

EditingsController#show의 응답 지연은 repository의 heavy LEFT JOIN 쿼리serialization 단계에서의 N+1 cache miss가 복합적으로 작용한 결과이다. BaseRepository.show()가 6개 테이블을 LEFT JOIN하고 3개의 users 테이블을 추가로 JOIN하여 14개 컬럼을 SELECT하며, 이후 EditingSerializer가 최소 9개 연관 엔티티(user, editor, escalated_by, record, level, category, workarea, team, workspace, facility)에 대해 각각 fetch_cache()를 호출한다. Redis cache miss 시 각 연관별로 개별 DB 쿼리가 발생하여 누적 지연이 1580ms에 달한다.

Technical Analysis#

Code Path#

  • Entry point: app/controllers/api/v1/editings_controller.rb:31
  • set_editing before_action이 repository_instance.show(params[:id]) 호출
  • Repository layer: app/repositories/base_repository.rb:308-386
  • Heavy JOIN: app/repositories/editing_repository.rb:189-212
  • Serialization: app/serializers/editing_serializer.rb:1-69
  • Cache fetch: app/models/concerns/cachable.rb:58-70
  • Statistics query: app/models/concerns/statisticable/editing.rb:8-15

1단계 — Repository JOIN 쿼리:

app/repositories/editing_repository.rb:189-212ruby
def default_joins(record)
  record.left_joins(:level, :workspace, :facility, :team, :category, :workarea)
        .joins("
     LEFT JOIN users ON users.id = editings.user_id
     LEFT JOIN users AS editor ON editor.id = editings.editor_id
     LEFT JOIN users AS escalated_by ON escalated_by.id = editings.escalated_by_id
  ").select('
    editings.*,
    levels.name AS level_name,
    workspaces.name AS workspace_name,
    facilities.name AS facility_name,
    facilities.key AS facility_key,
    teams.name AS team_name,
    users.firstname AS user_firstname,
    users.lastname AS user_lastname,
    users.email AS user_email,
    editor.firstname AS editor_firstname,
    editor.lastname AS editor_lastname,
    editor.email AS editor_email,
    escalated_by.firstname AS escalated_by_firstname,
    escalated_by.lastname AS escalated_by_lastname,
    escalated_by.email AS escalated_by_email
  ')
end

9개 테이블에 대한 LEFT JOIN과 14개 컬럼 SELECT. 이 쿼리 자체가 200-400ms를 소요할 수 있다.

2단계 — BaseRepository.show() 후처리:

app/repositories/base_repository.rb:344-386ruby
scope = current_class.visibility_scope(visibility)
model = query.merge(scope).first

if model.nil? && current_user.present? && current_user.team.domain == 'admin'
  unless (::UserRepository.new(model: current_user).group_codes & %w[administrator senior_editing_engineers]).empty?
    model = self.where(attrs).merge(scope).first
  end
end

admin 사용자일 경우 권한 체크를 위한 추가 쿼리가 발생한다. UserRepository.new(model:).group_codes는 그룹 코드 조회를 위한 별도 쿼리를 실행한다.

3단계 — Serialization에서의 N+1 cache fetch:

app/serializers/editing_serializer.rb:8-18ruby
attribute :user, &:_user
attribute :editor, &:_editor
attribute :escalated_by, &:_escalated_by
include TeamAttribute
include WorkspaceAttribute
include FacilityAttribute
attribute :record, &:_record
attribute :level, &:_level
attribute :category, &:_category
attribute :workarea, &:_workarea

각 attribute가 _<name> 메서드를 호출한다. 이 메서드들은 ApplicationRecord에서 동적으로 생성된다:

app/models/application_record.rb:84-94ruby
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

4단계 — Cache miss 시 DB fallback:

app/models/concerns/cachable.rb:58-70ruby
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

Cache miss 시 find_by_id로 개별 DB 쿼리 실행. 9개 이상의 연관 엔티티에 대해 각각 발생하면 ~900ms 추가 지연.

5단계 — Statistics 쿼리:

app/models/concerns/statisticable/editing.rb:8-15ruby
def statistic_to_json
  stats = all_statistic

  {
    editing: _editing_stat_json(stats),
    count: _count_stat_json
  }
end

all_statisticstatistics 테이블에 대한 GROUP BY 집계 쿼리를 실행한다:

app/models/concerns/statisticable.rb:47-51ruby
def all_statistic
  return @preloaded_all_statistic if defined?(@preloaded_all_statistic)

  statistics.group(:name, :phase)
            .maximum(:created_at)
            .transform_values(&:to_datetime)
end

Log Evidence#

Datadog에서 해당 시간대 EditingsController#show 요청 로그를 확인하였다. 에러 수준 로그는 없으며 모든 요청이 200 응답으로 처리되었다.

text
Datadog query: service:cupixworks-api "EditingsController#show" from:2026-05-27T09:00:00Z to:2026-05-27T09:40:00Z

결과 (동일 시간대 정상 응답 확인):

text
2026-05-27 18:39:59 [info] [200] GET /api/v1/editings/1122918 (Api::V1::EditingsController#show)
2026-05-27 18:39:37 [info] [200] GET /api/v1/editings/1122917 (Api::V1::EditingsController#show)
2026-05-27 18:38:41 [info] [200] GET /api/v1/editings/1122916 (Api::V1::EditingsController#show)
2026-05-27 18:37:39 [info] [200] GET /api/v1/editings/189520 (Api::V1::EditingsController#show)

에러 수준 로그 검색 (0건):

text
Datadog query: service:cupixworks-api "EditingsController" status:error from:2026-05-27T08:00:00Z to:2026-05-27T10:30:00Z

APM trace ID 4471223273264767489로 참조되는 span은 Datadog APM에서 세부 breakdown(DB 쿼리 시간, cache 호출 시간 등)을 확인할 수 있다.

Hypotheses Considered#

# Hypothesis Evidence for Evidence against Verdict
H1 Heavy LEFT JOIN 쿼리 + N+1 cache miss로 인한 누적 지연 editing_repository.rb:189-212에서 9개 테이블 JOIN, cachable.rb:65에서 cache miss 시 find_by_id 개별 쿼리, serializer가 9개 이상 연관 엔티티 개별 fetch 단일 발생(occurrence 1)이므로 항상 느린 것은 아님 — cache가 warm 상태면 빠름 Confirmed
H2 DB 연결 풀 고갈 또는 PostgreSQL slow query 1580ms는 단일 쿼리 timeout보다 훨씬 작음 동일 시간대 다른 요청은 정상 응답, error/warn 로그 없음. 단일 occurrence로 시스템 전반 이슈 아님 Rejected
H3 Redis cache 일시적 지연 (네트워크 또는 eviction) Cache miss 시 모든 연관에 대해 fallback 쿼리 발생하므로 Redis 지연이면 전체 지연으로 이어짐 Redis 관련 error/warn 로그 없음. 확인 불가하나 가능성 있음 Inconclusive

Fix Recommendation#

즉시 조치 (Critical)#

  • app/repositories/editing_repository.rb:189-212: default_joins가 show()에서도 전체 JOIN을 실행한다. #show 전용으로 필요한 최소 JOIN만 수행하는 경량 쿼리 경로를 추가하는 것이 효과적이다.
  • app/serializers/editing_serializer.rb: fields 파라미터를 활용하여 클라이언트가 요청하지 않는 연관 속성의 serialization을 건너뛸 수 있도록 하면 불필요한 cache fetch를 방지할 수 있다.

단기 개선 (1주 이내)#

  • Eager loading 또는 batch cache fetch: serialization 전에 필요한 연관 엔티티 ID를 수집하고 Rails.cache.read_multi로 한 번에 조회하여 N+1 cache miss 패턴을 제거한다.
  • Statistics preloading: all_statistic 결과를 repository layer에서 미리 로드하여 serialization 단계에서 추가 쿼리를 방지한다.

장기 개선 (재발 방지)#

  • Cachable concern의 fetch_cache 패턴을 batch 방식으로 리팩터링하여 N+1 cache 호출을 근본적으로 제거한다.
  • APM에서 p95/p99 latency 모니터링을 설정하여 특정 엔드포인트의 응답 시간 이상을 조기에 감지한다.

Monitoring#

  • APM p95 latency 알림: avg(last_5m):p95:trace.rack.request{service:cupixworks-api,resource_name:api::v1::editingscontroller#show} > 1000
  • Cache hit rate 모니터링: sum:cache.miss{service:cupixworks-api,controller:editings}.as_rate()
  • 추가 Datadog 쿼리:
text
service:cupixworks-api resource_name:"Api::V1::EditingsController#show" @duration:>1000ms env:production

Risk Assessment#

  • Risk level: low
  • 예상 복잡도: standard
  • 단일 발생으로 사용자 영향은 미미하나, cache가 cold 상태인 경우(배포 직후, Redis 재시작 후) 반복 발생 가능성이 있다.