RCA: Api::V1::Admin::EditingsController#add_reviewer latency outlier (248s)

Overview#

What Happened#

2026-06-15 20:27 KST cupixworks-api 의 Api::V1::Admin::EditingsController#add_reviewer 엔드포인트에서 단일 요청이 약 248초 동안 실행된 latency outlier가 감지되었다 (APM 트레이스 9175273460483011690). 동일 시간대의 다른 add_reviewer 요청은 65–180ms 수준으로 정상이었고, 이 한 건만 평소 p99 대비 약 1,000배 이상 느렸다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-06-15 20:27 KST — APM trace 9175273460483011690 종료, 총 duration 248,065ms 기록 (cluster first_seen/last_seen).
2. 2026-06-15 20:28 KST — 동일 사용자(claire.lee@cupix.com, team_id=133)가 editing 1166083에 대해 add_reviewer 정상 호출 (65.83ms, db 19.21ms). 시스템은 직후 정상 복구되었다.
3. 2026-06-15 20:29~20:33 KST — 같은 윈도 내 다른 add_reviewer/Priority score calculated 로그 정상 발생. 동일 outlier 재현 없음.
4. 2026-06-15 (수집 시점) — error-sweeper collector 가 @duration:>threshold 쿼리로 슬로우 스팬 수집, latency 클러스터 생성.

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::Admin::EditingsController#add_reviewer",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 248065,
  "max_ms": 248065,
  "sample_trace_id": "9175273460483011690"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 1
• 최초 발생: 2026-06-15 20:27 KST
• 최근 발생: 2026-06-15 20:27 KST

영향 범위는 한 번의 admin Retool 호출 1건. 동일 사용자/엔드포인트의 후속 요청은 모두 정상이었으므로 사용자 차원의 지속적 장애는 아니다. 다만 add_reviewer 응답이 동기적으로 EditingPriorityScorer를 호출하므로 (아래 Code Path 참조), 재발 시 admin 운영툴이 멈추는 UX 이슈를 다시 만들 수 있다.

Root Cause Summary#

Api::V1::Admin::EditingsController#add_reviewer 는 reviewer 생성 직후 EditingPriorityScorer.new(editing_id, editor_id).call 을 동기적으로 호출하고, scorer는 editing_entities (includes(:entity)), team.entity_parameters 등 여러 association 을 추가 쿼리한다. 평상시에는 65–180ms 수준이지만, 이번 1건에 한해 약 248초가 소요되었다. 확정된 root cause는 식별되지 않았다 (uncertain — needs verification): 해당 trace id 에 해당하는 request completion log 가 Datadog 에 존재하지 않는데, 정상 종료 시 항상 기록되는 [NNN] PUT /api/v1/admin/editings/:id/add_reviewer 로그가 없다는 점은 Rails worker (Puma) 가 ALB/Puma worker timeout 또는 SIGKILL 로 응답을 마치지 못하고 종료되었음을 시사한다. 가장 유력한 가설은 EditingPriorityScorer 가 호출하는 association 쿼리(editing_entities 또는 team.entity_parameters) 중 하나가 lock contention/네트워크 hiccup/이상 데이터 분포로 인해 비정상적으로 오래 블록되었고, 이로 인해 동기 경로 전체가 정체되었다는 것이다. 다만 동시간대 DB 에러나 lock timeout 로그는 관찰되지 않아 확증할 수는 없다.

Technical Analysis#

Code Path#

Entry point: app/controllers/api/v1/admin/editings_controller.rb:1 (route PUT /api/v1/admin/editings/:id/add_reviewer → ReviewableController#add_reviewer).

Controller action 은 단순히 repository 의 add_reviewer 를 호출하고 결과를 직렬화한다:

def add_reviewer
  repository_instance.add_reviewer(params)
  render_api Renderable.new({
    contents: @model,
    serializer_option: @serializer_option
  })
end

Repository 에서 user lookup → reviewer create → 동기적으로 scorer 호출:

def add_reviewer(params)
  raise Cupix::Errors::Parameter.new(code: 'ARG10000', reason: 'user_id is required') if params[:user_id].nil?

  user = User.find_by(team: current_user.team, id: params[:user_id])

  raise Cupix::Errors::Parameter.new(code: 'ARG10001', reason: 'Reviewer not found') if user.blank?

  existing_reviewer = self.model.reviewers.find_by(user: user)
  return existing_reviewer if existing_reviewer

  self.model.reviewers.create!(user: user).tap do
    EditingPriorityScorer.new(editing_id: self.model.id, editor_id: user.id).call
  end
end

Scorer 는 생성자에서 Editing.find + User.find 후, call 에서 점수를 계산하고 update! 로 저장한다. 점수 계산 단계는 여러 association 을 추가 쿼리한다:

def initialize(editing_id:, editor_id: nil)
  @editing = ::Editing.find(editing_id)
  @editor = editor_id ? ::User.find(editor_id) : nil
end

def call
  return nil unless @editing.editing_type == 'normal'

  score = calculate
  return nil if score.nil?

  @editing.update!(priority_score: score)
  score
end

def pano_capture?
  captures = @editing.editing_entities
                     .where(entity_type: 'Capture')
                     .includes(:entity)
                     .map(&:entity)
                     .compact

  capture_type_ids = captures.map(&:capture_type_id).compact.uniq
  return false if capture_type_ids.empty?

  ::CaptureType.where(id: capture_type_ids, method: %w[singleshot multishot]).exists?
end

def pointcloud_entity?
  @editing.editing_entities.where(entity_type: 'Pointcloud').exists?
end

def paid_a_lot_score
  boost_param = @editing.team&.entity_parameters&.find { |ep| ep.name == 'editing_priority_boost' }
  boost_param&.value == 'true' ? PAID_A_LOT_SCORE : 0
end

기대 동작: 전체 경로가 짧은 SQL 몇 개 + editing.update! 로 100ms 이내 완료되어야 한다. 실제 동작: 이번 trace 한 건에서 248초가 소요됨. 어디서 시간이 소진되었는지는 스팬 상세를 보지 않으면 단정할 수 없다(uncertain — needs verification via APM trace span breakdown).

Failure point (most likely): scorer 내부의 동기 association 쿼리 또는 이어지는 @editing.update! 한 곳에서 외부 요인(lock/네트워크/이상 데이터)에 의해 블록되었을 것으로 추정.

Log Evidence#

사용한 Datadog 쿼리:

service:cupixworks-api "EditingsController" "add_reviewer"
service:cupixworks-api "9175273460483011690"
service:cupixworks-api "1166083"
service:cupixworks-api "Priority score"
service:cupixworks-api status:warn
service:cupixworks-api status:error
service:cupixworks-worker status:error

(시간 범위: 2026-06-15T11:20:00Z ~ 2026-06-15T11:35:00Z UTC, 그리고 now-14d 범위)

핵심 관찰 1 — 정상 add_reviewer (직후 호출) 의 duration:

{
  "@timestamp": "2026-06-15T11:28:10.347Z",
  "action": "add_reviewer",
  "controller": "Api::V1::Admin::EditingsController",
  "params": { "id": "1166083" },
  "user": { "email": "claire.lee@cupix.com", "id": 22893, "team": { "id": 133 } },
  "user_agent": "Retool/2.0 (+https://docs.tryretool.com/docs/apis)",
  "duration": 65.83,
  "view": 0.06,
  "db": 19.21,
  "http": { "status_code": 200, "method": "PUT" },
  "request_id": "1afd9150-e1d3-4020-bc97-6b0fb3bb0f73"
}

핵심 관찰 2 — 14일 범위에서 본 add_reviewer 요청 로그의 duration 분포 (top 20, ms 단위):

840.57, 182.81, 170.13, 122.87, 114.66, 112.03,
89.79, 87.24, 84.42, 84.19, 84.07, 83.32, 82.84,
81.52, 80.59, 78.21, 77.56, 77.10, 76.74, 74.88

→ 정상 p99 는 ~200ms 이내. 248,065ms 는 약 1,200x 이상 outlier.

핵심 관찰 3 — trace id 9175273460483011690 으로 직접 검색한 결과 0건:

Searching: service:cupixworks-api "9175273460483011690"
Time range: now-2h to now
Found 0 logs:

핵심 관찰 4 — 동시간대 (11:20–11:35 UTC) cupixworks-api status:error 0건. status:warn 은 Pointcloud NotFound - attributes_in_database 등 무관한 메시지. EditingPriorityScorer 가 정상 종료한 케이스의 "Priority score calculated" 로그는 11:26:24, 11:28:32, 11:29:00, 11:31:05 ... 등 정상 분포 — 이 한 건만 누락.

→ trace 의 request completion 로그가 없음 + p99 대비 압도적 outlier + 동시간대 다른 호출은 정상 = 일시적 환경 stall (worker timeout 으로 종료) 가능성을 시사. 단, DB lock/timeout 의 직접 증거는 로그에 없음 (uncertain — needs verification with APM span breakdown 또는 RDS performance insights).

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 추가 코드 변경 권장하지 않음 (occurrence_count=1, root cause 미확정). 대신 다음을 수행하여 재발 시 즉시 진단 가능하도록 한다:
  1. 운영자(요청자)는 Datadog APM 의 trace 9175273460483011690 span breakdown 을 열어, 어느 SQL/외부 호출에서 시간이 소진됐는지 확인. (RDS Performance Insights 에서 동일 시점 lock/long-running query 도 함께 확인)
  2. 해당 trace 의 editing_id 를 식별하면 Kibana 로 editing_entities 카운트를 조회해 H3 검증.

단기 개선 (1주 이내)#

• EditingPriorityScorer.call 의 비동기화 검토 (app/repositories/concerns/reviewable_repository.rb:14-16). admin endpoint 응답 경로에서 분리하여 ActiveJob/Sidekiq worker 로 enqueue 하면, scorer 가 어떤 이유로 느려지더라도 사용자 응답에 영향이 없다. 단, 호출자 측에서 priority_score 업데이트의 즉시성 요구 여부를 product 와 합의 필요.
• Puma worker timeout 알림 강화: 60s 이상 실행되는 Rails 요청이 발생하면 별도 알림이 가도록 monitor 추가 (현재는 이번처럼 슬로우 스팬 수집기에서 사후 감지됨).

장기 개선 (재발 방지)#

• EditingPriorityScorer#pano_capture? 의 editing_entities.includes(:entity).map(&:entity) 패턴은 entity 수에 비례해 느려진다. 필요한 컬럼만 join 으로 가져오거나(joins(:entity).pluck(...)), editing_entities.where(entity_type: 'Capture').joins(entity: :capture_type).where(capture_types: { method: %w[singleshot multishot] }).exists? 형태로 단일 SQL 로 전환하여 데이터 분포에 robust 하게 만든다.
• admin 동기 경로에 의존하는 부수 작업(scorer, 통계, 인덱싱 등)은 일반적으로 background job 화하는 정책을 확립한다.

Monitoring#

다음 Datadog 쿼리를 release/health 대시보드 timeseries 위젯에 추가한다.

add_reviewer 평균/최대 응답시간 추이:

avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::admin::editingscontroller#add_reviewer}

max:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::admin::editingscontroller#add_reviewer}

add_reviewer 호출 수:

sum:trace.rack.request.hits{service:cupixworks-api,resource_name:api::v1::admin::editingscontroller#add_reviewer}.as_count()

5초 이상 걸린 cupixworks-api 요청 수 (worker stall 조기 감지):

sum:trace.rack.request.duration.by.service.5s{service:cupixworks-api}.as_count()

(위 메트릭 이름이 환경에 없는 경우 trace.rack.request.duration{service:cupixworks-api} 의 percentile 위젯 + threshold 마커로 대체)

Risk Assessment#

• Risk level: low (단일 outlier, occurrence_count=1, 사용자 영향 미미, 코드 결함 미확인)
• 예상 복잡도: trivial (즉시 코드 수정 필요 없음). 단기 개선(scorer 비동기화)은 standard 수준.