FacilityType with id 298 not found after 6 retries
RCA: FacilityType with id 298 not found after 6 retries
Overview#
What Happened#
2026-04-21 18:18:47Z ~ 18:19:05Z 사이에 cupixworks-worker의 SavePartialJsonToFileWorker가 FacilityType ID 298, 299, 300을 찾지 못해 6회 retry 후 error를 발생시켰다. 총 4건의 error와 24건의 warn retry 로그가 기록되었으며, 세 개의 연속된 FacilityType ID가 동시에 실패한 것으로 보아 사용자의 FacilityType 일괄 삭제 작업 중 race condition이 발생한 것으로 판단된다.
Quick Facts#
| Field | Value |
|---|---|
| exception.message | FacilityType with id 298 not found after 6 retries |
| top_frame | app/workers/save_partial_json_to_file_worker.rb:57 |
| runtime | Ruby (Sidekiq worker) |
| deploy | production-us-west-2-20260421T0540Z0-299add63-cupixworks |
| env | production, us-west-2 |
Timeline#
- 18:18:47.850Z — FacilityType 298, 299에 대한 첫 retry 시작 (Job
43456ba6...,5bfba891...) - 18:18:55.859Z — FacilityType 298 첫 번째 Job 6회 retry 후 error 기록; FacilityType 298 두 번째 Job 시작 (
470beec3...) - 18:18:59.864Z — FacilityType 300에 대한 retry 시작 (Job
cc0ccfb4...) - 18:19:01.868Z — FacilityType 298 두 번째 Job error
- 18:19:05.869Z — FacilityType 300 최종 error — 모든 에러 종료
- 2026-04-22 — Error Sweeper에서 감지, RCA 분석 수행
Error Log#
FacilityType with id 298 not found after 6 retries
Impact#
- Service:
cupixworks-worker - 발생 횟수: 4 (FacilityType 298 x2, 299 x1, 300 x1)
- 최초 발생: 2026-04-21T18:18:55.859Z
- 최근 발생: 2026-04-21T18:19:05.869Z
- 사용자 영향: Data warehouse로의 FacilityType 변경 데이터 전달 실패. 삭제된 레코드의 변경 이벤트이므로 실질적 데이터 손실은 없으나, data warehouse의 FacilityType 상태가 일시적으로 동기화되지 않을 수 있음.
Root Cause Summary#
SavePartialJsonToFileWorker에서 FacilityType 레코드를 조회할 때 발생하는 race condition이 근본 원인이다. FacilityType이 .touch (update callback으로 인해 after_commit on: :update 발동)되어 SavePartialJsonToFileWorker가 Sidekiq 큐에 enqueue된 후, 해당 FacilityType이 destroy!로 삭제되면 worker가 dequeue되어 실행될 때 레코드를 찾을 수 없다. FacilityType 298, 299, 300이 동시에 실패한 점은 FacilityTypeRepository#delete의 cascade_delete_children 로직에 의한 일괄 삭제를 강하게 시사한다. Worker의 6회 exponential backoff retry (총 ~6.3초)는 이미 삭제된 레코드를 복구할 수 없으므로 모두 실패한다.
Technical Analysis#
Code Path#
1. Entry point — FacilityType 삭제 요청
FacilityTypeRepository#delete가 호출되면 먼저 하위 FacilityType을 재귀적으로 삭제한다:
def delete
cascade_delete_children(@model)
facilities_scope = ::Facility.where(facility_type_id: @model.id, team_id: @current_team&.id)
facility_ids = facilities_scope.pluck(:id)
if facility_ids.present?
if @model.main_type?
facilities_scope.update_all(facility_type_id: nil, updated_at: Time.current)
else
facilities_scope.update_all(facility_type_id: @model.ancestry, updated_at: Time.current)
end
::Facility.bulk_operation!(facility_ids, 'update')
end
super # BaseRepository#delete → model.destroy!
end
하위 타입 삭제 시 cascade_delete_children이 각 child에 대해 perform_delete!를 호출한다:
def cascade_delete_children(facility_type)
facility_type.sub_types.each do |child|
cascade_delete_children(child)
facilities_scope = ::Facility.where(facility_type_id: child.id, team_id: @current_team&.id)
facility_ids = facilities_scope.pluck(:id)
if facility_ids.present?
facilities_scope.update_all(facility_type_id: child.ancestry, updated_at: Time.current)
::Facility.bulk_operation!(facility_ids, 'update')
end
child.perform_delete! # → ApplicationRecord#perform_delete! → destroy!
end
end
2. destroy!가 트리거하는 after_commit 콜백
FacilityType은 DataWareHouse::FacilityType을 include하며, 이는 DataWareHouse::PartialJson의 after_commit 콜백을 등록한다:
included do
after_commit :save_partial_json_to_file_as_created, on: :create
after_commit :save_partial_json_to_file_as_updated, on: :update, if: :not_new_record?
after_commit :save_partial_json_to_file_as_destroyed, on: :destroy
end
destroy 이벤트는 save_partial_json_to_file_as_destroyed를 호출하며, 이는 동기적으로 (worker 없이) 파일을 직접 생성한다:
def save_partial_json_to_file_as_destroyed
if $FORWARD_DATA_CHANGES != true
Cupix::Logger.debug('Data changes forwarding is disabled', ...)
return nil
end
Cupix::Logger.debug('Changed data will be forwarded in worker', ...)
generate_and_save_partial_json('(destroyed)', all_data: false)
end
3. Race condition 발생 지점
update 이벤트의 콜백은 비동기 worker를 enqueue한다:
def save_partial_json_to_file_in_worker(operation: '(updated)', all_data: false, changes: nil, timestamp: nil)
if !all_data && changes.blank? && operation == '(updated)'
Cupix::Logger.debug('No changes detected, skipping partial JSON generation', ...)
return nil
end
SavePartialJsonToFileWorker.perform_async(self.class.name, self.id, ...)
end
FacilityType에 .touch가 호출되면 (Facility#touch_facility_type_with_ancestors 등을 통해) after_commit on: :update 콜백이 발동되어 worker가 enqueue된다. 이후 FacilityType이 삭제되면:
model = nil
$MAX_RETRIES.times do |retries|
model = model_class.find_by_id(id)
if model.nil?
delay = 0.1 * (2**retries)
Cupix::Logger.warn("Retry #{retries + 1} - #{class_name} with id #{id} not found, retrying in #{delay} seconds", ...)
sleep(delay)
next
else
break
end
end
if model.nil?
Cupix::Logger.error("#{class_name} with id #{id} not found after #{$MAX_RETRIES} retries", ...)
return false
end
4. find_by_id의 INNER JOIN 문제
Worker에서 사용하는 find_by_id는 default_joins를 통해 teams 테이블과 INNER JOIN한다:
def find_by_id(id)
default_joins(current_class).find_by(id: id)
end
def self.default_joins(record)
record.joins(:team).select('facility_types.*, teams.id AS team_id')
end
실행되는 SQL:
SELECT facility_types.*, teams.id AS team_id
FROM facility_types
INNER JOIN teams ON facility_types.team_id = teams.id
WHERE facility_types.id = 298
레코드가 삭제된 후에는 당연히 nil을 반환한다. 또한 team이 삭제된 경우에도 INNER JOIN으로 인해 nil을 반환할 수 있다.
5. 실행 흐름 요약
Facility 생성/수정/삭제
→ Facility#reindex_facility_types
→ FacilityType#touch (update 이벤트)
→ after_commit on: :update
→ SavePartialJsonToFileWorker.perform_async('FacilityType', 298)
[Sidekiq 큐에서 대기 중]
FacilityType 삭제 요청
→ FacilityTypeRepository#delete
→ cascade_delete_children → child.perform_delete! → destroy!
→ @model.destroy!
→ after_commit on: :destroy → 동기적 파일 생성 (정상)
→ DB에서 레코드 삭제 완료
[Worker dequeue]
→ FacilityType.find_by_id(298) → nil (이미 삭제됨)
→ 6회 retry 후 error 로그
Log Evidence#
사용한 Datadog 쿼리:
service:cupixworks-worker "FacilityType" "298"
시간 범위: 2026-04-21T17:18:00Z ~ 2026-04-21T18:49:00Z
Job 1 (request_id: 43456ba6ab3ba311cf635539) — FacilityType 298:
18:18:47.850Z [warn] Retry 1 - FacilityType with id 298 not found, retrying in 0.1 seconds
18:18:47.851Z [warn] Retry 2 - FacilityType with id 298 not found, retrying in 0.2 seconds
18:18:47.851Z [warn] Retry 3 - FacilityType with id 298 not found, retrying in 0.4 seconds
18:18:49.852Z [warn] Retry 4 - FacilityType with id 298 not found, retrying in 0.8 seconds
18:18:49.853Z [warn] Retry 5 - FacilityType with id 298 not found, retrying in 1.6 seconds
18:18:51.856Z [warn] Retry 6 - FacilityType with id 298 not found, retrying in 3.2 seconds
18:18:55.859Z [error] FacilityType with id 298 not found after 6 retries
Job 2 (request_id: 470beec3159927c5063d3a6f) — FacilityType 298 (재시도):
18:18:55.859Z [warn] Retry 1 - FacilityType with id 298 not found, retrying in 0.1 seconds
18:18:55.860Z [warn] Retry 2 - FacilityType with id 298 not found, retrying in 0.2 seconds
18:18:55.860Z [warn] Retry 3 - FacilityType with id 298 not found, retrying in 0.4 seconds
18:18:57.861Z [warn] Retry 4 - FacilityType with id 298 not found, retrying in 0.8 seconds
18:18:57.862Z [warn] Retry 5 - FacilityType with id 298 not found, retrying in 1.6 seconds
18:18:59.865Z [warn] Retry 6 - FacilityType with id 298 not found, retrying in 3.2 seconds
18:19:01.868Z [error] FacilityType with id 298 not found after 6 retries
동시간대 관련 에러 (같은 패턴):
service:cupixworks-worker status:error "FacilityType"
18:18:55.859Z [error] FacilityType with id 298 not found after 6 retries (SavePartialJsonToFileWorker#perform)
18:18:55.859Z [error] FacilityType with id 299 not found after 6 retries (SavePartialJsonToFileWorker#perform)
18:19:01.868Z [error] FacilityType with id 298 not found after 6 retries (SavePartialJsonToFileWorker#perform)
18:19:05.869Z [error] FacilityType with id 300 not found after 6 retries (SavePartialJsonToFileWorker#perform)
연속된 ID (298, 299, 300)가 동시에 실패한 것은 cascade_delete_children에 의한 일괄 삭제를 강하게 시사한다.
동시간대 다른 에러:
service:cupixworks-worker status:error
동일 시간대에 42건의 thumbnail 503 에러, 8건의 geo-coordinate TCP 연결 실패도 발생했으나, FacilityType 에러와는 직접적 관련이 없다.
Hypotheses Considered#
| # | Hypothesis | Evidence for | Evidence against | Verdict |
|---|---|---|---|---|
| H1 | FacilityType이 .touch 후 destroy!로 삭제되어 worker가 조회 실패하는 race condition |
연속 ID 298/299/300 동시 실패 → cascade_delete_children 일괄 삭제 패턴 일치; after_commit on: :update가 worker를 비동기로 enqueue하는 코드 확인 (partial_json.rb:70); worker의 6회 retry 모두 nil 반환 (로그 확인) |
— | Confirmed |
| H2 | FacilityType 레코드 자체는 존재하지만 team 삭제로 INNER JOIN이 nil 반환 | find_by_id가 joins(:team) 사용 (facility_type_repository.rb:122-124); INNER JOIN은 team 없으면 nil 반환 |
FacilityType은 validates :team_id, presence: true이므로 team_id 없이 생성 불가; 3개 ID 동시 실패는 team 삭제보다 FacilityType 직접 삭제가 더 개연성 높음; team 삭제 시 더 광범위한 에러가 예상됨 |
Rejected |
| H3 | DB replication lag으로 인한 일시적 조회 실패 | retry 로직이 존재하여 replication lag 대응을 의도한 것으로 보임 | 6.3초 동안 6회 모두 실패 — replication lag이 6초 이상 지속되는 것은 극히 드묾; 298/299/300 연속 ID 실패는 replication lag 패턴과 불일치 | Rejected |
Fix Recommendation#
즉시 조치 (Critical)#
SavePartialJsonToFileWorker에서 이미 삭제된 레코드에 대한 조회 실패를 error가 아닌 warn으로 처리해야 한다. 레코드 삭제 후 해당 레코드의 update worker가 실패하는 것은 정상적인 운영 시나리오이며, destroy 이벤트는 save_partial_json_to_file_as_destroyed에서 이미 동기적으로 처리되므로 data warehouse 동기화에 실제 영향이 없다.
- 수정 파일:
app/workers/save_partial_json_to_file_worker.rb:56-59 - 방향:
Cupix::Logger.error를Cupix::Logger.warn으로 변경. 레코드를 찾을 수 없는 경우 error 대신 warn으로 로깅하여 불필요한 error 노이즈를 제거.
단기 개선 (1주 이내)#
Worker enqueue 전에 레코드가 destroy 상태인지 확인하는 guard를 추가하거나, after_commit on: :destroy 콜백에서 pending worker job을 무효화하는 메커니즘을 도입. 예를 들어 worker에서 operation이 (updated)인데 레코드가 없으면 조용히 skip하는 로직 (destroy 콜백이 이미 파일을 생성했으므로).
장기 개선 (재발 방지)#
DataWareHouse::PartialJson의 update 콜백이 비동기 worker를 사용하는 반면 destroy 콜백은 동기적으로 처리하는 비대칭 구조를 검토. 가능한 접근:
- Update 콜백도 동기적으로 처리하여 race condition 원천 제거 (성능 영향 고려 필요)
- 또는 worker에 operation 타입을 전달하여, 레코드 미발견 시 destroy 이벤트가 이미 처리되었음을 인지하고 graceful하게 종료
Monitoring#
- FacilityType not found error가 warn으로 변경된 후에도 지속적으로 모니터링:
service:cupixworks-worker "not found after" "retries" status:warn
- 비정상적으로 빈번한 발생 감지:
service:cupixworks-worker "not found after" "retries" status:error
Risk Assessment#
- Risk level: low
- 예상 복잡도: trivial
- 근거: 삭제된 FacilityType의 update worker 실패는 data warehouse에 실질적 영향이 없음 (destroy 이벤트가 이미 동기적으로 처리됨). error → warn 변경만으로 노이즈 제거 가능.