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#
- 2026-05-26T03:21:23Z — 최초 발생 (ap-southeast-2)
- 2026-05-26T13:15:13Z — 최근 발생
- 2026-05-27 — RCA 분석 완료
Error Log#
{
"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.instrument → SubscriptionGenerator/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 엔드포인트 진입점
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. 사용자별 순차 권한 부여 루프 — 핵심 병목 구간
(@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 트리거
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! 후 FacilityPermission의 after_commit 콜백이 실행된다:
after_commit do |model|
model.pub_sub_notifications_manager.publish_notifications(namespace)
model.pub_sub_notifications_manager.reset_notifications(namespace)
end
4. ActiveSupport::Notifications를 통한 동기 브로드캐스트
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회)
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회)
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초 소요
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 응답이다.
service:cupixworks-api @http.url_details.path:"/api/v1/facilities/*/share" @http.status_code:200
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 패턴:
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 생성 패턴:
{
"message": "recipe created: ...",
"class": "Cupix::NotificationService",
"function": "create_user_recipe",
"recipe_name": "record_preview_ready",
"facility_key": "..."
}
{
"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주 이내)#
- Batch API 도입: NotificationService에 batch subscription/recipe 생성 API를 추가하여 사용자당 4건의 개별 호출을 1건의 batch 호출로 통합.
@model.users.reload제거:sharable_repository.rb:141에서 불필요한 전체 사용자 reload를 제거하고, 공유 대상 사용자 ID로만 기존 권한을 확인하도록 변경.
장기 개선 (재발 방지)#
- PubSub subscriber 실행 정책 개선:
ActiveSupport::Notifications.instrument는 동기 실행이므로, HTTP 호출을 포함하는 subscriber는 반드시 async 실행 정책을 적용하도록 아키텍처 가이드라인 수립. - 요청 내 외부 API 호출 모니터링: APM에서 request 내 외부 HTTP 호출 수와 총 시간을 추적하는 metric 추가.
Monitoring#
FacilitiesController#shareP95 duration 추적:
avg:trace.rack.request.duration{service:cupixworks-api, resource_name:api::v1::facilitiescontroller#share} by {region}
- NotificationService 호출 횟수/지연 metric:
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 확인 필요 (recipeARG12001중복 처리 이미 구현됨).