RCA: failed to get captured area - error: 503 Service Unavailable

Overview#

What Happened#

2026-07-15 21:33~21:44 KST 사이 CUPIXVISTA 마이그레이션 워커에서 facility 8건에 대한 calculate_captured_size! 처리가 실패했다. 실패 원인은 downstream voxel service Lambda(captured_area)가 Athena GetQueryExecution API 호출에서 ThrottlingException을 받아 500을 반환했고, 일부는 API Gateway 단에서 503으로 반환된 데 있다. 마이그레이션 성격상 다수 facility를 병렬 처리하면서 Athena polling loop가 rate limit을 초과했다.

Quick Facts#

Affected Teams#

같은 시간대에 svc-scope incident로 묶인 관련 cluster: a558bd06-2374-433b-968a-5e17dfd21a2f, fe12d217-509c-4320-b68e-d1ec5c4460b2.

Timeline#

1. 2026-07-15 21:33 KST — Facility 594 처리 중 첫 503 발생 (captured_area!)
2. 2026-07-15 21:36~21:42 KST — Facility 597, 599, 604, 607, 609, 610 처리 중 500 (ThrottlingException) 및 503 반복
3. 2026-07-15 21:44 KST — Facility 612 처리 중 마지막 503 발생 (cluster last_seen)
4. 2026-07-15 21:49 KST — voxel Lambda가 다시 정상 응답 시작 (Athena throttle 해소)
5. 2026-07-15 21:58 KST — 별도의 재시도 파형에서 다시 ThrottlingException 발생 (동일 원인 재현)

Error Log#

Datadog Logs

failed to get captured area - error: 503 Service Unavailable

Impact#

• Service: cupixvista-api-migration-worker
• 발생 횟수: 3 (본 cluster). 동일 원인으로 묶인 svc-scope incident 전체는 다수 facility에 걸쳐 발생
• 최초 발생: 2026-07-15 21:33 KST
• 최근 발생: 2026-07-15 21:44 KST
• 비즈니스 영향: CUPIXVISTA tenant의 facility footprint 계산 실패. Facility.captured_size 갱신 누락 및 FootprintHistory 레코드 미생성. Sidekiq 옵션이 retry: 1이므로 재시도가 한 번만 이뤄지고 실패 시 데이터가 stale 상태로 남는다 (app/workers/refresh_captured_size_worker.rb:3).

Root Cause Summary#

Voxel service Lambda(services/voxel/lambda/captured_area.py)는 Athena query를 시작한 뒤 athena.get_query_execution()을 while True 루프에서 sleep 없이 폴링한다. 마이그레이션 워커가 다수 facility를 짧은 시간에 병렬로 호출하면 Lambda 인스턴스당 초당 수백 번의 GetQueryExecution 호출이 발생하고, 여러 Lambda 인스턴스가 동시에 실행되면서 AWS 계정 단위 Athena API rate limit을 초과한다. boto3 standard retry(max 3회)로도 회복되지 않아 ThrottlingException이 최종 예외로 반환되고, Lambda는 500 (Failed to calculate captured area - ...ThrottlingException)을 응답한다. 일부 요청은 Lambda 앞단(API Gateway) 또는 Lambda concurrency 한계에서 걸려 503으로 반환됐고, 상위 Ruby 서비스는 두 상태 모두 RestClient::Exception으로 잡아 SYS20000으로 재발생시킨다.

Technical Analysis#

Code Path#

Entry point: app/workers/refresh_captured_size_worker.rb:5 (Sidekiq perform)

class RefreshCapturedSizeWorker
  include Sidekiq::Worker
  sidekiq_options queue: :fresh, retry: 1

  def perform(model_name, id, session_token = nil)
    return if model_name.nil?
    return if id.nil?

    model = model_name.constantize.find_by_id(id)
    session = ::SessionRepository.find_by_token(session_token)

    Cupix::Logger.error("#{model_name} not found: #{id}", class: self.class.name, function: __method__) and return if model.nil?

    model.calculate_captured_size!(session: session)
  end
end

Facility#calculate_captured_size!는 Cupix::VoxelService.calculate_captured_size!로 위임한다 (app/models/concerns/voxel_module.rb:46-56).

Cupix::VoxelService.calculate_captured_size!가 captured_area!를 호출하여 downstream voxel service에 HTTP PUT 요청:

_floorplans_count = facility.floorplans.untrashed.count
response = captured_area!({
  facility_key: facility.key,
  group_by_record: _floorplans_count.zero?,
  'x-cupix-auth': Cupix::Auth::AccessToken.encode({ session: session })
})

facility.update!(captured_size: response['total'], captured_size_state: :fresh)
::FootprintHistory.create!({
  facility: facility,
  workspace_id: facility.workspace_id,
  team_id: facility.team_id,
  captured_size: response['total'],
  details: response['details'],
  floorplans_count: _floorplans_count
})

Failure point: app/services/cupix/voxel_service.rb:88-99 — downstream이 503/500을 반환하면 RestClient::Exception으로 잡혀 SYS20000 System error가 재발생한다:

begin
  response = Cupix::HttpClient.put("#{$CUPIX_VOXEL_SERVICE_URL}/captured_area", body.to_json, headers)

  body = JSON.parse(response.body)

  Cupix::Logger.info("Completed - total: #{body.dig('results', 'total')}, details: #{body.dig('results', 'details')}", class: self.name, function: __method__, facility: { key: params[:facility_key] }, group_by_record: params[:group_by_record])

  body['results']
rescue RestClient::Exception => e
  Cupix::Logger.error("failed to get captured area - error: #{e.message}", class: self.name, function: __method__, facility_key: params[:facility_key], group_by_record: params[:group_by_record])

  raise Cupix::Errors::System.new(code: 'SYS20000', reason: "failed to get captured area - error: #{e.message}")

Downstream root cause: services/voxel/lambda/captured_area.py의 Athena polling 루프에 sleep이 없다. run_athena_query가 query state를 확인하기 위해 초당 수백 번 get_query_execution을 호출한다:

config = Config(
  retries = {
    'max_attempts': 3,
    'mode': 'standard'
  }
)

athena = boto3.client('athena', config=config)

def run_athena_query(query, output_location):
  # ... start_query_execution ...
  query_execution_id = response['QueryExecutionId']

  # Wait for Athena query to finish
  while True:
    response = athena.get_query_execution(QueryExecutionId=query_execution_id)
    if response['QueryExecution']['Status']['State'] in ('SUCCEEDED', 'FAILED', 'CANCELLED'):
      break

Exception path:

except Exception as e:
  return handler_response(500, f'Failed to calculate captured area - {str(e)}')

기대 동작: 각 facility당 Athena query 1회 실행, polling 간 최소 지연으로 rate limit 준수. 실제 동작: sleep 없는 폴링으로 Lambda 인스턴스당 100+ TPS GetQueryExecution 호출 발생. 다수 facility 병렬 처리 시 계정 단위 rate limit(기본 100 TPS) 초과 → ThrottlingException → boto3 3회 재시도 후 최종 실패 → 500 반환.

Log Evidence#

Datadog query (worker에서 상위 에러):

service:cupixvista-api-migration-worker status:error "failed to get captured area"

관측된 상위 에러 로그 (facility 594 첫 실패):

{
  "timestamp": "2026-07-15 21:33:59 KST",
  "status": "error",
  "message": "failed to calculate captured size for Facility ID: 594, error: failed to get captured area - error: 503 Service Unavailable",
  "class": "Facility",
  "function": "calculate_captured_size"
}

{
  "timestamp": "2026-07-15 21:33:59 KST",
  "status": "error",
  "message": "failed to get captured area - error: 503 Service Unavailable",
  "class": "Cupix::VoxelService",
  "function": "captured_area!"
}

시간대 내 502/500 혼재 (facility 599, 604, 609, 610):

2026-07-15 21:38:03 KST  Facility 599  error: 500 Internal Server Error
2026-07-15 21:39:23 KST  Facility 604  error: 500 Internal Server Error
2026-07-15 21:41:37 KST  Facility 607  error: 503 Service Unavailable
2026-07-15 21:42:27 KST  Facility 609  error: 500 Internal Server Error
2026-07-15 21:42:27 KST  Facility 610  error: 500 Internal Server Error
2026-07-15 21:44:41 KST  Facility 612  error: 503 Service Unavailable

Downstream Lambda side — Datadog query:

"Voxel::CapturedArea | handler_response" 500

Lambda가 반환한 500의 실제 이유 (동일 시간대):

{
  "timestamp": "2026-07-15 21:42:20~28 KST",
  "status": "info",
  "message": "Voxel::CapturedArea | handler_response - status_code: 500, body: \"Failed to calculate captured area - An error occurred (ThrottlingException) when calling the GetQueryExecution operation (reached max retries: 3): Rate exceeded\""
}

같은 시간대 (21:42:19~28 KST) 사이에만 20건 이상의 동일 ThrottlingException 로그가 확인됨. 실패 종료 후 21:49 KST에는 Lambda가 다시 정상적으로 200을 반환:

{
  "timestamp": "2026-07-15 22:12:42 KST",
  "status": "info",
  "message": "Voxel::CapturedArea | handler_response - status_code: 200, body: {\"facility_key\": \"pwwaqh\", \"results\": {\"total\": 60777, ...}}"
}

Lambda의 503은 별도 Voxel 로그 없이 발생 — API Gateway 앞단이나 Lambda concurrency limit에서 반환됐음을 시사한다 (Voxel::CapturedArea | 로그가 남지 않음).

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• services/voxel/lambda/captured_area.py의 run_athena_query polling 루프에 sleep 도입. 파일 위치와 라인: services/voxel/lambda/captured_area.py:49-52.
  • Athena query는 최소 수백 ms 단위의 실행 시간이 필요하므로 즉시 재조회는 무의미. time.sleep(0.5) 또는 exponential backoff (0.2s → 최대 2s)로 폴링 간격 확보.
  • 동일 파일 내 다른 Lambda(Voxel::AddPartition 등)도 동일 패턴이면 같이 적용 검토.
• 상위 워커(app/workers/refresh_captured_size_worker.rb)의 retry: 1 설정 재검토. Throttling은 일시적 오류이므로 retry 횟수를 늘리거나 exponential backoff로 완화 필요 (파일: app/workers/refresh_captured_size_worker.rb:3).

단기 개선 (1주 이내)#

• Ruby 클라이언트 측 재시도: Cupix::VoxelService.captured_area!에서 503/500(ThrottlingException 유형)을 감지해 backoff 재시도. 지금은 즉시 예외를 raise하고 Sidekiq retry에 의존하므로 반복 실패 시 데이터 누락.
• 마이그레이션 워커의 병렬도 조절: queue: :fresh로 enqueue되는 facility 처리량을 rate-limit (예: Sidekiq Enterprise sidekiq_options rate_limit, 또는 커스텀 semaphore).
• Athena ResultReuseByAgeConfiguration.MaxAgeInMinutes: 720 (12시간)은 이미 활성화되어 있으나, 마이그레이션 시나리오에서는 각 facility_key가 유일하므로 재사용 이득이 낮다. 마이그레이션 전용 캐시 계층(예: S3 pre-computed CSV) 검토.

장기 개선 (재발 방지)#

• Voxel service 호출 패턴을 pull(REST synchronous) → async job (SQS + polling endpoint 또는 EventBridge)으로 전환. 현재 구조는 Rails Sidekiq worker가 Lambda + Athena를 synchronous하게 기다리므로 downstream 장애가 즉시 상위 실패로 전파된다.
• Athena rate limit을 계정 단위에서 서비스 단위로 격리하기 위해 dedicated workgroup 사용, 또는 Service Quotas를 통한 상향 요청.
• Lambda 내 Athena polling을 Step Functions의 .waitForTaskToken 또는 athena:StartQueryExecution native integration으로 대체하여 polling 자체를 제거하는 방안 검토.

Monitoring#

Ruby 상위 에러:

service:cupixvista-api-migration-worker status:error "failed to get captured area"

Downstream Lambda의 Athena throttling (proof-of-fix에 가장 직접적):

"Voxel::CapturedArea" "ThrottlingException" "GetQueryExecution"

Lambda 500 응답 발생율:

"Voxel::CapturedArea | handler_response - status_code: 500"

CUPIXVISTA 마이그레이션 워커 전반 에러:

service:cupixvista-api-migration-worker status:error

Risk Assessment#

• Risk level: medium — 데이터 자체는 손상되지 않지만 captured_size 갱신이 누락되어 UI 상 stale 상태가 되고, 마이그레이션 대상 facility가 재실행 없이는 보정되지 않는다. downstream fix는 다른 tenant(cupixworks)에도 영향이 있으므로 롤아웃 시 회귀 리스크가 있다.
• 예상 복잡도: standard — Python Lambda에 time.sleep 도입은 trivial이나, backoff 정책 결정, 다른 voxel Lambda 파일 동일 패턴 확인, 상위 Ruby retry 정책 조정까지 포함하면 표준 규모.