ES /docs

FacilitiesController#share 동기 HTTP 호출 병목 — 콜백 체인

RCA: FacilitiesController#share Latency (avg 8150ms, max 21027ms)

Overview#

What Happened#

2026-05-26 03:21 ~ 13:15 UTC 사이에 cupixworks-api 서비스의 Api::V1::FacilitiesController#share 엔드포인트에서 평균 8150ms, 최대 21027ms의 응답 지연이 5개 리전에 걸쳐 24회 발생했다. HTTP 응답은 모두 200이며 기능적 오류는 없으나, 사용자 경험에 심각한 영향을 미치는 latency 이슈이다.

Quick Facts#

Field Value
resource_name Api::V1::FacilitiesController#share
top_frame app/repositories/concerns/sharable_repository.rb:159
avg_duration 8150ms
max_duration 21027ms
env production (ap-southeast-2, eu-central-1, us-west-2, ap-northeast-1, ap-southeast-1)

Timeline#

  1. 2026-05-26T03:21:23Z — 최초 발생 (ap-southeast-2)
  2. 2026-05-26T13:15:13Z — 최근 발생
  3. 2026-05-27 — RCA 분석 완료

Error Log#

Datadog Logs

json
{
  "resource_name": "Api::V1::FacilitiesController#share",
  "service": "cupixworks-api",
  "occurrences": 7,
  "avg_ms": 2998,
  "max_ms": 6821,
  "sample_trace_id": "2403094205503981716"
}

Impact#

  • Service: cupixworks-api
  • 발생 횟수: 24
  • 최초 발생: 2026-05-26T03:21:23.198Z
  • 최근 발생: 2026-05-26T13:15:13.137Z
  • 영향: Facility 공유 시 사용자가 8~21초 동안 응답 대기. 모든 리전 동일 패턴.

Root Cause Summary#

FacilitiesController#share 엔드포인트가 사용자별로 4건의 동기 HTTP 호출(1건 subscription + 3건 recipe 생성)을 NotificationService에 순차적으로 수행한다. 이 호출은 FacilityPermission 모델의 after_commit 콜백 → ActiveSupport::Notifications.instrumentSubscriptionGenerator/UserRecipeGenerator 체인을 통해 웹 요청 스레드 내에서 동기적으로 실행된다. 7명의 사용자를 공유하면 28건의 순차 HTTP 호출이 발생하여 총 21초에 달하는 지연이 발생한다.

Technical Analysis#

Code Path#

  • Entry point: app/controllers/concerns/share_controller.rb:32
  • Repository 호출: app/repositories/concerns/sharable_repository.rb:131
  • 사용자 루프 및 권한 부여: app/repositories/concerns/sharable_repository.rb:159
  • Permission 저장 + PubSub 트리거: app/models/concerns/permissionable.rb:60
  • PubSub after_commit 발행: app/models/concerns/pub_sub/publisher.rb:41
  • 동기 subscriber 실행: lib/cupix/pub_sub/subscribers/base.rb:15 (ActiveSupport::Notifications.subscribe)
  • Subscription HTTP 호출: lib/cupix/pub_sub/subscribers/subscription_generator.rb:21
  • Recipe HTTP 호출 (x3): lib/cupix/pub_sub/subscribers/user_recipe_generator.rb:39-41

1. Share 엔드포인트 진입점

app/controllers/concerns/share_controller.rb:32-45ruby
def share
  validate_project_permissions_feature!

  members = repository_instance.share(
    params.slice(*SHARE_REQUEST_PARAMS),
    params[:permission]
  )

  render_api Renderable.new({
    contents: members,
    is_collection: true,
    serializer: MemberSerializer
  })
end

2. 사용자별 순차 권한 부여 루프 — 핵심 병목 구간

app/repositories/concerns/sharable_repository.rb:159-164ruby
(@users + @groups + already_joined_or_invited_users + invited_users).each do |user_or_group|
  @model.add_permission! user_or_group, permission
  shared_users_and_groups << user_or_group
rescue ActiveRecord::RecordInvalid => e
  raise Cupix::Errors::Entity.new(code: 'ENT10003', reason: e.message)
end

add_permission!FacilityPermission.save!를 호출하면 after_commit 콜백이 동기적으로 PubSub 이벤트를 발행한다.

3. Permission 저장 및 PubSub 트리거

app/models/concerns/permissionable.rb:60-68ruby
def add_permission!(user_or_group, permission)
  _permission = permissions.find_or_initialize_by(accessor: user_or_group)
  _permission.permission = permission
  _permission.save!

  Permissionable.flush_cached_permissions(user_or_group)
  Permissionable.flush_cached_permissions_by_user(user_or_group, self)

  _permission
end

_permission.save!FacilityPermissionafter_commit 콜백이 실행된다:

app/models/concerns/pub_sub/publisher.rb:41-44ruby
after_commit do |model|
  model.pub_sub_notifications_manager.publish_notifications(namespace)
  model.pub_sub_notifications_manager.reset_notifications(namespace)
end

4. ActiveSupport::Notifications를 통한 동기 브로드캐스트

lib/cupix/pub_sub/publisher.rb:5-11ruby
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

ActiveSupport::Notifications.instrument는 같은 스레드에서 동기적으로 subscriber를 호출한다.

5. 동기 HTTP 호출 — SubscriptionGenerator (사용자당 1회)

lib/cupix/pub_sub/subscribers/subscription_generator.rb:11-22ruby
def _create_subscriptions_by_facility_permission(model)
  return false unless model.accessor_type == ::User.name

  user = model.accessor
  facility_key = model.facility.key

  _create_subscription(user: user, facility_key: facility_key)
end

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

6. 동기 HTTP 호출 — UserRecipeGenerator (사용자당 3회)

lib/cupix/pub_sub/subscribers/user_recipe_generator.rb:24-41ruby
def _create_recipes_for_facility_permission(model)
  return false unless model.accessor_type == ::User.name

  user = model.accessor
  team_id = model.facility.team_id
  facility_key = model.facility.key

  _create_recipes(user: user, team_id: team_id, facility_key: facility_key)
end

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

7. NotificationService HTTP 클라이언트 — 각 호출이 1~2초 소요

lib/cupix/notification_service.rb:70-93ruby
def subscribe(facility_key: nil)
  return if @service_url.nil?

  begin
    response = Cupix::HttpClient.put(
      "#{@service_url}/api/v1/subscriptions",
      {
        model_type: 'Facility',
        model_id: facility_key
      }.to_json,
      {
        content_type: :json,
        'x-cupix-auth': @user.api_token
      }
    )
    # ...
  end
end

지연 계산:

  • 사용자당: 1 subscription + 3 recipes = 4 HTTP 호출 × ~1.5초/호출 = ~6초
  • 7명 공유 시: 7 × 4 = 28 HTTP 호출 × ~0.75초 = ~21초 (최대 관측값 21,027ms와 일치)

Log Evidence#

Datadog에서 검색한 결과, 해당 시간 대 49건의 요청이 확인되었으며 모두 HTTP 200 응답이다.

text
service:cupixworks-api @http.url_details.path:"/api/v1/facilities/*/share" @http.status_code:200
text
Duration breakdown for slowest request (21,026ms):
- DB time: 755ms (3.6%)
- Notification API calls: ~20,254ms (96.4%)
  - 7 subscriptions created
  - 22 recipes created (7 users × 3 + 1 retry)
  - Timestamps span: 09:56:42Z to 09:56:54Z (~12 seconds of sequential API calls)

요청 유형별 duration 패턴:

text
fields=11 (full share): 30 requests, avg 7,380ms, max 21,026ms
fields=2 (lightweight): 19 requests, avg 1,334ms, max 4,300ms

NotificationService 로그에서 확인된 recipe 생성 패턴:

json
{
  "message": "recipe created: ...",
  "class": "Cupix::NotificationService",
  "function": "create_user_recipe",
  "recipe_name": "record_preview_ready",
  "facility_key": "..."
}
json
{
  "message": "subscription of user@example.com on Facility abc123 created",
  "class": "Cupix::NotificationService",
  "function": "subscribe",
  "facility_key": "abc123"
}

Hypotheses Considered#

# Hypothesis Evidence for Evidence against Verdict
H1 동기 NotificationService HTTP 호출이 웹 요청 스레드에서 순차 실행되어 지연 발생 DB time 755ms vs total 21,026ms (96% 미설명 시간). NotificationService 로그 타임스탬프 12초 span. ActiveSupport::Notifications.instrument가 동기 실행. 코드: subscription_generator.rb:21, user_recipe_generator.rb:40 Confirmed
H2 N+1 쿼리 또는 DB 병목 @model.users.reload (line 141)로 인한 잠재적 N+1. 일부 요청 DB 2,373ms 대부분 요청 DB time 34~306ms. 전체 duration의 4% 미만. 느린 쿼리 로그 없음 Rejected
H3 대규모 facility의 member 목록 로딩 지연 최종 default_joins 쿼리가 complex JOIN 포함 (sharable_repository.rb:188) duration과 member 수의 상관관계 약함. DB time은 전체의 소수 Rejected
H4 NotificationService 자체의 성능 저하 리전별 latency 편차 존재 (eu-central-1 max 21s vs us-west-2 max 17s) 모든 리전에서 동일 패턴. 호출 자체보다 순차 호출 수가 결정적 요인 Rejected

Fix Recommendation#

즉시 조치 (Critical)#

PubSub subscriber의 NotificationService 호출을 비동기 background job으로 이동해야 한다.

  • 파일: lib/cupix/pub_sub/subscribers/subscription_generator.rb:21
  • 파일: lib/cupix/pub_sub/subscribers/user_recipe_generator.rb:34-41
  • 방향: 현재 Cupix::NotificationService.new(...).subscribe(...)create_user_recipe(...) 호출을 Sidekiq worker로 감싸서 after_commit 시점에 비동기로 실행한다. 이미 FlushCachedPermissionWorker 패턴이 존재하므로 동일 방식 적용.

단기 개선 (1주 이내)#

  1. Batch API 도입: NotificationService에 batch subscription/recipe 생성 API를 추가하여 사용자당 4건의 개별 호출을 1건의 batch 호출로 통합.
  2. @model.users.reload 제거: sharable_repository.rb:141에서 불필요한 전체 사용자 reload를 제거하고, 공유 대상 사용자 ID로만 기존 권한을 확인하도록 변경.

장기 개선 (재발 방지)#

  1. PubSub subscriber 실행 정책 개선: ActiveSupport::Notifications.instrument는 동기 실행이므로, HTTP 호출을 포함하는 subscriber는 반드시 async 실행 정책을 적용하도록 아키텍처 가이드라인 수립.
  2. 요청 내 외부 API 호출 모니터링: APM에서 request 내 외부 HTTP 호출 수와 총 시간을 추적하는 metric 추가.

Monitoring#

  • FacilitiesController#share P95 duration 추적:
text
avg:trace.rack.request.duration{service:cupixworks-api, resource_name:api::v1::facilitiescontroller#share} by {region}
  • NotificationService 호출 횟수/지연 metric:
text
service:cupixworks-api "Cupix::NotificationService" ("recipe created" OR "subscription of") | stats count by facility_key
  • 임계값 알림: share 엔드포인트 P95 > 3000ms 시 경고.

Risk Assessment#

  • Risk level: medium
  • 예상 복잡도: standard — subscriber를 Sidekiq worker로 감싸는 변경. 기존 FlushCachedPermissionWorker 패턴 재활용 가능. 단, idempotency 확인 필요 (recipe ARG12001 중복 처리 이미 구현됨).