Quote#schedule_apply! logs validation errors as ERROR — missing exception filtering
RCA: [Quote][GYVGXJU55F] Quote application failed: Billable already has a scheduled quote: 870
Overview#
What Happened#
2026-07-22 00:54 KST 경 cupixworks-api (production, ap-southeast-2) 에서 back-office 담당자가 PUT /api/v1/admin/quotes/{id}/apply 로 미래 시작일(2026-07-29) 의 Quote 를 Workspace 530 에 적용하려다 BILL10000 — Billable already has a scheduled quote: 870 로 실패했다. 직전 00:53 에 이미 다른 Quote(number R3B14IOIQL, id 870) 가 같은 Workspace 에 스케줄된 상태였기 때문이다. 이후 약 15분 동안 담당자가 6개의 서로 다른 Quote 로 재시도하며 동일 에러가 반복되어 총 7건이 error 로그로 남았다.
Quick Facts#
| Field | Value |
|---|---|
| exception.class | Cupix::Errors::Billing |
| exception.message | Billable already has a scheduled quote: 870 |
| error.code | BILL10000 |
| top_frame | app/models/quote.rb (schedule_apply!) |
| env | production / ap-southeast-2 |
| tenant | cupix |
| HTTP status | 400 (PUT /api/v1/admin/quotes/{id}/apply) |
Affected Teams#
| Team / Domain | Error Count | Impact |
|---|---|---|
| Back office / Accounting (Retool) | 7 (Workspace 530 대상 반복 재시도) | 미래 시작일 Quote 를 적용하지 못해 라이선스 발급 워크플로우가 15분간 진행되지 않음. 실제 서비스 사용자 영향 없음. |
Timeline#
- 2026-07-22 00:53:07 KST — Quote
R3B14IOIQL(id 870) 가 Workspace 530 에Schedule quote application for 2026-07-29로 정상 등록됨 →workspace.scheduled_quote_id = 870세팅. - 2026-07-22 00:54:03 KST — Quote
GYVGXJU55F로 재적용 시도 →Billable already has a scheduled quote: 870(본 클러스터의 first_seen). - 2026-07-22 00:54:19 KST — Quote
M9X89PV6G6(id 874) 재시도 → 동일 에러. - 2026-07-22 00:55:27 KST — Quote
ZT5TKAT9CA(id 876) 재시도 → 동일 에러. - 2026-07-22 00:58:15 KST — Quote
F43544W7U8(id 878) 재시도 → 동일 에러. - 2026-07-22 01:06:13 KST — Quote
VA8VQHH64X(id 880) 재시도 → 동일 에러. - 2026-07-22 01:06:49 KST — Quote
N7KE58TH44(id 884) 재시도 → 동일 에러. - 2026-07-22 01:08:37 KST — Quote
U5XQ1208JW(id 886) 재시도 → 동일 에러. 이후 재시도 중단.
Error Log#
[Quote][GYVGXJU55F] Quote application failed: Billable already has a scheduled quote: 870
Impact#
- Service:
cupixworks-api - 발생 횟수: 1 (본 fingerprint) / 실제로는 동일 원인으로 7건이 15분 사이 발생
- 최초 발생: 2026-07-22 00:54:03 KST
- 최근 발생: 2026-07-22 00:54:03 KST
Root Cause Summary#
TSLA-12975 (defer billing switch for future-dated quote applies) 로 도입된 Quote#schedule_apply! 는 billable(Workspace 530) 에 이미 scheduled_quote_id 가 세팅되어 있고 그 값이 현재 적용하려는 Quote 의 id 와 다르면 Cupix::Errors::Billing (BILL10000) 을 raise 한다. 담당자가 00:53 에 Quote 870 을 미래 시작일(2026-07-29) 로 정상 스케줄한 뒤, 00:54 부터 서로 다른 Quote 번호로 재적용을 반복 시도하면서 이 방어 로직에 걸린 것이 근본 원인이다. 즉 정상 방어 로직이 back-office 재시도 시나리오를 error 레벨로 로깅하여 노이즈로 감지된 케이스이며, 서비스 사용자 영향은 없다. 다만 (1) 재시도가 15분간 7회 반복된 점, (2) HTTP 400 (client-side input error) 임에도 서버 error 로그로 남는 점, (3) 담당자가 새 Quote 로 대체하려는 의도인지 실수인지 UX 상 명확하지 않은 점이 개선 여지로 남는다.
Technical Analysis#
Code Path#
- Entry point:
app/controllers/api/v1/admin/quotes_controller.rb:37(Api::V1::Admin::QuotesController#apply) - Repository:
app/repositories/admin/quote_repository.rb:45(Admin::QuoteRepository#apply→@model.apply!) - Model orchestrator:
app/models/quote.rb(Quote#apply!) — 로그Quote application begins ...를 남긴 뒤 미래 시작일이면schedule_apply!분기. - Failure point:
Quote#schedule_apply!— TSLA-12975 (2f412c97d) 에서 신규 추가된 private 메서드.
controller/repository 진입:
def apply
@model = repository_instance.apply
show
end
def apply
raise Cupix::Errors::Billing.new(code: 'BILL10000', reason: 'Permission denied operation: Only accounting deparment can apply the quote') unless Pundit.policy(self.current_user, @model).apply?
@model.apply!
@model
end
Quote 모델 진입 및 미래 시작일 분기 (TSLA-12975 이후):
def apply!
Cupix::Logger.info("[Quote][#{number}] Quote application begins #{billable.class.name} #{billable.id}")
check_appliable
_billing_started_at, _billing_expires_at = extract_billing_dates
if _billing_expires_at > MAX_BILLING_EXPIRES_AT
raise Cupix::Errors::Parameter.new(code: 'ARG14000', reason: 'Billing expiration date exceeds the maximum allowed value')
end
ActiveRecord::Base.transaction do
if _billing_started_at > Time.zone.today
schedule_apply!(_billing_started_at)
else
activate_apply!(_billing_started_at, _billing_expires_at)
end
end
rescue Cupix::Errors::Parameter => e
Cupix::Logger.error("[Quote][#{number}] Invalid Parameter : #{e.message}", ...)
raise e
rescue StandardError => e
Cupix::Logger.error("[Quote][#{number}] Quote application failed: #{e.message}")
raise e
실제 실패 지점 — schedule_apply! 의 첫 가드:
def schedule_apply!(billing_started_at)
if billable.scheduled_quote_id.present? && billable.scheduled_quote_id != id
raise Cupix::Errors::Billing.new(
code: 'BILL10000',
reason: "Billable already has a scheduled quote: #{billable.scheduled_quote_id}"
)
end
Cupix::Logger.info("[Quote][#{number}] Schedule quote application for #{billing_started_at} on #{billable.class.name} #{billable.id}")
billable.update!(
scheduled_quote: self,
scheduled_billing_started_at: billing_started_at
)
applied_state! if state_paid?
end
activate_apply! 는 정상 종료 시 scheduled_quote: nil 로 초기화하지만, 스케줄된 Quote 를 다른 Quote 로 교체하는 경로는 존재하지 않는다. 따라서 어떤 Quote 든 scheduled_quote_id 가 이미 다른 값으로 세팅되어 있으면 새 Quote 는 적용될 수 없다.
update_attrs = {
quote: self,
billing_started_at: billing_started_at,
billing_expires_at: billing_expires_at,
# ...
scheduled_quote: nil,
scheduled_billing_started_at: nil
}
billable.update!(update_attrs)
기대 동작: 담당자가 새 Quote 를 apply 하면, 이전 스케줄된 Quote 는 자동으로 취소되거나 명시적 취소 API 를 통해 정리된 뒤 새 Quote 가 스케줄되어야 함.
실제 동작: 이전 스케줄 Quote(id 870) 가 그대로 남아 있어 신규 apply 가 모두 400 으로 튕겨나가며, 담당자가 다른 Quote 번호로 여러 번 재시도해도 결과는 동일.
Log Evidence#
Datadog 쿼리 (본 클러스터):
service:cupixworks-api status:error @environment:production "[Quote][GYVGXJU55F] Quote application failed: Billable already has a scheduled quote: 870"
동일 Workspace/원인의 확장 쿼리:
service:cupixworks-api "scheduled quote"
핵심 로그 시퀀스 (Workspace 530 기준):
2026-07-22 00:53:07 INFO [Quote][R3B14IOIQL] Quote application begins Workspace 530
2026-07-22 00:53:07 INFO [Quote][R3B14IOIQL] Schedule quote application for 2026-07-29 on Workspace 530
2026-07-22 00:54:03 INFO [Quote][GYVGXJU55F] Quote application begins Workspace 530
2026-07-22 00:54:03 ERROR [Quote][GYVGXJU55F] Quote application failed: Billable already has a scheduled quote: 870
2026-07-22 00:54:19 INFO [Quote][M9X89PV6G6] Quote application begins Workspace 530
2026-07-22 00:54:19 ERROR [Quote][M9X89PV6G6] Quote application failed: Billable already has a scheduled quote: 870
2026-07-22 00:55:27 ERROR [Quote][ZT5TKAT9CA] Quote application failed: Billable already has a scheduled quote: 870
2026-07-22 00:58:15 ERROR [Quote][F43544W7U8] Quote application failed: Billable already has a scheduled quote: 870
2026-07-22 01:06:13 ERROR [Quote][VA8VQHH64X] Quote application failed: Billable already has a scheduled quote: 870
2026-07-22 01:06:49 ERROR [Quote][N7KE58TH44] Quote application failed: Billable already has a scheduled quote: 870
2026-07-22 01:08:37 ERROR [Quote][U5XQ1208JW] Quote application failed: Billable already has a scheduled quote: 870
각 실패는 HTTP 400 응답으로 이어짐:
{
"message": "[400] PUT /api/v1/admin/quotes/886/apply (Api::V1::Admin::QuotesController#apply)",
"error": {
"reason": "Billable already has a scheduled quote: 870",
"code": "BILL10000",
"message": "Billable already has a scheduled quote: 870",
"class": "Cupix::Errors::Billing"
}
}
R3B14IOIQL 로그만 유일하게 Schedule quote application for 2026-07-29 정상 정보 로그로 마무리되고, 이후 모든 재시도 Quote 는 error 로그만 남긴다 → 재시도 담당자가 첫 번째 스케줄된 Quote 를 인지하지 못했거나 교체하려는 시나리오로 추정.
Hypotheses Considered#
| # | Hypothesis | Evidence for | Evidence against | Verdict |
|---|---|---|---|---|
| H1 | back-office 담당자가 미래 시작일(2026-07-29) Quote 를 이미 스케줄한 뒤(Quote id 870), 다른 Quote 번호로 재적용을 반복 시도하여 schedule_apply! 의 기존 스케줄 가드에 걸림 |
00:53:07 R3B14IOIQL info 로그(Schedule quote application for 2026-07-29 on Workspace 530) 뒤 00:54~01:08 사이 7건의 다른 quote 번호로 PUT /api/v1/admin/quotes/{876,878,880,884,886,...}/apply 요청이 모두 동일 workspace 530 에서 발생. code path app/models/quote.rb#schedule_apply! 의 raise 조건과 로그 메시지가 정확히 일치. |
— | Confirmed |
| H2 | 동시성/race condition — 여러 Quote 가 동시에 apply 되면서 scheduled_quote_id 세팅과 충돌 |
없음 | 로그 타임스탬프가 16초~2분 간격으로 순차 발생. 동일 tid/session 재시도 패턴. apply! 는 ActiveRecord::Base.transaction 안에서 실행되어 원자적. |
Rejected |
| H3 | 데이터 무결성 손상 — scheduled_quote_id 필드가 오래된 데드 데이터로 남아 있음 |
없음 | 직전 성공 로그(R3B14IOIQL → id 870, 00:53:07)가 명확히 존재. 정상 세팅된 값. |
Rejected |
| H4 | 신규 배포된 TSLA-12975 코드의 회귀 — 예전에는 통과하던 케이스가 새로 raise 됨 | TSLA-12975(2f412c97d) 가 schedule_apply! 및 해당 raise 를 신규 도입한 것은 사실 (git show 확인) |
도입된 가드는 의도적(미래 스케줄 중복 방지) 이며 raise 메시지도 설계된 값. spec spec/lib/cupix/cron/scheduled_quote_spec.rb, spec/models/quote_spec.rb 가 함께 추가됨. 회귀가 아닌 by-design 동작. |
Rejected (by-design) |
Fix Recommendation#
본 에러는 코드 결함이 아니라 정상 방어 로직이 back-office 재시도 UX 로 인해 error 레벨로 다량 노출된 케이스다. 아래 개선안은 우선순위 순.
즉시 조치 (Critical)#
- 별도의 코드 즉시 조치는 필요하지 않음(서비스 사용자 영향 없음, 이미 배포된 로직대로 정상 동작).
- 운영/CS 채널에 back-office 담당자에게 "Workspace 530 에 이미 미래 스케줄 Quote(id 870, 시작일 2026-07-29) 가 존재하므로 새 Quote 로 대체하려면 별도의 취소/해제 절차가 필요하다" 를 안내 (프런트엔드/운영 조율 필요 — 자동 code-fix 대상 아님).
단기 개선 (1주 이내)#
- Log level 조정:
app/models/quote.rb의apply!에 있는rescue StandardError => e→Cupix::Logger.error("[Quote][#{number}] Quote application failed: #{e.message}")을Cupix::Errors::Billing(특히BILL10000계열의 사용자 입력 검증성 예외) 에 한해warn으로 낮추는 것을 검토. 무결성/시스템 오류는error유지. 그렇지 않으면 back-office 담당자의 정상 재시도가 매번 error 알림/대시보드 오염을 유발함. - 스케줄 취소 API 필요성 재확인:
schedule_apply!에서 세팅되는billable.scheduled_quote_id를 다른 Quote 로 교체하거나 취소하는 admin API 가 있는지 검토. 없다면 back-office 팀 요청 사항으로 도입. - 에러 응답 개선:
PUT /api/v1/admin/quotes/{id}/apply응답의error.reason에 기존 스케줄 Quote id 뿐 아니라number와scheduled_billing_started_at도 함께 노출하여 Retool UI 에서 담당자가 상황을 즉시 파악할 수 있도록.
장기 개선 (재발 방지)#
- Retool back-office 화면에서 Workspace/Team/Facility 의 현재
scheduled_quote_id및scheduled_billing_started_at을 apply 화면 진입 시점부터 노출하여 중복 시도 자체를 사전에 차단. - 스케줄 Quote 의 라이프사이클(생성 → 대기 → cron 활성화 or 취소) 이 문서화되었는지
docs/license-creation-flow.md에 확인/보강. 특히 "이미 스케줄된 Quote 가 있을 때 새 Quote 를 어떻게 대체하나?" 는 현재 문서에 없음.
Monitoring#
schedule_apply! 가드에 걸리는 빈도를 별도 계측하여 반복 시도 시 back-office 팀에 알림. 현재는 일반 error 와 섞여 있어 노이즈 판별이 어렵다.
Datadog Log-based Metric 쿼리 (release dashboard timeseries widget 용):
service:cupixworks-api @environment:production "Billable already has a scheduled quote"
전체 Quote apply 실패 추이:
service:cupixworks-api @environment:production "Quote application failed"
동일 billable 반복 재시도 감지용 (Workspace/Team/Facility id 별 분포는 대시보드 group-by 로 처리):
service:cupixworks-api @environment:production "Quote application begins Workspace"
주의: 위 쿼리들은 monitor-only 문법(| stats, count by(...) 등) 을 포함하지 않으므로 timeseries widget 에 그대로 사용 가능. group-by 는 widget 설정에서 지정.
Risk Assessment#
- Risk level: low — 서비스 사용자 영향 없음. 방어 로직이 정상 동작한 케이스이며, 데이터 손상이나 재정 손실 없음. 다만 back-office 워크플로우 지연(15분) 및 error 로그 노이즈 발생.
- 예상 복잡도: trivial — 즉시 조치 불필요. log-level 조정만 진행할 경우 trivial. 스케줄 취소 API 신설까지 확장하면 standard.