Api::V1::AnnotationsController#index (avg 1235ms, max 1432ms)
RCA: Api::V1::AnnotationsController#index Latency (avg 1235ms)
Overview#
What Happened#
2026-05-26 06:57~12:03 UTC 사이에 cupixworks-api 서비스의 Api::V1::AnnotationsController#index 엔드포인트에서 평균 1235ms, 최대 1432ms의 응답 지연이 25건 발생했다. 주로 eu-central-1과 ap-southeast-2 리전에서 review 범위 annotation 목록 조회 시 발생하며, DB 시간(33-46ms)과 serialization 시간(222-290ms)은 정상이나 permission JOIN 처리에서 700-1130ms의 "other" 시간이 소요되었다.
Quick Facts#
| Field | Value |
|---|---|
| resource_name | Api::V1::AnnotationsController#index |
| top_frame | app/repositories/annotation_repository.rb:60-304 |
| env | production (eu-central-1, ap-southeast-2) |
Affected Teams#
| Team / Domain | Error Count | Impact |
|---|---|---|
| repsol (eu-central-1) | 44 | Review annotation 목록 로딩 1.2-1.4초 지연 |
| byuk (eu-central-1) | 3 | Annotation 조회 지연 |
| forida-demo (ap-southeast-2) | 2 | 동일 지연 패턴 |
| bv-th (ap-southeast-2) | 1 | 동일 지연 패턴 |
Timeline#
- 2026-05-26T06:57:25Z — ap-southeast-2에서 최초 latency 발생 (forida-demo team)
- 2026-05-26T07:02Z~12:03Z — eu-central-1에서 반복 발생 (주로 repsol team)
- 2026-05-26T12:03:49Z — 마지막 관측된 slow trace
- 2026-05-26T13:26Z — RCA 분석 시작
Error Log#
{
"resource_name": "Api::V1::AnnotationsController#index",
"service": "cupixworks-api",
"occurrences": 25,
"avg_ms": 1235,
"max_ms": 1432,
"sample_trace_id": "797339765482690562"
}
Impact#
- Service:
cupixworks-api - 발생 횟수: 25
- 최초 발생: 2026-05-26T06:57:25.971Z
- 최근 발생: 2026-05-26T12:03:49.267Z
Root Cause Summary#
AnnotationsController#index는 Elasticsearch 검색 후 결과에 대해 14개 LEFT JOIN으로 구성된 permission_joins 쿼리를 실행한다. 이 permission JOIN은 review_permissions, annotation_permissions, annotation_layer_permissions, facility_permissions, workspace_permissions, team_permissions 6개 테이블에 대해 user/group 각각 조회하며, 결과를 GROUP BY id로 집계한다. total_entries가 1259~3309건인 대규모 review에서 이 JOIN이 Elasticsearch가 반환한 ID 목록 전체에 대해 수행되어, DB 쿼리 외의 ActiveRecord 객체 구성과 JOIN 결과 처리에서 700-1130ms가 소요된다.
Technical Analysis#
Code Path#
- Entry point:
app/controllers/api/v1/annotations_controller.rb:16-25 - Elasticsearch 검색:
app/repositories/annotation_repository.rb:345-436(_searchmethod) - Permission JOIN 적용:
app/repositories/base_repository.rb:70-112(searchmethod) - Permission JOIN 정의:
app/repositories/annotation_repository.rb:80-305(permission_joins) - Default JOIN:
app/repositories/annotation_repository.rb:60-69(default_joins)
1. Controller에서 repository search 호출:
def index
annotation_query_option = Cupix::QueryOption::Annotation.new(get_query_option, params)
annotations = repository_instance.search(annotation_query_option)
render_api Renderable.new({
search_result: annotations,
is_collection: true,
serializer_option: @serializer_option
})
end
2. BaseRepository#search — Elasticsearch 결과에 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?)
else
contents = self.class.permission_joins(self.class.default_joins(self.response.records), self.current_user, skip_join: _skip_join?)
end
여기서 self.response.records는 Elasticsearch가 반환한 현재 page의 record ID 목록으로, per_page (기본 30, 최대 300) 개의 레코드에 대해 JOIN을 수행한다.
3. default_joins — storage, facility, form_design, captures를 JOIN:
def self.default_joins(record)
record.includes(:storage).left_outer_joins(:facility, :form_design).joins("
LEFT OUTER JOIN captures ON annotations.annotatable_id = captures.id AND annotations.annotatable_type = 'CAPTURE'
").select("
annotations.*,
form_designs.description AS form_design_description,
form_designs.name AS form_design_name,
form_designs.icon as form_design_icon,
facilities.cycle_state AS applied_cycle_state
").where("captures.trashed_at": nil)
end
4. permission_joins — 14개 LEFT JOIN으로 권한 필터링 (핵심 병목):
def self.permission_joins(record, current_user, select: nil, review_id: -1, **kwargs)
# ... 14개 permission 테이블에서 SELECT + LEFT JOIN
# review_user_permissions, review_group_permissions,
# annotation_user_permissions, annotation_group_permissions,
# annotation_layer_user_permissions, annotation_layer_group_permissions,
# facility_user_permissions, facility_group_permissions,
# facility_system_group_permissions,
# workspace_user_permissions, workspace_group_permissions,
# team_user_permissions, team_group_permissions,
# team_system_group_permissions
record.joins("...14 LEFT JOINs...")
.group('id')
.select(_select)
.where("GREATEST(...) conditions")
end
5. _skip_join?은 Annotation에 대해 false를 반환:
def _skip_join?
return false if search_public_accessed?
[::Pano, ::Element, ::ElementTrace, ::Bookmark].include?(self.class.current_class) ||
search_own_model?
end
::Annotation이 skip 목록에 없으므로, 모든 annotation 검색에서 permission_joins가 실행된다.
Log Evidence#
APM 메트릭 쿼리로 확인한 duration 분포:
avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::annotationscontroller_index}
시간대별 duration 분포 (초 단위, 6시간):
- 최저: 0.048s (정상 응답)
- 빈번한 피크: 0.9-2.0s (permission JOIN 병목)
- 최대 스파이크: 4.055s (극단적 케이스)
- 평균 분포: ~50%가 0.5s 이상
Datadog APM trace에서 확인된 시간 분해:
# 대규모 review (total_entries: 1259-3309)
Total: 1311-1426ms
├── DB: 33-46ms (정상)
├── Serialization: 222-290ms (fields 49개)
└── Other (permission JOIN + AR object construction): 700-1130ms ← 병목
# 소규모 응답 (total_entries: 0-3)
Total: 56-152ms (정상)
├── DB: 11-25ms
├── Serialization: 0-31ms
└── Other: minimal
# 간헐적 zero-entry 지연
Total: 1021-1062ms
├── DB: 18ms
├── Serialization: 0ms
└── Other: ~1000ms ← 인증 토큰 검증 or cold permission join
Hypotheses Considered#
| # | Hypothesis | Evidence for | Evidence against | Verdict |
|---|---|---|---|---|
| H1 | Permission JOIN의 14개 LEFT JOIN이 대량 레코드에서 병목 | APM에서 DB=33-46ms인데 total=1235ms, "other" 시간이 700-1130ms. permission_joins가 6개 permission 테이블 × user/group JOIN + GROUP BY + GREATEST 연산 수행. _skip_join?이 Annotation에 false 반환 (annotation_repository.rb:80-305) |
— | Confirmed |
| H2 | N+1 쿼리 패턴 (serializer에서 연관 모델 개별 로딩) | Serializer가 _user, _team, _facility 등 연관 속성을 참조하며, default_joins에 includes(:storage)만 존재 |
Datadog에서 N+1 경고 0건, DB 시간이 33-46ms로 낮음 (N+1이면 DB가 높아야 함) | Rejected |
| H3 | Elasticsearch 쿼리 자체의 지연 | — | DB 시간(ES + MySQL 합산)이 33-46ms로 정상, ES circuit breaker 에러 없음 | Rejected |
| H4 | 인증 토큰 검증 (Cognito/Firebase) 간헐적 지연 | Zero-entry 요청에서도 1000ms+ 지연 발생 (db=18ms, serialization=0ms) | 대부분의 slow 요청은 대량 데이터와 상관관계가 있으며, 인증 지연은 소수 케이스 | Inconclusive |
Fix Recommendation#
즉시 조치 (Critical)#
app/repositories/annotation_repository.rb:80-305—permission_joins메서드에서 review 컨텍스트가 있을 때 불필요한 team/workspace 레벨 permission JOIN을 제거하거나, review permission이 이미 확인된 경우 하위 permission 체크를 생략하는 조건 분기 추가app/repositories/base_repository.rb:394-398—_skip_join?에서 review 컨텍스트 내 annotation 검색 시skip_join: true를 반환하도록 조건 추가 검토 (review permission이 이미 상위에서 확인되므로)
단기 개선 (1주 이내)#
permission_joins의 14개 서브쿼리를 단일 CTE(Common Table Expression) 또는 materialized view로 리팩터링하여 JOIN 횟수를 줄임- Review 범위 검색 시
annotation_layer_ids가 이미 제한되므로, permission 체크를 review-level만으로 단순화하는 별도review_permission_joins메서드 도입 default_joins의 captures LEFT JOIN에 대한 DB index 확인 (annotations.annotatable_id+annotatable_type복합 인덱스는 존재하나, captures 테이블의trashed_at필터 포함 인덱스 확인 필요)
장기 개선 (재발 방지)#
- Permission 체크를 DB JOIN 방식에서 Redis 기반 permission cache로 전환 — 이미
Cachable모듈이 존재하므로 permission 결과도 캐시 가능 - Elasticsearch 결과에 permission 정보를 인덱싱하여 DB JOIN 없이 필터링할 수 있는 구조 도입
per_page기본값 30이지만,total_entries계산이 전체 레코드에 대한 COUNT를 수행하므로 — review 내 annotation이 3000건 이상인 경우를 위한 근사 카운트 도입 검토
Monitoring#
- APM p95 duration alert:
avg(last_5m):p95:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::annotationscontroller_index} > 1.5 - Permission JOIN 시간 분리 측정을 위한 custom instrumentation 추가:
avg:trace.mysql2.query.duration{service:cupixworks-api,resource_name:annotationscontroller_index} by {query_type}
Risk Assessment#
- Risk level: medium
- 예상 복잡도: standard — permission_joins 리팩터링은 기존 권한 로직에 영향을 줄 수 있어 충분한 테스트 필요