trex/trex-core
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Merge pull request #90 from fourblocks2020/copilot/bug-ledger-shared-outbox-consumption

Browse Source 
Isolate ledger outbox delivery by instance and add lease-based claims
This commit is contained in:
genichin
2026-09-13 10:48:57 +09:00
committed by GitHub
parent 60a835fde1 762a953c95
commit 3cb0fdc303
18 changed files with 817 additions and 133 deletions
Download Patch File Download Diff File Expand all files Collapse all files
trex_core/application/ledger_outbox.py
+212 -19
View File
@@ -66,6 +66,10 @@ class WorkItemStatus(str, Enum):
DELIVERY_FAILED = "delivery_failed" # dcy-015 — permanent or dead-lettered (terminal)
class OutboxClaimLostError(RuntimeError):
"""The caller no longer owns the lease required for an outcome update."""
# Outcomes that move a row to the terminal delivery_failed state.
_DELIVERY_FAILED_OUTCOMES = frozenset(
{OutboxOutcome.PERMANENT_FAILURE, OutboxOutcome.DEAD_LETTERED}
@@ -104,11 +108,18 @@ class LedgerWorkItem:
next_retry_at: Optional[datetime] = None
created_at: Optional[datetime] = None
updated_at: Optional[datetime] = None
instance_key: Optional[str] = None
claim_expires_at: Optional[datetime] = None
class LedgerOutbox(Protocol):
"""Durable work-item store backing the ledger writer."""
@property
def instance_key(self) -> str:
"""Immutable owner partition for rows handled by this outbox."""
...
def enqueue(self, trade: LedgerTrade) -> LedgerWorkItem:
"""Enqueue a trade. Idempotent on correlation_id (returns the
existing row unchanged if it is already present)."""
@@ -118,6 +129,15 @@ class LedgerOutbox(Protocol):
"""Return pending work items in FIFO order, up to `limit`."""
...
def claim_pending(
self,
limit: int = 32,
*,
correlation_id: str | None = None,
) -> list[LedgerWorkItem]:
"""Atomically claim pending items for delivery."""
...
def pending_cash_delta(self) -> dict[str, float]:
"""Sum the estimated cash delta of ALL not-yet-settled (pending) rows,
grouped by asset_id (dcy-018 / REQ-029, OQ-4 estimate overlay).
@@ -136,6 +156,7 @@ class LedgerOutbox(Protocol):
*,
error: Optional[str] = None,
next_retry_at: Optional[datetime] = None,
expected_claim_expires_at: Optional[datetime] = None,
) -> LedgerWorkItem:
"""Record the outcome of a writer attempt and advance status.
@@ -151,6 +172,7 @@ class WriterStats:
retryable: int = 0
conflicts: int = 0
delivery_failed: int = 0 # dcy-015: permanent + dead-lettered terminals
claim_lost: int = 0
class LedgerWriter:
@@ -190,15 +212,46 @@ class LedgerWriter:
# dcy-033 / REQ-100: best-effort alarm emitter.
self._alarm_emitter = alarm_emitter
self._ledger_skip_store = ledger_skip_store
self._instance_key = instance_key
resolved_instance_key = outbox.instance_key if instance_key is None else instance_key
if not isinstance(resolved_instance_key, str) or not resolved_instance_key.strip():
raise ValueError("instance_key must be a non-empty string")
if resolved_instance_key != outbox.instance_key:
raise ValueError("writer instance_key must match outbox instance_key")
self._instance_key = resolved_instance_key
self.counters: dict[str, int] = {}
def _count(self, key: str) -> None:
self.counters[key] = self.counters.get(key, 0) + 1
def enqueue_fill(self, trade: LedgerTrade) -> LedgerWorkItem:
return self._outbox.enqueue(trade)
def run_once(self, limit: int = 32) -> WriterStats:
stats = WriterStats()
for item in self._outbox.list_pending(limit):
outcome = self._process(item)
items = self._outbox.claim_pending(limit)
claim_result = "claimed" if items else "empty"
self._count(f"claim:{claim_result}")
_log.info(
"ledger outbox claim: instance_key=%s claim_result=%s count=%d limit=%d",
self._instance_key,
claim_result,
len(items),
limit,
)
for item in items:
if not self._validate_instance(item):
continue
try:
outcome = self._process(item)
except OutboxClaimLostError:
self._count("claim:lost")
stats.claim_lost += 1
_log.warning(
"ledger outbox claim lost: instance_key=%s correlation_id=%s",
self._instance_key,
item.correlation_id,
)
continue
if outcome is OutboxOutcome.COMPLETED:
stats.completed += 1
elif outcome is OutboxOutcome.DUPLICATE_COMPLETED:
@@ -216,7 +269,50 @@ class LedgerWriter:
item = self._outbox.get(correlation_id)
if item is None:
return None
return self._process(item)
if not self._validate_instance(item):
return None
if item.status is WorkItemStatus.PENDING:
claimed = self._outbox.claim_pending(1, correlation_id=correlation_id)
if not claimed:
self._count("claim:unavailable")
_log.info(
"ledger outbox claim: instance_key=%s claim_result=unavailable "
"correlation_id=%s",
self._instance_key,
correlation_id,
)
return None
item = claimed[0]
self._count("claim:claimed")
_log.info(
"ledger outbox claim: instance_key=%s claim_result=claimed "
"count=%d correlation_id=%s",
self._instance_key,
len(claimed),
correlation_id,
)
try:
return self._process(item)
except OutboxClaimLostError:
self._count("claim:lost")
_log.warning(
"ledger outbox claim lost: instance_key=%s correlation_id=%s",
self._instance_key,
correlation_id,
)
return None
def _validate_instance(self, item: LedgerWorkItem) -> bool:
if item.instance_key == self._instance_key:
return True
self._count("claim:foreign_instance")
_log.warning(
"ledger outbox claim rejected: instance_key=%s "
"claim_result=foreign_or_unowned correlation_id=%s",
self._instance_key,
item.correlation_id,
)
return False
def _backoff_delay(self, attempts: int) -> float:
"""Exponential backoff with jitter: min(base*2^(n-1), cap) + up to 25%."""
@@ -228,14 +324,18 @@ class LedgerWriter:
# outbox row. Skip the adapter call.
existing = self._outbox.get(item.correlation_id)
if existing is not None and existing.status is WorkItemStatus.COMPLETED:
self._outbox.mark_outcome(item.correlation_id, OutboxOutcome.DUPLICATE_COMPLETED)
self._log_outcome(item, OutboxOutcome.DUPLICATE_COMPLETED)
return OutboxOutcome.DUPLICATE_COMPLETED
try:
outcome = self._ledger.record_trade(item.trade)
except LedgerConflictError as exc:
self._outbox.mark_outcome(
item.correlation_id, OutboxOutcome.CONFLICT_BLOCKED, error=str(exc)
item.correlation_id,
OutboxOutcome.CONFLICT_BLOCKED,
error=str(exc),
expected_claim_expires_at=item.claim_expires_at,
)
self._log_outcome(item, OutboxOutcome.CONFLICT_BLOCKED)
# dcy-033 / REQ-100: CRITICAL alarm — 409 conflict, operator resolution needed.
if self._alarm_emitter is not None:
self._alarm_emitter.publish_alarm(
@@ -250,11 +350,16 @@ class LedgerWriter:
# 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.PERMANENT_FAILURE, error=str(exc)
item.correlation_id,
OutboxOutcome.PERMANENT_FAILURE,
error=str(exc),
expected_claim_expires_at=item.claim_expires_at,
)
self._log_outcome(item, OutboxOutcome.PERMANENT_FAILURE)
_log.warning(
"ledger delivery_failed (permanent): correlation_id=%s reason=%s",
item.correlation_id, exc,
"ledger delivery_failed (permanent): instance_key=%s correlation_id=%s",
item.instance_key or self._instance_key,
item.correlation_id,
)
# dcy-033 / REQ-100: CRITICAL alarm — permanent failure, no retry.
if self._alarm_emitter is not None:
@@ -271,12 +376,18 @@ class LedgerWriter:
new_attempts = item.attempts + 1
if new_attempts >= self._max_attempts:
self._outbox.mark_outcome(
item.correlation_id, OutboxOutcome.DEAD_LETTERED, error=str(exc)
item.correlation_id,
OutboxOutcome.DEAD_LETTERED,
error=str(exc),
expected_claim_expires_at=item.claim_expires_at,
)
self._log_outcome(item, OutboxOutcome.DEAD_LETTERED)
_log.warning(
"ledger delivery_failed (dead-letter, attempts=%d): "
"correlation_id=%s reason=%s",
new_attempts, item.correlation_id, exc,
"instance_key=%s correlation_id=%s",
new_attempts,
item.instance_key or self._instance_key,
item.correlation_id,
)
# dcy-033 / REQ-100: CRITICAL alarm — dead-lettered after max retries.
if self._alarm_emitter is not None:
@@ -294,8 +405,11 @@ class LedgerWriter:
)
self._outbox.mark_outcome(
item.correlation_id, OutboxOutcome.RETRYABLE_FAILURE,
error=str(exc), next_retry_at=next_retry_at,
error=str(exc),
next_retry_at=next_retry_at,
expected_claim_expires_at=item.claim_expires_at,
)
self._log_outcome(item, OutboxOutcome.RETRYABLE_FAILURE)
return OutboxOutcome.RETRYABLE_FAILURE
# dcy-018 / REQ-019/030 (option D): write back portfolio-hub authoritative
# cash/quantity to the snapshot store on new+duplicate (OQ-2 b). *_after
@@ -306,13 +420,37 @@ class LedgerWriter:
# duplicate_completed; the ledger has exactly one entry for this
# execution_id either way (REQ-019 AC-1, AC-4).
if outcome.result is LedgerWriteResult.DUPLICATE_OK:
self._outbox.mark_outcome(item.correlation_id, OutboxOutcome.DUPLICATE_COMPLETED)
self._outbox.mark_outcome(
item.correlation_id,
OutboxOutcome.DUPLICATE_COMPLETED,
expected_claim_expires_at=item.claim_expires_at,
)
self._resolve_ledger_skip(item.trade)
self._log_outcome(item, OutboxOutcome.DUPLICATE_COMPLETED)
return OutboxOutcome.DUPLICATE_COMPLETED
self._outbox.mark_outcome(item.correlation_id, OutboxOutcome.COMPLETED)
self._outbox.mark_outcome(
item.correlation_id,
OutboxOutcome.COMPLETED,
expected_claim_expires_at=item.claim_expires_at,
)
self._resolve_ledger_skip(item.trade)
self._log_outcome(item, OutboxOutcome.COMPLETED)
return OutboxOutcome.COMPLETED
def _log_outcome(
self,
item: LedgerWorkItem,
outcome: OutboxOutcome,
) -> None:
self._count(f"outcome:{outcome.value}")
msg = "ledger outbox outcome: instance_key=%s correlation_id=%s outcome=%s"
args: tuple[object, ...] = (
item.instance_key or self._instance_key,
item.correlation_id,
outcome.value,
)
_log.info(msg, *args)
def _resolve_ledger_skip(self, trade: LedgerTrade) -> None:
if (
self._ledger_skip_store is None
@@ -349,7 +487,7 @@ class LedgerWriter:
except Exception: # noqa: BLE001 - write-back must not block the ledger path
_log.warning(
"snapshot cash/position write-back failed: asset_id=%s",
trade.asset_id, exc_info=True,
trade.asset_id,
)
@@ -358,7 +496,13 @@ class LedgerWriter:
class InMemoryLedgerOutbox:
"""Process-local outbox. Thread-safe; idempotent on correlation_id."""
def __init__(self, *, clock: Optional[Callable[[], datetime]] = None) -> None:
def __init__(
self,
*,
clock: Optional[Callable[[], datetime]] = None,
instance_key: str,
claim_ttl_sec: float = 60.0,
) -> None:
import threading
self._rows: dict[str, LedgerWorkItem] = {}
@@ -367,6 +511,16 @@ class InMemoryLedgerOutbox:
# 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))
if not isinstance(instance_key, str) or not instance_key.strip():
raise ValueError("instance_key must be a non-empty string")
if claim_ttl_sec <= 0:
raise ValueError("claim_ttl_sec must be positive")
self._instance_key = instance_key
self._claim_ttl_sec = claim_ttl_sec
@property
def instance_key(self) -> str:
return self._instance_key
def _now(self) -> datetime:
return self._clock()
@@ -383,6 +537,7 @@ class InMemoryLedgerOutbox:
status=WorkItemStatus.PENDING,
created_at=self._now(),
updated_at=self._now(),
instance_key=self._instance_key,
)
self._rows[cid] = row
self._order.append(cid)
@@ -396,14 +551,45 @@ class InMemoryLedgerOutbox:
row = self._rows[cid]
# 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
if (
row.status is WorkItemStatus.PENDING
and row.instance_key == self._instance_key
and (row.next_retry_at is None or row.next_retry_at <= now)
and (row.claim_expires_at is None or row.claim_expires_at <= now)
):
out.append(row)
if len(out) >= limit:
break
return out
def claim_pending(
self,
limit: int = 32,
*,
correlation_id: str | None = None,
) -> list[LedgerWorkItem]:
now = self._now()
lease_until = now + timedelta(seconds=self._claim_ttl_sec)
with self._lock:
claimed: list[LedgerWorkItem] = []
candidates = [correlation_id] if correlation_id is not None else self._order
for cid in candidates:
row = self._rows.get(cid)
if row is None or row.status is not WorkItemStatus.PENDING:
continue
if row.instance_key != self._instance_key:
continue
if row.next_retry_at is not None and row.next_retry_at > now:
continue
if row.claim_expires_at is not None and row.claim_expires_at > now:
continue
updated = replace(row, claim_expires_at=lease_until, updated_at=now)
self._rows[cid] = updated
claimed.append(updated)
if len(claimed) >= limit:
break
return claimed
def pending_cash_delta(self) -> dict[str, float]:
with self._lock:
out: dict[str, float] = {}
@@ -424,9 +610,15 @@ class InMemoryLedgerOutbox:
*,
error: Optional[str] = None,
next_retry_at: Optional[datetime] = None,
expected_claim_expires_at: Optional[datetime] = None,
) -> LedgerWorkItem:
with self._lock:
row = self._rows[correlation_id]
if expected_claim_expires_at is None:
if row.claim_expires_at is not None:
raise OutboxClaimLostError(correlation_id)
elif row.claim_expires_at != expected_claim_expires_at:
raise OutboxClaimLostError(correlation_id)
if outcome is OutboxOutcome.COMPLETED:
new_status = WorkItemStatus.COMPLETED
elif outcome is OutboxOutcome.CONFLICT_BLOCKED:
@@ -448,6 +640,7 @@ class InMemoryLedgerOutbox:
next_retry_at if outcome is OutboxOutcome.RETRYABLE_FAILURE else None
),
updated_at=self._now(),
claim_expires_at=None,
)
self._rows[correlation_id] = updated
return updated