ES /docs

Api::V1::Admin::TeamsController#create (avg 18082ms, max 18082ms)

RCA: Api::V1::Admin::TeamsController#create (18s latency)

Overview#

What Happened#

2026-06-24 21:40 KST에 cupixworks-api 서비스의 POST /api/v1/admin/teams 요청 1건이 약 18초(18,082ms) 만에 200 OK로 종료됐다. 어드민이 새 team을 생성하는 동기 경로가 form-design 템플릿 복사, 그룹 생성, workspace+facility 생성, 권한 캐시 flush까지 한 트랜잭션 안에서 직렬로 수행되기 때문에 응답이 느렸다. 동일 endpoint는 14일 동안 12회만 호출됐고, 모든 호출이 비슷한 지연을 보이는 만큼 1회성 사고가 아니라 구조적 지연이다.

Quick Facts#

Field Value
resource_name Api::V1::Admin::TeamsController#create
service cupixworks-api
avg_duration_ms 18082
max_duration_ms 18082
sample_trace_id 3568006001878499432
env production, us-west-2
tenant cupix

Affected Teams#

Team / Domain Error Count Impact
Admin console (internal ops) 1 신규 team 프로비저닝 요청이 18초 동안 블로킹. 어드민 UI에서 timeout/이중 클릭 위험

Timeline#

  1. 2026-06-24 21:40:16 KSTPOST /api/v1/admin/teams 요청 수신 (first_seen)
  2. 2026-06-24 21:40:28 KST[Skeleton][Team] Copy FormDesign/FormField to team.id: 1251 로그 발행 (request 시작 후 약 12초)
  3. 2026-06-24 21:40:34 KST[200] POST /api/v1/admin/teams 응답 완료 (총 18초)

Error Log#

Datadog Logs

cluster representative spanjson
{
  "resource_name": "Api::V1::Admin::TeamsController#create",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 18082,
  "max_ms": 18082,
  "sample_trace_id": "3568006001878499432"
}

Impact#

  • Service: cupixworks-api
  • 발생 횟수: 1 (14일간 동일 endpoint는 총 12회 호출)
  • 최초 발생: 2026-06-24 21:40 KST
  • 최근 발생: 2026-06-24 21:40 KST

cluster_type: latency로 분류된 클러스터다. 5xx/exception 은 발생하지 않았고 200 OK 로 정상 종료됐다. 다만 18초의 응답 시간은 어드민 콘솔의 사용자 경험을 크게 해치며, ALB/CloudFront timeout (보통 60초 이내) 에 가까운 마진을 남긴다. 동일 endpoint 의 14일치 호출 12건이 모두 @duration:>500ms 필터에 잡힌다는 점은 이 지연이 1건의 일시적 spike 가 아니라 코드 경로에 내재된 baseline 임을 시사한다.

Root Cause Summary#

Admin::TeamFactory#create! 가 신규 team 생성 시 필요한 모든 부수 작업(team 저장 + 6개 default group + user 저장 + form-design 템플릿 hardcopy + workspace + facility + permission cache flush + state machine 전이) 을 단일 동기 HTTP 요청 안에서 직렬로 수행한다. 그 중 create_default_form_designsTEMPLATE_TEAM_DOMAIN team 의 모든 FormDesign 과 각 form 의 FormField 를 하나씩 hardcopy 로 복제하는 N+1 성격의 루프를 돌고, WorkspaceFactory#flush_team_permission_cacheTeamPermission.where(permission >= 2) 를 순회하며 각 accessor 의 권한 캐시를 flush 한다. 새 team 호출 1건이 평균 18초 걸리는 이유다. 즉시 실패하는 bug 가 아니라 sync 경로에 누적된 work 의 합으로 인한 구조적 latency 다.

Technical Analysis#

Code Path#

요청 진입점은 admin controller 의 create 액션이다.

app/controllers/api/v1/admin/teams_controller.rb:11-15ruby
def create
  @model = factory_instance.create!(params.permit!)

  show
end

factory_instanceAdmin::TeamFactory 로 위임된다 (factory 메서드, 같은 파일 95-97).

app/factories/admin/team_factory.rb:28-40ruby
def create!(params = {})
  check_params!(params)

  team = create_team!(params)
  user = create_user!(params)
  team.create_default_form_designs
  create_workspace_and_facility(params)
  team.active_state!

  IspringCreateDepartmentWorker.perform_async(team.id)

  team
end

각 단계는 모두 동기 호출이며, 마지막 줄의 IspringCreateDepartmentWorker 만 Sidekiq async 다. 나머지는 전부 request thread 안에서 수행된다.

create_team! 는 team 저장 후 TeamFactory.create_default_groups 를 호출해서 super_admin / administrators / users / everyone / technical_support_engineers / assigned_customer_success_managers — 6개 group 을 한 번에 생성하고 각각에 대해 add_permission! 까지 호출한다.

app/factories/team_factory.rb:28-58ruby
def create_default_groups(team)
  unless team.groups.where(group_type_code: :super_admin).exists?
    super_admin_group = GroupFactory.create!(team: team, name: 'Super Admin', group_type_code: :super_admin)
    team.add_permission! super_admin_group, 16
  end
  # ... 5 more groups: administrators, users, everyone,
  #     technical_support_engineers, assigned_customer_success_managers
  true
end

team.create_default_form_designsTEMPLATE_TEAM_DOMAIN team 의 FormDesign 들을 모두 가져와 하나씩 hardcopy 한다. 각 form 안의 form_fields 도 마찬가지로 하나씩 복제된다 — 명시적 batch 처리 없이 map { ... hardcopy ... } 두 단의 중첩 루프다.

app/models/concerns/skeleton/team.rb:8-32ruby
def create_default_form_designs
  return if self.domain == TEMPLATE_TEAM_DOMAIN

  already_copied_form_ids = self.reload.form_designs.untrashed.select(&:cupix_template?).pluck(:sys).map { |form_design| form_design[:cupix_template_id] }
  template_form_designs = ::FormDesign.eager_load(:team).where(teams: { domain: TEMPLATE_TEAM_DOMAIN }).where.not(form_designs: { id: already_copied_form_ids })

  Cupix::Logger.info("[Skeleton][Team] Copy FormDesign/FormField to team.id: #{self.id}") if template_form_designs.present?

  template_form_designs.map do |form_design|
    copied_form_design = form_design.hardcopy({
      team_id: self.id,
      user_id: self.user_id,
      sys: { cupix_template_id: form_design.id }
    })

    form_design.form_fields.map do |form_field|
      copied_form_field = form_field.hardcopy({
        team_id: self.id,
        user_id: self.user_id,
        form_design_id: copied_form_design.id,
        sys: { cupix_template_id: form_field.id }
      })
    end
  end
end

create_workspace_and_facility 는 workspace + facility 를 두 번 더 만든다.

app/factories/admin/team_factory.rb:115-118ruby
def create_workspace_and_facility(params)
  workspace = ::WorkspaceFactory.new(current_user: self.user).create!(params[:workspace].merge({ skip_default_facility_creation: true }))
  facility = ::FacilityFactory.new(current_user: self.user).create!(params[:facility].merge(workspace_id: workspace.id))
end

WorkspaceFactory#create! 는 끝에서 flush_team_permission_cache 를 동기로 호출한다. permission ≥ 2 인 모든 TeamPermission 을 순회하며 accessor 마다 캐시 flush 를 수행한다.

app/factories/workspace_factory.rb:21-41ruby
WorkspaceFactory.create_default_facility(self.model, params[:facility]) unless params[:skip_default_facility_creation] == true

# Flush AFTER the default facility is created so a concurrent read from an
# administrator already inside the workspace cannot re-warm the cache with a
# facility list that predates the auto-created facility.
flush_team_permission_cache(team)

self.model
end

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 에 대해 sync 로 flush 를 돌린다.

app/models/concerns/permissionable.rb:120-128ruby
def flush_cached_permissions(user_or_group)
  Cupix::Logger.info("Flush cached permissions for #{user_or_group.class.name} #{user_or_group.id}", class: self.class.name, function: __method__)
  case user_or_group
  when ::User
    user_or_group.flush_cached_permission
  when ::Group
    user_or_group.users.find_each(&:flush_cached_permission)
  end
end

기대 동작: admin team 생성 요청이 1-2초 안에 응답하고 무거운 setup 은 background worker 로 위임. 실제 동작: 모든 setup 이 request thread 안에서 직렬 실행되어 단일 호출이 18초까지 늘어남.

Log Evidence#

Cluster 가 인용한 Datadog 쿼리(span 측):

text
service:cupixworks-api resource_name:"Api::V1::Admin::TeamsController#create" env:production @duration:>500ms

Datadog log 쪽에서 같은 시간대를 재현하기 위해 사용한 쿼리:

text
service:cupixworks-api "Api::V1::Admin::TeamsController#create"

지난 24시간 내 Api::V1::Admin::TeamsController#create 가 정상 200 으로 끝난 호출 4건. 모두 @duration:>500ms 필터에 잡힐 만큼 느리다.

text
2026-06-24 22:42:59 [200] POST /api/v1/admin/teams (Api::V1::Admin::TeamsController#create)
2026-06-24 21:40:34 [200] POST /api/v1/admin/teams (Api::V1::Admin::TeamsController#create)  <-- cluster span
2026-06-24 15:45:11 [200] POST /api/v1/admin/teams (Api::V1::Admin::TeamsController#create)
2026-06-24 09:31:24 [200] POST /api/v1/admin/teams (Api::V1::Admin::TeamsController#create)

지난 7일로 확장한 동일 쿼리는 12건 모두 @duration:>500ms 에 매칭됐다 — 즉 admin team 생성은 14일 retention 안에서 빠짐없이 slow 로 분류된다.

같은 트랜잭션 안에서 발행된 [Skeleton][Team] Copy FormDesign/FormField 로그가 요청이 들어오고 약 12초 뒤에 찍힌다. cluster span 의 18초 latency 중 절반 이상이 응답 종료 이전 단계에서 누적되고 있다는 직접 증거다.

text
2026-06-24 21:40:28 [Skeleton][Team] Copy FormDesign/FormField to team.id: 1251
2026-06-24 21:40:34 [200] POST /api/v1/admin/teams (Api::V1::Admin::TeamsController#create)

요청 시작이 first_seen: 2026-06-24T12:40:16.179Z (= 21:40:16 KST) 이고 form-design 복사 로그가 21:40:28 KST 에 찍혔으므로 form-design 복사 단계까지 약 12초가 소비됐다.

비교용으로 trace_id 3568006001878499432 로 직접 검색했을 때 로그가 0건 반환됐다. APM trace 가 log correlation 으로 색인되지 않은 케이스라 정확한 child-span 분해는 trace 화면에서 별도 확인이 필요하다 — uncertain -- needs verification (Datadog APM UI).

요청 시간대(now-12h)의 status:error 검색 결과는 Api::V1::Admin::TeamsController#create 와 무관한 OPC integration / set_upload_state / NotificationService 에러뿐이었다. 즉 이 latency 가 외부 의존성 장애와 동시에 일어난 것이 아니라, create 경로 자체의 비용에서 비롯됐음을 보여준다.

text
2026-06-24 22:35:53 [OpcOperation] Failed to get OPC API access token ... (unrelated)
2026-06-24 22:27:12 Exception occurred at set_upload_state ... (unrelated)
2026-06-24 19:45:03 processing 'facility_permission.created' failed: private method `service_jwt' ... (unrelated)

Status-board 조회 결과 이 cluster 는 svc:cupixworks-api::unknown (incident id 2026-06-24-svc-cupixworks-api--unknown-1) 에 묶여 있다. 같은 서비스의 다른 unknown root-cause cluster 들과 함께 묶인 상태이며, 외부 dependency outage 와는 매핑되어 있지 않다.

Hypotheses Considered#

# Hypothesis Evidence for Evidence against Verdict
H1 Admin::TeamFactory#create! 의 sync 경로 (form-design hardcopy + default groups + workspace/facility + permission cache flush) 가 누적되어 18초 latency 를 만든다 코드 경로 전체가 sync (app/factories/admin/team_factory.rb:28-40); [Skeleton][Team] Copy FormDesign 로그가 요청 시작 12초 뒤에 찍힘; 14일 retention 안의 create 호출 12건이 모두 @duration:>500ms 에 매칭 Confirmed
H2 외부 의존성(예: iSpring, S3) 장애로 인한 spike 같은 12분 윈도우의 OPC 409 에러, NotificationService service_jwt 에러 로그 존재 OPC/Notification 에러는 TeamsController#create 경로와 무관 (IspringCreateDepartmentWorker 만 iSpring 호출이며 perform_async); cluster 는 5xx 가 아닌 200 OK; 동일 endpoint 가 7일 내 12회 모두 >500ms 로 만성적임 (외부 outage 라면 일시적 spike 로 나타나야 함) Rejected
H3 DB lock / contention 으로 인한 일시적 stall (특정 시각 only) 트랜잭션 안에서 team / user / workspace / facility 저장 다수 발생 14일 내 12회 호출 모두 비슷한 지연 — random contention 이라면 분포가 더 불균등해야 함; cluster 는 1건만 잡혔으므로 metric 단일점만으로는 contention 증거 불충분 Inconclusive
H4 flush_team_permission_cache 가 기존 큰 team 의 모든 TeamPermission 을 도는 경우 WorkspaceFactory#flush_team_permission_cache 코드 (app/factories/workspace_factory.rb:31-41) 가 모든 permission ≥ 2 accessor 순회 이 경로는 신규 team 생성이라 TeamPermission 수가 매우 적음 (방금 만들어진 default group 6개 정도). 따라서 신규 team 시나리오에서는 이 단계의 비중이 크지 않다. 큰 team 의 workspace 추가 시에는 hot path 가 될 수 있으나 본 cluster 의 root cause 는 아님 Rejected

Fix Recommendation#

즉시 조치 (Critical)#

본 cluster 1건만으로 user 가시적 incident 는 발생하지 않았다. 즉시 prod 배포가 필요한 hotfix 는 없다. 다만 다음을 권고한다.

  • 어드민 콘솔 UI 가 POST /api/v1/admin/teams 호출에 대해 client-side timeout 을 20초 이상 잡고 있는지 점검. ALB/CloudFront 의 idle timeout (보통 60s) 보다 충분히 짧은 마진을 확보.
  • Datadog APM 에서 sample_trace_id 3568006001878499432 의 child span 분해를 직접 확인하여 form-design 복사가 실제 차지하는 시간을 측정한다 (uncertain -- needs verification).

단기 개선 (1주 이내)#

Admin::TeamFactory#create! 의 무거운 sub-step 들을 background worker 로 분리한다. 어디까지 sync 로 남겨야 하는지는 admin UI 가 응답에서 어떤 필드를 즉시 요구하는지에 따라 결정.

  • create_default_form_designs 를 비동기화: app/factories/admin/team_factory.rb:33 의 sync 호출을 CopyTemplateFormDesignsWorker.perform_async(team.id) 같은 worker 호출로 교체. IspringCreateDepartmentWorker 와 동일한 패턴.
  • form-design hardcopy 의 N+1 제거: app/models/concerns/skeleton/team.rb:16-31 의 중첩 map { ... hardcopy ... } 를 bulk insert (insert_all/copy_in) 로 재작성. hardcopy 가 callback 을 부르고 있으면 deep_dup + assign_attributes + batch save 로 분해.
  • default group 생성을 batch 화: app/factories/team_factory.rb:28-58 의 6번의 GroupFactory.create! + 5번의 add_permission! 호출을 단일 트랜잭션 + insert_all 로 묶거나 worker 로 분리.

장기 개선 (재발 방지)#

  • Team provisioning 을 명시적 multi-step orchestration 으로 분리: TeamFactory 가 한 메서드 안에서 7가지 setup 을 묶어 하는 현재 구조 대신, TeamProvisioningJob 같은 background orchestrator 가 단계별 worker 를 fan-out 시키도록 변경. create API 는 최소한의 team record 만 만들고 202 Accepted 반환 (UI 가 이를 지원하면).
  • Latency budget guard: admin endpoint 에 sync 작업 누적 시간이 예산(예: 3s) 을 넘으면 dev/staging 에서 RSpec/Sorbet 단계에서 경고하도록 spec 추가.
  • APM trace 의 자동 회귀 감지: service:cupixworks-api resource_name:Api::V1::Admin::TeamsController#create 의 p95 latency 가 임계치(예: 5s) 를 넘으면 알림.

Monitoring#

text
service:cupixworks-api resource_name:"Api::V1::Admin::TeamsController#create" env:production @duration:>500ms
text
service:cupixworks-api "[Skeleton][Team] Copy FormDesign"
text
avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::admin::teamscontroller#create}
text
p95:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::admin::teamscontroller#create}

trace.rack.request.duration 쿼리는 본 RCA 시점에는 빈 응답을 반환했다(Datadog metrics API series:[]). resource_name 의 정확한 normalization (lowercase 여부) 을 production tag 와 대조하여 검증해야 한다 — uncertain -- needs verification.

Risk Assessment#

  • Risk level: medium. 사용자 가시적 5xx 는 없으나 18초 응답은 admin 운영 부담과 timeout 위험 동반. 새 team 프로비저닝은 빈도는 낮지만 비즈니스 critical operation (신규 고객 onboarding) 이라 안정성·예측가능성이 중요하다.
  • 예상 복잡도: standard. form-design 복사 비동기화 + default group bulk insert 는 기존 IspringCreateDepartmentWorker 패턴과 동일하게 적용 가능. 다만 form-design hardcopy callback 의 사이드이펙트(예: ES 인덱싱) 와 admin UI 가 응답에서 form-design id 를 즉시 요구하는지 여부를 사전에 확인해야 함.