RCA: Api::V1::PointcloudsController#update Latency (avg 1200ms)

Overview#

What Happened#

2026-05-27 11:35경 cupixworks-api의 Api::V1::PointcloudsController#update 엔드포인트에서 평균 1200ms, 최대 1301ms의 응답 지연이 3건 발생했다. 모두 us-west-2 리전에서 동일 시간대에 발생한 burst 패턴이며, cupix-agent에 의한 대량 pointcloud 업데이트 요청이 원인이다.

Quick Facts#

Timeline#

1. 2026-05-27T11:35:06Z — 첫 번째 고지연 요청 감지 (1295ms, pointcloud 1109767)
2. 2026-05-27T11:35:12Z — 두 번째 고지연 요청 (1247ms, pointcloud 1109761)
3. 2026-05-27T11:35:20Z — 세 번째 고지연 요청 (1043ms, pointcloud 1108634)
4. 2026-05-27T11:35:06~22Z — ~30건의 동시 update 요청이 burst 형태로 발생 (cupix-agent)

Error Log#

Datadog Logs

{
  "resource_name": "Api::V1::PointcloudsController#update",
  "service": "cupixworks-api",
  "occurrences": 3,
  "avg_ms": 1200,
  "max_ms": 1301,
  "sample_trace_id": "1000527898911535839"
}

Impact#

• Service: cupixworks-api
• 발생 횟수: 3
• 최초 발생: 2026-05-27T11:35:06.996Z
• 최근 발생: 2026-05-27T11:35:20.982Z

Root Cause Summary#

Latency의 92~99%가 non-DB 처리 시간이다. 핵심 원인은 두 가지 synchronous callback이 요청 라이프사이클 내에서 실행되는 것이다: (1) MultiLevel::Pointcloud#update_sub_levels가 group pointcloud의 모든 children을 순차적으로 save!하며, (2) 각 save마다 EntityUpdates::Child#reset_parent_cached_entity_updates가 ObjectSpace.each_object로 parent class를 탐색하고 cache를 invalidate한다. 11:35경 cupix-agent가 ~30건의 update 요청을 동시에 보내면서 동일 Facility에 대한 cache invalidation이 중복 실행되어 지연이 증폭되었다.

Technical Analysis#

Code Path#

• Entry point: app/controllers/api/v1/pointclouds_controller.rb:34
• Repository update: app/repositories/pointcloud_repository.rb:19
• Model save: app/repositories/pointcloud_repository.rb:25
• Callback trigger (after_save): app/models/concerns/multi_level/pointcloud.rb:17
• Synchronous children iteration: app/models/concerns/multi_level/pointcloud.rb:33-42
• Cache invalidation (after_update on each child): app/models/concerns/entity_updates/child.rb:8-9
• ObjectSpace scan for parent classes: app/models/concerns/entity_updates/child.rb:13-18

1. Controller → Repository → save!

def update
  @model = repository_instance.update(params)

  super
end

def update(params = {})
  super

  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

2. after_save callback — 동기적 children 업데이트 (주요 병목)

Group pointcloud를 업데이트하면 update_associated_levels가 모든 children을 순회하며 각각 save!를 호출한다. 이 과정이 request lifecycle 내에서 동기적으로 실행된다.

after_save :update_associated_levels

def update_associated_levels
  return if is_updating_levels

  self.is_updating_levels = true

  if pointcloud_group?
    update_sub_levels
  end

  self.is_updating_levels = false
end

def update_sub_levels
  subs = self.children
  return if subs.nil?

  subs.each do |sub|
    sub.level = self.level
    sub.levels = self.levels
    sub.is_updating_levels = true
    sub.save!  # 각 child마다 DB write + 모든 after_update callback 실행
  end
end

3. after_update callback — 반복적 cache invalidation

각 child의 save!가 after_update :reset_parent_cached_entity_updates를 트리거한다. 이 메서드는 ObjectSpace.each_object(Class)로 모든 parent class를 동적 탐색한 뒤 cache key를 삭제한다.

after_create :reset_parent_cached_entity_updates
after_update :reset_parent_cached_entity_updates

def reset_parent_cached_entity_updates
  self.class.parent_classes.each do |class_name|
    Cupix::Logger.info("reset #{class_name} (ID: #{self.send("#{class_name.underscore}_id")}) cached entity updates", class: self.class.name, function: __method__, module: 'EntityUpdates::Child', child: { class: self.class.name, id: id })

    Rails.cache.delete(entity_updates_cache_key(class_name, self.send("#{class_name.underscore}_id")))
  end
end

parent_classes 메서드가 ObjectSpace.each_object(Class)를 호출하여 Ruby heap의 모든 Class 객체를 순회한다:

def parent_classes
  Cupix::Loader.load

  ObjectSpace.each_object(Class).select do |model|
    model.superclass == ApplicationRecord && !model.name.include?('::') && !model.name.ends_with?('Permission') && model.respond_to?(:entities) && model.entities.include?(self.name.underscore.to_sym)
  end.map(&:name)
end

4. Burst 패턴에 의한 증폭

11:35:0622Z 사이에 cupix-agent가 순차 pointcloud ID(11097411109770)에 대해 ~30건의 동시 update 요청을 발생시켰다. 동일 Facility(ID: 10732)에 속한 pointcloud들이므로 동일 cache key에 대한 invalidation이 중복 실행되며 Redis contention이 발생했다.

Log Evidence#

Datadog APM trace 분석에서 확인된 duration 분포:

Datadog query: service:cupixworks-api resource_name:"Api::V1::PointcloudsController#update" env:production @duration:>500ms
Time window: 2026-05-27T10:35:00Z ~ 2026-05-27T12:00:00Z

고지연 요청의 DB time vs non-DB time 비율:

| Timestamp    | Duration | DB Time  | Non-DB Time | Non-DB % | Pointcloud ID |
|--------------|----------|----------|-------------|----------|---------------|
| 11:35:08Z    | 1295ms   | 582.79ms | 712ms       | 55.0%    | 1109767       |
| 11:35:12Z    | 1247ms   | 73.53ms  | 1174ms      | 94.1%    | 1109761       |
| 11:35:22Z    | 1043ms   | 613.65ms | 430ms       | 41.2%    | 1108634       |

reset_parent_cached_entity_updates 호출 로그 (동일 Facility에 대해 반복):

Datadog query: service:cupixworks-api "reset_parent_cached_entity_updates" "Facility"

{
  "message": "reset Facility (ID: 10732) cached entity updates",
  "class": "Pointcloud",
  "function": "reset_parent_cached_entity_updates",
  "module": "EntityUpdates::Child"
}

이 로그가 단일 요청 내에서 children 수만큼 반복 출력된다 (10+ 회 확인).

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• app/models/concerns/multi_level/pointcloud.rb:33-42 — update_sub_levels를 비동기 worker로 이동. 현재 동기적으로 모든 children을 순회하며 save!하는 로직을 Sidekiq worker에서 처리하도록 변경한다. 이렇게 하면 response time에서 children 수 × save overhead가 제거된다.

단기 개선 (1주 이내)#

• app/models/concerns/entity_updates/child.rb:13-18 — parent_classes 메서드의 ObjectSpace.each_object(Class) 호출을 memoize하거나 class-level constant로 캐시한다. 매 callback 호출마다 Ruby heap 전체를 순회하는 것은 불필요하다.
• Bulk update 시 동일 Facility에 대한 중복 cache invalidation을 debounce하는 로직 추가를 검토한다 (예: request-scoped set으로 이미 invalidate된 key 추적).

장기 개선 (재발 방지)#

• cupix-agent의 대량 pointcloud 업데이트를 batch API로 전환하여 개별 HTTP 요청 대신 단일 bulk update endpoint를 사용하도록 한다.
• counter_culture callback(12개)의 execute_after_commit: true 설정 검증 — 일부가 synchronous하게 실행되지 않는지 확인.

Monitoring#

• PointcloudsController#update P95 duration 모니터:

avg(trace.rack.request.duration){service:cupixworks-api, resource_name:api::v1::pointcloudscontroller#update} by {env} > 1000

• reset_parent_cached_entity_updates 호출 빈도 모니터 (동일 request_id 내 10회 이상 발생 시 알림):

service:cupixworks-api "reset_parent_cached_entity_updates" | pattern

Risk Assessment#

• Risk level: medium
• 예상 복잡도: standard — update_sub_levels의 비동기화는 기존 Sidekiq 인프라를 활용하면 되나, children 업데이트의 순서 보장과 에러 핸들링을 고려해야 한다.