RCA: Api::V1::SessionsController#show Latency (1728ms)

Overview#

What Happened#

2026-05-27 08:07:38 UTC에 cupixworks-api 서비스의 Api::V1::SessionsController#show 엔드포인트에서 단일 요청이 1728ms의 비정상적으로 높은 응답 시간을 기록했다. 동일 시간대 다른 요청들의 평균 응답 시간은 50-100ms이며, 해당 요청은 극단적인 outlier이다.

Quick Facts#

Timeline#

1. 2026-05-27 08:07:38Z — SessionsController#show 요청이 1728ms 소요 (trace_id: 4452214226173397797)
2. 2026-05-27 08:07~08:30Z — 동일 시간대 S3 datalake 연결에서 다수의 I/O timeout 발생 (AWS us-west-2 네트워크 혼잡 징후)
3. 2026-05-27T08:07:38Z — error-sweeper가 latency cluster로 수집

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::SessionsController#show",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 1728,
  "max_ms": 1728,
  "sample_trace_id": "4452214226173397797"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 1
• 최초 발생: 2026-05-27T08:07:38.039Z
• 최근 발생: 2026-05-27T08:07:38.039Z

단일 요청에 대한 지연으로 사용자 영향은 극히 제한적이다. 해당 요청은 HTTP 200으로 정상 응답했으며 에러는 발생하지 않았다.

Root Cause Summary#

SessionsController#show 요청의 1728ms 지연은 다중 요인이 결합된 단발성 outlier이다. 핵심 원인은 Cognito get_user_by_access_token 캐시 미스 시 외부 API 호출, SessionSerializer의 .reload 호출로 인한 DB 강제 쿼리, touch_updated_at의 DB write, 그리고 TeamSerializer의 다수 attribute 모듈이 트리거하는 추가 쿼리가 동시간대 AWS us-west-2 네트워크 혼잡과 맞물려 누적 지연을 유발한 것으로 추정된다. 동일 시간대 S3 연결에서 다수의 I/O timeout이 관측되어 인프라 레벨의 일시적 지연이 발생했을 가능성이 높다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/sessions_controller.rb:4 (show → super)
• Parent show: app/controllers/api/v1/api_controller.rb:72-76 (render_api)
• Authentication: app/controllers/concerns/verification_controller.rb:15-35 (authenticate!)
• Serialization + session embed: app/controllers/concerns/renderable_controller.rb:40-100 (render_api)

1단계: 인증 (Cognito 호출 가능)

user_response = Cupix::Aws::Cognito.get_user_by_access_token(access_token: access_token, sub: sub)

def get_user_by_access_token(access_token: nil, sub: nil)
  sub ||= ::JWT.decode(access_token, nil, false).first['sub']

  Rails.cache.fetch(user_cache_key(sub), expires_in: 1.hour) do
    Cupix::Logger.info("Fetching an user from Cognito: #{sub}", function: __method__, module: 'Cupix::Aws', class: 'Cognito')

    response = client.get_user(access_token: access_token)
  rescue ::Aws::CognitoIdentityProvider::Errors::NotAuthorizedException
    raise Cupix::Errors::Unauthorized.new(code: 'AUTH20013', reason: 'Invalid access token')
  else
    Cupix::Aws::Cognito::UserResponse.new(
      user_response_hash(response)
    )
  end
end

캐시 미스 시 Cognito API 네트워크 호출이 발생한다. 1시간 TTL이므로 새 세션이나 토큰 갱신 직후 요청에서 미스가 발생할 수 있다.

2단계: render_api 내 session 임베딩

body = {
  result: nil,
  session: session
}

render_api 호출 시 session 메서드가 실행된다:

def session
  return nil if @session.nil?

  if @session.user_updated_at.nil? ||
     @session.team_updated_at.nil? ||
     @session.user_updated_at.to_i < @current_user.try(:updated_at).to_i ||
     @session.team_updated_at.to_i < @current_team.try(:updated_at).to_i ||
     @session.created_at > 2.second.ago ||
     @session.show_option == true

    @session.touch_updated_at

    SessionSerializer.new(@session).serializable_hash[:data][:attributes]
  end
end

조건이 충족되면 touch_updated_at (DB write) + SessionSerializer (추가 직렬화)가 실행된다.

3단계: Session touch_updated_at (DB Write)

def touch_updated_at
  self.user_updated_at = self.user.updated_at
  self.team_updated_at = self.team.updated_at
  self.save
end

self.user와 self.team 접근으로 2개의 DB 쿼리 + save로 1개의 DB write가 발생한다.

4단계: SessionSerializer (reload 호출)

attribute :user do |session|
  SessionUserSerializer.new(session.user.reload, {
    params: { team: session.team }
  }).serializable_hash[:data]
end

attribute :team do |session|
  TeamSerializer.new(session.team.reload).serializable_hash[:data]
end

.reload는 기존 캐시된 association을 무시하고 강제로 DB 쿼리를 수행한다. TeamSerializer는 BillableAttribute, StorageAttribute 등 다수의 모듈을 포함하여 추가 쿼리를 트리거할 수 있다.

5단계: 메인 show 직렬화

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

@model이 @session으로 설정되어 있으므로(sessions_controller.rb:18-20), 다시 한번 SessionSerializer를 통해 직렬화된다. 결과적으로 session 직렬화가 2회 (session embed + main render) 발생할 수 있다.

Log Evidence#

검색 쿼리:

service:cupixworks-api "SessionsController" from:2026-05-27T07:00:00Z to:2026-05-27T09:00:00Z

동일 시간대 모든 SessionsController#show 요청이 HTTP 200으로 정상 응답:

[200] GET /api/v1/sessions (Api::V1::SessionsController#show)

APM 메트릭 분석:

avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::sessionscontroller_show}

2시간 기준 평균 응답 시간: 35180ms (대부분 50100ms). 최대값이 336ms를 초과하는 구간이 없음. 1728ms는 메트릭 집계에서도 확인되지 않는 극단적 outlier.

동시간대 네트워크 문제 증거:

service:cupixworks-api "timeout" from:2026-05-27T07:30:00Z to:2026-05-27T08:30:00Z

{
  "timestamp": "2026-05-27 17:29:58",
  "status": "error",
  "message": "Failed to save Partial JSON element_records 68ca19fc19e8319d5de2b676, error: Error: connect: dial tcp4 3.5.167.1:443: i/o timeout 3.5.167.1:443",
  "function": "trigger_sync_s3_datalake"
}

2026-05-27 08:29~08:30 UTC 시간대에 다수의 S3 datalake 연결 timeout 발생 (3.5.167.x, 3.5.164.x, 3.5.169.x, 52.95.131.x). 이는 us-west-2 리전의 일시적 네트워크 혼잡을 시사한다.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 없음. 단발성 1회 발생으로 긴급 수정이 필요한 상황이 아님.

단기 개선 (1주 이내)#

• app/serializers/session_serializer.rb:5,11: .reload 제거 검토. 인증 단계에서 이미 로드된 user/team을 재사용하면 불필요한 DB 쿼리 2회를 제거할 수 있다. touch_updated_at에서 이미 최신 값을 확보하므로 .reload는 불필요할 수 있다.
• app/controllers/api/v1/api_controller.rb:49-63: session 메서드의 조건 분기 최적화. @session.created_at > 2.second.ago 조건은 거의 항상 true가 되어 불필요한 touch_updated_at + 직렬화를 매 요청마다 수행할 수 있다.

장기 개선 (재발 방지)#

• SessionSerializer에서 TeamSerializer를 전체 직렬화하지 말고 필요한 필드만 선택적으로 포함하는 경량 serializer를 도입하여 N+1 쿼리 위험을 줄인다.
• Cognito API 호출에 timeout 설정을 명시적으로 추가하여 외부 의존성 지연이 전체 요청에 미치는 영향을 제한한다.
• APM에서 p99 latency alert를 설정하여 1초 이상 지연 발생 시 즉시 감지한다.

Monitoring#

• SessionsController#show p99 latency alert:

avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::sessionscontroller_show}.rollup(max) > 1

• Cognito API 호출 지연 추적 (custom metric 또는 trace span duration):

avg:trace.http.request.duration{service:cupixworks-api,@peer.service:cognito-idp}

Risk Assessment#

• Risk level: low
• 예상 복잡도: trivial
• 단발성 이벤트로 반복 패턴 미확인. 인프라 레벨 일시적 네트워크 혼잡이 주요 원인으로 추정되며, 코드 레벨에서는 .reload 제거 및 session 직렬화 최적화가 장기적 개선 방향이다.