ES /docs

Api::V1::WorkareasController#bulk (avg 1925ms, max 2188ms)

RCA: WorkareasController#bulk latency (avg 1925ms)

Overview#

What Happened#

2026-05-27 06:04~06:52 UTC 사이 ap-southeast-2 리전에서 Api::V1::WorkareasController#bulk 엔드포인트의 응답 시간이 평균 1925ms(최대 2188ms)로 측정되었다. 동일 사용자가 facility sh9qll에서 7개 workarea를 bulk delete 시도했으며, 모든 항목이 ENT30001 에러(element 또는 task에 참조됨)로 실패했다. HTTP 200 응답이지만 비즈니스 로직상 전건 실패.

Quick Facts#

Field Value
resource_name Api::V1::WorkareasController#bulk
bulk_action delete (7 items)
bulk_status failed (ENT30001 on all items)
top_frame app/repositories/workarea_repository.rb:38
env production, ap-southeast-2
deploy production-ap-southeast-2-20260527t0555z0-650f3601-cupixworks

Timeline#

  1. 2026-05-27T06:04:33Z — 첫 번째 bulk delete 요청 (7 items), 2186ms 소요, 전건 실패
  2. 2026-05-27T06:52:26Z — 두 번째 bulk delete 요청 (동일 7 items), 1660ms 소요, 전건 실패
  3. 2026-05-27T06:21~06:24Z — 동일 호스트에서 GroupsController#index Faraday::TimeoutError 발생 (10초 timeout, 외부 서비스 응답 불능)

Error Log#

Datadog Logs

json
{
  "resource_name": "Api::V1::WorkareasController#bulk",
  "service": "cupixworks-api",
  "occurrences": 2,
  "avg_ms": 1925,
  "max_ms": 2188,
  "sample_trace_id": "4573130162613500192"
}

Impact#

  • Service: cupixworks-api
  • 발생 횟수: 2
  • 최초 발생: 2026-05-27T06:04:29.240Z
  • 최근 발생: 2026-05-27T06:52:24.523Z
  • 영향 범위: 단일 사용자 (Chan Lee, team: built), facility sh9qll 한정. 실제 데이터 손실이나 기능 장애 없음 (삭제 실패로 보호됨).

Root Cause Summary#

Bulk delete 작업 시 7개 workarea 각각에 대해 referenced_by_elements?와 referenced_by_task? 메서드가 순차적으로 Elasticsearch 쿼리를 실행한다. 7개 항목 × 2개 ES 쿼리 = 총 14회의 Elasticsearch 호출이 순차적으로 수행되며, ap-southeast-2 리전에서 동시간대 인프라 부하(Faraday::TimeoutError 등)로 인해 ES 응답 시간이 증가하여 전체 응답이 2초에 달했다. DB 시간은 9.510.4ms로 미미하여, 대부분의 latency는 Elasticsearch 쿼리 대기 시간에서 발생한다.

Technical Analysis#

Code Path#

  • Entry point: app/controllers/concerns/bulkable_controller.rb:25 — bulk 액션에서 repository_instance.bulk(params) 호출
  • Repository dispatch: app/repositories/concerns/bulkable_repository.rb:47-58 — when 'delete' 분기, _models.find_each.with_index 루프 진입
  • Per-item delete: app/repositories/workarea_repository.rb:37-45 — 각 workarea에 대해 참조 체크 후 삭제 시도
  • Failure point: app/repositories/workarea_repository.rb:38-39 — referenced_by_elements? || referenced_by_task? 에서 ES 쿼리 2회 실행, 참조 존재 시 ENT30001 raise
app/repositories/concerns/bulkable_repository.rb:47-58ruby
when 'delete'
  _models.find_each.with_index do |model, index|
    _repository = self.class.new(review: _review, current_user: current_user, model: model, parent: _parent)
    _repository.model.skip_siteinsights_event_publish! if _repository.model.respond_to?(:skip_siteinsights_event_publish!)
    _repository.delete  # 각 항목마다 ES 쿼리 2회 실행
  rescue StandardError => e
    _invalid_items << {
      index: index
    }.merge(Cupix::Util::ErrorParser.parse_error(e))

    next
  end
app/repositories/workarea_repository.rb:37-45ruby
def delete
  if referenced_by_elements? || referenced_by_task?
    raise Cupix::Errors::Entity.new(code: 'ENT30001', reason: 'Cannot delete workarea because it is referenced by element or task')
  end

  raise Cupix::Errors::Entity.new(code: 'ENT30002', reason: 'Cannot delete default workarea') if @model.is_default

  super
end
app/repositories/workarea_repository.rb:338-360ruby
def referenced_by_elements?
  response = ::Element.search({
    size: 1,
    query: {
      bool: {
        must: [
          { terms: { 'workarea.ids': [@model.id] } },
          { term: { 'cycle_state': 'created' } }
        ]
      }
    }
  })

  response.present?
end
app/repositories/workarea_repository.rb:362-384ruby
def referenced_by_task?
  response = ::Task.search({
    size: 1,
    query: {
      bool: {
        must: [
          { term: { 'workarea.id': @model.id } },
          { term: { 'cycle_state': 'created' } }
        ]
      }
    }
  })

  response.present?
end

기대 동작: Bulk delete 7개 항목이 수백 ms 이내에 처리되어야 한다. 실제 동작: 14회의 순차 ES 쿼리 + 인프라 부하로 인해 ~2초 소요. 모든 항목이 참조 중이므로 전건 실패.

Log Evidence#

Datadog에서 확인한 두 건의 요청 상세:

text
service:cupixworks-api resource_name:"Api::V1::WorkareasController#bulk" env:production @duration:>500ms
json
{
  "timestamp": "2026-05-27T06:04:33.095Z",
  "method": "PUT",
  "path": "/api/v1/workareas",
  "status": 200,
  "duration_ms": 2186.35,
  "db_time_ms": 9.5,
  "view_time_ms": 0.18,
  "bulk_action": "delete",
  "items_count": 7,
  "bulk_status": "failed",
  "error_code": "ENT30001",
  "user": "chan.lee@cupix.com",
  "facility_key": "sh9qll",
  "region": "ap-southeast-2",
  "request_id": "631a65d6-2664-4e8e-8b17-7f3aaa4f0e22"
}
json
{
  "timestamp": "2026-05-27T06:52:26.621Z",
  "method": "PUT",
  "path": "/api/v1/workareas",
  "status": 200,
  "duration_ms": 1660.53,
  "db_time_ms": 10.43,
  "view_time_ms": 0.17,
  "bulk_action": "delete",
  "items_count": 7,
  "bulk_status": "failed",
  "error_code": "ENT30001",
  "user": "chan.lee@cupix.com",
  "facility_key": "sh9qll",
  "region": "ap-southeast-2",
  "request_id": "027ff867-9df5-42b9-8dae-5cc8f0e429e8"
}

동일 시간대 인프라 부하 증거:

text
service:cupixworks-api status:error host:ip-10-1-19-203.ap-southeast-2.compute.internal
json
{
  "timestamp": "2026-05-27T06:21:45.821Z",
  "resource_name": "Api::V1::GroupsController#index",
  "duration_ms": 10014.95,
  "error": "Faraday::TimeoutError",
  "message": "Operation timed out after 10002 milliseconds with 0 bytes received"
}

DB 시간이 9.510.4ms로 매우 작고, view 시간도 0.170.18ms. 전체 2186ms 중 약 2166ms가 application logic (= Elasticsearch 쿼리)에서 소요됨을 의미한다.

Hypotheses Considered#

# Hypothesis Evidence for Evidence against Verdict
H1 Elasticsearch 순차 쿼리 14회가 latency의 주요 원인 DB time 9.5ms vs total 2186ms → ~2176ms가 app logic에서 소요. 7 items × 2 ES queries = 14회 순차 호출. 동시간대 ES 관련 timeout 발생 (Faraday::TimeoutError) — Confirmed
H2 N+1 DB 쿼리 (각 item별 repository 인스턴스 생성)가 원인 각 iteration에서 self.class.new() 호출 (line 49) DB time이 9.5~10.4ms로 매우 작음. DB는 bottleneck 아님 Rejected
H3 대량 데이터(1000개 항목)로 인한 처리 지연 bulk endpoint는 최대 1000개 지원 이 케이스는 7개 항목만 처리. 소량임에도 느림 Rejected
H4 ap-southeast-2 리전 전반적 인프라 부하 (ES cluster 부하) 동시간대 GroupsController에서 10초 timeout 발생, 50+ 건의 NotFound 경고 (ES 문서 동기화 문제) 두 번째 요청(06:52)은 1660ms로 첫 번째(2186ms)보다 개선됨 → 일시적 부하 요소 존재 Contributing factor

Fix Recommendation#

즉시 조치 (Critical)#

  • 파일: app/repositories/workarea_repository.rb:338-384
  • 방향: referenced_by_elements?와 referenced_by_task?를 batch 쿼리로 전환. 7개 workarea ID를 한 번에 ES multi-search (msearch) 또는 단일 terms 쿼리로 조회하여, N회 순차 쿼리를 1~2회로 줄인다.
  • 예: 모든 workarea_id에 대해 한 번의 terms 쿼리로 참조 여부를 확인하고, 참조된 ID 목록을 반환받은 뒤 delete 루프에서 해당 ID를 제외.

단기 개선 (1주 이내)#

  • 파일: app/repositories/concerns/bulkable_repository.rb:47-58
  • 방향: Bulk delete 루프 진입 전에 참조 체크를 일괄 수행하는 pre_validate_delete 단계를 추가. 참조된 항목은 미리 invalid_items에 추가하고, 참조되지 않은 항목만 실제 delete 루프를 수행하도록 변경.
  • 이를 통해 ES 쿼리 횟수를 items 수에 무관하게 2회(Element 1회 + Task 1회)로 고정.

장기 개선 (재발 방지)#

  • Bulk 작업의 참조 체크를 DB-level foreign key 또는 counter cache로 전환하여 ES 의존성 제거.
  • Elasticsearch 쿼리에 timeout 설정 추가 (현재 무제한 대기). ES cluster 부하 시 graceful degradation 가능하도록.
  • Bulk delete 실패 시 사용자에게 어떤 element/task가 참조 중인지 구체적 정보 제공 (현재는 일괄 ENT30001만 반환).

Monitoring#

  • Bulk delete endpoint p95 latency 추적:
text
service:cupixworks-api resource_name:"Api::V1::WorkareasController#bulk" @http.method:PUT
  • ES 쿼리 응답 시간 모니터링 (ap-southeast-2 리전):
text
service:cupixworks-api @elasticsearch.duration:>200ms env:production region:ap-southeast-2
  • Bulk 작업 전건 실패 비율 알림:
text
service:cupixworks-api @bulk_status:failed @bulk_action:delete

Risk Assessment#

  • Risk level: low
  • 예상 복잡도: standard — batch ES 쿼리 전환은 기존 패턴(terms query)을 활용 가능하나, delete 흐름 리팩터링이 필요하므로 테스트 범위 확인 필요.