RCA: Api::V1::BadgesController#index latency (12385ms)

Overview#

What Happened#

2026-07-30 21:06 KST 경 Api::V1::BadgesController#index 리소스에서 12.4초에 달하는 단일 latency trace 가 발생했다. 응답 자체는 200 OK 였고 오류가 아닌 latency 클러스터이며, 같은 시각 cupixworks-api 서비스 전반의 요청 지연이 baseline 대비 3~5배 상승한 자동 감지 인시던트(2026-07-30-svc-cupixworks-api--unknown-1, 21:23 KST 해소)의 일부다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-07-30 20:34 KST — 자동 인시던트 감지 시작 (svc:cupixworks-api::unknown, 첫 클러스터 9855766b) — status board started_at 참조.
2. 2026-07-30 21:05 KST — cupixworks-api 전반 avg request duration 이 baseline (0.3~0.7s) 에서 2s+ 로 상승 (Datadog trace.rack.request.duration).
3. 2026-07-30 21:06:40 KST — 본 클러스터에 해당하는 BadgesController#index 12.4s trace 발생 (first_seen).
4. 2026-07-30 21:23 KST — 인시던트 자동 해소 (resolved_at), latency 정상화.

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::BadgesController#index",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 12385,
  "max_ms": 12385,
  "sample_trace_id": "2692620878179662769"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 1
• 최초 발생: 2026-07-30 21:06 KST
• 최근 발생: 2026-07-30 21:06 KST

Root Cause Summary#

이 클러스터는 개별 코드 결함으로 인한 오류가 아니라, 해소된 서비스 전반 성능 저하 인시던트(2026-07-30-svc-cupixworks-api--unknown-1) 의 일부로 발생한 단발성 slow trace 다. 인시던트 창구(20:3421:23 KST) 동안 cupixworks-api 의 avg request duration 이 baseline 대비 35배 (약 0.30.7s → 2s+) 상승했고 요청 rate 도 23배 (약 2560 → 8095 req/s) 로 뛰어 컨테이너 request-handling 용량이 포화된 것으로 보인다. BadgesController#index 의 Elasticsearch _search 호출 자체는 5~30ms 수준으로 정상이었으므로, 지연은 (a) request queue / 스레드 대기, (b) BadgeRepository.permission_joins 의 무거운 다중 LEFT JOIN MySQL 쿼리가 부하 상승 시 병목이 된 것 중 하나 또는 조합일 가능성이 크다. 근본 원인은 badges 코드 자체가 아니며, 상위 인시던트의 원인(현재 root_cause_types: [unknown] 으로 미분류) 이 규명되어야 이 클러스터도 재발 방지된다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/badges_controller.rb:8 — BadgesController#index
• Search 실행: app/repositories/base_repository.rb:70 — BaseRepository#search
• Elasticsearch 호출: app/repositories/badge_repository.rb:124 — Badge.search(...).paginate(...)
• Permission JOIN (병목 후보): app/repositories/badge_repository.rb:33-88 — BadgeRepository.permission_joins

def index
  badge_query_option = Cupix::QueryOption::Badge.new(get_query_option, params)
  badges = repository_instance.search(badge_query_option)

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

BaseRepository#search 는 ES 검색 결과 record 들을 다시 MySQL 로 되돌려 permission JOIN 을 수행한다.

def search(query_option = nil)
  _search(query_option)

  begin
    if self.review.present?
      contents = self.class.permission_joins(self.class.default_joins(self.response.records), self.current_user, review_id: self.review.id, skip_join: _skip_join?)
    elsif self.review_id.present?
      contents = self.class.permission_joins(self.class.default_joins(self.response.records), self.current_user, review_id: self.review_id, skip_join: _skip_join?)
    elsif self.capture.present?
      contents = self.class.permission_joins(self.class.default_joins(self.response.records), self.current_user, capture_id: self.capture.id, skip_join: _skip_join?)
    else # = self.review_id.nil?
      contents = self.class.permission_joins(self.class.default_joins(self.response.records), self.current_user, skip_join: _skip_join?)
    end
  rescue Elasticsearch::Transport::Transport::Errors::BadRequest => e
    ...
  end

BadgeRepository.permission_joins 는 세 개의 서브쿼리를 LEFT JOIN 하고 GROUP BY id + MAX(GREATEST(...)) 로 권한을 계산한다. 정상 부하에서는 문제가 없지만, 서비스 전반이 포화되면 이 쿼리가 대기·경합의 큰 요인이 될 수 있다.

record.joins("
  LEFT JOIN (
    SELECT team_id, permission
    FROM team_permissions
    WHERE team_permissions.accessor_id = #{sanitized_user_id}
      AND team_permissions.accessor_type = 'User'
    ) AS team_user_permissions
      ON team_user_permissions.team_id = badges.team_id

  LEFT JOIN (
    SELECT team_id, permission
    FROM team_permissions
      LEFT JOIN grouped_users
        ON grouped_users.group_id = team_permissions.accessor_id
        AND grouped_users.user_id = #{sanitized_user_id}
    WHERE team_permissions.accessor_type = 'Group'
      AND grouped_users.user_id = #{sanitized_user_id}
    ) AS team_group_permissions
    ON team_group_permissions.team_id = badges.team_id
  ...
").group('id').select(_select).where("
  GREATEST(
    IFNULL(team_user_permissions.permission, 0),
    IFNULL(team_group_permissions.permission, 0),
    IFNULL(team_system_group_permissions.permission, 0)
  ) > 0
")

기대 동작: search 는 baseline 수백 ms 이내에 응답한다. 실제 동작: 인시던트 창구에서만 단일 요청이 12.4s 걸림. 같은 시각 badges _search ES metric 은 정상 수준이었으므로, 지연은 controller 진입 지점 이후 Ruby/Rack/MySQL 경로에서 발생한 것으로 판단됨.

Log Evidence#

같은 시각 BadgesController#index 요청 상태 (모두 200):

Datadog query:

service:cupixworks-api "BadgesController"

{ "timestamp": "2026-07-30 21:06:52", "status": "info", "message": "[200] GET /api/v1/badges (Api::V1::BadgesController#index)" }
{ "timestamp": "2026-07-30 21:06:52", "status": "info", "message": "[200] GET /api/v1/reviews/ha5r7z/badges (Api::V1::BadgesController#index)" }
{ "timestamp": "2026-07-30 21:07:11", "status": "info", "message": "[200] GET /api/v1/badges (Api::V1::BadgesController#index)" }

응답 코드는 모두 200 — 오류 없이 latency 만 튐. cluster_type=latency 와 일치.

서비스 전반 avg request duration (3h 기준 timeseries):

Datadog query:

avg:trace.rack.request.duration{service:cupixworks-api}

Baseline (19:0020:30 KST) 은 0.30.7s, 인시던트 창구(20:3421:23 KST) 에서 최고 2.5s 수준까지 상승. 예:

... 0.428, 0.710, 0.901, 0.818, ... (baseline)
... 2.023, 2.305, 1.770, 1.161, 1.166, 1.061, 0.906, 0.818, 1.242,
    1.718, 1.924, 1.758, 2.190, 2.262, 2.145, 2.367, 2.575, ...

요청 rate 상승 (동일 창구):

Datadog query:

sum:trace.rack.request.hits{service:cupixworks-api}.as_rate()

29.45, 30.81, 62.08, 82.40, 79.86, 77.03, 60.46, 57.90, 44.38, ...

Baseline 2560 req/s → 인시던트 창구 8095 req/s 로 상승 (2~3x).

Elasticsearch get_badges/_search latency 는 정상:

Datadog query:

avg:trace.elasticsearch.query.duration{service:cupixworks-api,resource_name:get_badges/_search}

0.005, 0.006, 0.006, 0.005, ... 0.015, 0.017, 0.011 (인시던트 창구 최고치)

ES badges 검색 자체는 5~30ms 수준으로 12s 지연을 설명할 수 없음 → 병목은 ES 가 아님.

Status board 컨텍스트:

$ bun run cli/incident-board.ts for-cluster 1feaf5c5-af3f-4902-96a8-537a72bd4d9e

{
  "scope": "svc:cupixworks-api::unknown",
  "active": null,
  "recent": [{
    "id": "2026-07-30-svc-cupixworks-api--unknown-1",
    "title": "cupixworks-api service degraded",
    "status": "resolved",
    "started_at": "2026-07-30T11:34:05.124Z",
    "resolved_at": "2026-07-30T12:23:30.350Z",
    "cluster_ids": [
      "9855766b-3975-47ac-9d01-4984a543fba9",
      "e758e925-3b09-4acf-bb97-4468f619239e",
      "dfa0ed54-7545-4c81-8023-e7def3db3669",
      "1feaf5c5-af3f-4902-96a8-537a72bd4d9e",
      "da6d4c75-28f5-4ac7-a8a1-721df2ead8c3"
    ]
  }]
}

이 클러스터를 포함한 5개의 latency 클러스터가 ~50분 창구에 몰려 발생 후 자동 해소됨.

동시각 발생한 service_jwt 에러(Cupix::PubSub::Subscribers::UserRecipeGenerator) 는 별도 코드 경로이며 BadgesController 와 무관 (uncertain — needs verification 여부는 별도 클러스터에서 다룸).

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 단일 이벤트이며 이미 해소된 상위 인시던트(2026-07-30-svc-cupixworks-api--unknown-1) 의 일부이므로 이 클러스터 단독으로 즉시 코드 수정은 불필요.
• 재발 감지를 위해 status board 및 아래 Monitoring 섹션 쿼리로 관찰 계속.

단기 개선 (1주 이내)#

• trace_id:2692620878179662769 의 APM flame graph 를 확인하여 12s 가 어느 span (rack queue / mysql / permission_joins 개별 sub-select / 기타) 에 실제로 분포되어 있는지 규명. Datadog APM trace 링크가 클러스터 상단 URL 에 그대로 존재.
• 같은 창구에 묶인 다른 4개 latency 클러스터 (9855766b, e758e925, dfa0ed54, da6d4c75) 의 resource_name 을 교차 확인하여 특정 endpoint 계열에 편중되었는지 아니면 API 전반인지 파악 — 편중되면 해당 endpoint 최적화, 아니면 인프라(스레드/컨테이너/DB 커넥션 풀) 튜닝 방향.
• BadgeRepository.permission_joins 는 요청마다 사용자 permission 을 SQL 로 재계산한다. app/repositories/badge_repository.rb:33-88 에서 3개 서브쿼리 LEFT JOIN 이 있으므로, 부하 시 이 쿼리가 슬로우 로그에 나타나는지 별도로 슬로우 쿼리 로그를 확인.

장기 개선 (재발 방지)#

• 서비스 전반의 부하 급증 시 자동 감지·알림을 강화. 현재 svc:*::unknown 스코프로만 자동 그룹핑되고 있어 root_cause 가 미분류 상태 (root_cause_types: [unknown]). request rate + duration 상관 알림을 별도로 구성해 부하 급증 시나리오를 별도 스코프로 분리.
• permission_joins 계열 무거운 권한 계산을 캐시하거나 (per-user permission cache), DB 인덱스 검토 (team_permissions.accessor_id, team_permissions.team_id, grouped_users.user_id/group_id).
• Puma / 컨테이너 동시성 metric (worker/thread busy, queued requests) 을 Datadog 로 노출해 (현재 puma 계열 metric 이 검색되지 않음) 다음 유사 인시던트에서 request queue 병목을 즉시 확인 가능하도록 계측.

Monitoring#

Datadog 쿼리 예시:

avg:trace.rack.request.duration{service:cupixworks-api}

sum:trace.rack.request.hits{service:cupixworks-api}.as_rate()

avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::badgescontroller#index}

avg:trace.elasticsearch.query.duration{service:cupixworks-api,resource_name:get_badges/_search}

각 쿼리 모두 timeseries widget 에 그대로 삽입 가능. count by(...) / | stats 같은 monitor-only 문법은 사용하지 않음.

Risk Assessment#

• Risk level: low — 단일 latency 이벤트, 이미 해소, 오류 아님 (200 응답).
• 예상 복잡도: trivial (이 클러스터 단독 관점). 상위 인시던트 원인 규명은 별도로 추적 필요.