RCA: Api::V1::PointcloudsController#create Latency (avg 5663ms, max 6803ms)

Overview#

What Happened#

2026-05-26 03:5605:11 UTC 사이 ap-southeast-2 리전에서 PointcloudsController#create 요청 3건이 5.66.8초의 비정상적 응답 시간을 기록했다. 동일 사용자(chris.bellamy@auav.com.au)가 CupixConnect 데스크톱 클라이언트로 새 Facility에 첫 Pointcloud를 생성할 때 발생했으며, DB 작업은 3487ms로 정상이었으나 NotificationService로의 동기 HTTP 호출(subscribe + create_user_recipe x3)이 36.5초를 추가했다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-05-26T03:56:48Z — 첫 slow request 감지 (3682ms, trace 3551876882539819185)
2. 2026-05-26T05:01:51Z — 두 번째 slow request (6500ms, trace 1214062276050154574)
3. 2026-05-26T05:11:39Z — 세 번째 slow request (6801ms, trace 389638474844797445)
4. 2026-05-26T05:15:21Z — 추가 slow request (3686ms, 클러스터 기간 외)

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::PointcloudsController#create",
  "service": "cupixworks-api",
  "occurrences": 3,
  "avg_ms": 5663,
  "max_ms": 6803,
  "sample_trace_id": "389638474844797445"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 3
• 최초 발생: 2026-05-26T03:56:48.701Z
• 최근 발생: 2026-05-26T05:11:39.648Z
• 영향 범위: ap-southeast-2 리전에서 새 Facility에 최초 Pointcloud를 업로드하는 사용자. 기존 Facility에 추가 업로드하는 요청은 189~317ms로 정상 응답.

Root Cause Summary#

FacilityPermission 생성 시 after_commit 콜백에서 ActiveSupport::Notifications.instrument를 통해 동기적으로 NotificationService에 4건의 HTTP 요청(subscribe 1건 + create_user_recipe 3건)을 보낸다. NotificationService가 ap-southeast-2와 다른 리전에 있어 cross-region 네트워크 latency로 인해 각 호출당 0.52초가 소요되며, 총 36.5초의 응답 지연이 request lifecycle 내에서 발생한다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/pointclouds_controller.rb:28
• Factory: app/factories/pointcloud_factory.rb:6 → BaseFactory#create! → model.save!
• Permission cascade: RecordPermission#create_facility_permission → FacilityPermission.find_or_create_by!
• PubSub trigger: app/models/concerns/pub_sub/publisher.rb:41 (after_commit → publish_notifications)
• Synchronous HTTP: lib/cupix/notification_service.rb:15 (subscribe) and lib/cupix/notification_service.rb:15 (create_user_recipe x3)

1. Controller → Factory → Save

def create
  @model = factory_instance.create!(params)
  super  # renders response
end

2. FacilityPermission 생성 시 PubSub 이벤트 등록

사용자가 처음으로 해당 Facility에 접근할 때 FacilityPermission.find_or_create_by!가 새 레코드를 생성하면 PubSub::Publisher 모듈의 after_create 콜백이 notification을 큐잉한다:

after_create do |model|
  model.pub_sub_notifications_manager.add_notification(namespace, 'created', { model: model })
end

3. after_commit에서 동기적으로 이벤트 발행

after_commit do |model|
  model.pub_sub_notifications_manager.publish_notifications(namespace)
  model.pub_sub_notifications_manager.reset_notifications(namespace)
end

publish_notifications는 ActiveSupport::Notifications.instrument를 호출하며, 이는 동기적으로 모든 subscriber를 실행한다:

def broadcast_event(namespace, event_name, payload = {}, &block)
  event_name = [namespace, event_name].compact.join('.')
  ActiveSupport::Notifications.instrument(event_name, payload) do
    yield if block_given?
  end
end

4. SubscriptionGenerator — 동기 HTTP 1회

def _create_subscription(opts = {})
  Cupix::NotificationService.new(user: opts[:user]).subscribe(facility_key: opts[:facility_key])
end

5. UserRecipeGenerator — 동기 HTTP 3회

def _create_recipes(opts = {})
  %w[
    record_preview_ready
    record_processing_completed
    facility_new_project
  ].each do |recipe_name|
    Cupix::NotificationService.new(user: opts[:user]).create_user_recipe(recipe_name, team_id: opts[:team_id], facility_key: opts[:facility_key])
  end
end

6. NotificationService — 실제 HTTP 호출

def create_user_recipe(recipe_name, team_id: nil, facility_key: nil)
  return if @service_url.nil?

  params = email_recipe_params(recipe_name, team_id, facility_key)
  response = Cupix::HttpClient.post(
    "#{@service_url}/api/recipes/v2",
    params.to_json,
    {
      content_type: :json,
      'x-cupix-auth': @user.api_token
    }
  )
end

기대 동작: subscribe + recipe 생성은 비동기(worker)로 처리되어 request에 영향 없음. 실제 동작: ActiveSupport::Notifications.instrument가 동기적으로 subscriber를 호출하므로, 4건의 HTTP 요청이 모두 request lifecycle 내에서 실행됨.

Log Evidence#

Datadog에서 slow request와 NotificationService 호출 타이밍을 비교:

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

Slow request 로그 (trace 389638474844797445):

{
  "timestamp": "2026-05-26T05:11:47.635Z",
  "duration_ms": 6801.43,
  "db_ms": 34.61,
  "host": "ip-10-1-17-211.ap-southeast-2.compute.internal",
  "pointcloud_name": "Point Cloud [15:10:09]",
  "pointcloud_id": 17200,
  "user": "chris.bellamy@auav.com.au",
  "user_id": 8624,
  "team": "endeavourgroup/180",
  "http_status": 200
}

NotificationService recipe 생성 로그 (같은 request 내):

service:cupixworks-api "recipe created" @class:Cupix::NotificationService

{
  "timestamp": "2026-05-26T05:11:44.775Z",
  "message": "recipe created",
  "class": "Cupix::NotificationService",
  "function": "create_user_recipe",
  "recipe_name": "facility_new_project",
  "facility_key": "..."
}

비교: fast request (같은 사용자, 기존 Facility에 추가 업로드):

{
  "timestamp": "2026-05-26T05:12:xx.xxxZ",
  "duration_ms": 190,
  "db_ms": 30,
  "pointcloud_name": "20260516112722960.cpc"
}

Fast request는 이미 FacilityPermission이 존재하므로 find_or_create_by!가 기존 레코드를 반환하고, PubSub created 이벤트가 발행되지 않아 NotificationService 호출이 스킵된다.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

NotificationService 호출을 비동기 worker로 이동:

• lib/cupix/pub_sub/subscribers/subscription_generator.rb:21 — subscribe 호출을 Sidekiq worker로 위임
• lib/cupix/pub_sub/subscribers/user_recipe_generator.rb:40 — create_user_recipe 호출을 Sidekiq worker로 위임
• 이미 FlushCachedPermissionWorker 패턴이 존재하므로, CreateSubscriptionWorker와 CreateUserRecipesWorker를 동일 패턴으로 생성

단기 개선 (1주 이내)#

• UserRecipeGenerator#_create_recipes에서 3건의 recipe를 순차 생성하는 대신, 하나의 worker에서 batch로 처리하도록 변경
• NotificationService에 connection timeout/read timeout 설정 추가 (현재 Cupix::HttpClient.post에 timeout 미설정)
• Recipe 생성이 idempotent하므로 (ARG12001 처리 존재) 재시도 안전

장기 개선 (재발 방지)#

• PubSub subscriber 전체를 감사하여 HTTP 호출을 수행하는 subscriber를 식별하고, 모두 비동기로 전환
• ActiveSupport::Notifications.instrument 대신 Sidekiq event bus 패턴 도입 검토
• Cross-region API 호출이 필요한 경우, 리전별 NotificationService 엔드포인트 또는 SQS 기반 비동기 메시징 도입

Monitoring#

• NotificationService 호출 duration 추적:

service:cupixworks-api @class:Cupix::NotificationService @function:(subscribe OR create_user_recipe) | measure @duration

• PointcloudsController#create p95 latency 알림:

avg(last_5m):trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::pointcloudscontroller_create,env:production} > 3000

• FacilityPermission 생성 빈도 (PubSub trigger 빈도):

service:cupixworks-api "subscription of" @class:Cupix::NotificationService | count by facility_key

Risk Assessment#

• Risk level: medium
• 예상 복잡도: standard — Sidekiq worker 추출은 기존 패턴(FlushCachedPermissionWorker)을 따르며, recipe 생성이 idempotent하여 비동기 전환에 따른 데이터 정합성 위험 없음. 단, subscriber 코드 변경 시 모든 FacilityPermission 생성 경로에서 테스트 필요.