RCA: Api::V1::AnnotationLayersController#index Latency (1142ms)

Overview#

What Happened#

2026-05-26 03:21:43 UTC에 ap-southeast-2 리전의 cupixworks-api 서비스에서 AnnotationLayersController#index 요청이 1142ms 소요되었다. DB 시간은 34ms, serialization은 2ms에 불과하며, 나머지 ~1100ms가 request queue/thread contention과 인증 시 user provisioning 처리에 소요된 것으로 확인되었다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-05-26 03:21:42Z — 사용자(luke.champion@naylorlove.co.nz)가 review dlf1mp 프로젝트를 로드, 30+ 병렬 API 호출 발생
2. 2026-05-26 03:21:43Z — AnnotationLayersController#index 요청 시작, thread pool 경합으로 대기
3. 2026-05-26 03:21:44Z — UserFactory#update_user_groups! 실행, Group document NotFound 경고 발생
4. 2026-05-26 03:21:44.240Z — 응답 완료 (200 OK, 1140ms)

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::AnnotationLayersController#index",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 1142,
  "max_ms": 1142,
  "sample_trace_id": "3018009494027224968"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 1 (단, 24시간 내 동일 엔드포인트 >500ms 요청 33건)
• 최초 발생: 2026-05-26T03:21:43.090Z
• 최근 발생: 2026-05-26T03:21:43.090Z

Root Cause Summary#

이 latency는 단일 코드 버그가 아닌 복합적 인프라/아키텍처 이슈이다. 사용자가 프로젝트를 로드할 때 30+ 병렬 API 요청이 동시에 발생하며, ap-southeast-2 리전의 Rails 서버에서 thread pool이 포화 상태에 이르렀다. 실제 DB 쿼리(34ms)와 serialization(2ms)은 정상 범위이나, request queuing과 인증 중 UserFactory#update_user_groups! 실행이 약 1100ms의 지연을 유발했다. 24시간 내 slow request의 82% (27/33건)가 ap-southeast-2 리전에서 발생하여 리전별 인프라 용량 문제가 주요 원인으로 판단된다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/annotation_layers_controller.rb:15 (index action)
• Authentication/Provisioning: UserFactory#update_user_groups! — Cognito 인증 후 사용자 그룹 프로비저닝
• Query option parsing: lib/cupix/query_option/annotation_layer.rb — facility_key, review_key 파라미터 처리
• Repository search: app/repositories/annotation_layer_repository.rb:276 — Elasticsearch 쿼리 실행
• Permission joins: app/repositories/annotation_layer_repository.rb:62-259 — 12개 LEFT JOIN subquery
• Serialization: app/serializers/annotation_layer_serializer.rb — Redis cache 기반 association lookup

def default_joins(records)
  records
    .joins("LEFT JOIN levels ON levels.id = annotation_layers.level_id")
    .joins("LEFT JOIN reviews ON reviews.id = annotation_layers.review_id")
    .joins("LEFT JOIN facilities ON facilities.id = annotation_layers.facility_id")
    .select("annotation_layers.*, reviews.id as review_id, reviews.name as review_name, reviews.key as review_key, reviews.applied_cycle_state")
end

# permission_joins: 12 LEFT JOIN subqueries across 5 permission tables
# (review_permissions, annotation_layer_permissions, facility_permissions,
#  workspace_permissions, team_permissions) - each joined twice (user + group)
# GROUP BY on id, GREATEST/IFNULL on 12 permission columns

이 요청의 경우 4건의 annotation_layer만 반환되었으므로 permission JOIN과 serialization 비용은 미미했다. 실제 병목은 request queue 대기 시간이다.

Log Evidence#

Datadog에서 확인한 trace 로그:

service:cupixworks-api @trace_id:3018009494027224968

{
  "timestamp": "2026-05-26T03:21:44.240Z",
  "controller": "Api::V1::AnnotationLayersController#index",
  "path": "GET /api/v1/reviews/dlf1mp/annotation_layers",
  "status": 200,
  "duration": 1140.27,
  "db": 34.06,
  "serialization": 2,
  "view": 0.08,
  "pagination_total": 4,
  "user": "luke.champion@naylorlove.co.nz",
  "team": "naylorlove"
}

동일 trace에서 발생한 인증 관련 로그:

[2026-05-26T03:21:44.156Z] [INFO] UserFactory#update_user_groups! - Provisioned user 3619 to groups
[2026-05-26T03:21:44.156Z] [WARN] Group#_update_document - "NotFound - attributes_in_database"
[2026-05-26T03:21:44.156Z] [INFO] User 3619 added to group c36571bb-a1c9-4c51-968c-08e70cae2c23

24시간 내 slow request 패턴 분석 쿼리:

service:cupixworks-api resource_name:"Api::V1::AnnotationLayersController#index" @duration:>500ms

결과: 33건 중 27건(82%)이 ap-southeast-2에서 발생. 동일 시간대(03:21:42-44Z)에 같은 호스트에서 다른 엔드포인트(PointcloudsController, WorkareasController, WorkareaGroupsController)도 839-1052ms 지연 확인.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

현재 단일 건(1회)이므로 즉각적인 코드 수정은 불필요. 다만 ap-southeast-2 리전의 slow request 빈도(24시간 33건)를 모니터링하고, worker/thread pool 설정을 확인해야 한다.

• config/puma.rb (또는 해당 리전의 infra config) — thread/worker 수 확인 및 조정 검토
• 프론트엔드의 프로젝트 로드 시 병렬 API 호출 수를 제한하는 방안 검토 (request batching 또는 staggering)

단기 개선 (1주 이내)#

• UserFactory#update_user_groups!가 매 요청마다 실행되는지 확인하고, 이미 프로비저닝된 사용자에 대해 skip 로직 추가 검토
• Group#_update_document의 NotFound 경고 원인 조사 — Elasticsearch 인덱스 동기화 지연 가능성
• ap-southeast-2 리전의 Puma worker/thread 수를 다른 리전과 비교하여 under-provisioning 여부 확인

장기 개선 (재발 방지)#

• 프론트엔드에서 프로젝트 로드 시 critical-path API 호출과 non-critical 호출을 분리하여 순차적/우선순위 기반으로 요청
• permission_joins의 12 LEFT JOIN subquery를 materialized view 또는 캐시 기반으로 리팩토링하여 대량 record 시 성능 보장
• 리전별 auto-scaling 정책 검토 — burst traffic에 대한 scale-out 반응 속도 개선

Monitoring#

• Latency percentile 모니터링:

service:cupixworks-api resource_name:"Api::V1::AnnotationLayersController#index" @duration:>500ms

• 리전별 slow request 비율 알림: ap-southeast-2에서 5분 내 >500ms 요청이 10건 초과 시 alert
• Thread pool saturation: Puma thread pool 사용률 메트릭 (puma.pool_capacity, puma.backlog) 모니터링
• User provisioning 빈도: UserFactory#update_user_groups! 호출 빈도 및 소요 시간 추적

Risk Assessment#

• Risk level: low
• 예상 복잡도: standard (인프라 조정 + 인증 플로우 최적화)