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#
- 2025-04-24 17:05 KST — 최초 발생 (first_seen). 22개월간 지속.
- 2026-08-04 13:48 KST — now-24h 창에서 다수 facility 에 대해 500 반복 발생 (Facility ID 16141, 4764, 4763... 다수 distinct).
- 2026-08-04 13:51 KST — 최근 발생 (last_seen). span
2026-08-04T04:51:31Z와 일치.
Error Log#
500 Internal Server Error
Impact#
- Service:
cupixvista-rest_client(APMrest_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::HttpClient 의 RETRIABLE_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_size 의 rescue → 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:13→app/models/concerns/voxel_module.rb:46calculate_captured_size! - Entry point (cron):
lib/cupix/cron/facility.rb:100facility.calculate_captured_size(rescued no-bang) - Downstream call:
app/services/cupix/voxel_service.rb:89→lib/cupix/http_client.rb:57put - Failure point (raise):
app/services/cupix/voxel_service.rb:96-99rescue RestClient::Exception → SYS20000
Cron batch 는 최대 30개의 stale facility 를 순차 처리하며, 각 실패를 warn 으로 기록하고 계속 진행한다. 이것이 로그에서 다수의 distinct facility ID 가 관찰되는 이유다.
::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 를 반환한다 — 사용자 경로가 아니다.
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 으로 변환된다.
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 됨과 대조).
RETRIABLE_STATUS_CODES = [429, 502, 503, 504].freeze
downstream lambda 는 Athena query 실패 시 500 을 반환한다.
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 으로만 존재):
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.
{
"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회씩 기록):
service filter: "failed to calculate captured size" "error: 500" (now-24h)
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_arealambda 의 Athena query 실패율/원인(FAILED/CANCELLED, concurrency limit) 을 확인.
장기 개선 (재발 방지)#
- downstream lambda 가 Athena 실패를 502/503(retriable) 로 매핑하도록 하면 tesla
Cupix::HttpClientretry 로 자연 흡수 가능. 전역RETRIABLE_STATUS_CODES에 500 을 추가하지 말 것 — 다른 endpoint(thumbnails/autodesk 등)에 영향. 필요 시 captured_area 경로에 국한된 retry 를 tesla 측에 추가. - Athena query 안정성 개선(파티션/데이터 정합성) — 근본 해결.
Monitoring#
captured_area 500 span 추이:
service:cupixvista-rest_client status:error @http.status_code:500 @http.url:*captured_area*
background captured size 계산 실패 로그 추이:
"failed to get captured area - error: 500"
500/503 을 함께 보는 downstream 신뢰성 추이:
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 코드 결함이 아니다.