RCA: Api::V1::WorkspacesController#create latency (10.5 s)

Overview#

POST /api/v1/workspaces 요청 한 건이 ap-southeast-2 production 환경에서 10,511 ms 만에 200 으로 응답했다. Latency threshold (LATENCY_THRESHOLD_MS=500) 의 21 배. DB 시간은 482 ms 에 불과하고 나머지 약 10 s 는 Ruby 단의 동기 처리(권한 캐시 flush, default facility 생성, after_create 콜백)에서 소모된 것으로 추정된다.

What Happened#

2026-06-25 09:47 KST 에 team 149 (successful) 의 사용자가 workspace "Brad Hardie Pavillion" 을 생성하자 응답이 10.5 s 만에 반환되었다. 동일 endpoint 의 ap-southeast-2 production 샘플은 최근 7 일 동안 2.5 s 에서 10.5 s 사이에 분포해 있어 일회성 spike 가 아니라 endpoint 자체가 구조적으로 느린 상태로 보인다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-06-25 09:47:46 KST — WorkspacesController#create 요청 수신 (request_id: 21670c89-ca7f-4b91-88b3-577018415ca0)
2. 2026-06-25 09:47:57 KST — 200 응답 (duration 10,511 ms, db 482 ms)
3. 2026-06-25 09:47:57 KST — error-sweeper collector 가 latency cluster 로 식별 (first_seen)

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::WorkspacesController#create",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 10513,
  "max_ms": 10513,
  "sample_trace_id": "3977113782513250106"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 1
• 최초 발생: 2026-06-25 09:47 KST
• 최근 발생: 2026-06-25 09:47 KST

Root Cause Summary#

WorkspacesController#create 는 컨트롤러 자체는 단순하지만, 호출 체인 안에 동기적으로 실행되는 비싼 작업이 다수 누적되어 있다. 구체적으로는 WorkspaceFactory.create! 가 (1) Workspace save! 의 after_create :share_to_creator 콜백, (2) WorkspaceFactory.create_default_facility 를 통한 또 다른 FacilityFactory.create! 전체 사이클 (이것 또한 share_to_creator 와 자체 권한 캐시 작업을 동반), (3) flush_team_permission_cache(team) 에서 TeamPermission.where(team_id: team.id).where('permission >= ?', 2).find_each 로 team 전체 권한 보유자를 순회하며 Permissionable.flush_cached_permissions 또는 user.flush_cached_permission 호출을 수행한다. team 149 처럼 권한 보유자가 많은 team 의 경우 이 순회가 길어지고, 각 user/group 에 대해 Rails.cache.delete 가 발생한다. DB 시간이 482 ms 밖에 안 되는데 총 응답이 10.5 s 인 점은 Ruby/캐시/Sidekiq enqueue 경로에 병목이 있음을 가리킨다.

uncertain — needs verification: 정확히 어느 단계(FacilityFactory.create! vs flush_team_permission_cache 의 iteration vs 콜백에서 enqueue 하는 Sidekiq job 의 동기 실행 여부)가 가장 큰 비중을 차지하는지는 APM span breakdown 이 필요하다. 현재 로그에는 step-level timing 이 없다.

Technical Analysis#

Code Path#

Entry point: app/controllers/api/v1/workspaces_controller.rb:22-26

def create
  @model = factory_instance.create!(params)

  super
end

Factory: app/factories/workspace_factory.rb:5-29

def create!(params = {})
  self.model = ::Workspace.new

  unless Pundit.policy(self.current_user, self.current_team).create_workspace?
    raise Cupix::Errors::PermissionDenied.new(...)
  end

  team = self.current_team

  self.model.append_event_extra({
    workspaces_count: team.workspaces_count + 1
  })
  self.model.track_team_event!

  super  # BaseFactory#create! → model.save! → after_create :share_to_creator

  WorkspaceFactory.create_default_facility(self.model, params[:facility]) unless params[:skip_default_facility_creation] == true

  flush_team_permission_cache(team)

  self.model
end

Default facility 생성: app/factories/workspace_factory.rb:43-63

def self.create_default_facility(workspace, params)
  ...
  FacilityFactory.new(current_user: workspace.user, current_team: workspace.team).create!(
    params.merge({
      workspace_id: workspace.id,
      name: facility_name
    })
  )
  ...
end

FacilityFactory.create! 은 WorkspaceRepository.show (DB 조회) + 다시 BaseFactory#create! → model.save! → after_create :share_to_creator 를 거친다 (app/factories/facility_factory.rb:5-37).

Team-wide 권한 캐시 flush: app/factories/workspace_factory.rb:31-41

def flush_team_permission_cache(team)
  # team_permission >= 2 (Read): these accessors auto-see all workspaces via readable_workspace_ids
  TeamPermission.where(team_id: team.id).where('permission >= ?', 2).find_each do |tp|
    case tp.accessor_type
    when 'Group'
      Permissionable.flush_cached_permissions(tp.accessor)
    when 'User'
      tp.accessor.flush_cached_permission
    end
  end
end

Permissionable.flush_cached_permissions 는 Group 인 경우 user_or_group.users.find_each(&:flush_cached_permission) 로 그룹 멤버 전체를 다시 순회한다 (app/models/concerns/permissionable.rb:119-128).

share_to_creator (Workspace, Facility 양쪽에서 호출) → add_permission! → Permissionable.flush_cached_permissions + Permissionable.flush_cached_permissions_by_user 추가 호출:

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
rescue ActiveRecord::RecordNotUnique
  ...
end

Failure point: 단일 함수의 throw 가 아니라 위 체인의 cumulative latency. duration 10,511 ms, db 482 ms, view 0.07 ms, serialization 0 ms 이므로 약 10 s 는 위 Ruby/cache/네트워크 경로에 분포한다.

Log Evidence#

Datadog 쿼리:

service:cupixworks-api "WorkspacesController#create" region:ap-southeast-2

대표 slow 요청 (이번 cluster):

{
  "@timestamp": "2026-06-25T00:47:57.485Z",
  "controller": "Api::V1::WorkspacesController",
  "action": "create",
  "duration": 10511.12,
  "db": 482.17,
  "view": 0.07,
  "serialization": { "duration": 0 },
  "http": { "status_code": 200, "method": "POST", "url_details": { "path": "/api/v1/workspaces" } },
  "team": { "domain": "successful", "id": 149 },
  "params": { "name": "Brad Hardie Pavillion" },
  "environment": "production",
  "request_id": "21670c89-ca7f-4b91-88b3-577018415ca0"
}

같은 endpoint 의 ap-southeast-2 production 최근 샘플 duration 분포:

duration  db
9661.84   361.77
10511.12  482.17
2568.01   ...
4984.36   ...
3260.93   ...
9337.6    ...

모든 샘플에서 200 응답이고 serialization.duration 은 0 이다. DB 시간이 응답 시간의 3 ~ 5 % 수준이므로 병목은 DB 가 아니다.

us-west-2 production 비교 샘플 (같은 endpoint):

duration
7588.10
3920.97

us-west-2 도 빠르지 않지만 ap-southeast-2 와 동일한 패턴. region 특이 이슈가 아니라 endpoint 구조 이슈로 해석된다.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

조치 사항 없음. 단일 occurrence (1 건) 이며 응답이 200 으로 성공했으므로 hotfix 대상은 아니다. APM (Datadog APM trace 3977113782513250106) 에서 span breakdown 을 확인해 어느 단계(flush_team_permission_cache iteration 길이 vs FacilityFactory.create! vs Sidekiq enqueue 동기 호출)가 가장 큰 비중인지 확정한다.

단기 개선 (1주 이내)#

1. app/factories/workspace_factory.rb:31-41 flush_team_permission_cache 를 backgrounded 처리 후보로 검토. 현재 request 안에서 team 의 모든 TeamPermission(permission >= 2) 와 그 산하 user 를 순회하며 Rails.cache.delete 를 동기 수행한다. 이 작업은 캐시 invalidation 이라 user-visible 응답에 포함될 필요가 없다. 별도 worker 로 분리하거나 batch 처리 권장. 단, 주석 ("Flush AFTER the default facility is created so a concurrent read ... cannot re-warm the cache") 의 일관성 요구를 어기지 않도록 cache key 설계와 함께 재검토.
2. app/factories/workspace_factory.rb:43-63 create_default_facility 호출이 user 응답 latency 에 포함되어 있다. UX 상 workspace 생성 직후 default facility 가 즉시 보일 필요가 없다면 비동기 worker 화 검토. 즉시 필요하다면 facility 생성 안의 share_to_creator → Permissionable.flush_cached_permissions 가 다시 user 별 cache delete 를 일으키는 중복을 정리.
3. app/factories/workspace_factory.rb:33 team.facilities.count + 1 와 app/factories/facility_factory.rb:32 team.facilities.count + 1 가 event extra 용으로 매 호출마다 COUNT(*) 를 실행한다. event extra 용도라면 cached counter (team.facilities_count column) 를 사용하도록 변경.

장기 개선 (재발 방지)#

1. APM continuous profiling 또는 rack-mini-profiler 결과를 RCA artifact 에 첨부할 수 있도록 trace export 자동화. 현재 cluster 가 단일 sample 만 가지고 있어 span 단위 진단이 어렵다.
2. Datadog APM 에 endpoint 별 P50/P95 SLO 와 알림 임계치 설정. WorkspacesController#create 의 ap-southeast-2 P95 가 7 ~ 10 s 대로 보이는데 현재 별도 알림이 없다 (cluster 1 occurrence 라는 점이 이를 시사).
3. 큰 team(권한 보유자 수가 많은 team) 에 대한 권한 캐시 invalidation 전략 재설계 — 현재는 O(team_permission count × group_member count) 의 동기 cache delete 가 모든 workspace 생성마다 실행된다.

Monitoring#

avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::workspacescontroller#create,env:production}.rollup(avg, 60)

p95:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::workspacescontroller#create,env:production}.rollup(avg, 60)

sum:trace.rack.request.hits{service:cupixworks-api,resource_name:api::v1::workspacescontroller#create,env:production,status:ok}.as_count()

avg:trace.active_record.duration{service:cupixworks-api,resource_name:api::v1::workspacescontroller#create,env:production}.rollup(avg, 60)

위 4 개 query 를 dashboard timeseries widget 에 그대로 사용. DB 시간 (trace.active_record.duration) 과 총 응답 시간 (trace.rack.request.duration) 의 격차가 endpoint Ruby 병목을 시각화한다.

Risk Assessment#

• Risk level: low (응답 성공, 단일 발생, 데이터 무결성 영향 없음)
• 예상 복잡도: standard (factory 체인 + 권한 cache 모듈 양쪽을 손대야 함, 회귀 위험 존재)