Cupix::HttpClient#post blocks on slow API Gateway — synchronous external call

RCA: ScheduleRevisionsController#mapping_rule_generation Latency (1746ms)

Overview#

What Happened#

2026-05-27T06:20:06Z에 cupixworks-api 서비스의 Api::V1::ScheduleRevisionsController#mapping_rule_generation 엔드포인트가 1746ms의 응답 시간을 기록했다. DB 쿼리 시간은 ~25ms에 불과하며, 나머지 ~1700ms는 AWS API Gateway로의 동기 HTTP POST 호출에서 소비되었다.

Quick Facts#

Field	Value
resource_name	`Api::V1::ScheduleRevisionsController#mapping_rule_generation`
top_frame	`lib/cupix/aws/lambda.rb:76`
env	production, us-west-2

Timeline#

2026-05-27T06:20:06Z — mapping_rule_generation 요청 수신 (trace_id: 1382922861301680490)
2026-05-27T06:20:08Z — 응답 완료 (1746ms 소요)
2026-05-27 — Error Sweeper가 latency cluster로 감지

Error Log#

Datadog Logs

json

{
  "resource_name": "Api::V1::ScheduleRevisionsController#mapping_rule_generation",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 1746,
  "max_ms": 1746,
  "sample_trace_id": "1382922861301680490"
}

Impact#

Service: cupixworks-api
발생 횟수: 1 (이번 클러스터), 약 10건/14일 (과거 포함)
최초 발생: 2026-05-27T06:20:06.419Z
최근 발생: 2026-05-27T06:20:06.419Z

Root Cause Summary#

mapping_rule_generation 액션은 AWS API Gateway에 동기적으로 HTTP POST를 수행하며, 이 외부 호출이 전체 응답 시간의 ~97%를 차지한다. DB 쿼리 시간은 25ms에 불과하지만, Cupix::HttpClient.post가 API Gateway 응답을 블로킹 대기하면서 ~1700ms가 소비된다. 이는 일시적 네트워크 지연이 아니라, 14일간의 모든 요청에서 일관되게 1650-1860ms 범위로 관찰되는 구조적 문제이다.

Technical Analysis#

Code Path#

Entry point: app/controllers/api/v1/schedule_revisions_controller.rb:67-74
before_action (set_schedule_revision): app/controllers/api/v1/schedule_revisions_controller.rb:109-111 — permission_joins 포함한 무거운 쿼리로 모델 로드
Repository delegation: app/repositories/schedule_revision_repository.rb:56-65 — Lambda 호출 위임
Lambda 호출: lib/cupix/aws/lambda.rb:61-92 — 세션 생성 + HTTP POST + 상태 변경
Failure point (bottleneck): lib/cupix/aws/lambda.rb:76-82 — 동기 HTTP POST 블로킹

컨트롤러는 단순히 repository에 위임한다:

app/controllers/api/v1/schedule_revisions_controller.rb:67-74ruby

def mapping_rule_generation
  @model = repository_instance.mapping_rule_generation

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

Repository는 Lambda 모듈을 동기 호출한다:

app/repositories/schedule_revision_repository.rb:56-65ruby

def mapping_rule_generation
  Cupix::Aws::Lambda.schedule_mapping_rule_generation({
    schedule_revision_id: @model.id,
    facility_key: @model.facility.key,
    current_user: self.current_user,
    current_team: @model.facility.team
  })

  @model
end

핵심 병목 구간 — 세션 조회/생성, 외부 HTTP POST, 그리고 중복 DB 조회가 순차적으로 실행된다:

lib/cupix/aws/lambda.rb:61-87ruby

def schedule_mapping_rule_generation(opts = {})
  raise Cupix::Errors::Argument.new(code: 'ARG10027', reason: 'schedule_revision_id is blank') if opts[:schedule_revision_id].blank?
  raise Cupix::Errors::Argument.new(code: 'ARG10028', reason: 'facility_key is blank') if opts[:facility_key].blank?

  session = opts[:current_user].agent_team_session(opts[:current_team])
  access_token = TokenFactory.create!(session).access_token

  payload = {
    schedule_revision_id: opts[:schedule_revision_id],
    facility_key: opts[:facility_key],
    access_token: access_token
  }

  resp = Cupix::HttpClient.post(
    $AWS[:api_gateway][:schedule_mapping_rule_generation_url] + '/process',
    payload.to_json,
    { content_type: :json }
  )

  ScheduleRevision.find(opts[:schedule_revision_id]).processing_processing_state!
  resp
end

HTTP 클라이언트에는 retry with exponential backoff 로직이 포함되어 있다:

lib/cupix/http_client.rb:34-46ruby

def self.post(url, payload, headers = {}, retries: MAX_RETRIES)
  attempt = 0
  begin
    RestClient.post(url, payload, headers)
  rescue RestClient::Exception => e
    if RETRIABLE_STATUS_CODES.include?(e.http_code) && attempt < retries
      attempt += 1
      sleep((2**(attempt - 1)) + rand(0.0..0.5))
      retry
    end
    raise
  end
end

세션 조회 — 복합 인덱스 없이 4개 조건으로 쿼리:

app/models/user.rb:116-126ruby

def agent_team_session(current_team)
  session = sessions.active
                    .where(grant_type: :auth_agent)
                    .where(team: current_team)
                    .where('expires_at > ?', 1.week.after)
                    .last

  return session if session.present? && session.active?

  SessionFactory.new(current_user: self, current_team: current_team).create!({ grant_type: :auth_agent })
end

Log Evidence#

Datadog에서 14일간의 mapping_rule_generation 요청을 조회한 결과, 모든 요청이 일관되게 1650-1860ms 범위의 응답 시간을 보였다:

text

service:cupixworks-api resource_name:"Api::V1::ScheduleRevisionsController#mapping_rule_generation" env:production @duration:>500ms

로그에서 확인된 주요 패턴:

text

2026-05-27T06:20:08Z | duration=1743ms | db=25ms | view=0.09ms | status=200
2026-05-26T15:41:21Z | duration=1799ms | db=25ms | view=0.09ms | status=200
2026-05-21T21:03:07Z | duration=1651ms | db=26ms | view=0.09ms | status=200
2026-05-21T20:39:28Z | duration=1680ms | db=29ms | view=0.09ms | status=200
2026-05-21T19:20:38Z | duration=1816ms | db=24ms | view=0.09ms | status=200
2026-05-21T17:48:34Z | duration=448ms  | db=67ms | view=0.09ms | status=200 (outlier)

DB 시간은 항상 25-40ms 범위인데 전체 응답은 1700ms — 차이(~1700ms)가 외부 HTTP 호출 시간이다. 에러 로그나 N+1 쿼리 경고는 없음. 모든 요청이 정상 200 응답.

동일 컨트롤러의 다른 액션과 비교:

text

create:                ~100ms (db: 36ms)
upload_url:            ~55ms  (db: 20ms)
check_uploading:       ~300-500ms (db: 15-55ms)
mapping_rule_generation: ~1750ms (db: 25ms)  ← 외부 호출 병목

Hypotheses Considered#

#	Hypothesis	Evidence for	Evidence against	Verdict
H1	AWS API Gateway 동기 호출이 병목	DB 25ms vs 전체 1746ms — 차이 ~1700ms가 일관적. 코드에서 `Cupix::HttpClient.post`가 블로킹 호출 (`lambda.rb:76-82`). 14일간 모든 요청에서 동일 패턴	1건의 outlier (448ms)가 있으나, 이는 API Gateway 측 응답이 빨랐던 것으로 추정	Confirmed
H2	N+1 쿼리 또는 DB 성능 문제	—	DB 시간이 항상 25-40ms로 일정. Bullet gem 경고 없음. 전체 응답 시간의 1.4%만 DB	Rejected
H3	세션 조회/생성 오버헤드	`agent_team_session`에서 4개 WHERE 조건, 복합 인덱스 부재 (`user.rb:117-121`)	DB 전체 시간이 25ms이므로 세션 조회 자체는 수 ms 수준. 전체 지연의 주 원인은 아님	Rejected (주 원인 아님, minor contributor)
H4	HttpClient retry로 인한 지연	retry시 exponential backoff (1s, 2s, 4s+) 대기 (`http_client.rb:39-42`)	응답이 1650-1860ms로 일관적. retry 발생시 최소 2.5s+ 예상되나 해당 패턴 없음	Rejected

Fix Recommendation#

즉시 조치 (Critical)#

lib/cupix/aws/lambda.rb:76-82: 동기 HTTP POST를 비동기로 전환. Sidekiq worker로 API Gateway 호출을 위임하고, 컨트롤러는 즉시 202 Accepted 응답 반환. 상태 변경(processing_processing_state!)은 worker 내에서 처리.
lib/cupix/aws/lambda.rb:84: ScheduleRevision.find(opts[:schedule_revision_id])는 이미 @model로 로드된 레코드를 중복 조회. 불필요한 DB round-trip 제거.

단기 개선 (1주 이내)#

API Gateway 호출에 timeout 설정 추가 (현재 RestClient 기본 timeout 사용 중). open_timeout: 5, timeout: 10 등의 명시적 제한 필요.
app/models/user.rb:117-121의 세션 조회에 대한 복합 인덱스 추가: (user_id, grant_type, team_id, expires_at) — 현재는 개별 컬럼 인덱스만 존재.

장기 개선 (재발 방지)#

API Gateway 호출 패턴을 Event-driven 아키텍처로 전환. SNS/SQS를 통해 비동기 처리하고, 클라이언트는 WebSocket 또는 polling으로 완료 상태를 확인.
외부 서비스 호출이 포함된 엔드포인트에 대한 latency SLO 설정 및 모니터링.

Monitoring#

API Gateway 호출 시간 추적을 위한 커스텀 메트릭 추가:

text

service:cupixworks-api @message:"schedule mapping rule generation API Gateway" | measure by @duration

Latency P95 알림 설정 (threshold: 2000ms):

text

avg(last_5m):trace.rack.request{service:cupixworks-api, resource_name:Api::V1::ScheduleRevisionsController#mapping_rule_generation} > 2000

Risk Assessment#

Risk level: low
예상 복잡도: standard — 비동기 전환은 기존 Sidekiq 인프라를 활용하면 되지만, 클라이언트 측 polling/callback 로직 추가가 필요하다. 기능적 오류는 아니고 성능 문제이므로 긴급도는 낮음.