"""Order execution service (REQ-013, REQ-014, REQ-018, dcy-003, dcy-004). A single background execution loop (invariant A single writer, invariant B single broker session) that, per tick: dispatch: claim pending slots with broker_order_id IS NULL (option A queue), submit the order, record broker_order_id (idempotency guard). dcy-020/REQ-062 (BAT-030): a SELL is dispatched with the broker balance quantity (hldg_qty) as the single source of truth — never the slot's mirror qty. Broker flat (qty 0) -> skip + WARN (divergence surfaces via reconcile, REQ-062 A). poll: observe fills on dispatched pending slots and transition the slot (pending_buy->holding / pending_sell->inactive), or roll back on reject. On a successful fill, enqueue a LedgerWorkItem (slot transition is kept ON the critical path; the ledger write is eventually-consistent via a separate writer — REQ-019). reconcile() re-polls dispatched slots on restart so a crash after dispatch converges without duplicate orders (REQ-014). All slot writes go through SlotService (advisory lock). The broker is touched only here, never by the domain or the HTTP API. The ledger outbox is the single producer for ledger work items (NFR-3, single record subject). """ from __future__ import annotations import logging import math from dataclasses import dataclass from datetime import datetime, timezone from typing import Callable, Optional from trex_core.application.broker_port import BrokerPort, OrderRequest from trex_core.application.ledger_outbox import LedgerOutbox from trex_core.application.ledger_port import LedgerTrade from trex_core.domain.slot import SlotService, SlotState, SlotStateMismatchError _log = logging.getLogger(__name__) # REQ-021/023: event emission hook. Runtime wires a callable that publishes # slot transition events through MessagingTransport. Application layer stays # transport-agnostic (NFR-1). Slot type is duck-typed to keep the application # layer free of domain re-imports (the slot is just used for attribute access). SlotEventEmitter = Callable[[str, object], None] # (event_type, slot) -> None _MAX_DISPATCH_PER_TICK = 64 @dataclass class ExecutionResult: dispatched: int = 0 filled: int = 0 rolled_back: int = 0 ledger_enqueued: int = 0 # REQ-019: ledger work items appended this tick ledger_skipped: int = 0 # REQ-018 AC-4: fills without portfolio_id stale_pending: int = 0 # dcy-013 / REQ-014 FR-3: pending orders over threshold sell_skipped_no_balance: int = 0 # dcy-020 / REQ-062: broker flat -> sell skipped timeout_cancelled: int = 0 # dcy-022 / REQ-069: cancel_order sent on timeout class ExecutionService: def __init__( self, slot_service: SlotService, repo, broker: BrokerPort, ledger_outbox: Optional[LedgerOutbox] = None, event_emitter: Optional[SlotEventEmitter] = None, stale_pending_threshold_sec: Optional[int] = None, instance_key: str = "default", ) -> None: self._svc = slot_service self._repo = repo self._broker = broker self._ledger_outbox = ledger_outbox self._event_emitter = event_emitter # dcy-020/REQ-056 (BAT-030): dispatch/poll are instance-scoped so two # daemons sharing a DB never touch each other's orders. self._instance_key = instance_key # dcy-013 / REQ-014 (issue #9): Alert-only pending-order stale watchdog. # <=0 or None disables it. When set, a dispatched-pending slot whose # last update is older than the threshold is surfaced (WARN + counter) # without changing its state — the backstop for a cancel-detection miss. self._stale_threshold_sec = ( stale_pending_threshold_sec if stale_pending_threshold_sec and stale_pending_threshold_sec > 0 else None ) # ------------------------------------------------------------ def run_once(self) -> ExecutionResult: r = ExecutionResult() self._dispatch(r) self._poll(r) return r def reconcile(self) -> ExecutionResult: """Restart recovery: re-poll dispatched-but-pending slots (REQ-014). Undispatched pending slots (broker_order_id IS NULL) are simply picked up by the next dispatch, so a crash before dispatch causes no duplicate. """ r = ExecutionResult() self._poll(r) return r # ------------------------------------------------------------ def _dispatch(self, r: ExecutionResult) -> None: sell_balance: Optional[dict[str, int]] = None # lazy, once per tick for slot in self._repo.list_undispatched_pending( self._instance_key, _MAX_DISPATCH_PER_TICK ): side = "buy" if slot.status is SlotState.PENDING_BUY else "sell" if side == "sell": # dcy-020 / REQ-062 (BAT-030, D3): the sell quantity is the # BROKER balance (hldg_qty) — the slot's mirror qty is never # trusted. Broker flat -> skip dispatch + WARN; the divergence # surfaces via reconcile_core_holdings (REQ-062 A). No mirror # fallback by design. if sell_balance is None: sell_balance = self._balance_map() bal = sell_balance.get(slot.symbol or "", 0) # dcy-021 / REQ-062 (D4): full sell (slot.qty is None) => broker # balance; partial sell => min(order qty, broker balance). Broker # flat -> skip + WARN (divergence surfaces via reconcile). qty = bal if slot.qty is None else min(int(slot.qty), bal) if qty <= 0: r.sell_skipped_no_balance += 1 _log.warning( "sell dispatch skipped: slot=%s symbol=%s broker balance is 0 " "(divergence — no order submitted; operator/reconcile attention)", slot.slot_id, slot.symbol, ) continue else: qty = int(slot.qty or 0) # dcy-012 / REQ-013: side-agnostic — use the slot's pending-order # limit_price only. A sell never reuses a buy limit (issue #10): # limit_price is cleared on entering HOLDING, so a market sell # carries None -> order_type "01". # dcy-022 / REQ-070: slippage_pct adjusts the effective limit price # when entry_price is set. buy: ceil(limit*(1+pct/100)); sell: floor. # No slippage when limit is None (market order — no reference price). limit = int(slot.limit_price) if slot.limit_price else None if limit is not None and slot.slippage_pct: factor = ( 1.0 + slot.slippage_pct / 100.0 if side == "buy" else 1.0 - slot.slippage_pct / 100.0 ) limit = ( int(math.ceil(limit * factor)) if side == "buy" else int(math.floor(limit * factor)) ) _log.debug( "slippage applied: slot=%s side=%s base_limit=%s pct=%.4f effective=%s", slot.slot_id, side, slot.limit_price, slot.slippage_pct, limit, ) ack = self._broker.submit_order( OrderRequest( slot_id=str(slot.slot_id), side=side, symbol=slot.symbol or "", qty=qty, limit_price=limit, order_type="00" if limit is not None else "01", ) ) if ack.accepted and ack.broker_order_id: self._repo.mark_dispatched(slot.slot_id, ack.broker_order_id) r.dispatched += 1 else: self._rollback(slot, reason=ack.reason or "order_rejected") r.rolled_back += 1 def _poll(self, r: ExecutionResult) -> None: now = datetime.now(tz=timezone.utc) for slot in self._repo.list_dispatched_pending(self._instance_key): side = "buy" if slot.status is SlotState.PENDING_BUY else "sell" fs = self._broker.poll_fill(slot.broker_order_id, side=side, symbol=slot.symbol or "") if fs.is_filled: self._on_filled(slot, fs, side, r) r.filled += 1 elif fs.is_partial_cancel: # dcy-013 / REQ-013 FR-2: partial fill then external cancel. self._on_partial_cancel(slot, fs, side, r) r.filled += 1 elif fs.is_terminal_reject: # rejected or full external cancel (dcy-013 FR-1) -> rollback. self._rollback(slot, reason=f"order_{fs.state}") r.rolled_back += 1 else: # accepted / partially_filled (not cancelled) -> leave for next # 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) # ------------------------------------------------------------ def _balance_map(self) -> dict: """Current broker balance as {symbol: hldg_qty} (REQ-062 ground truth).""" return {b.symbol: int(b.hldg_qty) for b in self._broker.get_balance()} def _on_filled(self, slot, fs, side: str, r: ExecutionResult) -> None: broker_order_id = slot.broker_order_id # captured BEFORE clear_dispatch try: if slot.status is SlotState.PENDING_BUY: # dcy-021/REQ-066: held qty = broker balance (authority, includes # the just-filled increase); avg_price = weighted average. For an # initial buy slot.avg_price is None (=0) so new_avg = fill price. total = self._balance_map().get(slot.symbol or "", 0) filled = float(fs.filled_qty) new_qty = float(total) if total > 0 else filled old_qty = max(0.0, new_qty - filled) old_avg = float(slot.avg_price) if slot.avg_price else 0.0 fill_price = float(fs.avg_price) if fs.avg_price is not None else old_avg new_avg = ( (old_qty * old_avg + filled * fill_price) / new_qty if new_qty > 0 else fill_price ) updated = self._svc.transit_slot( slot.slot_id, SlotState.PENDING_BUY, SlotState.HOLDING, reason="buy_filled", actor="execution_loop", avg_price=new_avg, qty=new_qty, ) event_type = "slot_filled_buy" else: # PENDING_SELL — dcy-021/REQ-066: remainder>0 stays holding, # full exit -> inactive. Held qty = broker balance. total = self._balance_map().get(slot.symbol or "", 0) if total > 0: updated = self._svc.transit_slot( slot.slot_id, SlotState.PENDING_SELL, SlotState.HOLDING, reason="sell_filled_partial", actor="execution_loop", qty=float(total), # avg_price (cost basis) preserved ) else: updated = self._svc.transit_slot( slot.slot_id, SlotState.PENDING_SELL, SlotState.INACTIVE, reason="sell_filled", actor="execution_loop", ) event_type = "slot_filled_sell" except SlotStateMismatchError: return # slot moved concurrently; next tick reconciles # REQ-018: enqueue ledger work item AFTER the slot transition is durable. # Slot transition is the critical path; ledger write is async (REQ-019). self._record_ledger(slot, fs, side, broker_order_id, r) # REQ-021/023: emit event AFTER transition + ledger enqueue (single # record subject). Best-effort: a publish failure must not roll back. self._emit_event(event_type, updated) self._repo.clear_dispatch(slot.slot_id) # done with this order def _on_partial_cancel(self, slot, fs, side: str, r: ExecutionResult) -> None: """Partial fill then external cancel (dcy-013 / REQ-013 FR-2, OQ-1 A). Record the filled portion to the ledger ONCE, decrement the held qty, and return the slot to holding with the remainder — so the remaining position can be re-sold and no over-sell / double-record occurs (NFR-3). avg_price (cost basis) is preserved on a sell; a buy keeps only the portion that actually filled. """ broker_order_id = slot.broker_order_id # captured BEFORE clear_dispatch filled = float(fs.filled_qty) try: if slot.status is SlotState.PENDING_BUY: # dcy-021: held qty = broker balance; avg_price weighted average # (consistent with _on_filled). Only the filled portion recorded. total = self._balance_map().get(slot.symbol or "", 0) new_qty = float(total) if total > 0 else filled old_qty = max(0.0, new_qty - filled) old_avg = float(slot.avg_price) if slot.avg_price else 0.0 fill_price = float(fs.avg_price) if fs.avg_price is not None else old_avg new_avg = ( (old_qty * old_avg + filled * fill_price) / new_qty if new_qty > 0 else fill_price ) updated = self._svc.transit_slot( slot.slot_id, SlotState.PENDING_BUY, SlotState.HOLDING, reason="buy_partial_cancel", actor="execution_loop", avg_price=new_avg, qty=new_qty, ) event_type = "slot_filled_buy" else: # PENDING_SELL: remainder = broker balance, cost basis unchanged. total = self._balance_map().get(slot.symbol or "", 0) if total > 0: updated = self._svc.transit_slot( slot.slot_id, SlotState.PENDING_SELL, SlotState.HOLDING, reason="sell_partial_cancel", actor="execution_loop", qty=float(total), ) else: updated = self._svc.transit_slot( slot.slot_id, SlotState.PENDING_SELL, SlotState.INACTIVE, reason="sell_partial_cancel", actor="execution_loop", ) event_type = "slot_filled_sell" except SlotStateMismatchError: return # slot moved concurrently; next tick reconciles self._record_ledger(slot, fs, side, broker_order_id, r) self._emit_event(event_type, updated) self._repo.clear_dispatch(slot.slot_id) def _check_stale_pending(self, slot, now: datetime, r: ExecutionResult) -> None: """Alert-only: surface a dispatched-pending slot stuck past the threshold. dcy-013 / REQ-014 FR-3 — state is NOT changed (auto-remediation is a follow-up). This is the backstop for a cancel-detection miss (R-1). """ if self._stale_threshold_sec is None or slot.updated_at is None: return age = (now - slot.updated_at).total_seconds() if age >= self._stale_threshold_sec: r.stale_pending += 1 _log.warning( "pending order stale: slot=%s status=%s broker_order_id=%s " "age_sec=%.0f threshold_sec=%d (no state change — ops attention)", slot.slot_id, slot.status.value, slot.broker_order_id, age, 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). """ if slot.timeout_sec is None or slot.updated_at is None: return age = (now - slot.updated_at).total_seconds() if age < slot.timeout_sec: return qty = int(slot.qty or 0) try: accepted = self._broker.cancel_order( slot.broker_order_id, side=side, symbol=slot.symbol or "", qty=qty, ) r.timeout_cancelled += 1 _log.warning( "timeout cancel sent: slot=%s status=%s broker_order_id=%s " "age_sec=%.0f timeout_sec=%d broker_accepted=%s", slot.slot_id, slot.status.value, slot.broker_order_id, age, slot.timeout_sec, accepted, ) except Exception: # noqa: BLE001 - best-effort; do not block the loop _log.warning( "timeout cancel failed (exception): slot=%s broker_order_id=%s " "(will retry next tick if still pending)", slot.slot_id, slot.broker_order_id, ) def _emit_event(self, event_type: str, slot) -> None: if self._event_emitter is None: return try: self._event_emitter(event_type, slot) except Exception: # noqa: BLE001 - event publish failure is non-critical return def _record_ledger(self, slot, fs, side: str, broker_order_id: str, r: ExecutionResult) -> None: """Append a LedgerWorkItem for the just-filled trade (REQ-018 + REQ-019).""" if self._ledger_outbox is None: return if not slot.portfolio_id: # dcy-011 / REQ-018 (issue #11): ledger skip must NOT be silent. # Slot transition still proceeded; surface for ops (FR-4). r.ledger_skipped += 1 _log.warning( "ledger skip: slot=%s symbol=%s side=%s reason=missing_portfolio_id " "(trade NOT recorded to portfolio-hub)", slot.slot_id, slot.symbol, side, ) return if fs.execution_id is None: # Broker contract regression — slot already transitioned; surface for ops. r.ledger_skipped += 1 _log.warning( "ledger skip: slot=%s portfolio_id=%s side=%s reason=missing_execution_id " "(trade NOT recorded to portfolio-hub)", slot.slot_id, slot.portfolio_id, side, ) return price = float(fs.avg_price) if fs.avg_price is not None else 0.0 trade = LedgerTrade( asset_id=str(slot.portfolio_id), order_id=str(broker_order_id), execution_id=str(fs.execution_id), side=side, qty=float(fs.filled_qty), price=price, fee=float(fs.fee), tax=float(fs.tax), executed_at=datetime.now(tz=timezone.utc), ) self._ledger_outbox.enqueue(trade) r.ledger_enqueued += 1 def cancel_pending_slot(self, slot_id) -> str: """Operator backstop: send cancel_order for a pending slot (dcy-022/REQ-071). Returns "ok" (cancel sent), "not_pending" (slot is HOLDING/INACTIVE), or "slot_not_found". Does NOT transition the slot — the execution loop's next poll handles the rollback via the normal is_terminal_reject path. """ from uuid import UUID sid = slot_id if isinstance(slot_id, UUID) else UUID(str(slot_id)) slot = self._repo.fetch_slot(sid) if slot is None: return "slot_not_found" if slot.status not in (SlotState.PENDING_BUY, SlotState.PENDING_SELL): return "not_pending" if not slot.broker_order_id: # Claimed but not yet dispatched — execution loop will pick up or rollback. return "not_dispatched" side = "buy" if slot.status is SlotState.PENDING_BUY else "sell" qty = int(slot.qty or 0) try: self._broker.cancel_order( slot.broker_order_id, side=side, symbol=slot.symbol or "", qty=qty, ) except Exception: # noqa: BLE001 - best-effort _log.warning( "operator cancel failed: slot=%s broker_order_id=%s", slot.slot_id, slot.broker_order_id, ) return "cancel_failed" _log.warning( "operator cancel sent: slot=%s status=%s broker_order_id=%s", slot.slot_id, slot.status.value, slot.broker_order_id, ) return "ok" def _rollback(self, slot, *, reason: str) -> None: total = self._balance_map().get(slot.symbol or "", 0) try: if slot.status is SlotState.PENDING_BUY: if total > 0: # dcy-021: increase rejected — the prior holding is intact # (broker still holds), so return to holding, not inactive. self._svc.transit_slot( slot.slot_id, SlotState.PENDING_BUY, SlotState.HOLDING, reason=reason, actor="execution_loop", qty=float(total), ) self._repo.clear_dispatch(slot.slot_id) else: # initial buy rejected -> inactive (clears broker_order_id) self._svc.transit_slot( slot.slot_id, SlotState.PENDING_BUY, SlotState.INACTIVE, reason=reason, actor="execution_loop", ) else: # PENDING_SELL rejected -> back to holding (broker authoritative qty) self._svc.transit_slot( slot.slot_id, SlotState.PENDING_SELL, SlotState.HOLDING, reason=reason, actor="execution_loop", qty=float(total) if total > 0 else None, ) self._repo.clear_dispatch(slot.slot_id) except SlotStateMismatchError: return