RCA: ElementRecordsController#bulk Latency (2110ms)

Overview#

What Happened#

2026-05-28 15:12 KST에 Api::V1::ElementRecordsController#bulk 엔드포인트에서 2110ms 응답 지연이 발생했다. 이 엔드포인트는 외부 SiteInsights Lambda 서비스로 bulk 요청을 프록시하는 구조로, DB 시간(6.87ms)은 정상이나 외부 Lambda 호출에서 대부분의 시간이 소요되었다.

Quick Facts#

Timeline#

1. 2026-05-28 14:55 KST — 동일 사용자의 동일 요청에서 첫 번째 지연 발생 (2057ms)
2. 2026-05-28 15:12 KST — 클러스터에 기록된 2110ms 지연 발생
3. 2026-05-28 15:33 KST — 다른 사용자(facility_key: fkw3fy)에서 최대 5267ms 지연 관측
4. 2026-05-28 15:12~15:15 KST — 시스템 전반적으로 다수 엔드포인트에서 지연 발생 (PanosController#bulk: 7155ms, ElementTracesController#bulk: 2297ms)

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::ElementRecordsController#bulk",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 2110,
  "max_ms": 2110,
  "sample_trace_id": "3397582978092509099"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 1
• 최초 발생: 2026-05-28 15:12 KST
• 최근 발생: 2026-05-28 15:12 KST

Root Cause Summary#

ElementRecordsController#bulk는 사용자 인증과 facility 권한 확인 후, 실제 bulk 작업을 외부 AWS API Gateway + Lambda 서비스(Cupix::Siteinsights.service_url)로 위임하는 thin proxy 구조이다. Datadog 로그에서 DB 시간이 6.87ms에 불과하고 view 시간도 0.12ms로 확인되므로, 2110ms 중 ~2100ms는 외부 Lambda 호출의 응답 대기 시간에 해당한다. 동일 시간대에 시스템 전반적으로 여러 엔드포인트에서 지연이 관측되어, Lambda 서비스의 일시적 부하 또는 cold start가 원인으로 판단된다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/element_records_controller.rb:17
• Service delegation: app/services/cupix/siteinsights_service.rb:155-175
• HTTP client: lib/cupix/http_client.rb:56-68
• SiteInsights URL resolver: lib/cupix/siteinsights.rb:4-33

1. Controller 진입 — bulk 액션

def bulk
  response = Cupix::SiteinsightsService.bulk_element_records!(params, current_user: @current_user, current_team: @current_team)

  render_json 200, response
end

2. Service 레이어 — 권한 확인 후 외부 호출

def bulk_element_records!(params = {}, current_user: nil, current_team: nil, visibility: nil)
  raise Cupix::Errors::Parameter.new(code: 'ARG10000', reason: 'facility_key is required') if params[:facility_key].blank?

  facility = ::FacilityRepository.new(current_user: current_user, current_team: current_team).show(params[:facility_key], visibility: visibility)
  raise Cupix::Errors::PermissionDenied.new(code: 'PERM10000', reason: 'Permission denied') unless facility.updatable_by?(current_user)

  begin
    params = self._merge_current_user(params, current_user)
    response = Cupix::HttpClient.put("#{Cupix::Siteinsights.service_url}/element_records/bulk", params.to_json, { content_type: :json })

    JSON.parse(response.body)['result']
  rescue RestClient::Exception => e
    Cupix::Logger.error("failed to bulk element records - error: #{e.message}", class: self.name, function: __method__, params: params)
    raise Cupix::Errors::System.new(code: 'SYS20000', reason: "failed to bulk element records - error: #{e.message}")
  end
end

실행 흐름:

1. facility_key 파라미터 검증
2. FacilityRepository.show — 8개의 LEFT JOIN을 사용한 권한 기반 facility 조회 (DB: ~7ms)
3. facility.updatable_by? — 인메모리 applied_permission 확인
4. Cupix::HttpClient.put — 외부 Lambda로 HTTP PUT 전송 (여기서 ~2100ms 소요)
5. JSON 파싱 후 응답 반환

3. HTTP Client — retry 로직 포함, timeout 미설정

def self.put(url, payload, headers = {}, retries: MAX_RETRIES)
  attempt = 0
  begin
    RestClient.put(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의 기본 timeout(60초)이 적용되며, 명시적 timeout 설정이 없다. 이로 인해 Lambda 응답이 느릴 경우 요청 스레드가 장시간 블로킹된다.

4. SiteInsights Lambda URL (production us-west-2)

else
  'https://6hdi0xzqqk.execute-api.us-west-2.amazonaws.com/api'

Log Evidence#

Datadog에서 동일 사용자의 요청 패턴을 확인:

service:cupixworks-api resource_name:"Api::V1::ElementRecordsController#bulk" env:production @duration:>500ms

정상 응답 시간과 비교:

동일 사용자 (mohammed.alshaikhli@exyte.net, user_id: 39592)
facility_key: 3ay7gx, fields: ["oid"]

정상 요청: 100-280ms (대부분)
지연 요청 1: 2026-05-28T05:55:26.924Z — 2057ms (db: 8.59ms, host: ip-10-1-80-134)
지연 요청 2: 2026-05-28T06:12:33.773Z — 2108ms (db: 6.87ms, host: ip-10-1-144-228)

동일 시간대 시스템 전반 지연 패턴:

2026-05-28T06:12~06:15 UTC 시간대 다른 엔드포인트 지연:
- ElementTracesController#bulk: 2297ms (db: 399ms)
- PanosController#bulk: 7155ms (db: 1120ms)
- ReviewsController#index: 1102ms (db: 1012ms)
- PointcloudsController#index: 1108ms (db: 67ms)

동시간대 warn 로그 (Elasticsearch sync 관련):

50+ entries: "NotFound - attributes_in_database" from _update_document
Classes: Record, Annotation, Pointcloud, Group, Capture

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 불필요: 단발성 이벤트(1회 발생)이며 현재 사용자 영향이 제한적. 즉시 조치 필요 없음.

단기 개선 (1주 이내)#

• lib/cupix/http_client.rb:59에 명시적 timeout 설정 추가. RestClient.put에 timeout: 5, open_timeout: 3 옵션을 전달하여 Lambda 응답 지연 시 빠른 실패(fail-fast) 보장.
• Lambda 호출 시간을 별도 metric으로 계측하여 외부 서비스 지연을 가시화.

장기 개선 (재발 방지)#

• SiteInsights Lambda의 provisioned concurrency 검토 — cold start 제거로 p99 응답시간 개선.
• HttpClient에 connection pooling 도입 (RestClient → Faraday with persistent adapter) — TLS handshake 오버헤드 제거.
• 대량 bulk 요청에 대한 payload size 제한 또는 비동기 처리(async job + polling) 패턴 전환 검토.

Monitoring#

• Lambda 응답 시간 분포 모니터링:

service:cupixworks-api resource_name:"Api::V1::ElementRecordsController#bulk" env:production @duration:>2000ms

• SiteInsights Lambda 서비스 자체 CloudWatch 메트릭 (Duration, ConcurrentExecutions, Throttles) 알림 설정
• HttpClient 호출별 duration custom metric 추가 → Datadog APM span으로 분리

Risk Assessment#

• Risk level: low
• 예상 복잡도: trivial
• 단발성 이벤트로 사용자 영향 제한적. 시스템 전반 부하 시 간헐적 재발 가능성 있으나, 기능적 장애(데이터 손실, 에러 응답)는 아님.