feat(execution): reconcile timed-out orders safely
This commit is contained in:
@@ -23,9 +23,10 @@ single producer for ledger work items (NFR-3, single record subject).
|
||||
|
||||
from __future__ import annotations
|
||||
|
||||
import inspect
|
||||
import logging
|
||||
from dataclasses import dataclass, replace
|
||||
from datetime import datetime, timezone
|
||||
from datetime import datetime, timedelta, timezone
|
||||
from typing import Callable, Optional
|
||||
|
||||
from trex_core.application.alarm_emitter import AlarmEmitter
|
||||
@@ -86,6 +87,7 @@ class ExecutionService:
|
||||
instance_key: str = "default",
|
||||
alarm_emitter: Optional[AlarmEmitter] = None,
|
||||
balance_reader: Optional[Callable[[], list[BalanceItem]]] = None,
|
||||
clock: Optional[Callable[[], datetime]] = None,
|
||||
) -> None:
|
||||
self._svc = slot_service
|
||||
self._repo = repo
|
||||
@@ -106,6 +108,11 @@ class ExecutionService:
|
||||
)
|
||||
# dcy-033 / REQ-100: best-effort alarm emitter (None = no alarms sent).
|
||||
self._alarm_emitter = alarm_emitter
|
||||
# One emission per durable unresolved state/attempt in this process.
|
||||
# A restart intentionally emits once again, covering a crash between a
|
||||
# durable cancel reservation and best-effort alarm publication.
|
||||
self._order_alarm_keys: set[tuple[str, str, int]] = set()
|
||||
self._clock = clock or (lambda: datetime.now(tz=timezone.utc))
|
||||
# dcy-041 / GitHub #45: pending-sell quantity may use a bounded
|
||||
# account snapshot only through this injected reader. Reconciliation
|
||||
# remains wired directly to the live broker.
|
||||
@@ -216,6 +223,7 @@ class ExecutionService:
|
||||
slot.slot_id,
|
||||
ack.broker_order_id,
|
||||
venue=ack.venue,
|
||||
submitted_at=ack.submitted_at,
|
||||
)
|
||||
r.dispatched += 1
|
||||
if ack.reason and ack.reason.startswith("submit_outcome_unknown:"):
|
||||
@@ -258,11 +266,11 @@ class ExecutionService:
|
||||
r.rolled_back += 1
|
||||
|
||||
def _poll(self, r: ExecutionResult) -> None:
|
||||
now = datetime.now(tz=timezone.utc)
|
||||
now = self._clock().astimezone(timezone.utc)
|
||||
for slot in self._repo.list_dispatched_pending(self._instance_key):
|
||||
side = "buy" if slot.status is SlotState.PENDING_BUY else "sell"
|
||||
set_correlation_id(str(slot.slot_id)) # REQ-084: same key as submit
|
||||
fs = self._broker.poll_fill(slot.broker_order_id, side=side, symbol=slot.symbol or "")
|
||||
fs = self._poll_fill(slot, side)
|
||||
resolved_order_id = (
|
||||
fs.raw.get("resolved_broker_order_id") if isinstance(fs.raw, dict) else None
|
||||
)
|
||||
@@ -312,7 +320,18 @@ class ExecutionService:
|
||||
# tick, but surface if it has been stuck too long (FR-3), and
|
||||
# send a cancel if the slot-level timeout is exceeded (REQ-069).
|
||||
self._check_stale_pending(slot, now, r)
|
||||
self._try_timeout_cancel(slot, now, side, r)
|
||||
self._try_timeout_cancel(slot, now, side, fs, r)
|
||||
|
||||
def _poll_fill(self, slot, side: str):
|
||||
"""Use immutable order metadata when the adapter supports the new seam."""
|
||||
poll = self._broker.poll_fill
|
||||
parameters = inspect.signature(poll).parameters
|
||||
kwargs = {"side": side, "symbol": slot.symbol or ""}
|
||||
if "order_date" in parameters:
|
||||
kwargs["order_date"] = slot.order_date
|
||||
if "submitted_at" in parameters:
|
||||
kwargs["submitted_at"] = slot.order_submitted_at
|
||||
return poll(slot.broker_order_id, **kwargs)
|
||||
|
||||
# ------------------------------------------------------------
|
||||
def _balance_map(self) -> dict:
|
||||
@@ -553,39 +572,40 @@ class ExecutionService:
|
||||
self._stale_threshold_sec,
|
||||
)
|
||||
|
||||
def _try_timeout_cancel(self, slot, now: datetime, side: str, r: ExecutionResult) -> None:
|
||||
"""Send cancel_order when the slot-level timeout is exceeded (dcy-022/REQ-069).
|
||||
|
||||
Best-effort: a failure only logs a warning — the slot is NOT changed here.
|
||||
Actual rollback happens on the next poll tick when the broker confirms the
|
||||
cancel (is_terminal_reject) or partial fill then cancel (is_partial_cancel).
|
||||
This design is safe across the cancel-fill race: if the cancel races with a
|
||||
fill, the next poll sees is_filled and follows the normal fill path (FR-4).
|
||||
"""
|
||||
def _try_timeout_cancel(self, slot, now: datetime, side: str, fs, r: ExecutionResult) -> None:
|
||||
"""Begin or safely retry cancellation after the immutable deadline."""
|
||||
if str(slot.broker_order_id or "").startswith("submission-unknown:"):
|
||||
return
|
||||
if slot.cancel_state is not None:
|
||||
if slot.timeout_sec is None:
|
||||
return
|
||||
if slot.timeout_sec is None or slot.updated_at is None:
|
||||
if slot.order_submitted_at is None or slot.order_date is None:
|
||||
self._emit_order_metadata_unknown_alarm(slot)
|
||||
return
|
||||
age = (now - slot.updated_at).total_seconds()
|
||||
age = (now - slot.order_submitted_at).total_seconds()
|
||||
if age < slot.timeout_sec:
|
||||
return
|
||||
|
||||
is_retry = slot.cancel_state in {
|
||||
CancelState.REJECTED.value,
|
||||
CancelState.UNKNOWN.value,
|
||||
}
|
||||
if slot.cancel_state is not None and not is_retry:
|
||||
return
|
||||
if is_retry:
|
||||
self._emit_unresolved_cancel_alarm(slot)
|
||||
if not (isinstance(fs.raw, dict) and fs.raw.get("order_open_confirmed") is True):
|
||||
return
|
||||
backoff_sec = min(300, 5 * (2 ** max(0, slot.cancel_attempts - 1)))
|
||||
retry_before = now - timedelta(seconds=backoff_sec)
|
||||
else:
|
||||
retry_before = None
|
||||
|
||||
qty = int(slot.qty or 0)
|
||||
# Write UNKNOWN before external I/O. If the process dies after KIS
|
||||
# receives the request but before the response is persisted, restart
|
||||
# polls the order instead of issuing a blind second cancellation.
|
||||
if not self._repo.mark_cancel_outcome(
|
||||
if not self._repo.reserve_cancel_attempt(
|
||||
slot.slot_id,
|
||||
str(slot.broker_order_id),
|
||||
CancelState.UNKNOWN.value,
|
||||
only_if_unset=True,
|
||||
retry_before=retry_before,
|
||||
):
|
||||
_log.error(
|
||||
"cancel attempt reservation conflict: slot=%s broker_order_id=%s",
|
||||
slot.slot_id,
|
||||
slot.broker_order_id,
|
||||
)
|
||||
return
|
||||
try:
|
||||
cancel_kwargs = {
|
||||
@@ -610,8 +630,7 @@ class ExecutionService:
|
||||
)
|
||||
if not persisted:
|
||||
_log.error(
|
||||
"cancel outcome persistence conflict: slot=%s broker_order_id=%s "
|
||||
"outcome=%s",
|
||||
"cancel outcome persistence conflict: slot=%s broker_order_id=%s outcome=%s",
|
||||
slot.slot_id,
|
||||
slot.broker_order_id,
|
||||
outcome.state.value,
|
||||
@@ -619,6 +638,14 @@ class ExecutionService:
|
||||
return
|
||||
if outcome.is_requested:
|
||||
r.timeout_cancelled += 1
|
||||
elif outcome.state in {CancelState.REJECTED, CancelState.UNKNOWN}:
|
||||
self._emit_unresolved_cancel_alarm(
|
||||
replace(
|
||||
slot,
|
||||
cancel_state=outcome.state.value,
|
||||
cancel_attempts=slot.cancel_attempts + 1,
|
||||
)
|
||||
)
|
||||
_log.warning(
|
||||
"timeout cancel result: slot=%s status=%s broker_order_id=%s "
|
||||
"age_sec=%.0f timeout_sec=%d outcome=%s",
|
||||
@@ -630,6 +657,52 @@ class ExecutionService:
|
||||
outcome.state.value,
|
||||
)
|
||||
|
||||
def _emit_unresolved_cancel_alarm(self, slot) -> None:
|
||||
key = (str(slot.slot_id), str(slot.cancel_state), slot.cancel_attempts)
|
||||
if key in self._order_alarm_keys:
|
||||
return
|
||||
self._order_alarm_keys.add(key)
|
||||
_log.critical(
|
||||
"cancel unresolved: slot=%s status=%s broker_order_id=%s outcome=%s "
|
||||
"(fail-closed pending; authoritative polling continues)",
|
||||
slot.slot_id,
|
||||
slot.status.value,
|
||||
slot.broker_order_id,
|
||||
slot.cancel_state,
|
||||
)
|
||||
if self._alarm_emitter is not None:
|
||||
self._alarm_emitter.publish_alarm(
|
||||
"order_cancel_unresolved",
|
||||
f"주문 취소 미확정: 슬롯 pending 유지 (slot={slot.slot_id})",
|
||||
fields={
|
||||
"slot_id": str(slot.slot_id),
|
||||
"symbol": slot.symbol,
|
||||
"cancel_state": slot.cancel_state,
|
||||
"order_date": slot.order_date,
|
||||
},
|
||||
)
|
||||
|
||||
def _emit_order_metadata_unknown_alarm(self, slot) -> None:
|
||||
key = (str(slot.slot_id), "order_metadata_unknown", slot.cancel_attempts)
|
||||
if key in self._order_alarm_keys:
|
||||
return
|
||||
self._order_alarm_keys.add(key)
|
||||
_log.critical(
|
||||
"order reconciliation metadata unknown: slot=%s status=%s "
|
||||
"(fail-closed pending; no timeout cancel retry)",
|
||||
slot.slot_id,
|
||||
slot.status.value,
|
||||
)
|
||||
if self._alarm_emitter is not None:
|
||||
self._alarm_emitter.publish_alarm(
|
||||
"order_reconciliation_metadata_unknown",
|
||||
f"주문 원시각/원주문일 미확인: 슬롯 pending 유지 (slot={slot.slot_id})",
|
||||
fields={
|
||||
"slot_id": str(slot.slot_id),
|
||||
"symbol": slot.symbol,
|
||||
},
|
||||
)
|
||||
|
||||
def _emit_event(self, event_type: str, slot, routing_strategy_id: Optional[str] = None) -> None:
|
||||
if self._event_emitter is None:
|
||||
return
|
||||
@@ -734,11 +807,9 @@ class ExecutionService:
|
||||
cancel_kwargs["venue"] = slot.venue
|
||||
# Durable unknown reservation closes the crash window between the
|
||||
# outbound request and saving its immediate result.
|
||||
if not self._repo.mark_cancel_outcome(
|
||||
if not self._repo.reserve_cancel_attempt(
|
||||
slot.slot_id,
|
||||
str(slot.broker_order_id),
|
||||
CancelState.UNKNOWN.value,
|
||||
only_if_unset=True,
|
||||
):
|
||||
return "cancel_already_recorded"
|
||||
outcome = self._broker.cancel_order(slot.broker_order_id, **cancel_kwargs)
|
||||
|
||||
Reference in New Issue
Block a user