Api::V1::Admin::MigrationsController#create (avg 1055ms, max 1057ms)
RCA: Api::V1::Admin::MigrationsController#create Latency (avg 1055ms)
Overview#
What Happened#
2026-05-26 04:45~07:26 UTC 사이에 cupixworks-api 서비스의 POST /api/v1/admin/migrations 엔드포인트에서 평균 1055ms의 응답 지연이 3회 감지되었다. 이 지연은 create 액션이 Evergreen API에 대한 동기식 HTTP POST 호출(~650ms)과 DB 쿼리(~400ms)를 순차적으로 수행하기 때문에 발생한다.
Quick Facts#
| Field | Value |
|---|---|
| resource_name | Api::V1::Admin::MigrationsController#create |
| top_frame | app/operations/migration_operation.rb:61 |
| env | production, us-west-2 |
| avg_duration | 1055ms |
| max_duration | 1131ms |
Timeline#
- 2026-05-26T04:44:28Z — 동일 사용자가 잘못된 API 토큰으로 401 응답 수신 (3.2~9.3ms, 인증 단계에서 short-circuit)
- 2026-05-26T04:46:00Z — 정상 인증 후 첫 slow 요청 (1054ms, 502 응답 — Evergreen 401 에러)
- 2026-05-26T04:46:16Z — 두 번째 slow 요청 (1049ms, 200 성공)
- 2026-05-26T07:26:21Z — 세 번째 slow 요청 (1131ms, 200 성공)
- 2026-05-27 — RCA 수행
Error Log#
{
"resource_name": "Api::V1::Admin::MigrationsController#create",
"service": "cupixworks-api",
"occurrences": 2,
"avg_ms": 1055,
"max_ms": 1057,
"sample_trace_id": "2748406546997011803"
}
Impact#
- Service:
cupixworks-api - 발생 횟수: 3
- 최초 발생: 2026-05-26T04:45:58.283Z
- 최근 발생: 2026-05-26T07:26:19.447Z
- 영향 범위: Admin migration 기능을 사용하는 내부 사용자 1명 (Postman을 통한 수동 호출). 일반 사용자에 대한 영향 없음.
Root Cause Summary#
MigrationsController#create 액션은 요청 처리 중 Evergreen API(POST /api/v1/migrations)에 동기식 HTTP 호출을 수행한다. 이 외부 호출이 ~650ms를 소비하고, DB 쿼리(세션 조회 + 모델 로딩)가 ~400ms를 추가하여 총 ~1050ms의 응답 시간이 발생한다. 이는 설계상의 구조적 지연으로, 외부 서비스 호출이 요청 스레드를 블로킹하는 전형적인 패턴이다.
Technical Analysis#
Code Path#
- Entry point:
app/controllers/api/v1/admin/migrations_controller.rb:6 - Before action
set_model:app/controllers/api/v1/admin/migrations_controller.rb:120— DB에서 facility/record 조회 - Service call:
app/operations/migration_operation.rb:4—create_migration_request호출 - Session query:
app/operations/migration_operation.rb:126—get_sessionDB 쿼리 - Failure/Latency point:
app/operations/migration_operation.rb:61— Evergreen API POST 호출
컨트롤러의 create 액션은 MigrationOperation.create_migration_request를 동기적으로 호출한다:
def create
response = MigrationOperation.create_migration_request(
current_user: current_user,
source_model: @model,
type: params[:type],
tenant: params[:tenant],
region: params[:region],
environment: params[:environment],
model_name: params[:model_name],
model_id: params[:model_id],
selected_models: params[:sources],
source_auth_token: params[:source_auth_token],
destination_auth_token: params[:destination_auth_token]
)
render_json 200, { migration_id: response['result']['data']['id'] }
end
MigrationOperation은 세션 조회 후 Evergreen API를 호출한다:
session = get_session(migration_operator) # DB query (~일부 400ms 중)
body = {
type: type,
service_name: Cupix::Tesla.service_name,
sender: {
id: migration_operator.id,
session: { id: session.id, token: session.token }
},
# ... payload 구성 ...
}
# 동기식 HTTP POST — 주요 지연 원인 (~650ms)
response = Cupix::HttpClient.post(
"#{$EVERGREEN[:api_endpoint]}/api/v1/migrations?fields=id",
body,
{ 'x-cupix-auth': $EVERGREEN[:api_key] }
)
HTTP Client는 retry 로직을 포함하고 있어 Evergreen 서비스가 502/503/504를 반환하면 지수 backoff으로 재시도한다:
MAX_RETRIES = 3
RETRIABLE_STATUS_CODES = [429, 502, 503, 504]
Log Evidence#
Datadog에서 MigrationsController#create 요청 로그를 조회한 결과:
service:cupixworks-api @http.url_details.path:/api/v1/admin/migrations @http.method:POST
성공 요청의 duration 분석:
{
"timestamp": "2026-05-26T04:46:16.500Z",
"duration_ms": 1049.19,
"db_ms": 401.13,
"status": 200,
"request_id": "b2c7527a-..."
}
{
"timestamp": "2026-05-26T07:26:21.450Z",
"duration_ms": 1130.73,
"db_ms": 399.81,
"status": 200,
"request_id": "b108d654-..."
}
실패 케이스(502)에서는 Evergreen가 401을 반환:
{
"timestamp": "2026-05-26T04:46:00.489Z",
"level": "error",
"function": "create_migration_request",
"message": "Migration request failed from evergreen - {\"result\":{\"code\":\"BG10004\",\"type\":\"Cupix::Errors::BadGateway\",\"reason\":\"Failed to fetch facility info from tesla server\",\"message\":\"Unable to retrieve facility info: 401 Unauthorized\"}}"
}
인증 실패(401) 요청은 3-9ms로 즉시 반환되어, 지연이 인증 이후의 비즈니스 로직에서 발생함을 확인:
{
"timestamp": "2026-05-26T04:44:28.450Z",
"duration_ms": 9.28,
"status": 401,
"error": "AUTH10008: Invalid API token"
}
Hypotheses Considered#
| # | Hypothesis | Evidence for | Evidence against | Verdict |
|---|---|---|---|---|
| H1 | Evergreen API 동기식 호출이 주요 지연 원인 | 모든 slow 요청에서 duration - db_time ≈ 650ms 일관됨. Evergreen POST 호출이 유일한 외부 I/O. |
— | Confirmed |
| H2 | DB 쿼리 N+1 문제 | DB 시간 ~400ms로 유의미한 비중 차지 | set_model은 단일 레코드 조회, get_session도 단일 쿼리. N+1 패턴 없음. slow query 로그 미발견. |
Rejected |
| H3 | HTTP Client retry로 인한 추가 지연 | retry 로직 존재 (MAX_RETRIES=3) | 모든 요청이 1050-1130ms 범위로 일관됨. Retry 시 최소 2초 추가되어야 하나 관측되지 않음. | Rejected |
| H4 | 네트워크 이슈 또는 일시적 Evergreen 과부하 | 한 건의 502 응답(Evergreen 401) 존재 | 성공 요청도 동일 지연. duration 일관성은 구조적 지연을 시사. | Rejected |
Fix Recommendation#
즉시 조치 (Critical)#
- 조치 불필요: 이 latency는 Admin 전용 엔드포인트에서 내부 사용자가 Postman으로 수동 호출하는 케이스로, 일반 사용자 영향 없음. 3건의 발생이며 모두 정상 처리(1건 502는 토큰 문제). 현재 500ms 임계값 기준으로 감지되었으나 Admin API의 1초 응답은 수용 가능한 수준.
단기 개선 (1주 이내)#
- Latency alert 임계값에서 Admin 엔드포인트 제외 고려.
Api::V1::Admin::*네임스페이스의 요청은 내부 운영 작업이므로 별도 SLO 적용이 적절. app/operations/migration_operation.rb:61의 Evergreen HTTP 호출에 명시적 timeout 설정 추가 (현재 기본값 사용 중). 10초 이내로 제한하여 Evergreen 장애 시 요청이 무한 대기하는 것을 방지.
장기 개선 (재발 방지)#
- Migration 생성을 비동기로 전환:
create액션에서 migration 요청을 DB에 저장하고 즉시 202 반환, Sidekiq worker가 Evergreen API 호출을 수행하는 구조로 변경. 단, Admin 전용이고 발생 빈도가 극히 낮아 우선순위는 낮음.
Monitoring#
- Admin 엔드포인트에 대한 별도 latency 모니터 설정:
service:cupixworks-api resource_name:"Api::V1::Admin::MigrationsController#create" @duration:>3000ms
- Evergreen API 호출 실패율 모니터링:
service:cupixworks-api "Migration request failed from evergreen" status:error
Risk Assessment#
- Risk level: low
- 예상 복잡도: trivial
- Admin 전용 엔드포인트이며 발생 빈도 극히 낮음 (3건/일). 일반 사용자 영향 없음. 구조적 지연이나 장애 위험은 아님.