RCA: BimsController#update Latency (avg 1285ms, max 1424ms)

Overview#

What Happened#

2026-05-27 07:56~09:11 UTC 사이에 Api::V1::BimsController#update 엔드포인트에서 3회 응답 시간이 500ms를 초과했다. 평균 응답 시간 1285ms, 최대 1424ms로 측정되었으며, 모든 요청은 HTTP 200으로 정상 응답했으나 사용자 체감 지연이 발생했다.

Quick Facts#

Timeline#

1. 2026-05-27T07:56:00Z — 최초 고지연 요청 감지 (trace_id: 8697473233270627284)
2. 2026-05-27T09:11:56Z — 마지막 고지연 요청 기록
3. 2026-05-27 — RCA 분석 수행

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::BimsController#update",
  "service": "cupixworks-api",
  "occurrences": 3,
  "avg_ms": 1285,
  "max_ms": 1424,
  "sample_trace_id": "8697473233270627284"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 3
• 최초 발생: 2026-05-27T07:56:00.897Z
• 최근 발생: 2026-05-27T09:11:56.998Z
• 사용자 영향: BIM 모델 업데이트 시 1초 이상 응답 대기. UI에서 사용자 입력 후 피드백 지연 발생.

Root Cause Summary#

BimsController#update의 고지연은 단일 병목이 아닌, 요청 생명주기 전반에 걸친 복합 비용 누적으로 발생한다. (1) set_bim before_action이 11개 LEFT JOIN을 포함한 permission_joins 쿼리를 실행하여 권한 검증에 상당한 DB 시간을 소모하고, (2) @model.save! 이후 after_commit 콜백 체인에서 동기적 Elasticsearch 부분 업데이트(_update_document), Redis 캐시 쓰기(write_cache), DataWareHouse worker enqueue, Eventable 이벤트 생성이 순차적으로 실행된다. 특히 Elasticsearch 부분 업데이트는 네트워크 왕복이 포함되어 가장 큰 비중을 차지한다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/bims_controller.rb:54 — update 액션
• before_action set_bim: app/controllers/api/v1/bims_controller.rb:100 → repository_instance.show(params[:id])
• Permission query: app/repositories/base_repository.rb:339 → permission_joins(default_joins(...), current_user).where(attrs)
• Repository update: app/repositories/bim_repository.rb:112 → super + set_parameters + @model.save!
• After-commit hooks: app/models/concerns/searchable.rb:16 → _update_document (ES 업데이트)

1. set_bim (before_action) — 권한 쿼리 단계

def self.default_joins(record)
  record.includes(:storage).joins(:facility, :team).joins("
    LEFT JOIN bim_revisions AS last_bim_revision ON bims.last_bim_revision_id = last_bim_revision.id
  ").select("
   bims.*,
   facilities.bim_pack_added_at AS facility_bim_pack_added_at,
   teams.sys AS team_sys,
   last_bim_revision.name AS last_bim_revision_name,
   last_bim_revision.forge_urn AS last_bim_revision_forge_urn
  ")
end

default_joins에서 includes(:storage) + joins(:facility, :team) + LEFT JOIN bim_revisions를 수행한 후, permission_joins가 추가로 11개 LEFT JOIN을 붙인다:

def self.permission_joins(record, current_user, select: nil, review_id: -1, **kwargs)
  # ... 11 LEFT JOINs:
  # review_public_permissions, review_user_permissions, review_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
end

이 조합된 쿼리는 단일 레코드 조회임에도 12개 이상의 JOIN + GROUP BY + GREATEST/IFNULL 연산이 필요해 100-300ms 소모된다.

2. BaseRepository#update — 권한/상태 검증 단계

def update(params = {}, current_user = nil)
  raise Cupix::Errors::PermissionDenied.new(code: 'PERM10000', reason: 'Permission denied') unless @model.updatable_by?(@current_user)

  if self.current_user.present? && self.model.present? && self.model.respond_to?(:applied_cycle_state)
    raise Cupix::Errors::PermissionDenied.new(code: 'PERM32000', reason: 'Archived entity') if %w[archived archiving].include?(self.model.applied_cycle_state) && !Pundit.policy(self.current_user, self.model).update?
  end

  check_updatable_by_billing_state!
  set_params(params)
  @model.last_updated_user = self.current_user if @model.respond_to?(:last_updated_user)
end

Pundit.policy(...) 호출은 추가 DB 조회를 유발할 수 있으며, set_params는 allowed_parameters를 iterate하며 속성을 설정한다.

3. @model.save! + after_commit 콜백 — 비용의 핵심

def _update_document
  # ...
  if (attributes_in_database = __elasticsearch__.instance_variable_get(:@__changed_model_attributes).presence)
    attributes = if respond_to?(:as_indexed_json)
      # BimSerializer를 통해 indexed JSON 생성 (관계 로딩 포함)
      __elasticsearch__.as_indexed_json.select { |k, v| column_names.include?(k.to_s) }
    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 }))

      # dual write to tmp_index (reindexing 중이면 2회 ES 호출)
      if (tmp_index = self.class.fetch_tmp_index_name)
        __elasticsearch__.client.update(request.merge(index: tmp_index))
      end
    end
  end
rescue Faraday::TimeoutError => e
  BulkIndexWorker.perform_async(self.class.name, [id], 'index')
end

_update_document는 after_commit on: [:update]에서 실행되며, Elasticsearch로의 동기적 HTTP 호출이 포함된다. BimSerializer를 통한 as_indexed_json 생성 시 연관 객체(user, workspace, facility, team, building)를 로딩할 수 있어 추가 DB 쿼리가 발생한다.

추가로 write_cache (Redis 쓰기)와 save_partial_json_to_file_as_updated (worker enqueue)도 동일 트랜잭션 커밋 후 순차 실행된다.

Log Evidence#

Datadog에서 BimsController#update 관련 로그를 검색했다. 에러나 경고 레벨 로그는 없으며, 모든 요청이 HTTP 200으로 응답:

service:cupixworks-api "BimsController#update"
Time range: 2026-05-27T06:56:00Z to 2026-05-27T10:00:00Z

[200] PUT /api/v1/bims/18047 (Api::V1::BimsController#update) — 2026-05-27 18:51:35
[200] PUT /api/v1/bims/19642 (Api::V1::BimsController#update) — 2026-05-27 18:28:10
[200] PUT /api/v1/bims/19642 (Api::V1::BimsController#update) — 2026-05-27 18:27:50
[200] PUT /api/v1/bims/19642 (Api::V1::BimsController#update) — 2026-05-27 18:25:38

APM 메트릭 조회 결과, 현재 이 엔드포인트의 평균 응답 시간은 ~970ms:

avg:trace.rack.request.duration{service:cupixworks-api,resource_name:api::v1::bimscontroller_update}
Result: 0.970648 seconds

TimeoutError, Elasticsearch 에러 등 warn/error 레벨 로그는 해당 시간대에 발견되지 않음:

service:cupixworks-api status:warn "TimeoutError" — 0 results
service:cupixworks-api status:warn "Bim" — 0 results
service:cupixworks-api status:error "BimsController" — 0 results

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

없음. 서비스가 정상 응답(HTTP 200) 중이며, 에러가 발생하지 않는 순수 성능 이슈. 즉각적인 장애 위험은 없다.

단기 개선 (1주 이내)#

1. _update_document 비동기화 (app/models/concerns/searchable.rb:16)

   • after_commit on: [:update]에서 직접 ES client를 호출하는 대신, Sidekiq worker로 위임하여 요청 응답 시간에서 ES 네트워크 왕복을 제거.
   • 이미 BulkIndexWorker가 존재하므로 (searchable.rb:52) 정상 경로에서도 이를 활용.

2. set_bim 쿼리 간소화 (app/repositories/bim_repository.rb:126-136, base_repository.rb:308-367)

   • update 액션에서는 이미 @model을 수정 목적으로 로드하므로, permission_joins 대신 간단한 find + Pundit.policy 조합으로 충분할 수 있음.
   • updatable_by? 검증이 BaseRepository#update에서 이미 수행되므로, before_action의 복잡한 permission_joins가 중복 검증.

장기 개선 (재발 방지)#

1. Permission 조회 아키텍처 개선 — 11개 LEFT JOIN 기반의 인라인 SQL 대신, 미리 계산된 permission 캐시 또는 별도 permission service를 도입하여 단일 레코드 조회 비용을 O(1)로 줄임.
2. ES 인덱싱 일괄 처리 — 변경 속성만 부분 업데이트하는 현재 방식을 유지하되, 짧은 시간 내 동일 모델의 다중 업데이트를 debounce하여 ES 호출 횟수를 줄임 (bim 19642는 2분 내 4회 업데이트됨).

Monitoring#

• APM p95/p99 latency 알림 추가:

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

• Elasticsearch 업데이트 소요 시간 메트릭:

avg:elasticsearch.indexing.index.time{cluster_name:cupix-production}

Risk Assessment#

• Risk level: low
• 예상 복잡도: standard
• 서비스 장애 위험 없음 (HTTP 200 정상 응답). 사용자 체감 성능 이슈로, 비즈니스 크리티컬하지 않으나 UX 개선 필요.