Api::V1::AnnotationsController#create (avg 2281ms, max 3421ms)
RCA: Api::V1::AnnotationsController#create Latency (avg 2281ms, max 3421ms)
Overview#
What Happened#
2026-05-26 08:28~12:10 UTC 사이에 eu-central-1 리전의 cupixworks-api 서비스에서 AnnotationsController#create 요청이 평균 2281ms, 최대 3421ms의 응답 시간을 기록했다. 전체 요청 시간의 75-82%가 DB 쿼리 시간이며, 특정 review(zao9w4, ubdy79)에서 가장 심각한 지연이 발생했다. 모든 요청은 HTTP 200으로 성공 응답했으나, 사용자 체감 성능이 크게 저하되었다.
Quick Facts#
| Field | Value |
|---|---|
| resource_name | Api::V1::AnnotationsController#create |
| top_frame | app/repositories/annotation_layer_repository.rb:62-258 (permission_joins) |
| env | production, eu-central-1 |
| avg_duration | 2281ms |
| max_duration | 3421ms (review zao9w4), 4825ms (review ubdy79 outlier) |
Affected Teams#
| Team / Domain | Error Count | Impact |
|---|---|---|
| repsol (team_id: 102) | 6+ (50+ slow requests total) | Annotation 생성 시 2-5초 대기, 사용자 생산성 저하 |
Timeline#
- 2026-05-26 08:28 UTC — 최초 slow request 감지 (1763ms, review
emlkv5) - 2026-05-26 08:51 UTC — 최악의 케이스 발생 (4825ms, review
ubdy79) - 2026-05-26 12:10 UTC — 마지막 감지된 slow request (1935ms)
- 2026-05-26 — RCA 분석 수행
Error Log#
{
"resource_name": "Api::V1::AnnotationsController#create",
"service": "cupixworks-api",
"occurrences": 6,
"avg_ms": 2281,
"max_ms": 3421,
"sample_trace_id": "993609889660661642"
}
Impact#
- Service:
cupixworks-api - 발생 횟수: 6 (threshold 초과 건수), 실제 >1000ms slow request 50건
- 최초 발생: 2026-05-26T08:28:04.707Z
- 최근 발생: 2026-05-26T12:10:00.422Z
Root Cause Summary#
AnnotationsController#create의 latency는 AnnotationLayerRepository.permission_joins에서 수행되는 12개 LEFT JOIN을 포함한 복합 permission 쿼리가 원인이다. Annotation 생성 시 AnnotationLayerRepository.show()가 두 번 호출되어(factory에서 1회, set_parameters에서 1회) 동일한 heavy permission query가 중복 실행된다. 특히 repsol 팀(team_id: 102)의 review zao9w4, ubdy79는 permission 테이블의 데이터가 많아 JOIN 비용이 높으며, DB 시간이 전체 요청 시간의 75-82%를 차지한다.
Technical Analysis#
Code Path#
- Entry point:
app/controllers/api/v1/annotations_controller.rb:27 - Factory 호출:
app/factories/annotation_factory.rb:12— 첫 번째AnnotationLayerRepository.show()호출 - Parameter 설정:
app/concerns/parameter/annotation.rb:18— 두 번째AnnotationLayerRepository.show()호출 (중복) - Permission 쿼리 실행:
app/repositories/base_repository.rb:337→app/repositories/annotation_layer_repository.rb:62-258 - Event 생성:
app/models/concerns/eventable/callbacks.rb:31—after_create콜백에서 Event INSERT
1단계: Controller → Factory
def create
@model = factory_instance.create!(params)
super
end
2단계: Factory에서 AnnotationLayer를 permission_joins로 조회 (1차)
self.model = ::Annotation.new
self.model.annotation_layer = AnnotationLayerRepository.new(current_user: self.current_user, review: review).show(params[:annotation_layer_id])
3단계: set_parameters에서 동일한 AnnotationLayer를 다시 조회 (2차 — 중복)
if params[:annotation_layer_id].present?
annotation_layer = AnnotationLayerRepository.new(current_user: current_user, review: self.review).show(params[:annotation_layer_id])
@model.annotation_layer = annotation_layer
end
annotation_layer_id는 create!에서 required parameter이므로 항상 present하며, 따라서 set_parameters에서도 항상 조회가 실행된다.
4단계: permission_joins — 12개 LEFT JOIN 포함 복합 쿼리
def self.permission_joins(record, current_user, select: nil, review_id: -1, **kwargs)
if select.present?
_select = ApplicationRecord.sanitize_sql(select)
else
_select = "annotation_layers.*,
MAX(review_user_permissions.permission) AS review_user_permission,
MAX(review_group_permissions.permission) AS review_group_permission,
MAX(annotation_layer_user_permissions.permission) AS annotation_layer_user_permission,
MAX(annotation_layer_group_permissions.permission) AS annotation_layer_group_permission,
MAX(facility_user_permissions.permission) AS facility_user_permission,
MAX(facility_group_permissions.permission) AS facility_group_permission,
MAX(facility_system_group_permissions.permission) AS facility_system_group_permission,
MAX(workspace_user_permissions.permission) AS workspace_user_permission,
MAX(workspace_group_permissions.permission) AS workspace_group_permission,
MAX(team_user_permissions.permission) AS team_user_permission,
MAX(team_group_permissions.permission) AS team_group_permission,
MAX(team_system_group_permissions.permission) AS team_system_group_permission,
MAX(GREATEST(
IFNULL(annotation_layer_user_permissions.permission, 0),
...
)) AS applied_permission"
end
elsif current_class == ::Review || (review_id || capture_id).present?
permission_joins(default_joins(current_class), current_user, review_id: review_id || -1, capture_id: capture_id || -1).where(attrs)
이 쿼리는 review_permissions, annotation_layer_permissions, facility_permissions, workspace_permissions, team_permissions, grouped_users 테이블을 각각 user/group 별로 LEFT JOIN하여 총 12개의 서브쿼리를 조합한다. repsol 팀처럼 permission 엔트리가 많은 경우 쿼리 비용이 급격히 증가한다.
Log Evidence#
Datadog에서 확인한 slow request 패턴:
service:cupixworks-api resource_name:"Api::V1::AnnotationsController#create" @duration:>500ms env:production
대표적인 slow request 로그:
{
"timestamp": "2026-05-26T08:51:23.188Z",
"duration_ms": 4825,
"db_ms": 3959,
"path": "/api/v1/reviews/ubdy79/annotations",
"host": "ip-10-1-147-251",
"request_id": "4ac619ab-75a1-4770-99c6-94bc031209d3",
"user": "adnande.chahboun@servexternos.repsol.com",
"status": 200
}
{
"timestamp": "2026-05-26T09:50:42.694Z",
"duration_ms": 3419,
"db_ms": 2486,
"path": "/api/v1/reviews/zao9w4/annotations",
"host": "ip-10-1-82-161",
"request_id": "72128da0-b192-4ce5-b4b1-83ca34d7dbb7",
"user": "cristian.mendoza@servexternos.repsol.com",
"status": 200
}
DB 시간 비율 분석:
- review
ubdy79: 3959ms / 4825ms = 82% DB - review
zao9w4: 2486ms / 3419ms = 73% DB - review
emlkv5: 1383ms / 1763ms = 78% DB
모든 케이스에서 DB 시간이 전체의 73-82%를 차지하며, 호스트(ip-10-1-147-251, ip-10-1-82-161) 무관하게 동일한 패턴이 발생한다. 이는 특정 인스턴스의 문제가 아닌 쿼리 자체의 비용 문제임을 확인한다.
에러 로그 부재: Annotation 생성과 관련된 error/warn 로그는 없었으며, 모든 요청이 HTTP 200으로 완료되었다. 이는 기능적 장애가 아닌 순수 성능 문제임을 확인한다.
Hypotheses Considered#
| # | Hypothesis | Evidence for | Evidence against | Verdict |
|---|---|---|---|---|
| H1 | permission_joins 12-LEFT-JOIN 쿼리의 중복 실행이 latency 원인 |
DB 시간 73-82% 차지, AnnotationLayerRepository.show() 2회 호출 확인 (annotation_factory.rb:12, parameter/annotation.rb:18), 모든 호스트에서 동일 패턴 |
— | Confirmed |
| H2 | DB connection pool 고갈 또는 connection timeout | 여러 호스트에서 동시 발생 가능 | error/warn 로그 없음, connection timeout/pool 관련 에러 0건, 모든 요청 성공 | Rejected |
| H3 | Elasticsearch 병목 (annotation layer 검색) | AnnotationLayerRepository가 ES search 사용 가능 |
show()는 ES가 아닌 permission_joins SQL 쿼리 사용 (base_repository.rb:337), ES 에러 0건 |
Rejected |
| H4 | after_create EventFactory의 동기 INSERT 추가 비용 |
eventable/callbacks.rb:31에서 Event 레코드 생성 |
Event INSERT는 단일 테이블 INSERT로 비용이 낮음, DB 시간의 대부분은 SELECT permission 쿼리에 소요 | Rejected |
Fix Recommendation#
즉시 조치 (Critical)#
app/concerns/parameter/annotation.rb:17-19에서annotation_layer_id에 대한 중복 조회 제거.AnnotationFactory#create!에서 이미@model.annotation_layer를 설정하므로,set_parameters에서는@model.annotation_layer가 nil인 경우에만 조회하도록 조건 변경.- 이 변경만으로 permission_joins 쿼리 1회 제거 — 예상 latency 40-50% 감소.
단기 개선 (1주 이내)#
AnnotationLayerRepository.permission_joins쿼리 최적화:repsol팀처럼 permission 엔트리가 많은 경우를 위해, permission 테이블에 복합 인덱스 추가 (accessor_id,accessor_type조합).BaseRepository.show()결과를 request 스코프에서 캐싱하는 메커니즘 도입 (예:RequestStoregem 활용), 동일 request 내 동일 ID 조회 시 DB 쿼리 재실행 방지.
장기 개선 (재발 방지)#
- Permission 확인 로직을 materialized view 또는 캐시 레이어로 분리. 현재 12개 LEFT JOIN은 permission 구조가 확장될수록 성능이 선형적으로 저하된다.
- 권한 변경 시 비동기로 permission 결과를 갱신하는 이벤트 기반 캐시 도입 검토.
Monitoring#
AnnotationsController#createp95/p99 latency 모니터 추가- DB 시간 비율이 80% 이상인 요청에 대한 알림 설정
service:cupixworks-api resource_name:"Api::V1::AnnotationsController#create" @duration:>2000ms env:production
Risk Assessment#
- Risk level: medium
- 예상 복잡도: standard (중복 호출 제거는 trivial, permission 쿼리 최적화는 standard)