Api::V1::ElementRecordsController#validation (avg 21811ms, max 21811ms)

RCA: ElementRecordsController#validation Latency (21.8s)

Overview#

What Happened#

2026-05-27T08:13:59Z에 cupixworks-api 서비스의 Api::V1::ElementRecordsController#validation 엔드포인트가 facility 10ofni에 대한 요청을 처리하는 데 21.8초가 소요되었다. 해당 facility는 252,217개의 element record를 보유한 대규모 시설로, DB 쿼리(9.9초)와 Ruby 애플리케이션 내 반복 로직(11.9초)이 결합되어 과도한 지연이 발생했다.

Quick Facts#

Field	Value
resource_name	`Api::V1::ElementRecordsController#validation`
top_frame	`app/services/cupix/siteinsights_service.rb:196`
duration	21,806 ms
db_time	9,938 ms
env	production, us-west-2
deploy	`production-us-west-2-20260527t0524z0-650f3601-cupixworks`

Timeline#

2026-05-27T08:13:59Z — 요청 수신 (GET /api/v1/siteinsights/element_records/validation?facility_key=10ofni)
2026-05-27T08:14:21Z — validate_element_records completed 로그 기록 (validation 로직 완료)
2026-05-27T08:14:22Z — HTTP 200 응답 반환 (총 21,806ms 소요)
2026-05-27T08:14:22Z — error-sweeper latency 클러스터 감지

Error Log#

Datadog Logs

json

{
  "resource_name": "Api::V1::ElementRecordsController#validation",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 21811,
  "max_ms": 21811,
  "sample_trace_id": "4026559609858390375"
}

Impact#

Service: cupixworks-api
발생 횟수: 1
최초 발생: 2026-05-27T08:13:59.286Z
최근 발생: 2026-05-27T08:13:59.286Z
영향 범위: 단일 사용자 (noah.park@cupix.com), facility 10ofni (252,217 element records)의 validation 요청. HTTP 200으로 정상 응답하였으나 UX 관점에서 21초 대기 발생.

Root Cause Summary#

Facility 10ofni는 252,217개의 element record를 보유한 대규모 시설이다. validate_element_records 메서드는 (1) DB에서 전체 Task/Element를 pluck하여 (2) Ruby 메모리 내에서 O(elements × matching_tasks) 반복을 수행하고, (3) 외부 Siteinsights 서비스에 HTTP 호출을 한다. DB 쿼리에 9.9초, Ruby 내 반복 로직에 약 11.9초가 소요되어 총 21.8초의 응답 시간이 발생했다. timeout이나 pagination 없이 전체 데이터를 한 번에 처리하는 설계가 근본 원인이다.

Technical Analysis#

Code Path#

Entry point: app/controllers/api/v1/element_records_controller.rb:29

app/controllers/api/v1/element_records_controller.rb:29-33ruby

def validation
  response = Cupix::SiteinsightsService.validate_element_records(params[:facility_key], current_user: @current_user, current_team: @current_team)

  render_json 200, response
end

Orchestration: app/services/cupix/siteinsights_service.rb:196-212

app/services/cupix/siteinsights_service.rb:196-212ruby

def validate_element_records(facility_key, current_user: nil, current_team: nil)
  raise Cupix::Errors::Parameter.new(code: 'ARG10000', reason: 'facility_key is required') if facility_key.blank?

  facility = ::FacilityRepository.new(current_user: current_user, current_team: current_team).show(facility_key)

  element_counts = _calculate_element_counts(facility)

  element_record_counts = _get_element_record_counts(facility_key, element_counts[:tasks_for_query])

  stale_elements = _get_stale_elements_if_needed(facility, facility_key, element_record_counts)

  result = _build_validation_result(facility_key, element_counts, element_record_counts, stale_elements)

  Cupix::Logger.info('validate_element_records completed', class: self.name, function: __method__, facility_key: facility_key, is_valid: result[:is_valid], summary: result[:summary])

  result
end

Failure point (성능 병목): app/services/cupix/siteinsights_service.rb:216-270

_calculate_element_counts에서 252,217개의 element를 모두 메모리에 로드한 후 중첩 반복문으로 task-element 매칭을 수행한다:

app/services/cupix/siteinsights_service.rb:240-256ruby

elements_data.each do |element_id, category_id, workarea_ids|
  next if workarea_ids.blank?

  workarea_ids.each do |element_workarea_id|
    matching_tasks = tasks_by_category_workarea[[category_id, element_workarea_id]] || []

    matching_tasks.each do |task_id, texture_id, task_category_id, task_phase_id|
      element_texture_key = [element_id, texture_id]
      next if counted_element_textures.include?(element_texture_key)

      counted_element_textures.add(element_texture_key)
      count_by_task[task_id] += 1
      count_by_category[task_category_id] += 1
      count_by_phase[task_phase_id] += 1
      total_count += 1
    end
  end
end

252,217 elements × workarea_ids × matching_tasks로 인해 Set#include? 및 Set#add 연산이 수백만 회 발생한다.

External HTTP call (timeout 미설정): app/services/cupix/siteinsights_service.rb:275-279

app/services/cupix/siteinsights_service.rb:275-279ruby

response = Cupix::HttpClient.post(
  "#{Cupix::Siteinsights.service_url}/element_records/validation",
  { facility_key: facility_key, tasks: tasks_for_query }.to_json,
  { content_type: :json }
)

HTTP client (timeout 미설정, retry 포함): lib/cupix/http_client.rb:34-46

lib/cupix/http_client.rb:34-46ruby

def self.post(url, payload, headers = {}, retries: MAX_RETRIES)
  attempt = 0
  begin
    RestClient.post(url, payload, headers)
  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
end

RestClient.post에 timeout 또는 open_timeout 파라미터가 전달되지 않아, 외부 서비스가 느릴 경우 무한 대기가 가능하다.

Log Evidence#

Datadog 검색 쿼리:

text

service:cupixworks-api @trace_id:4026559609858390375

요청 완료 로그:

json

{
  "timestamp": "2026-05-27T08:14:22.368Z",
  "status": "info",
  "message": "[200] GET /api/v1/siteinsights/element_records/validation (Api::V1::ElementRecordsController#validation)",
  "duration": 21806.1,
  "db": 9938.32,
  "view": 5.12,
  "params": { "facility_key": "10ofni" },
  "user": "noah.park@cupix.com",
  "team": { "domain": "admin", "id": 133 }
}

Validation 완료 로그:

json

{
  "timestamp": "2026-05-27T08:14:21.142Z",
  "status": "info",
  "message": "validate_element_records completed",
  "class": "Cupix::SiteinsightsService",
  "function": "validate_element_records",
  "facility_key": "10ofni",
  "is_valid": true,
  "summary": {
    "element_record_total": 252217,
    "element_total": 252217,
    "difference": 0,
    "total_discrepancies": 0,
    "duplicate_count": 0,
    "orphan_count": 0,
    "mismatch_count": 0
  }
}

시간 분해:

Component	Duration	%
DB 쿼리 (Task + Element pluck)	9,938 ms	45.6%
Ruby 애플리케이션 로직 (반복 + HTTP)	11,863 ms	54.4%
View 렌더링	5 ms	~0%

Hypotheses Considered#

#	Hypothesis	Evidence for	Evidence against	Verdict
H1	대규모 facility(252K records)에 대한 전체 데이터 로드 + O(N×M) Ruby 반복이 지연 원인	DB 9.9초 + 앱 11.9초 = 21.8초, 로그에 252,217 element_record_total 확인, `_calculate_element_counts`의 중첩 loop 구조 (`siteinsights_service.rb:240-256`)	—	Confirmed
H2	외부 Siteinsights API 호출 지연 또는 retry가 주 원인	`HttpClient.post`에 timeout 미설정 (`http_client.rb:37`), retry 시 exponential backoff 존재	validation 결과 `is_valid: true`이며 discrepancy 0 — `_get_stale_elements_if_needed`가 조기 반환됨 (두 번째 HTTP 호출 미발생), 에러 로그 없음	Rejected
H3	DB deadlock 또는 lock contention으로 인한 쿼리 지연	같은 날 다른 endpoint에서 deadlock 발생 기록 (08:43 EditingsController)	해당 시간대(08:13-08:14)에는 deadlock/lock 관련 로그 없음, 동일 facility 후속 요청(08:19 spacetimes) 정상 응답(130-240ms)	Rejected

Fix Recommendation#

즉시 조치 (Critical)#

app/services/cupix/siteinsights_service.rb:275-279: Cupix::HttpClient.post에 timeout 파라미터 추가 (예: 15초). 외부 서비스 응답 대기가 무제한이므로 상한을 설정해야 한다.
lib/cupix/http_client.rb:37: RestClient.post 호출에 timeout과 open_timeout을 받을 수 있도록 옵션 전파 구현.

단기 개선 (1주 이내)#

app/services/cupix/siteinsights_service.rb:216-270: 대규모 facility에 대해 _calculate_element_counts의 DB 쿼리를 batch 처리하거나, element count를 DB 레벨 집계 쿼리(GROUP BY)로 변경하여 Ruby 반복 제거. 252K element를 메모리에 로드하는 대신 SQL COUNT로 처리하면 DB 시간과 앱 시간 모두 대폭 감소 가능.
Controller에 request timeout 설정 (예: Rack::Timeout 또는 서비스 레벨 timeout 15초).

장기 개선 (재발 방지)#

Validation 로직을 비동기 작업(background job)으로 전환하고, 결과를 캐시하여 폴링 방식으로 제공. 대규모 facility에서 동기 API 호출로 수십 초 대기는 UX상 부적절.
Element count를 materialized view 또는 counter cache로 관리하여 실시간 계산 불필요하게 만들기.
Facility 크기 기반 경고/제한 로직 도입 (예: 100K 이상 시 비동기 전환).

Monitoring#

추가할 메트릭: ElementRecordsController#validation 응답 시간 P95/P99 알림.
Datadog 쿼리:

text

service:cupixworks-api resource_name:"Api::V1::ElementRecordsController#validation" @duration:>10000000000

element_record_total > 100,000인 facility에 대한 validation 호출 시 경고 로그 추가.

Risk Assessment#

Risk level: low
예상 복잡도: standard
현재 단일 발생이며 요청은 정상 완료(HTTP 200). 그러나 해당 facility나 유사 대규모 시설에서 반복 호출 시 사용자 경험 저하 및 서버 리소스 점유가 누적될 수 있다. timeout 미설정으로 인한 잠재적 thread 고갈 위험은 medium으로 평가.