RCA: BimsController#check_grid_system_uploading Latency (4316ms)

Overview#

What Happened#

2026-06-04 07:17 KST에 cupixworks-api의 Api::V1::BimsController#check_grid_system_uploading 엔드포인트가 4316ms로 응답하여 500ms 임계치를 초과했다. 요청 자체는 HTTP 200으로 성공했으나, 동일 호스트의 과도한 Pano 처리 부하와 S3 HEAD 요청 지연이 결합되어 비정상적 지연이 발생했다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-06-04 07:16 KST — 사용자(davidd@sellen.com)가 BIM 18669 업로드 워크플로우 시작 (show, update)
2. 2026-06-04 07:17 KST — grid_system_upload_url 요청 (581ms)
3. 2026-06-04 07:17:55 KST — check_grid_system_uploading 요청 시작, 4292ms 소요
4. 2026-06-04 07:18:01 KST — 요청 완료 (HTTP 200), 이벤트 발행 및 Facility 캐시 리셋

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::BimsController#check_grid_system_uploading",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 4316,
  "max_ms": 4316,
  "sample_trace_id": "2458764040887365654"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 1
• 최초 발생: 2026-06-04 07:17 KST
• 최근 발생: 2026-06-04 07:17 KST

Root Cause Summary#

호스트 ip-10-1-19-190이 대량의 Pano 처리 요청(초당 50건 이상)으로 과부하 상태에서, check_grid_system_uploading 요청이 해당 호스트에 라우팅되었다. 이 액션은 S3 HEAD 요청(grid_system_object.exists?)을 수행하는데, 호스트의 리소스 경합으로 인해 Ruby 프로세스 큐잉 지연과 S3 응답 지연이 결합되어 총 4292ms가 소요되었다. DB 시간은 253ms에 불과하여, 약 4초의 미설명 시간은 프로세스 큐잉 대기 및 S3 네트워크 호출에서 발생한 것으로 확인된다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/concerns/grid_system_controller.rb:4
• Permission join query (set_bim): app/repositories/bim_repository.rb:138-314
• S3 existence check: app/models/concerns/grid_system.rb:28
• State transition: app/models/concerns/grid_system.rb:46
• Serialization (presigned URL): app/serializers/grid_system_attribute.rb:6-7

요청 흐름:

1. before_action :set_bim — 복잡한 permission JOIN으로 BIM 레코드 로드

def self.permission_joins(user, team, ...)
  # 10+ LEFT JOINs for permission checking
end

2. check_grid_system_uploading 액션 — S3 HEAD 요청으로 파일 존재 여부 확인

def check_grid_system_uploading
  repository_instance.check_grid_system_uploading
  render_api Renderable.new({
    contents: @model
  })
end

3. Repository에서 state 확인 후 모델 메서드 호출

def check_grid_system_uploading
  case @model.grid_system_state_name
  when :uploading
    raise Cupix::Errors::Resource.new(code: 'RESC10000', reason: 'grid_system does not uploaded') unless @model.check_grid_system_uploading
  else
    raise Cupix::Errors::InvalidState.new(code: 'STAT10000', reason: "Invalid state: #{@model.grid_system_state}")
  end

  @model
end

4. Failure point — S3 HEAD 요청 (네트워크 I/O)

def grid_system_uploaded?
  grid_system_object.exists?
end

def grid_system_object
  Cupix::StorageService.object(
    storage_option: storage_option,
    bucket_name: storage_option.s3_hosting_bucket_name,
    key: self.grid_system_object_key
  )
end

grid_system_object.exists?는 AWS S3에 HEAD 요청을 보내 객체 존재 여부를 확인한다. 정상 시 50-200ms이지만, 호스트 부하 상태에서는 수 초까지 지연될 수 있다.

5. 성공 시 state machine 전환 및 저장

def check_grid_system_uploading
  if grid_system_uploaded?
    uploaded_grid_system_state
    true
  else
    false
  end
end

Log Evidence#

사용한 Datadog 쿼리:

service:cupixworks-api resource_name:"Api::V1::BimsController#check_grid_system_uploading" @duration:>500ms

service:cupixworks-api @request_id:3600971c-a3d0-4084-9ec2-7a7e051bb430

핵심 로그 — 느린 요청:

{
  "timestamp": "2026-06-03T22:18:01.223Z",
  "resource_name": "Api::V1::BimsController#check_grid_system_uploading",
  "method": "PUT",
  "path": "/api/v1/bims/18669/check_grid_system_uploading",
  "status": 200,
  "duration": 4292.55,
  "db_runtime": 253.68,
  "view_runtime": 0.09,
  "host": "ip-10-1-19-190.us-west-2.compute.internal",
  "user": "davidd@sellen.com",
  "team_id": 1170
}

정상 비교 (동일 엔드포인트, 다른 호스트):

{
  "timestamp": "2026-06-03T22:16:23.092Z",
  "resource_name": "Api::V1::BimsController#check_grid_system_uploading",
  "bim_id": 18668,
  "duration": 286.55,
  "db_runtime": 20.17,
  "host": "ip-10-1-144-228"
}

호스트 부하 증거 — 동일 호스트에서 초당 50건 이상의 Pano 요청 처리 중:

service:cupixworks-api host:ip-10-1-19-190 @http.method:PUT

호스트에서 다수의 warn 로그 확인:

"NotFound - attributes_in_database" from Pano#_update_document — dozens per second during 22:10-22:25 window

시간 분석:

• 총 소요: 4292.55ms
• DB 시간: 253.68ms (5.9%)
• View 렌더링: 0.09ms
• 미설명 시간: ~4039ms (94.1%) → S3 HEAD + 프로세스 큐잉 지연

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 없음. 단발성 사건(1회)으로 즉각 대응 불필요.

단기 개선 (1주 이내)#

• app/models/concerns/grid_system.rb:28 — grid_system_object.exists? 호출에 timeout 설정 추가. AWS SDK의 :http_open_timeout과 :http_read_timeout을 2초로 제한하여, S3 지연 시 빠르게 실패하도록 변경.
• app/controllers/concerns/grid_system_controller.rb — S3 호출 결과를 짧은 TTL(10초)로 캐싱하여 반복 호출 방지 검토.

장기 개선 (재발 방지)#

• 호스트 단위 요청 큐잉 모니터링 추가 — 특정 인스턴스에 요청이 집중될 때 조기 감지.
• S3 존재 확인을 비동기 패턴(background job + callback)으로 전환 검토. 클라이언트가 업로드 완료 후 S3 Event Notification을 통해 상태를 업데이트하면 HEAD 요청 자체가 불필요.
• ALB의 least-outstanding-requests 라우팅 알고리즘 검토로 과부하 호스트 회피.

Monitoring#

• Datadog APM에서 해당 resource의 p95/p99 latency 알림 설정:

avg(last_5m):p95:trace.rack.request{service:cupixworks-api, resource_name:api::v1::bimscontroller#check_grid_system_uploading} > 2000

• 호스트별 요청 큐잉 시간 모니터링:

avg(last_5m):avg:trace.rack.request.queue_time{service:cupixworks-api} by {host} > 1000

Risk Assessment#

• Risk level: low
• 예상 복잡도: trivial — 단발성 사건으로 코드 변경 없이도 재발 가능성 낮음. S3 timeout 설정은 방어적 개선 수준.