RCA: Api::V1::SearchesController#counts High Latency (avg 2997ms, max 4329ms)

Overview#

What Happened#

2026-05-26 04:56~13:08 UTC 동안 cupixworks-api의 Api::V1::SearchesController#counts 엔드포인트에서 평균 2997ms, 최대 4329ms의 높은 응답 지연이 ap-southeast-2, us-west-2, eu-central-1 세 리전에서 14건 발생했다. 모든 요청은 HTTP 200으로 정상 응답했으나 사용자 체감 성능이 크게 저하되었다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-05-26T04:56:42Z — 최초 고지연 요청 감지
2. 2026-05-26T05:14:17Z — 최대 지연(4329ms) 발생 (admin 팀, state:"holding" 필터)
3. 2026-05-26T13:08:04Z — 마지막 고지연 요청 기록
4. 2026-05-27 — RCA 분석 완료

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::SearchesController#counts",
  "service": "cupixworks-api",
  "occurrences": 4,
  "avg_ms": 2652,
  "max_ms": 4329,
  "sample_trace_id": "3914089223142541906"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 14
• 최초 발생: 2026-05-26T04:56:42.761Z
• 최근 발생: 2026-05-26T13:08:04.418Z
• 영향: 검색 카운트 API 응답 지연으로 UI 검색 결과 패널의 카운트 뱃지 로딩이 3~4초 이상 소요. 대규모 데이터셋을 가진 팀(admin, nestle, performance, voith, tpc, graymont)의 사용자가 영향을 받음.

Root Cause Summary#

SearchesController#counts 액션이 10개 엔티티 타입(Workspace, Facility, Record, Report, Review, Capture, Bim, Pointcloud, Room, RealityCapture)에 대해 순차적으로 개별 Elasticsearch 검색을 수행한다. 각 검색은 Elasticsearch 쿼리 실행 후 total_entries만 반환하지만, 10개 쿼리가 직렬로 실행되어 각 쿼리의 지연이 누적된다. 대규모 팀에서는 Elasticsearch 쿼리 자체의 지연(permission 필터의 복잡한 terms 쿼리)과 DB 시간(permission JOIN)이 결합되어 총 응답 시간이 3~4초에 달한다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/searches_controller.rb:4 — counts 액션 시작
• 10개의 Repository가 순차적으로 total_entries(query_option) 호출
• 각 Repository는 _search(query_option) 실행 → Elasticsearch 검색
• Elasticsearch 결과의 total_entries만 반환

def counts
  workspace_count = WorkspaceRepository.new(current_user: current_user, current_team: @current_team).total_entries(
    Cupix::QueryOption::Workspace.new(get_query_option, params)
  )
  facility_count = FacilityRepository.new(current_user: current_user, current_team: @current_team).total_entries(
    Cupix::QueryOption::Facility.new(get_query_option, params)
  )
  # ... 8개 더 (record, report, review, capture, bim, pointcloud, room, reality_capture)

  render_json 200, {
    workspace_count: workspace_count,
    facility_count: facility_count,
    # ...
  }
end

total_entries 메서드는 _search를 호출하여 전체 Elasticsearch 쿼리를 실행한 뒤 카운트만 반환한다:

def total_entries(query_option = nil)
  _search(query_option) if query_option.present?
  return nil if self.response.nil?

  self.response.total_entries
end

각 Repository의 _search는 복잡한 permission 필터를 Elasticsearch 쿼리에 추가한 후 전체 검색을 실행한다:

response = ::Facility.search(
  self.query_option.serializable_hash
).paginate(
  per_page: self.query_option.per_page,
  page: self.query_option.page
)

set_response(response)

핵심 문제: total_entries만 필요하지만 .paginate()까지 포함한 전체 검색이 실행된다. 또한 10개 쿼리가 순차 실행되어 각 쿼리의 지연이 합산된다.

• Failure point: 특정 코드 실패는 없음. 구조적으로 순차 실행 + 불필요한 pagination이 지연의 원인.

Log Evidence#

Datadog APM 트레이스에서 확인한 지연 패턴:

service:cupixworks-api resource_name:"Api::V1::SearchesController#counts" env:production @duration:>500ms

Pattern A: DB-bound 고지연 (대규모 팀)

{
  "timestamp": "2026-05-26T05:14:17Z",
  "duration_ms": 4328,
  "db_ms": 2460,
  "team_domain": "admin",
  "params": {"state": "holding"},
  "host": "ip-10-1-19-190.us-west-2.compute.internal"
}

{
  "timestamp": "2026-05-26T11:45:31Z",
  "duration_ms": 3507,
  "db_ms": 2369,
  "team_domain": "performance",
  "params": {"q": "new albany"}
}

Pattern B: Elasticsearch-bound 고지연 (voith 팀)

{
  "timestamp": "2026-05-26T06:42:00Z",
  "duration_ms": 3931,
  "db_ms": 349,
  "team_domain": "voith",
  "params": {"q": "palm"}
}

DB 시간이 349ms에 불과하지만 총 응답 3931ms → 나머지 ~3500ms가 Elasticsearch 검색 시간. 10개 쿼리를 순차 실행하면 각 쿼리당 ~350ms의 ES 지연도 누적됨.

Pattern C: 빠른 응답 (소규모 팀)

{
  "timestamp": "2026-05-26T06:49:33Z",
  "duration_ms": 177,
  "db_ms": 3,
  "team_domain": "sinsw",
  "params": {"q": "central mangrove"}
}

소규모 팀(sinsw)은 170~200ms로 정상 응답 — 데이터셋 크기가 핵심 변수임을 확인.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• app/controllers/api/v1/searches_controller.rb:4-35 — 10개의 total_entries 호출을 병렬 실행으로 전환. Ruby의 Concurrent::Future 또는 Parallel gem을 사용하여 10개 Elasticsearch 쿼리를 동시에 실행하면 총 응답 시간이 가장 느린 단일 쿼리 시간으로 줄어든다.
• app/repositories/base_repository.rb:114-119 — total_entries 전용 경로를 추가하여 Elasticsearch의 _count API를 사용. 현재 .search().paginate()로 전체 검색 후 count만 추출하는 방식을 Model.search(..., size: 0)으로 변경하여 document fetch를 생략.

단기 개선 (1주 이내)#

• Elasticsearch 쿼리에 size: 0과 track_total_hits: true 옵션을 적용하여 카운트 전용 쿼리로 최적화. 현재 paginate로 실제 문서까지 조회하는 것은 불필요.
• 대규모 팀(admin, nestle, performance)에 대한 카운트 결과를 Redis에 30~60초 TTL로 캐싱. 동일 검색어에 대한 반복 요청 시 Elasticsearch 부하 감소.

장기 개선 (재발 방지)#

• 각 엔티티의 permission 필터를 Elasticsearch 인덱스에 사전 계산(denormalize)하여 복잡한 terms 쿼리 제거. 현재 readable_workspace_ids, directly_accessible_facility_ids 등을 매 요청마다 조회하여 ES 쿼리에 주입하는 패턴이 대규모 팀에서 쿼리 복잡도를 증가시킨다.
• Multi-search API(_msearch)를 활용하여 10개 쿼리를 단일 HTTP 요청으로 배치 실행.

Monitoring#

• APM 모니터: avg(trace.duration) by resource_name where resource_name:Api::V1::SearchesController#counts > 2000ms
• Datadog 쿼리 예시:

service:cupixworks-api resource_name:"Api::V1::SearchesController#counts" @duration:>2000ms

• Elasticsearch slow query log 활성화하여 개별 ES 쿼리 지연 추적
• 팀별 카운트 응답 시간 P95 대시보드 추가

Risk Assessment#

• Risk level: medium
• 예상 복잡도: standard — 병렬화 변경은 기존 로직을 크게 수정하지 않으며, thread safety 검증이 필요하지만 각 Repository 인스턴스가 독립적이므로 안전한 병렬화가 가능하다.