ES /docs

RestClient::InternalServerError: 500 Internal Server Error

RCA: RestClient::InternalServerError: 500 Internal Server Error (voxel-service captured_area)

Overview#

What Happened#

tesla (vista 배포)의 background 작업이 voxel-service 로 보내는 PUT /api/v1/voxels/captured_area 요청이 downstream 에서 500 Internal Server Error 를 반환하면서 RestClient::InternalServerError 가 발생했다. 이 500 은 tesla Cupix::HttpClient 의 retriable 목록에 없어 즉시 raise 되고, APM rest_client 컴포넌트 span 이 error 로 태깅되어 Error Tracking 에 집계된다. 실제 실행 경로는 RefreshCapturedSizeWorker 와 cron flush_stale_captured_size batch 로, 두 경로 모두 완전히 rescue 되어 사용자 영향은 없다. 근본 원인은 downstream voxel-service lambda 의 Athena query 실패(transient)이며, tesla 코드 결함이 아니다.

Quick Facts#

Field Value
exception.class RestClient::InternalServerError
exception.message 500 Internal Server Error
top_frame app/services/cupix/voxel_service.rb:96 (captured_area! rescue)
runtime Ruby / Sidekiq (RefreshCapturedSizeWorker), Cron (Cupix::Cron::Facility)
env production, us-west-2 (tenant: cupix / vista deployment)

Affected Teams#

Team / Domain Error Count Impact
tesla (cupixvista) background 28 spans (500, now-24h) 사용자 영향 없음 — background 작업, 다층 rescue
voxel-service (data-pipeline-functions) downstream Athena query 실패로 500 반환 (근본 원인 위치)

Timeline#

  1. 2025-04-24 17:05 KST — 최초 발생 (first_seen). 22개월간 지속.
  2. 2026-08-04 13:48 KST — now-24h 창에서 다수 facility 에 대해 500 반복 발생 (Facility ID 16141, 4764, 4763... 다수 distinct).
  3. 2026-08-04 13:51 KST — 최근 발생 (last_seen). span 2026-08-04T04:51:31Z 와 일치.

Error Log#

Datadog Logs

text
500 Internal Server Error

Impact#

  • Service: cupixvista-rest_client (APM rest_client 컴포넌트 span — 실제 app 은 tesla vista 배포)
  • 발생 횟수: 1068
  • 최초 발생: 2025-04-24 17:05 KST
  • 최근 발생: 2026-08-04 13:51 KST

Root Cause Summary#

tesla 의 background 작업(RefreshCapturedSizeWorker 및 cron flush_stale_captured_size)이 facility 별 captured size 를 재계산하기 위해 Cupix::VoxelService.captured_area! 를 호출하고, 이것이 Cupix::HttpClient.put 으로 voxel-service PUT /api/v1/voxels/captured_area 를 호출한다. downstream lambda(data-pipeline-functions/services/voxel/lambda/captured_area.py)는 Athena query 가 FAILED/CANCELLED(=run_athena_query returns None) 이거나 except Exception 시 HTTP 500 을 반환한다. tesla Cupix::HttpClientRETRIABLE_STATUS_CODES = [429, 502, 503, 504] 에는 500 이 없어 retry 없이 즉시 raise 되고, APM rest_client span 이 error 로 태깅되어 Error Tracking 에 잡힌다. 그러나 이 500 은 captured_area!rescue RestClient::Exception → SYS20000, 그리고 상위 calculate_captured_sizerescue → warn/false(cron) 또는 Sidekiq retry:1(worker) 로 완전히 처리되어 사용자 영향이 전혀 없다. 근본 원인은 downstream 의 transient Athena 신뢰성 문제이며 tesla 코드 결함이 아니다 → noise.

Technical Analysis#

Code Path#

  • Entry point (worker): app/workers/refresh_captured_size_worker.rb:13app/models/concerns/voxel_module.rb:46 calculate_captured_size!
  • Entry point (cron): lib/cupix/cron/facility.rb:100 facility.calculate_captured_size (rescued no-bang)
  • Downstream call: app/services/cupix/voxel_service.rb:89lib/cupix/http_client.rb:57 put
  • Failure point (raise): app/services/cupix/voxel_service.rb:96-99 rescue RestClient::Exception → SYS20000

Cron batch 는 최대 30개의 stale facility 를 순차 처리하며, 각 실패를 warn 으로 기록하고 계속 진행한다. 이것이 로그에서 다수의 distinct facility ID 가 관찰되는 이유다.

lib/cupix/cron/facility.rb:97-105ruby
::Facility.stale_captured_size.limit(30).find_each do |facility|
  Cupix::Logger.info("Flushing stale captured size for Facility #{facility.id}", ...)

  if facility.calculate_captured_size(session: session)
    Cupix::Logger.info("Successfully flushed stale captured size for Facility #{facility.id}", ...)
  else
    Cupix::Logger.warn("Failed to flush stale captured size for Facility #{facility.id}", ...)
  end
end

calculate_captured_size (no-bang) 는 예외를 삼켜 error 로그를 남기고 false 를 반환한다 — 사용자 경로가 아니다.

app/models/concerns/voxel_module.rb:19-27ruby
def calculate_captured_size(session: nil)
  calculate_captured_size!(session: session)
rescue => e
  Cupix::Logger.error("failed to calculate captured size for #{self.class.name} ID: #{id}, error: #{e.message}", ...)
  false
else
  true
end

downstream 호출 실패는 captured_area! 에서 SYS20000 으로 변환된다.

app/services/cupix/voxel_service.rb:88-99ruby
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')}, ...", ...)
  body['results']
rescue RestClient::Exception => e
  Cupix::Logger.error("failed to get captured area - error: #{e.message}", ...)
  raise Cupix::Errors::System.new(code: 'SYS20000', reason: "failed to get captured area - error: #{e.message}")

500 은 retriable 목록에 없어 즉시 raise 된다 (503 은 retry 됨과 대조).

lib/cupix/http_client.rb:8ruby
RETRIABLE_STATUS_CODES = [429, 502, 503, 504].freeze

downstream lambda 는 Athena query 실패 시 500 을 반환한다.

data-pipeline-functions/services/voxel/lambda/captured_area.py:132-145python
    if response is not None and len(response['Rows']) > 0:
      return handler_response(200, { 'facility_key': facility_key, 'results': parse_captured_area_result(response['Rows']) })
    else:
      return handler_response(500, f'Athena query failed - response is None')
  except KeyError as e:
    return handler_response(400, { 'result': 'ARG10000', 'message': 'Missing required attribute in the request body:' + str(e) })
  except Exception as e:
    return handler_response(500, f'Failed to calculate captured area - {str(e)}')

기대 동작: transient downstream 실패면 재시도하거나 background 에서 조용히 흡수. 실제 동작: 500 은 retry 되지 않고 raise → APM span error 태깅 → Error Tracking noise (사용자 영향 없음).

Log Evidence#

APM span 검색 (rest_client 예외는 로그가 아닌 span 으로만 존재):

text
service:cupixvista-rest_client status:error @http.status_code:500   (now-24h)

결과: 28 spans, 전부 PUT /api/v1/voxels/captured_area, RestClient::InternalServerError / 500 Internal Server Error.

json
{
  "ts": "2026-08-04T04:51:31.015Z",
  "resource": "PUT",
  "statusCode": "500",
  "errType": "RestClient::InternalServerError",
  "errMsg": "500 Internal Server Error",
  "url": "/api/v1/voxels/captured_area",
  "tenant": "cupix"
}

같은 창의 500/503 분포 (now-6h): 503 RestClient::ServiceUnavailable 62건 + 500 RestClient::InternalServerError 4건 — 500 과 503 은 같은 endpoint 의 별개 ET 이슈다.

실제 error 로그 (span 이 아닌 로그, 500 발생 시 2회씩 기록):

text
service filter: "failed to calculate captured size" "error: 500"   (now-24h)
text
2026-08-04 17:48:30  error  failed to calculate captured size for Facility ID: 16141, error: failed to get captured area - error: 500 Internal Server Error  (class:Facility function:calculate_captured_size)
2026-08-04 17:48:30  error  failed to get captured area - error: 500 Internal Server Error  (class:Cupix::VoxelService function:captured_area!)
2026-08-04 17:48:26  error  failed to calculate captured size for Facility ID: 4764, error: failed to get captured area - error: 500 Internal Server Error  (class:Facility function:calculate_captured_size)

Facility ID 분포 (now-24h): 16141, 4764, 4763, 4756, 4752, 4742, 4733, 4729, 4726, 4708, 4689, 4687... 대부분 1회씩 등장하는 다수의 distinct facility → 특정 facility 재진입이 아닌 broad downstream Athena 신뢰성 문제. 순차적인 ID 나열은 cron flush_stale_captured_size batch(limit(30)) 처리 패턴과 일치.

status:error 키워드 로그 (RestClient::InternalServerError) 검색은 0건 — RestClient 예외는 로그로 직접 남지 않고 APM span 으로만 존재하기 때문. class:Facility / Cupix::VoxelService 의 wrapped 문자열 로그로만 관찰됨.

Hypotheses Considered#

# Hypothesis Evidence for Evidence against Verdict
H1 downstream voxel-service captured_area lambda 의 transient Athena query 실패가 500 을 반환하고, tesla background 작업에서 완전 rescue 됨 (noise) 28/28 span 이 PUT /api/v1/voxels/captured_area 500; lambda captured_area.py:132,145 가 Athena 실패 시 500 반환; voxel_module.rb:23/Sidekiq retry:1 rescue; 다수 distinct facility ID Confirmed
H2 Representative Error 가 stale (실제 현재 메시지가 다름) ET 는 500/503 변형을 묶는 경향 있음 last_seen span 2026-08-04T04:51:31Z 가 rep 500 Internal Server Error 와 정확히 일치; 메시지는 고정 HTTP status 문자열 Rejected
H3 tesla 코드 결함 (nil ref, retry 누락으로 인한 사용자 500) 500 이 RETRIABLE_STATUS_CODES 에 없어 retry 안 됨 500 은 non-retriable 이 정상 (client 가 downstream 500 재시도할 이유 없음); background 경로만이고 다층 rescue 로 사용자 영향 0 Rejected
H4 503 sibling 이슈와 동일 클러스터 같은 endpoint, 같은 service span error_type/status 다름 (ServiceUnavailable 503 vs InternalServerError 500); ET 별개 이슈; cross-merge 금지 Rejected

Fix Recommendation#

즉시 조치 (Critical)#

없음. tesla 코드는 정상 동작하며 사용자 영향이 없다. 근본 원인은 downstream voxel-service lambda 의 Athena query 실패다. Error Tracking IGNORE 권장.

단기 개선 (1주 이내)#

  • 알람 노이즈 완화 (선택): cron flush_stale_captured_size 경로에서 downstream 500 은 이미 voxel_module.rb:22 가 error 로 기록한다. background retry 경로의 transient 실패이므로 voxel_service.rb:97 또는 voxel_module.rb:22 의 로그 레벨을 warn 으로 낮추는 것을 검토 (alarm 노이즈 감소, 코드 결함 수정 아님).
  • downstream 조사: data-pipeline-functions 팀과 voxel-service captured_area lambda 의 Athena query 실패율/원인(FAILED/CANCELLED, concurrency limit) 을 확인.

장기 개선 (재발 방지)#

  • downstream lambda 가 Athena 실패를 502/503(retriable) 로 매핑하도록 하면 tesla Cupix::HttpClient retry 로 자연 흡수 가능. 전역 RETRIABLE_STATUS_CODES 에 500 을 추가하지 말 것 — 다른 endpoint(thumbnails/autodesk 등)에 영향. 필요 시 captured_area 경로에 국한된 retry 를 tesla 측에 추가.
  • Athena query 안정성 개선(파티션/데이터 정합성) — 근본 해결.

Monitoring#

captured_area 500 span 추이:

text
service:cupixvista-rest_client status:error @http.status_code:500 @http.url:*captured_area*

background captured size 계산 실패 로그 추이:

text
"failed to get captured area - error: 500"

500/503 을 함께 보는 downstream 신뢰성 추이:

text
service:cupixvista-rest_client status:error @http.url:*captured_area*

Risk Assessment#

  • Risk level: low
  • 예상 복잡도: trivial (코드 변경 불필요; downstream 조사 및 선택적 로그 레벨 조정만)

Noise Verdict#

noise — downstream voxel-service 의 transient Athena 실패로 인한 500 이며 background 작업에서 완전히 rescue 되어 사용자 영향이 없는 정상적으로 흡수되는 외부 신뢰성 문제이므로 tesla 코드 결함이 아니다.