RCA: Api::V1::Admin::TeamsController#update Latency (avg 3632ms, max 4612ms)

Overview#

What Happened#

2026-05-27 02:47 UTC, cupixworks-api 서비스의 Api::V1::Admin::TeamsController#update 엔드포인트에서 평균 3632ms, 최대 4612ms의 응답 지연이 발생했다. ap-southeast-2 리전의 team ID 157에 대해 Prism/CS 1.1.6 클라이언트가 연속 3회 PATCH 요청을 보냈으며, 그 중 2건이 latency 임계값(500ms)을 초과했다.

Quick Facts#

Timeline#

1. 02:47:42Z — Prism/CS가 team 157에 대한 show 요청 수행 (18ms, 정상)
2. 02:47:54Z — 첫 번째 PATCH 요청 (97ms, 정상 — Segment 이벤트 미발생)
3. 02:47:55Z — 두 번째 PATCH 요청 (4610ms, Segment 이벤트 발생 확인)
4. 02:47:57Z — 세 번째 PATCH 요청 (2651ms, Segment 이벤트 발생 확인)

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::Admin::TeamsController#update",
  "service": "cupixworks-api",
  "occurrences": 2,
  "avg_ms": 3632,
  "max_ms": 4612,
  "sample_trace_id": "3492693178291784393"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 2
• 최초 발생: 2026-05-27T02:47:49.253Z
• 최근 발생: 2026-05-27T02:47:53.085Z
• 영향 범위: Admin 패널(Prism/CS)에서 team 설정 업데이트 시 4초 이상 응답 대기. 일반 사용자 API에는 영향 없음.

Root Cause Summary#

TeamsController#update 요청 시 after_update 콜백 체인에서 발생하는 synchronous Segment API 호출(::Analytics.group)과 PaperTrail versions.last.reify에 의한 이전 모델 역직렬화, 그리고 after_commit :write_cache의 전체 모델 직렬화 + Redis 쓰기가 누적되어 총 2600-4600ms의 지연이 발생한다. DB 시간은 53-61ms에 불과하며, 나머지 2500-4500ms는 모두 비-DB 동기 작업에 소요된다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/admin/teams_controller.rb:29 — update action
• Repository 호출: app/repositories/admin/team_repository.rb:17-27 — 파라미터 설정 + @model.save!
• PaperTrail before_action: app/controllers/api/v1/admin/teams_controller.rb:118-129 — user_for_paper_trail
• Segment callback: app/models/concerns/eventable/team.rb:12-32 — segment_team_event
• Cache callback: app/models/concerns/cachable.rb:23-52 — write_cache

1. PaperTrail versions.last.reify (before_action)#

def user_for_paper_trail
  email = @current_user.email
  versions = @model.versions
  if versions.length.positive?
    previous_editing_support = versions.last.reify.use_editing_support
    message = "[Team] use_editing_support changed { #{previous_editing_support} -> #{@model.use_editing_support} } on team_id: { #{@model.id} } by { #{email} }"
  else
    message = "[Team] use_editing_support changed { #{@model.use_editing_support} } on team_id: { #{@model.id} } by { #{email} }"
  end
  Cupix::Logger.info(message)
  email
end

이 메서드는 before_action으로 매 update마다 실행된다. versions.last.reify는 PaperTrail이 저장한 이전 버전을 역직렬화하여 모델 인스턴스를 재구성하는 비용이 큰 작업이다. use_editing_support 변경 여부와 관계없이 항상 실행된다.

2. Segment Analytics 동기 호출 (after_update)#

after_create :segment_team_event, if: :send_segment_event?
after_update :segment_team_event, if: :send_segment_event?

def segment_team_event
  ::Analytics.group(
    group_id: crn,
    user_id: self.current_user.try(:crn),
    traits: {
      id: id,
      name: name,
      domain: domain,
      state: state,
      createdAt: created_at.to_s,
      userId: self.current_user.id,
      teamId: id,
      tenant: Cupix::Tesla.tenant,
      regionCode: Cupix::Tesla.region_code,
      region: Cupix::Tesla.region_short_name,
      groupId: crn
    }
  )

  Cupix::Logger.info("Segment event sent for Team #{id}", class: self.class.name, function: __method__, team: { id: id, name: name, domain: domain, state: state, created_at: created_at, user_id: user_id, crn: crn })
end

analytics-ruby gem (v2.0.13)은 내부적으로 background thread와 message queue를 사용하지만, 큐가 가득 차거나 flush 조건에 도달하면 호출 스레드에서 동기적으로 HTTP 전송이 발생할 수 있다. ap-southeast-2에서 Segment API 서버(US)까지의 네트워크 레이턴시가 추가된다.

3. Segment 초기화 — stub_mode 없음#

Analytics = Segment::Analytics.new({
  write_key: ENV['SEGMENT_WRITE_KEY'] || '9WcP1zI6srugOXfjiAwAAR5WMAgnMEjx',
  on_error: proc { |status, msg| print msg }
})

stub 모드나 batch_size 커스터마이징 없이 기본값으로 초기화된다. 기본 batch_size는 100이며, queue max_size 초과 시 동기 flush가 발생한다.

4. Cache serialization (after_commit)#

def write_cache(force: false)
  prior_to_write_cache
  _cache_keys = []
  _cache_value = nil

  if cachable? && respond_to?(:serialized_json)
    _cache_value = self.send(:serialized_json)
    # ...
    _cache_keys.each do |_cache_key|
      next if _cache_value.nil?
      Rails.cache.write(_cache_key, _cache_value, expires_in: self.class.cache_expires_in)
    end
  end
  write_delegated_cache
  _cache_value
end

prior_to_write_cache에서 logo 변경 시 logo.store!(파일 업로드)가 발생할 수 있고, serialized_json은 Team 모델의 모든 cacheable 필드(16개 이상)를 직렬화한다.

Log Evidence#

Datadog 쿼리:

service:cupixworks-api "teams/157"
Time: 2026-05-27T01:47:00Z to 2026-05-27T03:47:00Z

핵심 로그 (3건의 PATCH 요청 비교):

{"timestamp": "2026-05-27T02:47:54.316Z", "duration": 97.29, "db": 19.41, "action": "update", "params": {"id": "157"}}
{"timestamp": "2026-05-27T02:47:55.311Z", "duration": 4610.03, "db": 53.59, "action": "update", "params": {"id": "157"}}
{"timestamp": "2026-05-27T02:47:57.312Z", "duration": 2651.54, "db": 61.92, "action": "update", "params": {"id": "157"}}

Segment 이벤트 로그 (2건만 확인 — 첫 번째 빠른 요청에서는 미발생):

2026-05-27 11:47:55 KST | info | Segment event sent for Team 157 | class: Team | function: segment_team_event
2026-05-27 11:47:57 KST | info | Segment event sent for Team 157 | class: Team | function: segment_team_event

분석:

• 97ms 요청: Segment 이벤트 미발생 → name, domain, state 변경 없는 업데이트
• 4610ms / 2651ms 요청: Segment 이벤트 발생 확인 → name, domain, 또는 state 필드 변경 포함
• DB 시간 비율: 53ms / 4610ms = 1.2% — 지연의 98.8%가 비-DB 작업

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• app/models/concerns/eventable/team.rb:12-31 — segment_team_event 메서드를 비동기 worker로 이동. after_update 콜백에서 직접 ::Analytics.group을 호출하는 대신 Sidekiq job을 enqueue하여 HTTP 호출을 request cycle에서 분리.
• config/initializers/segment.rb — batch_size: 1 설정 추가로 즉시 flush 방지, 또는 request 내에서 flush가 발생하지 않도록 보장.

단기 개선 (1주 이내)#

• app/controllers/api/v1/admin/teams_controller.rb:118-129 — user_for_paper_trail 메서드를 use_editing_support 파라미터가 실제로 전달된 경우에만 reify를 호출하도록 조건 분기 추가. 현재는 매 update마다 무조건 실행됨.
• app/models/concerns/cachable.rb:23-52 — write_cache를 after_commit 대신 background job으로 이동하거나, serialized_json 결과를 캐시하여 중복 직렬화 방지.

장기 개선 (재발 방지)#

• Admin API의 after_update / after_commit 콜백 체인 전체에 대한 성능 감사. 동기 외부 API 호출이나 무거운 직렬화가 request cycle에 포함되어 있지 않은지 확인.
• APM trace에 Segment API 호출 시간을 별도 span으로 계측하여 정확한 latency attribution 가능하도록 함.

Monitoring#

• TeamsController#update p95 응답 시간에 대한 Datadog APM monitor 설정 (임계값: 1000ms)
• Segment 이벤트 전송 지연을 추적하는 커스텀 메트릭 추가

avg:trace.rack.request.duration{service:cupixworks-api,resource_name:Api::V1::Admin::TeamsController#update} by {region}

Risk Assessment#

• Risk level: low
• 예상 복잡도: standard
• Admin 패널 전용 엔드포인트이므로 일반 사용자에게는 영향 없음. 발생 빈도도 낮음 (2건). 단, Segment 호출이 request cycle에 포함된 구조적 문제는 다른 Eventable 모델에도 영향을 줄 수 있어 수정 가치가 있음.