RCA: BIM360 refresh_token failed: - error: 400 Bad Request

Error Log#

Datadog Logs

BIM360 refresh_token failed:  - error: 400 Bad Request

Impact#

• Service: cupixworks-api
• 발생 횟수: 1
• 최초 발생: 2026-04-17T07:23:55.187Z
• 최근 발생: 2026-04-17T07:23:55.187Z
• 영향 범위: integration(6033), review 80ztbx, team hodulee(ID 1107), 사용자 ruebente@gmail.com(ID 43623). 해당 integration의 state가 failed로 변경되어 이후 BIM360 토큰 갱신이 중단됨.

Root Cause Summary#

동일한 BIM360 integration(6033)에 대해 약 1초 간격으로 두 번의 access_token 요청이 들어왔다. 첫 번째 요청(07:23:53Z)이 Autodesk OAuth 서버에서 refresh_token을 성공적으로 갱신하면서 기존 refresh_token이 소비(invalidation)되었다. 그러나 두 번째 요청(07:23:55Z)은 이미 소비된 이전 refresh_token으로 갱신을 시도하여 Autodesk로부터 400 Bad Request를 받았다. Redis 기반 lock(setnx, TTL 5초)이 존재하지만, 첫 번째 요청이 성공 후 uncheck_refresh_request로 lock을 즉시 해제하므로 두 번째 요청이 lock을 획득할 수 있었다. 문제는 첫 번째 요청이 DB에 새 refresh_token을 save!하기 전이거나, 두 번째 요청이 DB에서 모델을 로드한 시점에 아직 이전 refresh_token이 남아있었기 때문에 stale token으로 갱신을 시도한 것이다.

Technical Analysis#

Code Path#

• Entry point: Api::V1::IntegrationsController#access_token (app/controllers/api/v1/integrations_controller.rb:35-38)

# app/controllers/api/v1/integrations_controller.rb:35-38
def access_token
  token = repository_instance.access_token
  render_json 200, token
end

• 토큰 만료 확인 및 갱신 분기: IntegrationRepository#access_token (app/repositories/integration_repository.rb:76-101)

# app/repositories/integration_repository.rb:90-91
if @model.expired_at < 10.minutes.since
  refresh_token  # 만료 임박 시 refresh 호출
end

integration(6033)의 expired_at은 06:39:43 UTC로, 요청 시점(07:23:53Z) 기준 이미 만료 상태. 따라서 두 요청 모두 refresh_token 메서드를 호출.

• Redis lock 획득: IntegrationRepository#check_refresh_request (app/repositories/integration_repository.rb:29-34)

# app/repositories/integration_repository.rb:29-34
def check_refresh_request
  key = @model.cache_key
  value = @model.provider
  lock_key = "#{key}::Lock::Key"
  @model.setnx(lock_key, @model.provider)
end

• Lock 구현: Cachable#setnx (app/models/concerns/cachable.rb:121-127)

# app/models/concerns/cachable.rb:121-127
def setnx(lock_key, value)
  return if Rails.cache.is_a?(ActiveSupport::Cache::NullStore)
  lock_acquired = Rails.cache.redis_instance.setnx(lock_key, value)
  Rails.cache.redis_instance.expire(lock_key, 5.second)
  lock_acquired
end

Redis SETNX로 lock을 설정하고 TTL 5초를 부여. 그러나 SETNX와 EXPIRE가 atomic하지 않으며, 첫 번째 요청 성공 후 uncheck_refresh_request(line 131)에서 lock을 즉시 삭제하므로, 5초 TTL이 보호 역할을 하지 못함.

• Refresh 실행: Bim360Operation.refresh_token (app/operations/bim360_operation.rb:50-81)

# app/operations/bim360_operation.rb:50-62
def self.refresh_token(refresh_token, region)
  data = {
    grant_type: 'refresh_token',
    refresh_token: refresh_token,
    redirect_uri: $OAUTH[:autodesk_forge][:bim360][:redirect_uri]
  }
  header = {
    authorization: "Basic #{$OAUTH[:autodesk_forge][:bim360][:token]}"
  }
  url = "#{$OAUTH[:autodesk_forge][:site]}#{$OAUTH[:autodesk_forge][:refresh_url]}"
  response = RestClient.post(url, data, header)
end

이 메서드는 @model.refresh_token 값을 인자로 받아 Autodesk에 POST 요청을 보냄. 첫 번째 요청이 성공하면 Autodesk 측에서 기존 refresh_token을 즉시 무효화(OAuth2 refresh token rotation). 두 번째 요청이 동일한 구 refresh_token으로 호출하면 400 Bad Request 반환.

• Failure point: app/operations/bim360_operation.rb:63-70

# app/operations/bim360_operation.rb:63-70
rescue RestClient::Exception => e
  response = JSON.parse(e.response)
  Cupix::Logger.error("BIM360 refresh_token failed: #{response['developerMessage']} - error: #{e.message}")
  raise Cupix::Errors::Parameter.new(
    code: 'ARG10000',
    reason: "BIM360 Authentication failed: #{response['developerMessage']}"
  )
end

400 응답을 받으면 RestClient::BadRequest 예외가 발생하고, 이 rescue 블록에서 에러 로그를 남김. developerMessage가 비어있어 로그에 "failed: - error: 400 Bad Request"로 기록됨.

• Integration 상태 변경: IntegrationRepository#refresh_token rescue 블록 (app/repositories/integration_repository.rb:130-142)

# app/repositories/integration_repository.rb:130-142
rescue StandardError => e
  uncheck_refresh_request
  raise e if e.code == 'ARG10060'
  @model.refresh_token_failed_at = DateTime.now
  @model.refresh_token_expired_at = nil
  @model.refresh_token_response_body = token
  @model.failed_state!
  Cupix::Logger.error("[Integration] failed to refresh token for #{@model.provider} integration(#{@model.id}) - state: #{@model.state}, error_message: #{e.message}")
  raise e
end

실패 시 refresh_token_expired_at을 nil로 설정하고 state를 failed로 변경. 이후 cron이나 사용자 요청에서 이 integration은 check_failed_state에 의해 차단됨.

Log Evidence#

사용한 Datadog 쿼리:

service:cupixworks-api status:error "BIM360 refresh_token failed"

service:cupixworks-api "BIM360" "integration(6033)"

service:cupixworks-api status:error 400

핵심 타임라인 (integration(6033), review 80ztbx):

핵심 관찰:

• 07:23:53Z와 07:23:54Z에 동일 integration(6033)에 대해 두 번의 refresh token 로그가 출력됨 — 두 요청 모두 expired_at: 06:39:43 UTC (이미 만료)를 확인하고 refresh를 시도
• 첫 번째 요청은 07:23:54.379Z에 성공하여 expired_at을 08:23:51 UTC로 갱신
• 두 번째 요청은 07:23:55.187Z에 이미 소비된 refresh_token으로 실패
• 같은 시간대 다른 integration(392, 9, 427, 6014, 6982 등)은 모두 정상 갱신됨 — 이 문제는 동시 요청이 있는 integration(6033)에만 발생

400 응답 상세:

{
  "controller": "Api::V1::IntegrationsController#access_token",
  "params": { "review_key": "80ztbx" },
  "error": "Cupix::Errors::Parameter",
  "error_code": "ARG10000",
  "error_reason": "BIM360 Authentication failed: ",
  "duration": 1680.16,
  "user_email": "ruebente@gmail.com",
  "team": "hodulee"
}

Fix Recommendation#

즉시 조치 (Critical)#

파일: app/repositories/integration_repository.rb:76-101 (access_token 메서드)

갱신된 토큰으로 응답할 수 있도록 access_token 메서드에서 refresh 전에 DB 모델을 reload하여 최신 expired_at과 refresh_token 값을 확인해야 함. 첫 번째 요청이 이미 토큰을 갱신했다면 두 번째 요청은 갱신된 expired_at을 보고 refresh를 건너뛸 수 있음.

# app/repositories/integration_repository.rb:90 수정 제안
@model.reload  # DB에서 최신 상태 로드
if @model.expired_at < 10.minutes.since
  refresh_token
end

단기 개선 (1주 이내)#

1. Lock 해제 시점 변경: IntegrationRepository#refresh_token (line 129)에서 uncheck_refresh_request를 성공 시 DB save! 이후로 이동. 현재는 Autodesk 응답 수신 직후(line 129)에 lock을 해제하고, 그 이후에 DB 저장(line 160)이 일어나므로 race window가 존재함.

2. Lock TTL 연장 또는 lock 유지: cachable.rb:125의 TTL을 5초에서 30초 이상으로 늘리거나, uncheck_refresh_request를 DB save! 완료 후에만 호출하도록 변경.

3. setnx + expire atomic 처리: cachable.rb:121-127에서 SETNX + EXPIRE를 별도 명령으로 실행하고 있어 race condition 가능성이 있음. Redis SET key value NX EX 30 단일 명령으로 변경 권장.

장기 개선 (재발 방지)#

1. Optimistic locking 또는 DB-level mutex: Redis lock 대신 DB의 lock_version 또는 SELECT FOR UPDATE를 사용하여 동일 integration에 대한 동시 refresh를 방지.

2. Refresh token을 사전 갱신: cron job(Cupix::Cron::Integration.renew_before_expiration)이 만료 전에 미리 갱신하므로, API 요청 시점에 refresh가 필요한 상황을 최소화할 수 있음. cron 주기를 조정하여 expired_at 임박 시점을 줄이는 방안 검토.

3. 실패 시 자동 복구: integration이 failed 상태로 전환된 후 수동 개입 없이는 복구되지 않음. race condition으로 인한 일시적 실패는 자동 retry 또는 상태 복구 로직 추가 필요.

Monitoring#

• BIM360 refresh token 실패율 모니터링:

service:cupixworks-api "BIM360 refresh_token failed" status:error

• 동시 refresh 시도 감지 (동일 integration에 대한 짧은 간격 refresh 로그):

service:cupixworks-api "[Integration] refresh token for bim360" | pattern

• Integration failed state 전환 추적:

service:cupixworks-api "[Integration] failed to refresh token" status:error

Risk Assessment#

• Risk level: medium — integration이 failed 상태로 전환되면 해당 사용자의 BIM360 연동이 중단되지만, 발생 빈도가 낮고(1건) 동시 요청이라는 특정 조건에서만 발생함.
• 예상 복잡도: standard — access_token 메서드에 reload 추가는 간단하나, lock 구조 개선은 기존 동작에 영향을 줄 수 있어 테스트가 필요함.