ES /docs

Cupix::HttpClient missing timeout — Forge API calls

RCA: BimsController#create_forge_access_token Latency (1215ms)

Overview#

What Happened#

2026-05-27 06:31 UTC에 cupixworks-api 서비스의 Api::V1::BimsController#create_forge_access_token 엔드포인트에서 1215ms의 응답 지연이 발생했다. 이 엔드포인트는 Autodesk Forge OAuth API에 대한 동기식 HTTP 호출을 수행하며, 외부 API 응답 지연이 그대로 클라이언트에 전파되었다.

Quick Facts#

Field Value
resource_name Api::V1::BimsController#create_forge_access_token
top_frame app/controllers/api/v1/bims_controller.rb:88
env production, us-west-2
avg_duration 1215ms (이 trace)
normal_avg 265ms (24시간 평균)

Timeline#

  1. 2026-05-27T06:31:23Z — trace_id 2695155056518300336에서 1215ms 응답 감지
  2. 2026-05-27T06:31:26Z — 요청 완료, HTTP 200 반환
  3. 2026-05-27 RCA — 분석 완료, 외부 API latency로 확인

Error Log#

Datadog Logs

json
{
  "resource_name": "Api::V1::BimsController#create_forge_access_token",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 1215,
  "max_ms": 1215,
  "sample_trace_id": "2695155056518300336"
}

Impact#

  • Service: cupixworks-api
  • 발생 횟수: 1 (이 trace), 하지만 24시간 내 max > 1s인 5분 구간이 44/287개 (15%)
  • 최초 발생: 2026-05-27T06:31:23.814Z
  • 최근 발생: 2026-05-27T06:31:23.814Z

Root Cause Summary#

create_forge_access_token 엔드포인트는 Autodesk Forge OAuth API (https://developer.api.autodesk.com/authentication/v2/token)에 대해 동기식 HTTP POST를 수행한다. Cupix::HttpClient.postRestClient를 사용하며 timeout이 설정되어 있지 않다. 또한 토큰 캐싱이 없어 매 요청마다 외부 API를 호출한다. 1215ms 지연은 Autodesk API의 tail latency 변동에 의해 발생했으며, 이는 구조적 문제로 반복 발생할 수 있다 (24시간 내 max > 1s 구간이 15%).

Technical Analysis#

Code Path#

  • Entry point: app/controllers/api/v1/bims_controller.rb:87create_forge_access_token 메서드
  • HTTP call: lib/cupix/http_client.rb:34Cupix::HttpClient.post 호출
  • External API: https://developer.api.autodesk.com/authentication/v2/token
app/controllers/api/v1/bims_controller.rb:87-96ruby
def create_forge_access_token
  response = Cupix::HttpClient.post("#{$OAUTH[:autodesk_forge][:site]}/authentication/v2/token", {
    grant_type: 'client_credentials',
    scope: 'data:read'
  }, {
    authorization: "Basic #{$OAUTH[:autodesk_forge][:bim360][:token]}"
  })

  render_json 200, JSON.parse(response.body)
end

이 메서드는 매 호출 시 Autodesk Forge API에 client_credentials grant로 토큰을 요청한다. 캐싱 없이 매번 새 토큰을 발급받으므로, 외부 API의 응답 시간이 그대로 엔드포인트 latency가 된다.

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

RestClient.post는 timeout 파라미터 없이 호출되므로 Ruby의 기본 소켓 timeout(60초)이 적용된다. 외부 API 응답이 느려도 최대 60초까지 기다리게 되어 있다.

config/environments/production.rb:142-153ruby
$OAUTH = {
  autodesk_forge: {
    authorize_url: '/authentication/v2/authorize',
    token_url: '/authentication/v2/token',
    refresh_url: '/authentication/v2/token',
    site: 'https://developer.api.autodesk.com',
    bim360: {
      token: Base64.urlsafe_encode64("#{ENV['AUTODESK_FORGE_CLIENT_ID']}:#{ENV['AUTODESK_FORGE_CLIENT_SECRET']}"),
      region: ENV['AUTODESK_FORGE_REGION'] || 'US',
      redirect_uri: "#{$APP_PROTOCOL}://app.#{$APP_HOST}/app/bim360/auth"
    }
  },

Log Evidence#

사용한 Datadog 쿼리:

text
service:cupixworks-api "create_forge_access_token"
Time: 2026-05-27T06:00:00Z to 2026-05-27T06:45:00Z

trace_id 2695155056518300336에 해당하는 로그:

json
{
  "timestamp": "2026-05-27 15:31:26",
  "status": "info",
  "message": "[200] POST /api/v1/reviews/iosq5k/bims/9546/forge_access_token (Api::V1::BimsController#create_forge_access_token)"
}

APM 메트릭 분석 (24시간):

text
avg:trace.rack.request.duration — Avg: 265ms, Max: 509ms
max:trace.rack.request.duration — Avg: 631ms, Max: 2008ms
5분 구간 중 max > 1s: 44/287 (15.3%)

이 엔드포인트는 에러 없이 모두 HTTP 200을 반환하지만, 외부 API 응답 시간의 분산이 크다 (143ms ~ 2008ms). 호출 빈도가 높아 (분당 수회) tail latency가 반복적으로 관찰된다.

Hypotheses Considered#

# Hypothesis Evidence for Evidence against Verdict
H1 Autodesk Forge API의 tail latency 변동으로 인한 외부 지연 APM max 2008ms, 15% 구간에서 1s 초과. 코드에 timeout/cache 없음 (http_client.rb:34) Confirmed
H2 DB 쿼리나 before_action에 의한 내부 지연 set_bim before_action이 있음 create_forge_access_tokenset_bim에서 제외됨 (bims_controller.rb:9). DB 호출 없음 Rejected
H3 RestClient retry 로직에 의한 추가 지연 retry 시 exponential backoff sleep 포함 (http_client.rb:19) Retry는 429/502/503/504에서만 발동. 이 요청은 200 응답이므로 retry 미발생 Rejected

Fix Recommendation#

즉시 조치 (Critical)#

  • lib/cupix/http_client.rb:37RestClient.post에 timeout 옵션 추가 (open_timeout: 5, timeout: 10)
  • app/controllers/api/v1/bims_controller.rb:87-96 — Forge access token에 대한 캐싱 도입. client_credentials grant로 받은 토큰은 일반적으로 expires_in 필드를 포함하며 (보통 3600초), 만료 전까지 재사용 가능

단기 개선 (1주 이내)#

  • Rails cache (Rails.cache.fetch)를 사용하여 Forge 토큰을 expires_in - 300 초 동안 캐싱. 이렇게 하면 대부분의 요청이 외부 API 호출 없이 즉시 응답 가능
  • 캐싱 적용 시 이 엔드포인트의 평균 latency가 10ms 이하로 감소할 것으로 예상

장기 개선 (재발 방지)#

  • Cupix::HttpClient 모듈 전체에 기본 timeout 정책 설정 (현재 어떤 외부 호출에도 timeout 없음)
  • 외부 API 호출에 대한 circuit breaker 패턴 도입 검토

Monitoring#

  • Forge token endpoint의 p95/p99 latency 알림 추가
  • Datadog 쿼리 예시:
text
avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::bimscontroller_create_forge_access_token} > 1.0

Risk Assessment#

  • Risk level: low
  • 예상 복잡도: trivial — 캐싱과 timeout 추가는 단순한 변경이며, 기존 동작에 영향 없음