Api::V1::WorkspacesController#create (avg 3661ms, max 3661ms)

RCA: Api::V1::WorkspacesController#create Latency (3661ms)

Overview#

What Happened#

2026-05-26 07:18 UTC에 cupixworks-api 서비스의 WorkspacesController#create 엔드포인트가 3661ms 응답 시간을 기록했다. DB 시간은 303ms에 불과했으나, workspace 생성 시 동기적으로 실행되는 외부 HTTP 호출(Notification Service recipe 생성 6회, Kinesis event 발행 2회, Elasticsearch indexing 2회, Segment analytics 2회)이 나머지 ~3358ms를 소비했다.

Quick Facts#

Field	Value
resource_name	`Api::V1::WorkspacesController#create`
top_frame	`app/factories/workspace_factory.rb:19`
runtime	Ruby 3.3.7 / Rails
env	production, us-west-2
duration	3661ms (DB: 303ms)
trace_id	`3364104123778959333`

Timeline#

07:18:51.650Z — 요청 시작, Cognito 인증 완료
07:18:51.843Z — Workspace + Facility DB 생성, create_default_reviews 실행, permission cache flush
07:18:51.843~53.844Z — NotificationService HTTP 호출 6회 (recipe 생성 3 + 중복 체크 3 + subscribe 1)
07:18:53.844Z — SiteInsights EventProducer 호출, _update_document warn
07:18:54.181Z — 200 응답 반환 (총 3659ms)

Error Log#

Datadog Logs

json

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

Impact#

Service: cupixworks-api
발생 횟수: 1
최초 발생: 2026-05-26T07:18:49.831Z
최근 발생: 2026-05-26T07:18:49.831Z
영향: Workspace 생성 API가 3.6초 소요되어 사용자 체감 지연 발생. 동일 시간대 다른 요청(CapturesController#update 4.9초, UsersController#destroy 4.9초)도 유사한 지연 패턴을 보임.

Root Cause Summary#

Workspace 생성 시 WorkspaceFactory#create!가 workspace와 default facility를 순차 생성하며, 각 엔티티의 after_create/after_commit 콜백에서 외부 서비스(Notification Service, AWS Kinesis, Elasticsearch, Segment)로의 동기 HTTP 호출이 누적되어 총 ~3.3초의 네트워크 대기 시간이 발생한다. 특히 Cupix::NotificationService#create_user_recipe가 3개 recipe에 대해 순차 HTTP POST를 수행하고, FacilityPermission 생성 시 추가 recipe 3회 + subscription 1회가 동기적으로 실행된다.

Technical Analysis#

Code Path#

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

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

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

WorkspaceFactory#create!에서 workspace 생성 후 default facility 동기 생성:

app/factories/workspace_factory.rb:5-24ruby

def create!(params = {})
  self.model = ::Workspace.new
  unless Pundit.policy(self.current_user, self.current_team).create_workspace?
    raise Cupix::Errors::PermissionDenied.new(code: 'PERM10000', reason: 'Only Workspace Creators or Administrators can create workspace')
  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! (triggers all callbacks)
  WorkspaceFactory.create_default_facility(self.model, params[:facility]) unless params[:skip_default_facility_creation] == true
  self.model
end

model.save! 시 Eventable::Events::Base.create_event가 동기적으로 Kinesis + Segment 호출:

app/models/concerns/eventable/events/base.rb:7-18ruby

def create_event(model)
  return nil if invalid_event?(model)
  begin
    event = _create_event(model)
    reason = extract_reason(event, model)
    properties = build_properties(model)
    track_event(model, reason, properties)          # → Analytics.track (Segment HTTP)
    Cupix::EventService.publish_event([event])      # → Kinesis put_records!
    Cupix::Event.publish(event.serializable_hash(stringify_nested_fields: false))
  rescue StandardError => e
    # ...
  end
end

after_commit에서 Elasticsearch 동기 인덱싱:

app/models/concerns/searchable.rb:12-14ruby

after_commit on: [:create] do
  _index_document  # synchronous HTTP call to Elasticsearch
end

Facility 생성 후 FacilityPermission PubSub가 NotificationService recipe 생성 + subscribe 동기 호출:

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

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

lib/cupix/notification_service.rb:11-24ruby

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 }
  )
  Cupix::Logger.info("recipe created: #{response.body}", class: self.class.name, function: __method__)
end

Failure point: 특정 코드 실패는 아님. 설계 문제 — 모든 외부 호출이 요청 처리 스레드에서 동기적으로 실행됨.

Log Evidence#

Datadog 쿼리:

text

service:cupixworks-api @request_id:f3fc8538-3d65-4d4b-8be0-2e5fd15d2777

요청 내 로그 타임라인:

text

07:18:51.843Z [info] Facility::create_default_reviews - Copy C. Expert Review Review to facility.key: j5q86f
07:18:51.843Z [info] Deleting cached_permission on user 49220
07:18:53.844Z [info] recipe created: record_preview_ready  (Cupix::NotificationService/create_user_recipe)
07:18:53.844Z [info] recipe created: record_processing_completed
07:18:53.844Z [info] recipe created: facility_new_project
07:18:53.844Z [info] subscription of hani.yoo@cupix.com on Facility j5q86f created
07:18:53.844Z [info] Recipe already exists, skipping creation (x3)
07:18:53.844Z [warn] NotFound - attributes_in_database  (Workspace/_update_document)
07:18:53.844Z [info] Publishing 1 create events for Workarea (EventProducer)
07:18:54.181Z [info] [200] POST /api/v1/workspaces (3659.22ms, db:302.89ms)

외부 API 호출 확인 (trace_id: 3364104123778959333):

text

07:18:51.650Z POST /api/recipes/v2 → lbk178fhsb.execute-api.us-west-2.amazonaws.com
User-Agent: rest-client/2.1.0 (linux x86_64) ruby/3.3.7p123

시간 소비 분석:

DB 작업: ~303ms
NotificationService HTTP 호출 (recipe 3건 + duplicate check 3건 + subscribe 1건): ~2000ms
Kinesis put_records + Segment track (workspace + facility 각 1회): ~600ms
Elasticsearch index (workspace + facility): ~400ms
기타 (cache flush, default reviews): ~350ms

Hypotheses Considered#

#	Hypothesis	Evidence for	Evidence against	Verdict
H1	동기 NotificationService HTTP 호출이 주요 지연 원인	로그상 07:18:51→53 간 2초 갭 확인. recipe 생성 6회 + subscribe 1회 순차 실행. Lambda API Gateway 경유 확인	—	Confirmed
H2	DB 쿼리 과부하 (N+1 등)	—	DB time 303ms로 전체의 8%에 불과	Rejected
H3	Elasticsearch indexing 지연	`_update_document` warn 로그, after_commit에서 동기 호출 확인	전체 지연의 일부(~400ms)이며 주요 원인은 아님	Partial
H4	Kinesis/Segment 동기 호출 지연	`Eventable::Events::Base.create_event`에서 동기 호출 코드 확인, workspace + facility 2회 실행	개별 호출은 ~150-300ms로 주요 원인은 아니나 누적 기여	Partial
H5	서버 부하로 인한 일시적 지연	동일 호스트에서 4-5초대 요청 다수 관찰	패턴이 일관적이어서 부하보다 구조적 문제	Rejected

Fix Recommendation#

즉시 조치 (Critical)#

lib/cupix/pub_sub/subscribers/user_recipe_generator.rb:34-41: recipe 생성 루프를 비동기 worker로 이동. NotificationRecipeWorker.perform_async(user_id, recipe_names, team_id, facility_key) 패턴으로 Sidekiq worker 위임.
lib/cupix/pub_sub/subscribers/subscription_generator.rb:20-21: subscribe 호출도 동일하게 비동기화.

단기 개선 (1주 이내)#

app/models/concerns/eventable/events/base.rb:15-17: track_event (Segment) 및 Cupix::EventService.publish_event (Kinesis) 호출을 after_commit 이후 비동기 worker에서 실행하도록 변경. 이미 RunAfterEventCreatedWorker가 존재하므로, event 발행 로직을 해당 worker로 통합 가능.
app/models/concerns/searchable.rb:12-14: _index_document를 UpdateSearchIndexWorker.perform_async(model.class.name, model.id) 형태로 비동기화 검토.

장기 개선 (재발 방지)#

Workspace 생성 응답 시간 SLO 설정 (예: p99 < 1000ms).
모든 after_create/after_commit 콜백에서의 외부 HTTP 호출을 감사(audit)하고, 동기 호출을 비동기 worker 패턴으로 통일하는 가이드라인 수립.
Notification Service 호출을 배치 API로 전환하여 개별 recipe마다 HTTP 왕복을 줄임.

Monitoring#

Workspace 생성 응답 시간 p95/p99 모니터링:

text

service:cupixworks-api resource_name:"Api::V1::WorkspacesController#create" @duration:>2000ms

NotificationService 외부 호출 지연 추적:

text

service:cupixworks-api @http.url:*recipes* @duration:>500ms

Elasticsearch indexing 지연 모니터링:

text

service:cupixworks-api "NotFound - attributes_in_database" status:warn

Risk Assessment#

Risk level: medium
예상 복잡도: standard — 기존 Sidekiq worker 패턴을 활용하여 비동기화하면 되나, callback 실행 순서와 의존성 검증 필요.