RCA: Api::V1::FloorplansController#update Latency (1066ms)

Overview#

What Happened#

2026-05-26 13:04 UTC에 cupixworks-api 서비스의 Api::V1::FloorplansController#update 엔드포인트에서 1066ms 응답 시간이 감지되었다. 이는 해당 엔드포인트의 평균 응답 시간(200-400ms) 대비 약 3배 느린 수치로, 500ms 임계값을 초과하여 latency 클러스터로 분류되었다.

Quick Facts#

Timeline#

1. 2026-05-26T13:04:11Z — FloorplansController#update 요청이 1066ms로 처리됨 (trace ID: 9145203085652470032)
2. 2026-05-26T13:04:11Z — Error-sweeper collector가 latency 클러스터로 감지

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::FloorplansController#update",
  "service": "cupixworks-api",
  "occurrences": 1,
  "avg_ms": 1066,
  "max_ms": 1066,
  "sample_trace_id": "9145203085652470032"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 1
• 최초 발생: 2026-05-26T13:04:11.440Z
• 최근 발생: 2026-05-26T13:04:11.440Z

Root Cause Summary#

FloorplansController#update 요청의 1066ms latency는 update 흐름에서 순차적으로 실행되는 여러 동기 작업의 누적으로 발생한다: (1) before_action :set_floorplan에서 13개 LEFT JOIN이 포함된 복잡한 permission SQL 쿼리 실행, (2) BaseRepository#update에서 permission 재검증 및 Pundit policy 체크, (3) set_parameters에서 모델 속성 설정 및 state machine 이벤트 발생, (4) @model.save!에서 DB write + has_paper_trail 버전 기록, (5) after_update 콜백에서 Eventable::Events::Update.create_event 실행, (6) after_update에서 EntityUpdates::Child#reset_parent_cached_entity_updates로 부모 캐시 무효화, (7) after_commit에서 Elasticsearch 동기 문서 업데이트(_update_document). 24시간 메트릭 분석 결과, 해당 엔드포인트는 주기적으로 1-1.7초 스파이크를 보이며 이는 Elasticsearch 동기 업데이트 지연이 주 원인으로 판단된다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/floorplans_controller.rb:34
• before_action set_floorplan: app/controllers/api/v1/floorplans_controller.rb:79-81
• Permission SQL: app/repositories/floorplan_repository.rb:40-237
• BaseRepository#update (permission + state check): app/repositories/base_repository.rb:131-143
• FloorplanRepository#update: app/repositories/floorplan_repository.rb:19-31
• set_parameters: app/concerns/parameter/floorplan.rb:8-39
• after_update callbacks: app/models/concerns/eventable/callbacks.rb:34-36
• EntityUpdates cache reset: app/models/concerns/entity_updates/child.rb:22-28
• Elasticsearch sync: app/models/concerns/searchable.rb:55-114

1. before_action에서 permission_joins로 모델 로드:

def set_floorplan
  @model = repository_instance.show(params[:id])
end

이 호출은 BaseRepository.show를 통해 FloorplanRepository.permission_joins를 실행한다:

def self.permission_joins(record, current_user, select: nil, review_id: -1, **kwargs)
  if select.present?
    _select = ApplicationRecord.sanitize_sql(select)
  else
    _select = "floorplans.*,
    MAX(review_user_permissions.permission) AS review_user_permission,
    MAX(review_group_permissions.permission) AS review_group_permission,
    MAX(review_public_permissions.permission) AS review_public_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(...)) AS applied_permission"
  end

이 쿼리는 13개의 LEFT JOIN (review, facility, workspace, team, level 각각의 user/group 권한 테이블)을 결합하여 단일 레코드를 조회한다.

2. FloorplanRepository#update에서 save! 호출:

def update(params = {})
  super  # BaseRepository#update — permission check, state check

  set_parameters(params)

  begin
    @model.save!
  rescue StandardError => e
    raise Cupix::Errors::Parameter.new(code: 'ARG10001', reason: 'Invalid argument', message: e.message)
  end

  @model
end

3. after_commit에서 Elasticsearch 동기 업데이트:

def _update_document
  Cupix::Logger.debug('begin - _update_document', class: self.class.name, function: __method__)
  if @skip_index_document == true
    return
  end

  if (attributes_in_database = __elasticsearch__.instance_variable_get(:@__changed_model_attributes).presence)
    attributes = if respond_to?(:as_indexed_json)
                   # ... serialize changed attributes
                 end

    unless attributes.empty?
      request = {
        id: __elasticsearch__.id,
        body: { doc: attributes },
        retry_on_conflict: 5
      }
      results = __elasticsearch__.client.update(request.merge({ index: __elasticsearch__.index_name }))
    end
  end
end

Elasticsearch 업데이트는 after_commit 콜백에서 동기적으로 실행되므로, ES 클러스터의 응답 시간이 직접적으로 API 응답 시간에 영향을 준다.

4. PaperTrail 버전 기록:

has_paper_trail only: %i[revision transformation]

transformation 필드가 변경될 때 versions 테이블에 INSERT가 발생한다.

Log Evidence#

Datadog 메트릭 쿼리로 24시간 latency 패턴을 확인:

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

24시간 데이터에서 주요 스파이크 관측:

1779756900000 (approx 10:15 UTC) — 1.199s
1779757200000 (approx 10:20 UTC) — 1.230s
1779757500000 (approx 10:25 UTC) — 1.711s
1779757800000 (approx 10:30 UTC) — 1.685s

이 스파이크들은 연속된 5분 간격에서 집중적으로 발생하며, 이는 Elasticsearch 클러스터 부하 또는 GC 지연과 일치하는 패턴이다.

최근 2시간 평균 응답 시간 분포:

Min: 0.125s
Avg: ~0.33s
Max: 0.736s (2h window)
P90 (estimated): 0.5-0.6s

FloorplansController#update 요청 로그 (모두 200 OK):

[200] PUT /api/v1/floorplans/6059 (Api::V1::FloorplansController#update) — 2026-05-26 22:46:23 KST
[200] PUT /api/v1/floorplans/6058 (Api::V1::FloorplansController#update) — 2026-05-26 22:46:05 KST
[200] PUT /api/v1/floorplans/6057 (Api::V1::FloorplansController#update) — 2026-05-26 22:45:51 KST
[200] PUT /api/v1/floorplans/6056 (Api::V1::FloorplansController#update) — 2026-05-26 22:45:37 KST

에러나 timeout 로그는 검색되지 않았으며, Elasticsearch TimeoutError도 해당 시간대에 발생하지 않았다.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 현재 1회 발생이며, 24시간 메트릭상 간헐적 스파이크로 즉각적인 코드 변경은 불필요하다.
• 500ms 임계값을 넘는 요청 빈도를 모니터링하여 악화 추세인지 확인 필요.

단기 개선 (1주 이내)#

• app/models/concerns/searchable.rb의 _update_document 메서드를 비동기로 전환 고려.
  • 현재: after_commit에서 동기 ES 업데이트
  • 개선: after_commit에서 Sidekiq worker(BulkIndexWorker)로 위임하여 API 응답 시간에서 ES 지연을 분리
  • 이미 BulkIndexWorker가 timeout 시 fallback으로 사용되고 있으므로 (searchable.rb:113-114), 기본 경로에서도 활용 가능

장기 개선 (재발 방지)#

• FloorplanRepository.permission_joins의 13개 LEFT JOIN 쿼리를 materialized view 또는 캐시 기반 접근으로 리팩터링하여 set_floorplan before_action의 기본 지연을 줄인다.
• EntityUpdates::Child#reset_parent_cached_entity_updates에서 ObjectSpace.each_object(Class) 호출을 제거하고 정적 매핑으로 대체하여 Ruby GC 부하를 줄인다.

Monitoring#

• FloorplansController#update P95 latency 추적:

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

• Elasticsearch 동기 업데이트 지연 모니터링:

service:cupixworks-api "TimeoutError" "Floorplan"

• 500ms 초과 요청 발생 빈도 알림:

sum:trace.rack.request.hits{service:cupixworks-api,resource_name:api::v1::floorplanscontroller_update,@duration:>500000000}.as_count()

Risk Assessment#

• Risk level: low
• 예상 복잡도: standard