Api::V1::UsersController#index (avg 1033ms, max 1033ms)

RCA: Api::V1::UsersController#index Latency (1033ms)

Overview#

What Happened#

2026-05-26 10:06:55 UTC에 cupixworks-api의 Api::V1::UsersController#index 엔드포인트가 1033ms 응답 시간을 기록했다. 500ms SLO를 초과하는 latency 이슈로, 동일 시간대에 Team 133 (439명 사용자)에 대한 요청에서 반복적으로 발생했다.

Quick Facts#

Field	Value
resource_name	`Api::V1::UsersController#index`
top_frame	`app/repositories/user_repository.rb:210-265`
env	production, us-west-2
avg_duration	1033ms
db_time	736ms (71% of total)

Timeline#

2026-05-26T09:13:19Z — Team 133 대상 다수 동시 요청 시작 (thundering herd, 9초간 13건)
2026-05-26T10:06:55Z — 대표 트레이스 기록 (1033ms)
2026-05-27 — RCA 완료

Error Log#

Datadog Logs

json

{
  "resource_name": "Api::V1::UsersController#index",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 1033,
  "max_ms": 1033,
  "sample_trace_id": "1199124425035914742"
}

Impact#

Service: cupixworks-api
발생 횟수: 1 (500ms 초과 건은 동일 시간대 14건)
최초 발생: 2026-05-26T10:06:55.417Z
최근 발생: 2026-05-26T10:06:55.417Z
영향 범위: Team 133 관리자 (chris.choi@cupix.com) — 사용자 목록 조회 지연

Root Cause Summary#

UsersController#index의 permission_joins 메서드가 3개의 LEFT OUTER JOIN과 GROUP BY를 포함한 복잡한 SQL 쿼리를 실행하여, 439명 규모의 대형 팀에서 DB 시간이 736ms(전체의 71%)를 차지한다. per_page=300이라는 높은 페이지 크기와 결합되어 단일 요청에서 300개 레코드에 대한 permission 계산이 수행되며, 이것이 1033ms latency의 주된 원인이다.

Technical Analysis#

Code Path#

Entry point: app/controllers/api/v1/users_controller.rb:15-24
Permission joins: app/repositories/user_repository.rb:210-265
Default joins: app/repositories/user_repository.rb:206-208
Serializer: app/serializers/user_serializer.rb:1-55

1. Controller index action:

app/controllers/api/v1/users_controller.rb:15-24ruby

def index
  user_query_option = Cupix::QueryOption::User.new(get_query_option, params)
  users = repository_instance.search(user_query_option)

  render_api Renderable.new({
    search_result: users,
    is_collection: true,
    serializer_option: @serializer_option
  })
end

2. Repository search — permission_joins 실행:

app/repositories/base_repository.rb:70-81ruby

def search(query_option = nil)
  _search(query_option)

  contents = self.class.permission_joins(
    self.class.default_joins(self.response.records),
    self.current_user,
    skip_join: _skip_join?
  )
  # ...
end

3. Permission joins — 3중 LEFT OUTER JOIN (병목 지점):

app/repositories/user_repository.rb:210-265ruby

def self.permission_joins(record, current_user, select: nil, **kwargs)
  # 3개의 LEFT OUTER JOIN 서브쿼리:
  # 1. team_permissions (직접 사용자 권한)
  # 2. team_permissions + grouped_users (그룹 권한)
  # 3. system-wide grouped user permissions
  # + GROUP BY id + permission aggregation
  record.joins("
    LEFT JOIN (SELECT team_id, permission FROM team_permissions
      WHERE team_permissions.accessor_id = #{sanitized_user_id} ...)
    LEFT JOIN (SELECT team_id, permission FROM team_permissions
      LEFT JOIN grouped_users ...)
    LEFT JOIN (SELECT team_id, permission FROM team_permissions
      LEFT JOIN grouped_users WHERE team_permissions.team_id IS NULL ...)
  ").group('id').select(_select).where("GREATEST(...) > 0")
end

기대 동작: 사용자 목록을 빠르게 반환 (200ms 이내) 실제 동작: 439명 팀에서 300건 per_page로 permission JOIN 실행 시 DB 쿼리만 736ms 소요

4. Default joins — eager load:

app/repositories/user_repository.rb:206-208ruby

def self.default_joins(record)
  record.eager_load(:team, :sales_info)
end

Log Evidence#

사용한 Datadog 쿼리:

text

service:cupixworks-api "UsersController#index" @duration:>500
Time: 2026-05-26 09:00-11:00 UTC

대표 로그 항목 (1033ms 트레이스와 일치):

text

2026-05-26T10:06:57.562Z
duration: 1030.95ms | db: 736.37ms | serialization: 12ms | view: 0.09ms
pagination: { per_page: 300, total_pages: 2, total_entries: 439, current_page: 1 }
host: ip-10-1-19-190.us-west-2.compute.internal
request_id: 7ef722c9-7e4a-4c62-9fde-cad4d8b14f58
params: { per_page: "300", page: "1", fields: ["id","email","firstname","lastname","state","editor_level","meta","team"] }

Thundering herd 패턴 (09:13 UTC, 9초간 13건):

text

2026-05-26T09:13:19.687Z | dur=1077.54ms | db=913.16ms
2026-05-26T09:13:22.303Z | dur=868.20ms  | db=745.00ms
2026-05-26T09:13:23.301Z | dur=1076.01ms | db=826.67ms
2026-05-26T09:13:23.694Z | dur=1271.30ms | db=902.99ms
2026-05-26T09:13:25.699Z | dur=1211.68ms | db=1045.45ms

비교 — 소규모 팀 (Team 1, 306명) 동일 시간대:

text

2026-05-26T10:06:57.680Z | dur=158.9ms | db=72.6ms | entries=306
2026-05-26T10:06:56.822Z | dur=151.1ms | db=31.3ms | entries=312

Hypotheses Considered#

#	Hypothesis	Evidence for	Evidence against	Verdict
H1	permission_joins의 3중 LEFT OUTER JOIN이 대형 팀(439명)에서 DB 시간 폭증	DB 시간 736-1045ms (전체의 70-85%), 소규모 팀은 31-72ms, `user_repository.rb:210-265`	—	Confirmed
H2	N+1 쿼리 또는 serializer의 lazy loading 문제	serializer가 10+ attribute 포함	serialization 시간 12-56ms로 전체의 2-5%에 불과, Bullet 경고 없음, eager_load 적용됨	Rejected
H3	Elasticsearch 쿼리 자체의 지연	ES 쿼리도 실행됨	DB 시간이 전체의 71-85%로 주된 병목은 SQL 쪽, ES는 별도 분리 가능	Rejected
H4	per_page=300이 과도하게 높아 처리량 증가	300건 로드 시 1033ms, 139건(page 2)은 530ms	per_page 자체보다 permission JOIN의 복잡도가 레코드 수에 비례하여 증가하는 것이 핵심	Contributing

Fix Recommendation#

즉시 조치 (Critical)#

app/repositories/user_repository.rb:210-265 — permission_joins 쿼리에 데이터베이스 인덱스 확인 및 추가. team_permissions 테이블의 (accessor_id, team_id, permission) 복합 인덱스와 grouped_users JOIN 조건에 대한 인덱스가 필요할 수 있음.
클라이언트 측에서 per_page=300 대신 적절한 값(50-100)으로 제한하거나, 서버에서 최대 per_page를 제한하는 가드 추가.

단기 개선 (1주 이내)#

permission 결과를 캐싱하여 동일 사용자의 반복 요청 시 DB 부하 감소. Redis 캐시에 팀별 permission 매핑을 저장하고 TTL 설정.
permission_joins의 3개 서브쿼리를 단일 CTE(Common Table Expression)로 리팩토링하여 DB 실행 계획 최적화.

장기 개선 (재발 방지)#

Permission을 비정규화된 컬럼 또는 materialized view로 분리하여 매 요청마다 JOIN 계산을 수행하지 않도록 아키텍처 변경.
대형 팀에 대한 사용자 목록 API를 cursor-based pagination으로 전환하여 일관된 응답 시간 보장.

Monitoring#

UsersController#index p95 latency 모니터 추가 (threshold: 500ms)
Team 규모별 응답 시간 추적 메트릭

text

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

Risk Assessment#

Risk level: low
예상 복잡도: standard — 기능 동작에는 이상 없으며 latency 최적화 이슈. 사용자 경험에 영향을 주지만 데이터 손실이나 에러는 없음.