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-api 의 PUT /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#
- 2026-06-24 14:17:27 KST — 요청 시작. 첫 신규 이메일
htateisi@tanseisha.co.jp에 대해 Cognito 사용자 생성 시작 - 2026-06-24 14:17:29 KST — 두 번째 신규 이메일
mkomatsuda@tanseisha.co.jpCognito 사용자 생성 (~+2s) - 2026-06-24 14:17:31 KST — 세 번째 신규 이메일
kmiyamoto@tanseisha.co.jpCognito 사용자 생성 (~+2s) - 2026-06-24 14:17:36–14:17:43 KST — 각 신규 사용자별 notification-service
create_user_recipe3건 +subscribe1건 순차 HTTP 호출. 기존 사용자yyabe@tanseisha.co.jp(id 38925) 도 동일 흐름 반복 - 2026-06-24 14:17:43 KST —
Cupix::EventService.publish_event호출 +flush_cached_permissions다수 - 2026-06-24 14:17:44 KST — 요청 완료 (HTTP 200, 총 16643ms)
Error Log#
{
"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_share 는 params[: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(routePUT /api/v1/reviews/share→ actionbulk_share,ShareControllerconcern 에서 정의) - 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
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 비용이 그대로 누적된다.
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 를 돈다.
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_event 와 flush_cached_permissions 를 호출한다.
기대 동작 vs 실제 동작: 컨트롤러는 응답을 빠르게 반환하고 외부 의존 호출은 비동기(Sidekiq)로 위임해야 하지만, 실제로는 모든 외부 호출을 요청 thread 안에서 직렬로 수행하여 응답 시간이 외부 RTT 합과 같아진다.
Log Evidence#
Datadog 쿼리:
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 메타데이터 (대표):
{
"@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):
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_document 가 NotFound - 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-77의bulk_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_user와send_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:
p95:trace.rack.request.duration{service:cupixworks-api,resource_name:Api::V1::ReviewsController#bulk_share}
p99:trace.rack.request.duration{service:cupixworks-api,resource_name:Api::V1::ReviewsController#bulk_share}
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 (워커 분리 리팩토링 + 호출자 응답 형태 조정 필요)