RCA: Api::V1::PointcloudsController#create_resource latency spike (20.8s)

Overview#

What Happened#

2026-07-08 12:34:37 KST 경 cupixworks-api의 POST /api/v1/pointclouds/1203858/resources (Api::V1::PointcloudsController#create_resource) 요청 1건이 20,803ms에 걸쳐 처리되었다. 응답 자체는 200 OK로 성공했지만 평소 서비스 평균(~500ms) 대비 40배 이상 느렸고, 같은 서비스에서 약 2분 30초 전(12:32:02 KST) 발생한 클러스터(1a719bfe-5c3f-4428-9ba8-d0af2c7c4d37)와 함께 status board가 cupixworks-api service degraded 인시던트로 그룹핑했다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-07-08 12:32:02 KST — 형제 클러스터(1a719bfe-…) first_seen — 같은 cupixworks-api service의 latency 시그널
2. 2026-07-08 12:34:37 KST — 본 클러스터 first_seen / last_seen (Datadog APM이 span 시작으로 집계한 시각)
3. 2026-07-08 12:34:59 KST — Rack access log에 [200] POST /api/v1/pointclouds/1203858/resources 기록 (응답 반환, span 시작 후 약 22초)
4. 2026-07-08 12:35:00 KST — 후속 cpc_mesh_upload_url, check_semantic_taxonomy_uploading 등 정상 200 응답 (지연 없음)
5. 2026-07-08 12:34:37 KST — status board가 2026-07-08-svc-cupixworks-api--unknown-1 인시던트로 편입 후 resolved 처리

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::PointcloudsController#create_resource",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 20803,
  "max_ms": 20803,
  "sample_trace_id": "307177218057975194"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 1
• 최초 발생: 2026-07-08 12:34:37 KST
• 최근 발생: 2026-07-08 12:34:37 KST

Root Cause Summary#

Uncertain — needs verification. 단일 발생(occurrence_count=1)의 latency 스파이크이며 예외(exception)가 아니라 성공 응답(200)이 오래 걸린 케이스다. 액세스 로그와 앞뒤 요청 로그에서 오류, DB 예외, ES 인덱싱 실패, 외부 스토리지 오류 어떤 신호도 확인되지 않았다. 코드 경로(MultipleResourcableController#create_resource)는 duplicate-kind 체크 + Resource#save 뿐으로, save 시 동기적으로 실행되는 것은 EntityIndexable의 after_commit :_entity_index_document(Elasticsearch 색인)와 ancestry/캐시 조회 정도다. 관측 증거만으로는 ES/DB/외부 스토리지 라운드트립 중 하나가 일시적으로 blocking되었을 가능성이 유력하지만, APM span breakdown 이나 slow-query 로그가 남지 않아 원인을 특정하기에 evidence가 부족하다. 형제 클러스터와의 근접성(약 2분 30초)을 감안하면 host/DB/ES 인스턴스 레벨의 일시적 성능 저하일 가능성이 높다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/pointclouds_controller.rb:1 — 컨트롤러가 include MultipleResourcableController로 create_resource action을 상속
• Action: app/controllers/concerns/multiple_resourcable_controller.rb:52-78
• 실행 흐름:
  1. before_action :check_kind — params[:kind]("plane") 유효성 검증 (동기, O(1))
  2. @model.resources.find_by_kind(params[:kind]) — duplicate 체크 (DB 1회 쿼리)
  3. @model.resources.new(...) + resource.save — INSERT 및 after_commit 콜백 실행
  4. save 성공 후 render_api Renderable.new(...)로 응답 직렬화
• Failure point (관측된 slow point): resource.save 이후 응답 반환까지의 구간. EntityIndexable.included가 after_commit :_entity_index_document, on: [:create]로 Elasticsearch 문서 색인을 트리거한다.

def create_resource
  raise Cupix::Errors::Parameter.new(code: 'ARG10001', reason: "Duplicate kind: #{params[:kind]}") and return unless @model.resources.find_by_kind(params[:kind]).blank?

  resource = @model.resources.new kind: params[:kind],
                                  user: current_user,
                                  team: @model.team,
                                  name: params[:name]

  begin
    unless resource.save
      raise Cupix::Errors::Parameter.new(code: 'ENT10003', reason: resource.errors.full_messages)
    end
  rescue Cupix::Errors::Parameter => e
    raise e
  else
    render_api Renderable.new({
      contents: resource,
      serializer: ResourceSerializer,
      serializer_option: { fields: { resource: @fields }, is_collection: false }
    })
  end
end

class Resource < ApplicationRecord
  include WorkspaceEntity::Resource
  include EntityIndexable
  # ... (Storagable, Statable, Cyclable, Metable, Revisionable::Resource, ...)

  belongs_to :resourcable, polymorphic: true

  before_validation :set_by_resourcable

  validates :kind, length: { maximum: 24 }, allow_nil: true, format: { with: /\A[a-z\d][a-z\w]*[a-z\d]\z/i }
  validates :name, presence: true
  validates :resourcable, presence: true

included do
  after_commit :_entity_index_document, on: [:create]
  after_commit :_entity_update_document, on: [:update]
  after_commit :_entity_delete_document, on: [:destroy]
end

• 기대 동작: Resource.new(kind: 'plane', ...).save → PostgreSQL INSERT + after_commit으로 ES 색인 1회 → 200 응답까지 수백 ms 이내
• 실제 동작: 20,803ms 소요. create_resource 응답 access log가 12:34:59 KST에 남았지만 클러스터 first_seen은 12:34:37 KST — 사이 22초 동안의 span breakdown은 로그로 남지 않음

Log Evidence#

Datadog query used:

service:cupixworks-api trace_id:307177218057975194

Result (본 요청):

{
  "timestamp": "2026-07-08 12:34:59 KST",
  "status": "info",
  "message": "[200] POST /api/v1/pointclouds/1203858/resources (Api::V1::PointcloudsController#create_resource)"
}

Datadog query for 관련 컨텍스트:

service:cupixworks-api 1203858

Result 요약 (같은 pointcloud 1203858 요청들, 12:34:32 ~ 12:39:37 KST):

12:34:32  Cachable::ReviewLoad | Invalidated facility review cache on create | model=Pointcloud | model_id=1203858 | facility_id=20917
12:34:34  [200] PUT /api/v1/pointclouds/1203858/meta/prop
12:34:34  [200] PUT /api/v1/pointclouds/1203858/meta/mesh
12:34:36  [200] POST /api/v1/pointclouds/1203858/octree_upload_url
12:34:36  StateMachines::Machine  pointcloud state changed from initializing to queued. id: 1203858
12:34:36  [200] PUT /api/v1/pointclouds/1203858/check_uploading
12:34:38  [200] PUT /api/v1/pointclouds/1203858/check_octree_uploading
12:34:59  [200] POST /api/v1/pointclouds/1203858/resources        <- 본 요청
12:34:59  [200] PUT  /api/v1/pointclouds/1203858/resources/plane/check_uploading
12:35:00  [200] POST /api/v1/pointclouds/1203858/cpc_mesh_upload_url
12:35:00  [200] PUT  /api/v1/pointclouds/1203858/check_cpc_mesh_uploading

같은 pointcloud 1203858의 앞뒤 요청은 모두 정상 지연(수백 ms 수준)으로 완료되어 pointcloud-level lock 대기 신호는 관측되지 않는다.

Datadog query for concurrent errors:

service:cupixworks-api status:error

시간 범위 2026-07-08T03:20:00Z ~ 2026-07-08T03:45:00Z에서 2건만 반환되었으며 모두 무관한 BIM360 refresh_token 실패:

12:35:08  BIM360 refresh_token failed:  - error: 400 Bad Request
12:35:08  [Integration] failed to refresh token for bim360 integration(389) - state: failed, error_message: BIM360 Authentication failed:

Datadog metric baseline:

avg:trace.rack.request.duration{service:cupixworks-api}

전체 서비스 평균 요청 시간은 조회 창(6h) 내내 약 0.35 ~ 0.77s 범위였고, 20s 수준의 스파이크는 이 한 트레이스에 국한됨.

Status board:

bun run cli/incident-board.ts for-cluster 50f67fca-f831-47cd-bf85-d5937de59eaa

{
  "id": "2026-07-08-svc-cupixworks-api--unknown-1",
  "scope": "svc:cupixworks-api::unknown",
  "status": "resolved",
  "started_at": "2026-07-08T03:32:02.845Z",
  "cluster_ids": [
    "1a719bfe-5c3f-4428-9ba8-d0af2c7c4d37",
    "50f67fca-f831-47cd-bf85-d5937de59eaa"
  ]
}

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 없음. 단일 발생(occurrence=1) latency 이벤트이며 응답은 성공(200)했다. 사용자 영향은 pointcloud 1203858 리소스 생성 응답이 20s 지연된 것에 국한된다. 코드 변경 불필요.

단기 개선 (1주 이내)#

• APM span 세부 확인: 클러스터에 첨부된 sample_trace_id: 307177218057975194를 Datadog APM UI에서 열어 span breakdown(db.query, elasticsearch.query, aws.s3.request 등)을 확인해 어느 하위 호출이 20s를 차지했는지 특정한다. 이 정보 없이 root cause 확정은 불가능.
• 재발 감시: 같은 fingerprint(d7e7c139d82b8465ab0b8c0379f2beb4)의 클러스터가 24~72시간 내 재발하면 latency 패턴이 systematic 한 것으로 간주하고 별도 인시던트로 승격.

장기 개선 (재발 방지)#

• EntityIndexable 색인 비동기화 검토: app/models/concerns/entity_indexable.rb:42-44의 after_commit :_entity_index_document 콜백이 현재 동기 호출인지 async(worker enqueue) 인지 확인. 동기라면 write 경로 latency의 tail을 늘리는 구조적 요인이므로 Sidekiq worker로 이관 검토.
• APM p99 지표에 대한 alert: Api::V1::PointcloudsController#create_resource 및 다른 MultipleResourcableController#create_resource 파생 endpoint들에 대해 p99 latency > 5s 지속 시 감지되도록 alert 등록.

Monitoring#

Baseline latency for the endpoint:

avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::pointcloudscontroller#create_resource}

p99 latency for the endpoint:

p99:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::pointcloudscontroller#create_resource}

All create_resource variants across resourcable types:

avg:trace.rack.request.duration{service:cupixworks-api,resource_name:*create_resource*}

Service-wide slow request rate (>5s):

sum:trace.rack.request.hits{service:cupixworks-api,resource_name:api::v1::pointcloudscontroller#create_resource,duration:>5000000000}.as_count()

Risk Assessment#

• Risk level: low — single event, 응답은 성공, 사용자 영향 미미
• 예상 복잡도: trivial — 즉시 코드 변경 불필요. APM trace 검토 및 재발 여부 모니터링 위주