ES /docs

Api::V1::ReviewsController#bulk_share (avg 16645ms, max 16645ms)

RCA: Api::V1::ReviewsController#bulk_share (avg 16645ms, max 16645ms)

Overview#

What Happened#

2026-06-24 14:17 KST, cupixworks-apiPUT /api/v1/reviews/share 요청 1건이 16.6초 동안 실행되었다. 사용자가 bulk_share items 안에 새 초대 이메일 3건 + 기존 사용자 1건을 함께 전달했고, 컨트롤러가 각 이메일을 순차적으로 Cognito 사용자 생성 → notification-service recipe 등록 → subscription 생성으로 처리하는 동안 외부 서비스 RTT 가 누적되어 응답이 지연되었다.

Quick Facts#

Field Value
resource_name Api::V1::ReviewsController#bulk_share
duration 16643.14 ms
db 1051.16 ms
view 0.09 ms
serialization.duration 9 ms
http.method / status PUT / 200
http.url /api/v1/reviews/share
env production, us-west-2
tenant / team cupix / tanseisha (id 745)
user id 13097 (rfujisaki@tanseisha.co.jp)
request_id fe6c8843-286e-4937-b309-5a4e4c1eb0e1
sample_trace_id 4066188360319898813
deploy production-us-west-2-20260624t0500z0-24b9962e-cupixworks

Affected Teams#

Team / Domain Error Count Impact
tanseisha (id 745) 1 bulk_share UI 16.6초 hang. HTTP 200 으로 종료되어 데이터 손실은 없으나, 사용자 체감 지연 + ALB/Cloudflare idle timeout 위험

Timeline#

  1. 2026-06-24 14:17:27 KST — 요청 시작. 첫 신규 이메일 htateisi@tanseisha.co.jp 에 대해 Cognito 사용자 생성 시작
  2. 2026-06-24 14:17:29 KST — 두 번째 신규 이메일 mkomatsuda@tanseisha.co.jp Cognito 사용자 생성 (~+2s)
  3. 2026-06-24 14:17:31 KST — 세 번째 신규 이메일 kmiyamoto@tanseisha.co.jp Cognito 사용자 생성 (~+2s)
  4. 2026-06-24 14:17:36–14:17:43 KST — 각 신규 사용자별 notification-service create_user_recipe 3건 + subscribe 1건 순차 HTTP 호출. 기존 사용자 yyabe@tanseisha.co.jp (id 38925) 도 동일 흐름 반복
  5. 2026-06-24 14:17:43 KSTCupix::EventService.publish_event 호출 + flush_cached_permissions 다수
  6. 2026-06-24 14:17:44 KST — 요청 완료 (HTTP 200, 총 16643ms)

Error Log#

Datadog Logs

text
{
  "resource_name": "Api::V1::ReviewsController#bulk_share",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 16645,
  "max_ms": 16645,
  "sample_trace_id": "4066188360319898813"
}

Impact#

  • Service: cupixworks-api
  • 발생 횟수: 1
  • 최초 발생: 2026-06-24 14:17 KST
  • 최근 발생: 2026-06-24 14:17 KST

DB time 은 1051ms, view 0.09ms, serialization 9ms 로 합산이 ~1.06s. 나머지 ~15.5s 는 모두 외부 HTTP 동기 호출(Cognito + notification-service + event-service) 누적 시간이며 사용자 facing latency 로 그대로 노출되었다.

Root Cause Summary#

Api::V1::ReviewsController#bulk_shareparams[:items] 의 각 항목에 대해 repository_instance.share 를 직렬로 호출하고, 그 안에서 params[:emails] 가 있으면 InvitationOperation.invite_people 가 신규 이메일마다 Cognito 사용자 생성 + notification-service recipe 등록 + subscription 생성을 모두 동기로 수행한다. 이번 요청은 신규 이메일 3건과 기존 사용자 1건을 포함했고, 외부 서비스 호출 한 사이클이 약 2초씩 누적되며 총 16.6초가 되었다. 즉 root cause 는 N개의 외부 의존 호출(Cognito, notification-service, event-service)을 controller 요청 thread 안에서 직렬로 수행하는 구조 이며, 호출 자체가 실패한 것은 아니다 (HTTP 200 으로 종료).

Technical Analysis#

Code Path#

  • Entry point: app/controllers/api/v1/reviews_controller.rb (route PUT /api/v1/reviews/share → action bulk_share, ShareController concern 에서 정의)
  • Action body: app/controllers/concerns/share_controller.rb:62-77
  • Per-item share: app/repositories/concerns/sharable_repository.rb:131-193
  • Invite path: app/operations/invitation_operation.rb:32-97
  • Feature flag check (외부 HTTP): app/operations/midas_operation.rb:63-74
app/controllers/concerns/share_controller.rb:62-77ruby
def bulk_share
  validate_project_permissions_feature!
  check_share_requests!(params)

  members = params[:items].map do |item|
    @model = repository_instance.show(item[:model_id])

    repository_instance.share(item.slice(*SHARE_REQUEST_PARAMS), item[:permission])
  end.flatten.compact

  render_api Renderable.new({
    contents: members.uniq,
    is_collection: true,
    serializer: MemberSerializer
  })
end

items.map 이 동기 직렬 루프이므로 각 항목의 share 비용이 그대로 누적된다.

app/repositories/concerns/sharable_repository.rb:131-186ruby
def share(params, permission)
  # ...
  if params[:emails].present?
    email_array = params[:emails].is_a?(Array) ? params[:emails] : params[:emails].split(',').collect(&:strip)
    already_joined_or_invited_users = UserRepository.where(email: email_array, team: @current_team, state: %i[active invited])
    invite_candidate_user_emails = email_array - already_joined_or_invited_users.pluck(:email)

    if invite_candidate_user_emails.present?
      invited_users = InvitationOperation.invite_people(
        { user_emails: invite_candidate_user_emails, skip_permission_check: true },
        self.current_user, @current_team, @model
      )
    end
  end

  (@users + @groups + already_joined_or_invited_users + invited_users).each do |user_or_group|
    @model.add_permission! user_or_group, permission
    # ...
  end
  # ...
  ShareEntityMailerWorker.perform_async(...)

InvitationOperation.invite_people 는 동기 호출이며, 그 내부에서 신규 이메일마다 다시 직렬 loop 를 돈다.

app/operations/invitation_operation.rb:61-94ruby
invitees = emails.map do |email|
  # ...
  invitee = User.find_by(team: current_team, email: email)
  if invitee.present?
    # reuse path
  else
    user_factory = UserFactory.new(...)
    invitee = user_factory.create!({ team: current_team, email: email })
  end
  # ...
  send_invitation_mail({ user_email: email, redirect_url: redirect_url }, current_user, current_team, invitee)
  invitee
end

UserFactory#create! 는 DB 저장 외에 Cognito 사용자 생성 (Cognito#create_cognito_user) 과 notification-service 의 create_user_recipe × N 종, subscribe 호출을 동기로 수행한다 (아래 로그 evidence 참조). add_permission! 자체도 Cupix::EventService.publish_eventflush_cached_permissions 를 호출한다.

기대 동작 vs 실제 동작: 컨트롤러는 응답을 빠르게 반환하고 외부 의존 호출은 비동기(Sidekiq)로 위임해야 하지만, 실제로는 모든 외부 호출을 요청 thread 안에서 직렬로 수행하여 응답 시간이 외부 RTT 합과 같아진다.

Log Evidence#

Datadog 쿼리:

text
service:cupixworks-api @request_id:fe6c8843-286e-4937-b309-5a4e4c1eb0e1

Time window: 2026-06-24T05:17:00Z – 2026-06-24T05:18:00Z (UTC). 60 entries.

Request 메타데이터 (대표):

json
{
  "@timestamp": "2026-06-24T05:17:44.054Z",
  "duration": 16643.14,
  "view": 0.09,
  "serialization.duration": 9,
  "db": 1051.16,
  "http.method": "PUT",
  "http.url_details.path": "/api/v1/reviews/share",
  "http.status_code": 200,
  "action": "bulk_share",
  "controller": "Api::V1::ReviewsController",
  "user.id": 13097,
  "team.id": 745,
  "request_id": "fe6c8843-286e-4937-b309-5a4e4c1eb0e1"
}

요청 안에서 발생한 외부 호출 순서 (KST):

text
14:17:27  Cognito.create_cognito_user  htateisi@tanseisha.co.jp   (신규 user 51565)
14:17:27  Cupix::EventService.publish_event
14:17:27  User.segment_user_event × 3   (User 51565)
14:17:29  Cognito.create_cognito_user  mkomatsuda@tanseisha.co.jp (신규 user 51566)
14:17:29  Cupix::EventService.publish_event
14:17:29  User.segment_user_event × 3   (User 51566)
14:17:31  Cognito.create_cognito_user  kmiyamoto@tanseisha.co.jp  (신규 user 51567)
14:17:31  Cupix::EventService.publish_event
14:17:31  User.segment_user_event × 3   (User 51567)
14:17:36+ Cupix::NotificationService.create_user_recipe × 3  per user (51565, 51566, 51567, 38925)
14:17:39+ Cupix::NotificationService.subscribe  per user
14:17:43  Cupix::EventService.publish_event
14:17:43  ReviewPermission._update_document → "NotFound - attributes_in_database" (warn) × 4
14:17:43  Module.flush_cached_permissions / flush_cached_permissions_by_user × 다수
14:17:44  request 종료 (HTTP 200)

Cognito 호출 간격이 명확히 2초 단위로 누적되는 것이 보이며 (14:17:27 → 14:17:29 → 14:17:31), 이후 4명의 사용자별로 recipe/subscribe HTTP 호출이 다시 직렬로 진행된다. DB time 은 전체 16.6s 중 1.05s 에 불과해 latency 의 ~94% 가 외부 HTTP 동기 호출에서 발생한 것이 확인된다.

부가 신호: ReviewPermission._update_documentNotFound - attributes_in_database warn 을 반복적으로 남긴다. 이번 latency 의 직접 원인은 아니지만 share 흐름 중 ElasticSearch indexer 가 방금 만든 permission 의 prior state 를 못 찾는 race 가 있어 별도 점검이 필요하다 (uncertain — needs verification, 본 RCA 범위 밖).

Hypotheses Considered#

# Hypothesis Evidence for Evidence against Verdict
H1 Bulk_share 가 신규 이메일 초대를 포함할 때, 항목·이메일별 Cognito + notification-service + event-service 호출을 직렬로 수행해 외부 RTT 가 누적된 응답 지연 request_id fe6c8843 안에서 14:17:27→14:17:29→14:17:31 의 2초 간격 Cognito 호출 3건, 그 뒤 4 사용자에 대한 recipe×3 + subscribe 직렬 호출 (@request_id:fe6c8843-286e-4937-b309-5a4e4c1eb0e1 60건). duration 16643ms / db 1051ms / view 0.09ms — 94% 가 외부 HTTP. 코드: share_controller.rb:62-77, sharable_repository.rb:131-186, invitation_operation.rb:61-94 Confirmed
H2 DB slow query / N+1 가 원인 Datadog request log 의 db: 1051.16ms 가 전체 16643ms 중 6.3% 에 불과. view/serialization 도 합 9ms. DB latency 로는 16.6s 설명 불가 Rejected
H3 MidasOperation.validate_feature 또는 단일 외부 API timeout 한 건이 전체 지연 원인 validate_feature 는 외부 HTTP POST 1건 (midas_operation.rb:63-74) 로그에 timeout/에러 흔적 없음. status 200 으로 정상 종료. 또한 14:17:27 이후 2초 간격으로 다수 Cognito/notification-service 호출이 누적되는 분포가 단일 stall 패턴과 불일치 Rejected
H4 외부 의존(SVC cupixworks-api::unknown 인시던트, status board) 자체가 다운되어 모든 호출이 느려졌다 status-board 가 active incident 2026-06-24-svc-cupixworks-api--unknown-1 안에 본 cluster 포함 active 인시던트는 svc:*::unknown 스코프이며 외부 dependency 가 아닌 같은 서비스의 root_cause_types=unknown 그룹. 본 trace 의 외부 호출들은 모두 200 으로 응답했고 통상 RTT 범위 (Cognito ~2s, notification-service 수백 ms) 안에 있음 Rejected

Fix Recommendation#

즉시 조치 (Critical)#

  • 즉시 코드 변경 없음. 이 1건은 신규 초대 3건 + recipe×3 + subscribe 등 외부 RTT 누적의 정상 한계로, latency 가 점진적으로 누적되어 발생한 것이지 버그/장애가 아니다. SLA 관점에서만 후속 개선 필요.

단기 개선 (1주 이내)#

  • app/controllers/concerns/share_controller.rb:62-77bulk_share 동작을 분리:
    • 권한 부여 (add_permission!) 와 즉시 응답에 필요한 DB 작업만 동기로 유지
    • notification-service 호출 (create_user_recipe, subscribe), Segment 이벤트, Cupix::EventService.publish_event 는 Sidekiq worker 로 위임 (이미 존재하는 ShareEntityMailerWorker 와 동일 패턴 차용 권장)
  • app/operations/invitation_operation.rb:61-94 의 이메일별 Cognito.create_cognito_usersend_invitation_mail 호출을 모아 별도 InviteUsersWorker (Sidekiq) 로 비동기 실행. 응답에는 invited user 의 임시 record id 만 반환하고, Cognito 생성 결과는 폴링/푸시로 클라이언트에 전달.
  • 동기 유지가 필요한 경우라도 params[:emails] 개수에 상한(예: 5) 을 두고 초과 시 ARG10001 로 거절하여 사용자 facing latency 의 worst-case 를 캡한다.

장기 개선 (재발 방지)#

  • 외부 HTTP 의존(Cognito, notification-service, event-service, segment) 을 호출하는 모든 컨트롤러 path 에 대해 "request thread 안에서 외부 호출 N회 이상 금지" 규칙을 도입하고, lint/spec 단계에서 정적 검사 (InvitationOperation, Cupix::NotificationService, Cognito.create_cognito_user 등의 호출 stack 을 컨트롤러까지 trace) 를 자동화.
  • bulk endpoint 패턴 (bulk_share, bulk_unshare, bulk_share 류의 items.map 컨트롤러) 을 전수 조사해 N(items) × M(외부 호출) 형태의 잠재 latency hot spot 식별.

Monitoring#

추가/유지할 timeseries:

text
p95:trace.rack.request.duration{service:cupixworks-api,resource_name:Api::V1::ReviewsController#bulk_share}
text
p99:trace.rack.request.duration{service:cupixworks-api,resource_name:Api::V1::ReviewsController#bulk_share}
text
sum:trace.rack.request.hits{service:cupixworks-api,resource_name:Api::V1::ReviewsController#bulk_share}.as_count()

비동기로 전환하기 전까지는 bulk_share 의 p95 가 5s 이상일 때 Slack 경고. 신규 worker 도입 후에는 ShareEntityMailerWorker / 신규 InviteUsersWorker 의 queue lag 도 함께 모니터.

Risk Assessment#

  • Risk level: low (1회, HTTP 200 정상 종료, 데이터 영향 없음)
  • 예상 복잡도: standard (워커 분리 리팩토링 + 호출자 응답 형태 조정 필요)