Api::V1::WorkspacesController#unshare (avg 1921ms, max 1921ms)

RCA: WorkspacesController#unshare Latency (1921ms)

Overview#

What Happened#

2026-05-27 10:43경 eu-central-1 리전에서 Api::V1::WorkspacesController#unshare 엔드포인트가 1921ms로 응답했다. DB 시간은 37.71ms에 불과했으나, FacilityPermission 삭제 시 PubSub 이벤트로 트리거되는 NotificationService 외부 HTTP 호출이 동기적으로 수행되어 약 2초의 wall-clock 지연이 발생했다.

Quick Facts#

Field	Value
resource_name	`Api::V1::WorkspacesController#unshare`
top_frame	`app/controllers/concerns/share_controller.rb:47`
duration	1921ms (DB: 37.71ms, View: 0.31ms)
env	production, eu-central-1
trace_id	`3982244350201681761`

Timeline#

10:43:11.033Z — PUT /api/v1/workspaces/540/unshare 요청 시작
10:43:11.593Z — WorkspacePermission, FacilityPermission 삭제 시작
10:43:11.594Z — FacilityPermission destroyed → PubSub 이벤트 발행
10:43:11.594Z ~ 10:43:13.594Z — NotificationService 외부 HTTP 호출 (약 2초 소요)
10:43:13.594Z — Cache flush, event publish 완료
10:43:16.218Z — 204 응답 반환 (총 1920ms)

Error Log#

Datadog Logs

json

{
  "resource_name": "Api::V1::WorkspacesController#unshare",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 1921,
  "max_ms": 1921,
  "sample_trace_id": "3982244350201681761"
}

Impact#

Service: cupixworks-api
발생 횟수: 1
최초 발생: 2026-05-27T10:43:11.033Z
최근 발생: 2026-05-27T10:43:11.033Z

Root Cause Summary#

WorkspacesController#unshare에서 사용자 권한을 삭제할 때 FacilityPermission의 dependent: :destroy가 트리거되고, 이 destroy 이벤트가 PubSub를 통해 UserRecipeCleaner와 SubscriptionCleaner를 동기적으로 호출한다. UserRecipeCleaner는 3개의 recipe에 대해 각각 find_email_recipe + delete_user_recipe HTTP 호출을 수행하고(총 6회), SubscriptionCleaner는 unsubscribe HTTP 호출을 1회 수행하여, 최소 7회의 외부 HTTP round-trip이 요청 lifecycle 내에서 동기적으로 실행된다. 이 외부 호출들이 약 2초의 지연을 유발했다.

Technical Analysis#

Code Path#

Entry point: app/controllers/concerns/share_controller.rb:47

app/controllers/concerns/share_controller.rb:47-50ruby

def unshare
  repository_instance.unshare(params.slice(*UNSHARE_REQUEST_PARAMS))
  render_api
end

WorkspaceRepository#unshare → SharableRepository#unshare가 사용자 목록을 순회하며 @model.remove_permission!(user) 호출:

app/repositories/concerns/sharable_repository.rb:205-216ruby

# @users 배열을 순회하며 개별 권한 삭제
@users.each do |user|
  @model.remove_permission!(user)
end

Permissionable#remove_permission!에서 permission을 찾아 destroy:

app/models/concerns/permissionable.rb:81-96ruby

def remove_permission!(user_or_group)
  _permission = permissions.find_by(accessor: user_or_group)
  if _permission.present?
    _permission.destroy!
    Permissionable.flush_cached_permissions(user_or_group)
    Permissionable.flush_cached_permissions_by_user(...)
    _permission
  end
end

WorkspacePermission destroy 시 has_many :facility_permissions, dependent: :destroy 발동:

app/models/workspace_permission.rb:12ruby

has_many :facility_permissions, dependent: :destroy

FacilityPermission destroy 시 PubSub destroyed 이벤트 발행 (FacilityPermission은 PubSub::Publisher include):

app/models/facility_permission.rb:7ruby

include ::PubSub::Publisher

PubSub subscriber 등록:

config/initializers/subscribers/facility_permission.rb:1-7ruby

Rails.application.config.to_prepare do
  Cupix::PubSub::Subscribers::UserRecipeGenerator.attach_to(::FacilityPermission.name.underscore)
  Cupix::PubSub::Subscribers::UserRecipeCleaner.attach_to(::FacilityPermission.name.underscore)
  Cupix::PubSub::Subscribers::SubscriptionGenerator.attach_to(::FacilityPermission.name.underscore)
  Cupix::PubSub::Subscribers::SubscriptionCleaner.attach_to(::FacilityPermission.name.underscore)
end

Failure point (성능 병목): UserRecipeCleaner#_delete_recipes에서 3개 recipe에 대해 순차 HTTP 호출:

lib/cupix/pub_sub/subscribers/user_recipe_cleaner.rb:34-41ruby

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

각 delete_user_recipe는 내부에서 find_email_recipe GET 호출 후 DELETE 호출 (2회 HTTP per recipe):

lib/cupix/notification_service.rb:48-68ruby

def delete_user_recipe(recipe_name, team_id: nil, facility_key: nil)
  return if @service_url.nil?
  recipe = find_email_recipe(recipe_name, facility_key)  # HTTP GET
  return if recipe.nil?
  response = Cupix::HttpClient.delete(                    # HTTP DELETE
    "#{@service_url}/api/recipes/v2/#{recipe['id']}",
    { content_type: :json, 'x-cupix-auth': @user.api_token }
  )
end

SubscriptionCleaner도 동기 HTTP DELETE 호출:

lib/cupix/pub_sub/subscribers/subscription_cleaner.rb:20-22ruby

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

Log Evidence#

Datadog APM trace에서 확인한 요청 상세:

text

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

요청 타임라인 (trace ID: 3982244350201681761):

text

10:43:11.033Z  Request start (PUT /api/v1/workspaces/540/unshare)
10:43:11.593Z  WorkspaceRepository#_set_users_or_groups - requested user_ids: 5010
10:43:11.593Z  UserFactory#update_user_groups! - No custom groups found for user 823
10:43:11.593Z  [Permission][Cleanup] Skipping WorkspacePermission deletion - permission > A
10:43:11.593Z  [Permission][Cleanup] FacilityPermission destroyed (facility_permission_id: 25574)
10:43:11.594Z  [Permission][Cleanup] WorkspacePermission being destroyed (workspace_permission_id: 10772)
--- ~2초 gap: NotificationService HTTP 호출 ---
10:43:13.594Z  Cupix::NotificationService#find_email_recipe (3 recipes found for facility l70u81)
10:43:13.594Z  Cupix::NotificationService#unsubscribe - pauline.fichaux@danfoss.com from Facility l70u81
10:43:13.594Z  Cupix::NotificationService#delete_user_recipe x3
10:43:13.594Z  User#flush_cached_permission for user 5010
10:43:13.594Z  Cupix::EventService#publish_event - failed_record_count: 0/1
10:43:16.218Z  Request completes - 204 (total: 1920.03ms, DB: 37.71ms)

비교 대상 — 같은 사용자, 같은 엔드포인트, 6초 전 요청 (user 5011 unshare):

text

10:43:10.217Z  PUT /api/v1/workspaces/540/unshare -> 204 (108.97ms, DB: 29.71ms)

user 5011은 notification recipe가 없어 NotificationService 호출이 skip됨 → 109ms로 정상 응답.

Hypotheses Considered#

#	Hypothesis	Evidence for	Evidence against	Verdict
H1	NotificationService 동기 HTTP 호출이 지연 원인	로그에서 10:43:11.594Z~10:43:13.594Z 사이 2초 gap 확인. find_email_recipe 3회 + delete 3회 + unsubscribe 1회 = 7회 HTTP round-trip. DB 시간 37ms로 DB는 병목 아님. recipe가 없는 user 5011은 109ms로 응답	—	Confirmed
H2	DB 쿼리 N+1 또는 lock contention	개별 find_by 쿼리가 user당 1회 실행됨	DB 시간이 37.71ms로 전체 1921ms 중 2%에 불과. 쿼리 자체는 빠름	Rejected
H3	Sidekiq worker 큐잉 지연	flush_cached_permission worker가 enqueue됨	Worker는 perform_async로 즉시 반환되므로 request 지연에 기여하지 않음	Rejected

Fix Recommendation#

즉시 조치 (Critical)#

lib/cupix/pub_sub/subscribers/user_recipe_cleaner.rb:34-41: recipe 삭제를 비동기 worker로 이동
lib/cupix/pub_sub/subscribers/subscription_cleaner.rb:20-22: unsubscribe도 비동기 worker로 이동
PubSub subscriber에서 직접 HTTP 호출하지 않고 Sidekiq worker를 enqueue하는 방식으로 변경하면 요청 응답 시간이 즉시 개선됨

단기 개선 (1주 이내)#

NotificationService#delete_user_recipe에서 각 recipe마다 find + delete를 별도로 호출하는 대신, batch delete API가 있다면 활용하여 round-trip 감소
최소한 3개 recipe 삭제를 병렬(Thread/Concurrent::Future)로 처리하여 sequential wait 제거

장기 개선 (재발 방지)#

PubSub subscriber 정책 검토: destroy callback에 의한 외부 서비스 호출은 원칙적으로 비동기(worker) 처리로 통일
NotificationService에 bulk unsubscribe / bulk recipe delete API 추가 검토
권한 계층 삭제 시 cascading 호출 depth를 모니터링하는 metric 추가

Monitoring#

WorkspacesController#unshare 엔드포인트의 p95/p99 latency alert 추가:

text

service:cupixworks-api resource_name:"Api::V1::WorkspacesController#unshare" env:production @duration:>1000ms

NotificationService HTTP 호출 duration metric 추적:

text

service:cupixworks-api "NotificationService" (@duration OR "recipe")

Risk Assessment#

Risk level: low
예상 복잡도: standard — PubSub subscriber 내부 로직을 worker로 이동하는 표준적인 리팩토링. 기능 동작은 동일하되 실행 시점만 비동기로 변경.