RCA: failed to get captured area - error: Timed out reading data from server

Overview#

What Happened#

2026-08-06, production cupixworks-worker(tesla Sidekiq)의 background footprint 계산 경로에서 voxel-service captured_area 호출이 30초 read timeout으로 실패했다. tesla가 Cupix::HttpClient의 DEFAULT_READ_TIMEOUT = 30초 안에 voxel-service Lambda(동기 Athena 쿼리)의 응답을 받지 못해 RestClient::Exceptions::ReadTimeout("Timed out reading data from server")이 발생했고, Cupix::VoxelService.captured_area!의 rescue가 이를 SYS20000으로 재-raise했다. 이 timeout은 Cupix::HttpClient의 재시도 조건(RETRIABLE_STATUS_CODES = [429, 502, 503, 504])에 해당하지 않아 재시도되지 않는다. footprint 계산은 background 작업이며 모든 계층에서 rescue되어 사용자 영향은 없다 → noise (downstream Athena 지연으로 인한 transient/deterministic timeout).

Quick Facts#

Affected Teams#

Timeline#

1. 2026-08-06 17:32 KST — 클러스터 first_seen. burst 시작 (production cupixworks-worker).
2. 2026-08-06 17:47 KST — 클러스터 last_seen. ~15분 창에 10건 수집.
3. 참고: Facility ID 13은 now-14d 전 기간에 걸쳐 4시간 주기(cron)로 동일 timeout 반복 (84건).

Error Log#

Datadog Logs

failed to get captured area - error: Timed out reading data from server

Impact#

• Service: cupixworks-worker
• Team: cupix
• 발생 횟수: 10 (클러스터), now-14d 실측 94건 (class:Facility timeout 로그)
• 최초 발생: 2026-08-06 17:32 KST
• 최근 발생: 2026-08-06 17:47 KST

Root Cause Summary#

tesla background footprint 계산이 voxel-service captured_area 엔드포인트를 Cupix::HttpClient.put으로 동기 호출하는데, 이 클라이언트의 DEFAULT_READ_TIMEOUT은 30초다. voxel-service Lambda는 tb_raw_voxel(원시 voxel) 테이블과 reality-captures를 조인하는 동기 Athena 쿼리를 실행하며, 데이터가 큰 facility의 경우 이 쿼리가 30초를 초과한다. tesla가 먼저 read timeout에 도달해 RestClient::Exceptions::ReadTimeout("Timed out reading data from server")이 raise되고, captured_area!의 rescue RestClient::Exception(voxel_service.rb:98)이 이를 Cupix::Errors::System SYS20000으로 감싸 다시 raise한다. 이 timeout은 HTTP status가 없어(e.http_code가 nil) Cupix::HttpClient의 재시도 조건 RETRIABLE_STATUS_CODES = [429, 502, 503, 504]에 매칭되지 않아 재시도되지 않는다. footprint 계산은 background 경로(cron flush_stale_captured_size / RefreshCapturedSizeWorker)이고 상위에서 rescue되어 사용자 영향이 없으므로 코드 결함이 아닌 downstream 지연 noise다. 500/503 sibling(ab4f1e3c/bc8ca9b0)과 root cause 위치(downstream Athena)는 같으나, 이 변형은 Lambda가 status를 반환하기 전에 tesla가 연결을 포기한 read-timeout이라는 점이 다르다.

Technical Analysis#

Code Path#

• Entry point (background): cron Cupix::Cron::Facility#flush_stale_captured_size (lib/cupix/cron/facility.rb:92) 및 RefreshCapturedSizeWorker#perform (app/workers/refresh_captured_size_worker.rb)
• Facility#calculate_captured_size (app/models/concerns/voxel_module.rb:21) → calculate_captured_size! → Cupix::VoxelService.captured_area!
• Failure point: app/services/cupix/voxel_service.rb:97-98 (Cupix::HttpClient.put read timeout → rescue)

cron은 stale facility 30개를 순회하며 no-bang calculate_captured_size를 호출하고, 실패 시 warn 후 continue한다. facility가 timeout으로 계속 실패하면 captured_size_state가 fresh로 갱신되지 않아 다음 cron 주기(4시간마다)에 다시 선택된다 — 이것이 Facility 13의 주기적 반복 원인이다.

::Facility.stale_captured_size.limit(30).find_each do |facility|
  Cupix::Logger.info("Flushing stale captured size for Facility #{facility.id}", class: self.name, function: __method__, module: 'Cupix::Cron')

  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

no-bang calculate_captured_size는 calculate_captured_size!를 호출하고 예외를 rescue → 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}", class: self.class.name, function: __method__, model: { id: id, type: self.class.name })

  false
else
  true
end

실제 timeout이 발생하고 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}", 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}")

Cupix::HttpClient.put은 read timeout을 30초로 고정하고, 재시도는 HTTP status code 기반이라 timeout(e.http_code == nil)은 재시도하지 않는다:

RETRIABLE_STATUS_CODES = [429, 502, 503, 504].freeze
MAX_RETRIES = 3
DEFAULT_OPEN_TIMEOUT = 5
DEFAULT_READ_TIMEOUT = 30

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

기대 동작: voxel-service가 30초 이내에 응답 → footprint 계산 완료. 실제 동작: 데이터가 큰 facility에서 downstream Athena 쿼리가 30초를 초과 → tesla가 read timeout으로 연결 포기 → ReadTimeout → SYS20000. e.http_code가 nil이라 재시도 없이 즉시 실패.

Downstream (voxel-service Lambda)#

Lambda는 동기 Athena 쿼리를 실행한다. tb_raw_voxel(원시 voxel) 대량 테이블 조인 + COUNT(DISTINCT ...) 집계는 facility의 voxel 수에 비례해 느려지며, tesla의 30초 read timeout을 초과할 수 있다. 이 경로에서 Lambda는 500/503을 반환하지 않는다 — tesla가 응답 전에 연결을 끊기 때문이다 (500/503 sibling과의 차이점).

captured_area_query = f"""
  WITH rc ( ... ) AS (
      SELECT * FROM tb_tesla_reality_captures
      WHERE facility_key = '{facility_key}' AND (model_type = 'pointcloud' OR model_type = 'capture')
  )
  SELECT rc.level_id AS level_id..., COUNT(DISTINCT CONCAT(...)) AS "captured_area"
  FROM tb_raw_voxel AS v, rc
  WHERE v.model_id = rc.model_id AND v.model_type = rc.model_type
  GROUP BY rc.level_id...
"""
response = run_athena_query(captured_area_query, output_location)

Log Evidence#

Datadog 쿼리 (재현용):

service:cupixworks-worker "failed to get captured area - error: Timed out reading data from server"

service:cupixworks-worker "failed to calculate captured size" "Timed out reading data from server"

에러당 2건이 로깅된다 — Cupix::VoxelService#captured_area!(내부)와 Facility#calculate_captured_size(no-bang wrapper). 클러스터 창(2026-08-06 17:45~17:47 KST) 실측:

{
  "timestamp": "2026-08-06 17:47:05",
  "status": "error",
  "message": "failed to get captured area - error: Timed out reading data from server",
  "class": "Cupix::VoxelService",
  "function": "captured_area!"
}

{
  "timestamp": "2026-08-06 17:47:05",
  "status": "error",
  "message": "failed to calculate captured size for Facility ID: 15680, error: failed to get captured area - error: Timed out reading data from server",
  "class": "Facility",
  "function": "calculate_captured_size"
}

class:Facility timeout 로그의 facility ID 분포 (now-14d, 94건):

84  Facility ID: 13       ← 결정론적 반복 (아래 참조)
 1  Facility ID: 9486
 1  Facility ID: 5309
 1  Facility ID: 4470
 1  Facility ID: 282
 1  Facility ID: 15680
 1  Facility ID: 15662
 1  Facility ID: 15643
 1  Facility ID: 15441
 1  Facility ID: 13788
 1  Facility ID: 11288

Facility 13은 4시간 주기(cron 주기)로 동일 timeout이 재발 — stale 상태가 해소되지 않아 매 cron이 재선택:

2026-08-06 17:32:15
2026-08-06 13:32:17
2026-08-06 09:32:20
2026-08-06 05:32:17
2026-08-06 01:32:17
2026-08-05 21:32:20
2026-08-05 17:32:20
2026-08-05 13:32:17

→ Facility 13 = downstream Athena 쿼리가 이 facility 데이터에 대해 결정론적으로 30초 초과 (per-facility 재진입 아님, cron이 stale이라 재선택). 나머지 facility들은 단발성 transient timeout으로, 광범위 downstream 지연 신호.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 코드 변경 불필요. background footprint 계산 경로는 모든 계층에서 rescue되어 사용자 영향이 없다. Error Tracking에서 이 이슈는 ignore/noise 처리 권장.

단기 개선 (1주 이내)#

• alarm noise 감소: flush_stale_captured_size cron이 timeout을 만성적으로 겪는 facility(예: Facility 13)를 매 4시간 재시도하며 status:error 로그를 반복 생성한다. voxel_service.rb:98의 timeout(read timeout) 케이스를 error가 아닌 warn으로 강등하거나, cron 경로에서 만성 실패 facility에 backoff/skip 마킹을 두어 반복 error 로그를 줄이는 방향을 검토. (단, timeout 케이스만 좁혀서 강등 — 진짜 downstream 5xx는 error 유지.)
• downstream 확인: Facility 13에 대한 voxel-service Lambda / Athena 쿼리 실행 시간을 확인해 30초 초과가 데이터 규모 때문인지 검증 (voxel-service 로그).

장기 개선 (재발 방지)#

• voxel-service captured_area를 대용량 facility에 대해 비동기 처리(Athena 쿼리 제출 후 결과 poll/callback)로 전환하거나, tesla 측에서 이 경로만 read timeout을 상향(예: footprint 계산 전용 client)하는 방안 검토. 단, 무작정 timeout 상향은 Sidekiq worker 점유 시간을 늘리므로 신중해야 함.
• Athena 쿼리 최적화 (tb_raw_voxel 파티셔닝/사전 집계)로 대용량 facility의 쿼리 시간을 30초 이내로 낮추는 것이 근본 해소.

Monitoring#

captured_area timeout 발생 추이 (release dashboard timeseries widget용):

service:cupixworks-worker "failed to get captured area - error: Timed out reading data from server"

특정 facility(예: 13) 결정론적 timeout 지속 여부 확인:

service:cupixworks-worker "failed to calculate captured size for Facility ID: 13," "Timed out reading data from server"

captured_area 관련 전체 실패(timeout + 500 + 503) 추이 비교:

service:cupixworks-worker "failed to get captured area - error"

Risk Assessment#

• Risk level: low (background 경로, 사용자 영향 없음, self-heal)
• 예상 복잡도: trivial (코드 변경 시 log-level 강등 수준; 근본 해소는 downstream Athena/비동기화로 standard)