RCA: Category with ids [nil] does not match after 6 retries

Overview#

What Happened#

2026-04-21 09:23 UTC에 cupixworks-worker의 BulkSavePartialJsonToFileWorker가 ["Category", [""]] args로 호출되었다. 빈 문자열 ""이 ID로 전달되어 DB 조회 시 매칭되는 레코드가 없었고, 6회 retry 후 error로 실패했다. 동일 시간대에 Workarea 모델에서도 같은 패턴의 에러가 5건 추가 발생했다.

Quick Facts#

Timeline#

1. 09:23:07Z — Sidekiq job enqueued: BulkSavePartialJsonToFileWorker with args ["Category", [""]]
2. 09:23:09Z — Retry 14 시작 (exponential backoff 0.1s0.8s)
3. 09:23:11Z — Retry 56 (1.6s3.2s delay)
4. 09:23:15Z — 6회 retry 실패 후 error 로깅
5. 09:23:14Z — Sidekiq job 완료 (status: done, duration: 6.347s)

Error Log#

Datadog Logs

Category with ids [nil] does not match after 6 retries

Impact#

• Service: cupixworks-worker
• 발생 횟수: 1 (Category) + 5 (Workarea) = 같은 패턴 총 6건
• 최초 발생: 2026-04-21T09:23:15.310Z
• 최근 발생: 2026-04-21T09:23:15.310Z
• 영향: data warehouse에 partial JSON이 기록되지 않음. 실시간 데이터 동기화 누락 가능. 사용자에게 직접적인 에러는 노출되지 않으나, downstream 데이터 일관성에 영향.

Root Cause Summary#

BulkSavePartialJsonToFileWorker에 빈 문자열 ""이 ID로 전달되었다. worker의 guard clause(line 9)는 Array(ids).compact를 사용하여 nil만 제거하고 빈 문자열 ""은 필터링하지 않는다. 결과적으로 model_class.where(id: [""]) 쿼리가 0건을 반환하지만 ids.count는 1이므로 count mismatch가 발생하고, 6회 retry 후 실패한다. 빈 문자열은 upstream의 BulkableRepository#bulk!에서 params[:items].pluck(:id)가 빈 문자열 ID를 포함한 요청을 그대로 전달하면서 발생한다.

Technical Analysis#

Code Path#

1. Entry point — BulkableRepository#bulk! 에서 ID 추출

_model_ids = params[:items].pluck(:id)

API 요청에서 id 필드를 추출한다. 클라이언트가 id: ""(빈 문자열)을 전달하면 그대로 배열에 포함된다.

2. 실패한 항목에 nil 할당

_invalid_items.each { |invalid_item| _model_ids[invalid_item[:index]] = nil }

Bulk operation 중 실패한 항목의 위치에 nil을 삽입한다.

3. Worker 호출 — compact는 nil만 제거

bulk_save_changes_to_partial_json(_model_ids.compact)

.compact는 nil을 제거하지만 ""(빈 문자열)은 제거하지 않는다. 따라서 원래 빈 문자열이었던 ID는 그대로 worker에 전달된다.

4. Worker의 guard clause — 빈 문자열 미처리

# Filter out nil IDs early
ids = Array(ids).compact

if ids.empty?
  Cupix::Logger.debug('Skipping BulkSavePartialJsonToFileWorker - no valid IDs provided',
                      class: self.class, function: 'perform', class_name: class_name)
  return nil
end

compact는 nil만 제거한다. [""]은 compact 후에도 [""]이 되어 empty check를 통과한다.

5. Failure point — DB 조회 count mismatch

$MAX_RETRIES.times do |retries|
  models = model_class.where(id: ids)

  if models.count != ids.count
    delay = 0.1 * (2**retries)
    Cupix::Logger.warn("Retry #{retries + 1} - #{class_name} with ids #{ids} count does not match, retrying in #{delay} seconds", class: self.class, function: 'perform')

    sleep(delay)

    next
  else
    break
  end
end

if models.count != ids.count
  Cupix::Logger.error("#{class_name} with ids #{ids} does not match after #{$MAX_RETRIES} retries", class: self.class, function: 'perform')

  return false
end

Category.where(id: [""]) → 0건 반환, ids.count = 1 → mismatch. 6회 retry 후 error.

Log Evidence#

Datadog에서 request ID b5694a912bd5a79641b32f95로 검색한 결과:

service:cupixworks-worker @request_id:b5694a912bd5a79641b32f95

Retry 로그 (warn level):

2026-04-21T09:23:09.308Z [warn] Retry 1 - Category with ids [nil] count does not match, retrying in 0.1 seconds
2026-04-21T09:23:09.308Z [warn] Retry 2 - Category with ids [nil] count does not match, retrying in 0.2 seconds
2026-04-21T09:23:09.308Z [warn] Retry 3 - Category with ids [nil] count does not match, retrying in 0.4 seconds
2026-04-21T09:23:09.308Z [warn] Retry 4 - Category with ids [nil] count does not match, retrying in 0.8 seconds
2026-04-21T09:23:11.308Z [warn] Retry 5 - Category with ids [nil] count does not match, retrying in 1.6 seconds
2026-04-21T09:23:11.308Z [warn] Retry 6 - Category with ids [nil] count does not match, retrying in 3.2 seconds

최종 에러 (error level):

2026-04-21T09:23:15.310Z [error] Category with ids [nil] does not match after 6 retries

Sidekiq job 정보:

{
  "class": "BulkSavePartialJsonToFileWorker",
  "queue": "data_changes",
  "args": ["Category", [""]],
  "jid": "b5694a912bd5a79641b32f95",
  "created_at": "2026-04-21T09:23:07.873Z",
  "enqueued_at": "2026-04-21T09:23:07.873Z",
  "duration": 6.347,
  "retry": false
}

동일 패턴의 추가 에러 (08:00~10:00 UTC):

service:cupixworks-worker status:error "does not match after 6 retries"

모두 동일 호스트(ip-10-1-18-233.us-west-2.compute.internal), 동일 PID(2761350), 동일 배포 버전에서 발생했다.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• app/workers/bulk_save_partial_json_to_file_worker.rb:9: compact 대신 빈 문자열과 nil을 모두 필터링하도록 변경. ids.compact → ids.reject { |id| id.blank? } 또는 동등한 로직 적용. 이렇게 하면 빈 문자열 ID가 전달되어도 early return으로 불필요한 6회 retry를 방지.

단기 개선 (1주 이내)#

• app/repositories/concerns/bulkable_repository.rb:19: params[:items].pluck(:id) 이후 빈 문자열/nil ID를 즉시 필터링하여 downstream에 invalid ID가 전파되지 않도록 input validation 강화. 마찬가지로 BulkableFactory#bulk!(line 63)와 BulkableFactory::AssetCategory#finalize_bulk_response(line 168)에서도 .compact 대신 .reject(&:blank?) 적용.

장기 개선 (재발 방지)#

• Bulk API 엔드포인트에서 request payload의 ID 필드에 대한 type/presence validation을 추가하여, 빈 문자열이나 nil이 포함된 요청을 API 레벨에서 거부.
• BulkSavePartialJsonToFileWorker의 retry 로직에서, 절대 성공할 수 없는 케이스(빈 문자열, nil 등)를 사전 감지하여 불필요한 retry와 sleep을 방지.

Monitoring#

• 아래 Datadog 쿼리로 동일 패턴 재발 모니터링:

service:cupixworks-worker status:error "does not match after 6 retries"

• Worker에 빈 문자열 ID 감지 시 warn 로그 추가 고려:

service:cupixworks-worker "Skipping BulkSavePartialJsonToFileWorker - no valid IDs provided"

Risk Assessment#

• Risk level: low
• 예상 복잡도: trivial
• 사용자에게 직접적인 에러 노출은 없으나, data warehouse 동기화 누락이 축적되면 데이터 불일치 발생 가능. 수정은 guard clause 한 줄 변경으로 해결 가능.