ES /docs

Post-split cap still exceeded after max re-split retries, giving up

RCA: Post-split cap still exceeded after max re-split retries, giving up

Overview#

What Happened#

2026-07-09 15:04 KST부터 15:10 KST 사이에 cupixworks-worker (us-west-2 production)에서 Cupix::EditingSplitService#split!가 4개 siteinsights editing (1178504, 1177289, 1186375, 1202324)에 대해 재분할(re-split) 루프에 빠져 각 editing이 MAX_RESPLIT_RETRIES=10 상한을 초과하며 error 로그 8건이 발생했다. 각 editing은 ElementTrace 기준 element 수가 cap(1000)을 크게 초과(1246~6540)하지만, 연결된 EditingEntity(Task) 행이 하나도 남아 있지 않은 orphan ET 상태였다.

Quick Facts#

Field Value
exception.class (no exception raised — Cupix::Logger.error call)
exception.message Post-split cap still exceeded after max re-split retries, giving up
top_frame app/services/cupix/editing_split_service.rb:111
deploy production-us-west-2-20260709T0602Z0-6eb3f711-cupixworks
env production, us-west-2
tenant cupix
affected editing_ids 1178504, 1177289, 1186375, 1202324 (all task_count=0)

Affected Teams#

Team / Domain Error Count Impact
siteinsights (SQA editing pipeline) 8 4개 siteinsights editing이 cap을 초과한 채 :waiting 상태로 남아 후속 QA workflow 진행 불가

Timeline#

  1. 2026-07-09 15:04:52 KST — 4개 editing에 대한 첫 번째 "giving up" error 4건 동시 발생 (모두 resplit_count=10에 도달) — first_seen
  2. 2026-07-09 15:07:28 KST — editing 1178504 재시도 후 다시 error (post_split_count=6540)
  3. 2026-07-09 15:08:32 KST — editing 1177289 다시 error (post_split_count=5880)
  4. 2026-07-09 15:09:46 KST — editing 1186375 다시 error (post_split_count=3630)
  5. 2026-07-09 15:10:20 KST — editing 1202324 다시 error (post_split_count=1246) — last_seen

Error Log#

Datadog Logs

text
Post-split cap still exceeded after max re-split retries, giving up

핵심 attribute (editing 1178504, 2026-07-09T06:07:28Z):

json
{
  "message": "Post-split cap still exceeded after max re-split retries, giving up",
  "class": "Cupix::EditingSplitService",
  "function": "split!",
  "editing_id": 1178504,
  "post_split_count": 6540,
  "resplit_count": 10,
  "max_resplit_retries": 10,
  "level": "error",
  "environment": "production",
  "region": "us-west-2"
}

Impact#

  • Service: cupixworks-worker
  • 발생 횟수: 8
  • 최초 발생: 2026-07-09 15:04:52 KST
  • 최근 발생: 2026-07-09 15:10:20 KST

Root Cause Summary#

Cupix::EditingSplitService#split!의 종료 단계에서 실행하는 post_count 쿼리는 editing_id로만 필터링(ElementTrace.where(editing_id: ..., purpose: STATUS_UPDATE).distinct.count(:element_id))하지만, 재분할 이후 재실행되는 do_split!의 fallback 경로는 editing_task_ids(untrashed EditingEntity(Task) 기반)로 얻은 task_id 목록으로 다시 필터링(ElementTrace.where(...task_id: task_ids...))한다. 문제의 4개 editing은 Task EE가 모두 trashed된 orphan ET 상태(task_count=0)라 fallback 쿼리 결과는 항상 0이 되어 element 청킹 경로로 진입하지 못하고 do_split! aborting (no split needed)으로 조기 종료된다. 그 뒤 외부 post-split 체크가 editing_id 스코프로 다시 6540개 등의 ET를 발견해 EditingSplitWorker.perform_in(5.seconds, ...)를 재예약하고, 이 무한 루프가 TSLA-13192에서 도입한 MAX_RESPLIT_RETRIES=10 상한에 걸려 error 로그로 기록된 것이다. 실제 데이터 결함은 orphan ET 자체이며, 오늘의 error는 상한 도달을 알리는 defense-in-depth 신호이다.

Technical Analysis#

Code Path#

  • Worker entry: app/workers/editing_split_worker.rb:5perform(editing_id, resplit_count = 0)Cupix::EditingSplitService.new(editing_id: ..., resplit_count: ...).split!
  • Pre-lock splittable? check (editing-scoped, no task filter) → true (element_count=6540 > 1000)
  • Lock 획득 후 do_split! 진입 → compute_split_groups 내부에서 task_ids = editing_task_ids = []
  • compute_split_groupsnil 반환 → fallback 분기에서 다시 task-scoped count로 재확인 → 0으로 계산되어 abort
  • 상위 split!가 editing-scoped post_count를 계산해 6540 > 1000 확인 → resplit_count >= MAX_RESPLIT_RETRIES 이므로 error 로그
  • Entry point: app/workers/editing_split_worker.rb:5
  • Failure point: app/services/cupix/editing_split_service.rb:111 (error 로그 라인)

splittable? (editing-scoped, task 필터 없음):

app/services/cupix/editing_split_service.rb:108-138 (origin/master)ruby
def splittable?
  # ...
  actual_count = ::ElementTrace.where(editing_id: editing.id, purpose: PURPOSE_STATUS_UPDATE).distinct.count(:element_id)
  result = actual_count > MAX_ELEMENTS_PER_EDITING
  # ...
  result
end

do_split! fallback (task-scoped 필터가 존재 → orphan ET는 카운트에서 누락):

app/services/cupix/editing_split_service.rb:251-273 (origin/master)ruby
def do_split!
  final_groups = compute_split_groups
  if final_groups.nil? || final_groups.size <= 1
    task_ids = editing_task_ids
    actual_count = ::ElementTrace.where(editing_id: editing.id, task_id: task_ids, purpose: PURPOSE_STATUS_UPDATE)
                                 .distinct.count(:element_id)
    if actual_count > MAX_ELEMENTS_PER_EDITING
      # falling back to element chunking
      final_groups = split_group_by_element_count(task_ids)
    else
      Cupix::Logger.info('do_split! aborting (no split needed)', ...)
      return [editing]
    end
  end
  # ...
end

외부 post-split 체크 (editing-scoped) — 위 fallback과 스코프 불일치:

app/services/cupix/editing_split_service.rb:103-125 (origin/master)ruby
editing.reload
post_count = ::ElementTrace.where(editing_id: editing.id, purpose: PURPOSE_STATUS_UPDATE).distinct.count(:element_id)
if post_count > MAX_ELEMENTS_PER_EDITING
  if @resplit_count >= MAX_RESPLIT_RETRIES
    Cupix::Logger.error('Post-split cap still exceeded after max re-split retries, giving up', ...)
  else
    Cupix::Logger.warn('Post-split cap still exceeded, scheduling re-split', ...)
    ::EditingSplitWorker.perform_in(5.seconds, editing.id, @resplit_count + 1)
  end
end

editing_task_ids — untrashed Task EE만 조회 (orphan ET의 task_id는 배제됨):

app/services/cupix/editing_split_service.rb:410-423 (origin/master)ruby
def editing_task_ids
  ids = editing.editing_entities
               .where(entity_type: 'Task')
               .untrashed
               .pluck(:entity_id)
  # ...
  ids
end

기대 동작 vs 실제 동작:

  • 기대: do_split! fallback이 cap 초과 시 element_id 청킹으로 새 editing을 생성해 원본 editing의 ET를 재할당해야 함.
  • 실제: editing_task_ids[]를 반환해 WHERE task_id IN ()가 되면서 fallback count가 0으로 나오고, 청킹이 실행되지 않은 채 abort. 외부 post-check는 editing-scoped 카운트로 6540개를 그대로 관측하고 5초 뒤 재시도만 반복.

Log Evidence#

Datadog 쿼리 (재현 가능):

text
service:cupixworks-worker "Post-split cap still exceeded after max re-split retries"
text
service:cupixworks-worker @editing_id:1178504

splittable? 결과 — editing-scoped 카운트로는 6540이 관측됨:

json
{
  "message": "Splittable check",
  "editing_id": 1178504,
  "actual_element_count": 6540,
  "max_elements": 1000,
  "splittable": true
}

같은 editing에서 editing_task_ids는 즉시 0을 반환 (Task EE가 없음):

json
{
  "message": "Editing task ids loaded",
  "editing_id": 1178504,
  "task_count": 0
}

그 결과 fallback 대신 abort 경로가 선택됨:

json
{
  "message": "do_split! aborting (no split needed)",
  "editing_id": 1178504,
  "function": "do_split!",
  "@timestamp": "2026-07-09T06:07:28.132Z"
}

그리고 외부 post-check가 editing-scoped 카운트(=6540)를 근거로 error 로그 기록:

json
{
  "message": "Post-split cap still exceeded after max re-split retries, giving up",
  "editing_id": 1178504,
  "post_split_count": 6540,
  "resplit_count": 10,
  "max_resplit_retries": 10,
  "@timestamp": "2026-07-09T06:07:28.133Z"
}

resplit_count=10이 8건 모두에서 관측되어 (1178504/1177289/1186375/1202324 × 각 2회) 각 editing이 실제로 재시도 상한까지 순환했음이 확인된다.

Hypotheses Considered#

# Hypothesis Evidence for Evidence against Verdict
H1 do_split! fallback의 task-scoped count 쿼리가 orphan ET를 놓쳐 element 청킹으로 진입하지 못하고, 외부 editing-scoped post-check가 계속 재분할을 예약해 MAX_RESPLIT_RETRIES=10에 도달 8건 모두 resplit_count=10, 4개 editing 모두 task_count=0 + actual_element_count=1246~6540, error 직전 do_split! aborting (no split needed) 로그 존재, splittable check는 editing-scoped 카운트로 true 반환 Confirmed
H2 EditingSplitWorker에서 StandardError가 raise되어 Sidekiq retry가 error를 만든 것 클러스터 로그에 Editing split failed: (worker의 rescue 로그, editing_split_worker.rb:12)이 없고 stacktrace도 없다. 로그는 명시적 Cupix::Logger.error 호출로 예외 없이 발생 Rejected
H3 SQA_EDITING_MAX_ELEMENTS 상수가 잘못 설정(예: 배포로 인해 1000으로 하향)되어 정상 editing이 초과로 오판 post_split_count 값(1246~6540)이 1000을 훨씬 초과하며 4개 editing 모두 task_count=0인 orphan 상태 — 정상 데이터가 아님. 배포 SHA 6eb3f711는 오늘 06:02Z 배포로 상수 변경 이력 없음 Rejected
H4 Split lock이 다른 워커에 의해 계속 점유되어 재예약만 반복 로그에 Split lock acquiredSplit lock release attempt가 각 재시도마다 존재. Split skipped (lock acquire failed)은 관측되지 않음 Rejected

Fix Recommendation#

즉시 조치 (Critical)#

  • app/services/cupix/editing_split_service.rb:255-273 fallback 카운트 스코프 정합화: fallback 분기의 actual_count 계산에서 task_id: task_ids 필터를 제거하거나, task_ids가 비어 있으면 editing-scoped 쿼리로 폴백하도록 수정한다. splittable?와 외부 post_count 체크와 동일하게 editing_id + purpose 스코프로 통일해야 orphan ET가 존재할 때에도 element 청킹 경로로 진입해 실제 분할이 이루어진다.
  • root data 정리 (운영): 재분할이 상한에 걸린 4개 editing (1178504, 1177289, 1186375, 1202324)은 데이터 자체가 이미 손상(Task EE는 없는데 ET만 6540/5880/3630/1246 잔존)된 상태다. 위 코드 fix 후에도 이 editing들은 새 EE를 합성하는 로직(_check_d1_recurrence, Phase 4 reconcile) 또는 수동 개입으로 EE 재구축이 필요할 수 있다 — uncertain, 수동 확인 필요.

단기 개선 (1주 이내)#

  • orphan ET 탐지 알람 추가: post_split_count > 0 && task_count == 0인 editing을 관측하면 즉시 error/warn로 노출하고, 별도 Cupix::Logger.error('Orphan ET on editing without Task EE', ...) 로그를 남긴다. 원인이 되는 상류(stamp overwrite / Phase 4 trash race)를 추적하기 위해 TSLA-12839 D1/D3 recurrence 로직과 유사한 histogram metric을 추가한다.
  • 후속 원인 조사: TSLA-13155, TSLA-13192가 다룬 Phase 4 read-trash gap과 stamp overwrite race가 여전히 orphan ET를 생성하는지 검토. 4개 editing의 EditingEntity trashed 이력과 마지막 stamp 시각을 대조해 어느 경로가 orphan을 남겼는지 확정한다.

장기 개선 (재발 방지)#

  • 단일 count 정의로 통일: _live_et_count 같은 helper를 이미 두었지만 (app/services/cupix/editing_split_service.rb:243) split! 진입/외부 post-check/do_split! fallback 세 곳에서 서로 다른 방식(untrashed/with task filter/no filter)으로 element를 센다. 세 곳 모두 하나의 helper로 통합해 스코프 표류를 원천 차단한다.
  • orphan ET self-heal 경로: Task EE가 전무한 editing이 감지되면 ET를 재할당할 대상 EE를 합성(Phase 4 reconcile의 template 검색 로직을 재사용)하거나, editing 자체를 trash 처리해 무한 재분할을 방지한다.

Monitoring#

Datadog widget에 넣을 timeseries 쿼리 (writing-datadog-monitoring-queries 룰 준수 — pipe/stats 없음, threshold 접미사 없음):

  • Re-split retry 상한 도달 발생 추이:
text
logs("service:cupixworks-worker @class:Cupix::EditingSplitService @function:split! status:error \"max re-split retries\"").index("*").rollup("count").by("editing_id")
  • 재분할 warn 이벤트 (early warning, 상한 도달 전에 급증하면 다음 상한 도달 예측 가능):
text
logs("service:cupixworks-worker @class:Cupix::EditingSplitService @function:split! status:warn \"Post-split cap still exceeded\"").index("*").rollup("count").by("editing_id")
  • resplit_count 분포로 상한 근접 editing 조기 발견:
text
logs("service:cupixworks-worker @class:Cupix::EditingSplitService @function:split! \"Post-split cap still exceeded\"").index("*").rollup("max","@resplit_count").by("editing_id")

알림 제안: resplit_count >= 5가 5분 창에서 관측되면 warn, resplit_count >= 10가 관측되면 error 알림.

Risk Assessment#

  • Risk level: medium — 특정 소수 editing(orphan ET 상태)만 영향을 받고 실제 예외/워커 실패는 없으며 상한 도달 후 재큐잉이 중단된다. 다만 해당 editing의 SQA workflow는 정상 진행되지 못하고 :waiting 상태에 남는다.
  • 예상 복잡도: standard — count 쿼리 스코프 정합화는 국소 수정이지만, orphan ET를 만든 상류 원인 조사와 데이터 정리는 추가 손이 필요하다.