fix(ledger): dcy-015 outbox 영속 오류 분류 + 백오프/dead-letter (BAT-019)
portfolio-hub 404(미등록 포트폴리오)가 retryable 로 분류되어 백오프·상한 없이 초당 영구 재시도되던 버그(issue #13, 실측 930회) 정정. 거버넌스: 전부 change-req (신규 REQ 없음, dcy-015 OQ-3; 백오프 env 는 REQ-019 흡수). - REQ-017: 404/400/422 → LedgerPermanentError 분류 (409 conflict / 408·429·5xx· network retryable 불변). LedgerPort 에 permanent 타입 추가 - REQ-019: 영속 → 터미널 delivery_failed 즉시(재시도 0). retryable 지수 백오프 +jitter+next_retry_at, max_attempts 초과 시 dead-letter delivery_failed. list_pending 이 백오프 행 스킵(head-of-line 보호). 마이그레이션 007(status enum +next_retry_at). 백오프 env(base/cap/max-attempts) - REQ-018: 터미널/dead-letter WARN + WriterStats.delivery_failed 카운터 가시화 - REQ-020: runtime-flows/data-model/interface-contract 정합 단일 터미널 delivery_failed(permanent/dead-letter, last_outcome 로 사유 구분) — conflict_blocked 패턴과 동형. dead-letter 는 운영자 재처리 가능 상태. 검증: 단위 311 passed/34 skipped, 인프라 게이트(PG+RabbitMQ) 345 passed, ruff clean. 신규 test_ledger_outbox_backoff + adapter/PG 테스트, 기존 retryable 백오프 정합. BAT-019 release-candidate. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
This commit is contained in:
@@ -9,39 +9,64 @@ of:
|
||||
completed -- adapter accepted (new ledger entry).
|
||||
duplicate_completed -- the correlation_id was already done in this outbox
|
||||
(local dedup, no adapter call).
|
||||
retryable_failure -- transient adapter failure; left pending for next tick.
|
||||
retryable_failure -- transient adapter failure; backoff + retry (next_retry_at).
|
||||
conflict_blocked -- portfolio-hub 409; operator must resolve, no retry.
|
||||
permanent_failure -- 404/400/422 client error; terminal immediately (dcy-015).
|
||||
dead_lettered -- retryable that exhausted max_attempts; terminal (dcy-015).
|
||||
|
||||
`permanent_failure` and `dead_lettered` both land in the single terminal
|
||||
`delivery_failed` status (distinguished by last_outcome/last_error), mirroring
|
||||
the `conflict_blocked` single-status pattern (dcy-015 OQ-2).
|
||||
|
||||
This separation (orbit `LedgerWriter` pattern) keeps slot transitions on the
|
||||
critical path while making ledger writes eventually-consistent and idempotent.
|
||||
"""
|
||||
from __future__ import annotations
|
||||
|
||||
import logging
|
||||
import random
|
||||
from dataclasses import dataclass, replace
|
||||
from datetime import datetime, timezone
|
||||
from datetime import datetime, timedelta, timezone
|
||||
from enum import Enum
|
||||
from typing import Optional, Protocol
|
||||
from typing import Callable, Optional, Protocol
|
||||
|
||||
from trex_core.application.ledger_port import (
|
||||
LedgerConflictError,
|
||||
LedgerPermanentError,
|
||||
LedgerPort,
|
||||
LedgerRetryableError,
|
||||
LedgerTrade,
|
||||
LedgerWriteResult,
|
||||
)
|
||||
|
||||
_log = logging.getLogger(__name__)
|
||||
|
||||
# dcy-015 / REQ-019: exponential backoff defaults (overridable via config/env).
|
||||
_DEFAULT_RETRY_BASE_SEC = 1.0
|
||||
_DEFAULT_RETRY_CAP_SEC = 300.0
|
||||
_DEFAULT_MAX_ATTEMPTS = 8
|
||||
|
||||
|
||||
class OutboxOutcome(str, Enum):
|
||||
COMPLETED = "completed"
|
||||
DUPLICATE_COMPLETED = "duplicate_completed"
|
||||
RETRYABLE_FAILURE = "retryable_failure"
|
||||
CONFLICT_BLOCKED = "conflict_blocked"
|
||||
PERMANENT_FAILURE = "permanent_failure" # dcy-015: 404/400/422 — terminal now
|
||||
DEAD_LETTERED = "dead_lettered" # dcy-015: retryable exhausted max_attempts
|
||||
|
||||
|
||||
class WorkItemStatus(str, Enum):
|
||||
PENDING = "pending" # awaiting next writer tick
|
||||
COMPLETED = "completed" # adapter accepted (terminal success)
|
||||
CONFLICT_BLOCKED = "conflict_blocked" # 409 — operator resolves (terminal failure)
|
||||
DELIVERY_FAILED = "delivery_failed" # dcy-015 — permanent or dead-lettered (terminal)
|
||||
|
||||
|
||||
# Outcomes that move a row to the terminal delivery_failed state.
|
||||
_DELIVERY_FAILED_OUTCOMES = frozenset(
|
||||
{OutboxOutcome.PERMANENT_FAILURE, OutboxOutcome.DEAD_LETTERED}
|
||||
)
|
||||
|
||||
|
||||
@dataclass(frozen=True)
|
||||
@@ -58,6 +83,9 @@ class LedgerWorkItem:
|
||||
attempts: int = 0
|
||||
last_outcome: Optional[OutboxOutcome] = None
|
||||
last_error: Optional[str] = None
|
||||
# dcy-015 / REQ-019: earliest time a retryable row may be re-attempted.
|
||||
# list_pending skips rows whose next_retry_at is still in the future.
|
||||
next_retry_at: Optional[datetime] = None
|
||||
created_at: Optional[datetime] = None
|
||||
updated_at: Optional[datetime] = None
|
||||
|
||||
@@ -83,8 +111,12 @@ class LedgerOutbox(Protocol):
|
||||
outcome: OutboxOutcome,
|
||||
*,
|
||||
error: Optional[str] = None,
|
||||
next_retry_at: Optional[datetime] = None,
|
||||
) -> LedgerWorkItem:
|
||||
"""Record the outcome of a writer attempt and advance status."""
|
||||
"""Record the outcome of a writer attempt and advance status.
|
||||
|
||||
For a retryable outcome `next_retry_at` schedules the backoff; terminal
|
||||
outcomes ignore it (dcy-015 / REQ-019)."""
|
||||
...
|
||||
|
||||
|
||||
@@ -94,6 +126,7 @@ class WriterStats:
|
||||
duplicates: int = 0
|
||||
retryable: int = 0
|
||||
conflicts: int = 0
|
||||
delivery_failed: int = 0 # dcy-015: permanent + dead-lettered terminals
|
||||
|
||||
|
||||
class LedgerWriter:
|
||||
@@ -104,9 +137,25 @@ class LedgerWriter:
|
||||
the adapter (REQ-019 AC-4).
|
||||
"""
|
||||
|
||||
def __init__(self, outbox: LedgerOutbox, ledger: LedgerPort) -> None:
|
||||
def __init__(
|
||||
self,
|
||||
outbox: LedgerOutbox,
|
||||
ledger: LedgerPort,
|
||||
*,
|
||||
retry_base_sec: float = _DEFAULT_RETRY_BASE_SEC,
|
||||
retry_cap_sec: float = _DEFAULT_RETRY_CAP_SEC,
|
||||
max_attempts: int = _DEFAULT_MAX_ATTEMPTS,
|
||||
clock: Optional[Callable[[], datetime]] = None,
|
||||
rng: Optional[Callable[[], float]] = None,
|
||||
) -> None:
|
||||
self._outbox = outbox
|
||||
self._ledger = ledger
|
||||
# dcy-015 / REQ-019: exponential backoff + jitter + max-attempts cap.
|
||||
self._retry_base = retry_base_sec
|
||||
self._retry_cap = retry_cap_sec
|
||||
self._max_attempts = max_attempts
|
||||
self._clock = clock or (lambda: datetime.now(tz=timezone.utc))
|
||||
self._rng = rng or random.random # jitter source; inject for determinism
|
||||
|
||||
def enqueue_fill(self, trade: LedgerTrade) -> LedgerWorkItem:
|
||||
return self._outbox.enqueue(trade)
|
||||
@@ -123,8 +172,15 @@ class LedgerWriter:
|
||||
stats.retryable += 1
|
||||
elif outcome is OutboxOutcome.CONFLICT_BLOCKED:
|
||||
stats.conflicts += 1
|
||||
elif outcome in _DELIVERY_FAILED_OUTCOMES:
|
||||
stats.delivery_failed += 1
|
||||
return stats
|
||||
|
||||
def _backoff_delay(self, attempts: int) -> float:
|
||||
"""Exponential backoff with jitter: min(base*2^(n-1), cap) + up to 25%."""
|
||||
base_delay = min(self._retry_base * (2 ** (attempts - 1)), self._retry_cap)
|
||||
return base_delay * (1.0 + 0.25 * self._rng())
|
||||
|
||||
def _process(self, item: LedgerWorkItem) -> OutboxOutcome:
|
||||
# Local dedup: another writer pass (or restart) already completed this
|
||||
# outbox row. Skip the adapter call.
|
||||
@@ -139,9 +195,36 @@ class LedgerWriter:
|
||||
item.correlation_id, OutboxOutcome.CONFLICT_BLOCKED, error=str(exc)
|
||||
)
|
||||
return OutboxOutcome.CONFLICT_BLOCKED
|
||||
except LedgerRetryableError as exc:
|
||||
except LedgerPermanentError as exc:
|
||||
# dcy-015 / REQ-017/018 (issue #13): non-retryable client error →
|
||||
# terminal delivery_failed immediately (no retry spam). Surface for ops.
|
||||
self._outbox.mark_outcome(
|
||||
item.correlation_id, OutboxOutcome.RETRYABLE_FAILURE, error=str(exc)
|
||||
item.correlation_id, OutboxOutcome.PERMANENT_FAILURE, error=str(exc)
|
||||
)
|
||||
_log.warning(
|
||||
"ledger delivery_failed (permanent): correlation_id=%s reason=%s",
|
||||
item.correlation_id, exc,
|
||||
)
|
||||
return OutboxOutcome.PERMANENT_FAILURE
|
||||
except LedgerRetryableError as exc:
|
||||
# dcy-015 / REQ-019: backoff, or dead-letter once max_attempts hit.
|
||||
new_attempts = item.attempts + 1
|
||||
if new_attempts >= self._max_attempts:
|
||||
self._outbox.mark_outcome(
|
||||
item.correlation_id, OutboxOutcome.DEAD_LETTERED, error=str(exc)
|
||||
)
|
||||
_log.warning(
|
||||
"ledger delivery_failed (dead-letter, attempts=%d): "
|
||||
"correlation_id=%s reason=%s",
|
||||
new_attempts, item.correlation_id, exc,
|
||||
)
|
||||
return OutboxOutcome.DEAD_LETTERED
|
||||
next_retry_at = self._clock() + timedelta(
|
||||
seconds=self._backoff_delay(new_attempts)
|
||||
)
|
||||
self._outbox.mark_outcome(
|
||||
item.correlation_id, OutboxOutcome.RETRYABLE_FAILURE,
|
||||
error=str(exc), next_retry_at=next_retry_at,
|
||||
)
|
||||
return OutboxOutcome.RETRYABLE_FAILURE
|
||||
# Adapter-level dedup (server says "already recorded"): outcome is
|
||||
@@ -159,16 +242,18 @@ class LedgerWriter:
|
||||
class InMemoryLedgerOutbox:
|
||||
"""Process-local outbox. Thread-safe; idempotent on correlation_id."""
|
||||
|
||||
def __init__(self) -> None:
|
||||
def __init__(self, *, clock: Optional[Callable[[], datetime]] = None) -> None:
|
||||
import threading
|
||||
|
||||
self._rows: dict[str, LedgerWorkItem] = {}
|
||||
self._order: list[str] = []
|
||||
self._lock = threading.Lock()
|
||||
# dcy-015: shared clock lets tests align backoff (next_retry_at) with
|
||||
# list_pending's "now" deterministically.
|
||||
self._clock = clock or (lambda: datetime.now(tz=timezone.utc))
|
||||
|
||||
@staticmethod
|
||||
def _now() -> datetime:
|
||||
return datetime.now(tz=timezone.utc)
|
||||
def _now(self) -> datetime:
|
||||
return self._clock()
|
||||
|
||||
def enqueue(self, trade: LedgerTrade) -> LedgerWorkItem:
|
||||
with self._lock:
|
||||
@@ -188,11 +273,16 @@ class InMemoryLedgerOutbox:
|
||||
return row
|
||||
|
||||
def list_pending(self, limit: int = 32) -> list[LedgerWorkItem]:
|
||||
now = self._now()
|
||||
with self._lock:
|
||||
out: list[LedgerWorkItem] = []
|
||||
for cid in self._order:
|
||||
row = self._rows[cid]
|
||||
if row.status is WorkItemStatus.PENDING:
|
||||
# dcy-015 / REQ-019: skip rows still in backoff so they don't
|
||||
# occupy the FIFO batch (head-of-line protection, NFR-3).
|
||||
if row.status is WorkItemStatus.PENDING and (
|
||||
row.next_retry_at is None or row.next_retry_at <= now
|
||||
):
|
||||
out.append(row)
|
||||
if len(out) >= limit:
|
||||
break
|
||||
@@ -208,6 +298,7 @@ class InMemoryLedgerOutbox:
|
||||
outcome: OutboxOutcome,
|
||||
*,
|
||||
error: Optional[str] = None,
|
||||
next_retry_at: Optional[datetime] = None,
|
||||
) -> LedgerWorkItem:
|
||||
with self._lock:
|
||||
row = self._rows[correlation_id]
|
||||
@@ -215,6 +306,8 @@ class InMemoryLedgerOutbox:
|
||||
new_status = WorkItemStatus.COMPLETED
|
||||
elif outcome is OutboxOutcome.CONFLICT_BLOCKED:
|
||||
new_status = WorkItemStatus.CONFLICT_BLOCKED
|
||||
elif outcome in _DELIVERY_FAILED_OUTCOMES:
|
||||
new_status = WorkItemStatus.DELIVERY_FAILED # dcy-015 terminal
|
||||
elif outcome is OutboxOutcome.DUPLICATE_COMPLETED:
|
||||
# already terminal; keep COMPLETED status
|
||||
new_status = WorkItemStatus.COMPLETED
|
||||
@@ -226,6 +319,9 @@ class InMemoryLedgerOutbox:
|
||||
attempts=row.attempts + (0 if outcome is OutboxOutcome.DUPLICATE_COMPLETED else 1),
|
||||
last_outcome=outcome,
|
||||
last_error=error,
|
||||
next_retry_at=(
|
||||
next_retry_at if outcome is OutboxOutcome.RETRYABLE_FAILURE else None
|
||||
),
|
||||
updated_at=self._now(),
|
||||
)
|
||||
self._rows[correlation_id] = updated
|
||||
|
||||
Reference in New Issue
Block a user