Files
trex-core/tests/application/test_execution_policy.py
T
genichinandClaude Opus 4.8 d8d9021260 feat(execution,obs): 호가단위 스냅(dcy-030/#28) + 운영 관측성(dcy-029/#29) + REL-007 환류
dcy-030 (issue #28, P0 체결 복구):
- REQ-083 KRX 호가단위(tick) 순수 유틸 (domain/pricing.py)
- REQ-070 CHG: 슬리피지 실효가 호가단위 스냅 — 상한 준수(매수 floor/매도 ceil)
  + band<1tick 하한/상한 보장 + 부동소수 epsilon 가드. 147700→148400/54500→54700.
- BAT-044 release-candidate

dcy-029 (issue #29, 운영 관측성):
- REQ-084 구조화 로깅 기반 (runtime/logging_setup.py): ISO8601 KST·레벨·Loki JSON
  ·correlation id(slot_id)
- REQ-085 주문 결과 로깅 (event=order_submit|fill|reject)
- REQ-087 거부 ERROR 가시성 (조용한 롤백 제거)
- REQ-086 청산 reason+actor 동반 노출 (안전망/전략 구분, 신규 필드 없음)
- REQ-088 운영 조회 CLI report (application/operator_report.py, 보유·오늘 체결
  ·실현 PnL net·대기, direct-DB)
- REQ-089 운영자 런북 docs/operations.md
- REQ-090 baseline 정합 (runtime-flows·project-structure·interface-contract)
- BAT-045(P0)·BAT-046(P1) release-candidate

REL-007: confirmed → feedback-captured (운영 인스턴스 라이브 검증 + #28/#29 환류
정규화). BAT-037~041 released.

검증: 537 passed, 47 skipped, 회귀 0, ruff clean.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-06-16 13:19:31 +09:00

442 lines
19 KiB
Python

"""Execution policy tests: slippage dispatch + timeout cancel (dcy-022 / REQ-069/070).
Uses ProgrammableBroker from test_execution_cancel for fine-grained control.
Also covers operator cancel_pending_slot (REQ-071).
"""
from __future__ import annotations
import logging
from dataclasses import replace
from datetime import datetime, timedelta, timezone
from trex_core.adapters.persistence.in_memory_intent_store import InMemoryIntentStore
from trex_core.application.broker_port import BalanceItem, FillStatus, OrderAck, OrderRequest
from trex_core.application.execution import ExecutionService
from trex_core.application.intents import BuyIntent, IntentService, SellIntent
from trex_core.domain.slot import SlotService, SlotState
from trex_core.domain.slot.in_memory_repository import InMemorySlotRepository
class _RecordingBroker:
"""Broker that records submitted orders and lets tests control poll responses."""
def __init__(self):
self._seq = 0
self.orders: list[OrderRequest] = []
self.cancel_calls: list = []
self.cancel_raises = False
self.responder = lambda side: FillStatus(
state="filled", filled_qty=10, avg_price=1000.0,
execution_id="exec-1", fee=0.0, tax=0.0,
)
self.balance: dict[str, int] = {"005930": 10}
def name(self):
return "stub"
def submit_order(self, req: OrderRequest):
self._seq += 1
self.orders.append(req)
return OrderAck(accepted=True, broker_order_id=f"o{self._seq}")
def poll_fill(self, broker_order_id, *, side, symbol):
return self.responder(side)
def cancel_order(self, broker_order_id, *, side, symbol, qty):
self.cancel_calls.append((broker_order_id, side, symbol, qty))
if self.cancel_raises:
raise RuntimeError("broker error")
return True
def get_balance(self):
return [BalanceItem(symbol=s, hldg_qty=q) for s, q in self.balance.items() if q > 0]
def get_current_price(self, symbol):
return None
def _wire(broker):
repo = InMemorySlotRepository()
svc = SlotService(repo)
intents = IntentService(svc, repo, InMemoryIntentStore(),
resolve_symbol=lambda pid: "005930")
execution = ExecutionService(svc, repo, broker)
repo.reconcile_universe("default", {"PF-1": "SYM"})
return repo, svc, intents, execution
def _buy_to_pending(intents, qty=10, entry_price=1000, timeout_sec=None, slippage_pct=None):
return intents.submit_buy(BuyIntent(
intent_id="b1", qty=qty, entry_price=entry_price,
portfolio_id="PF-1",
timeout_sec=timeout_sec, slippage_pct=slippage_pct,
)).slot_id
# ============================================================================
# REQ-070: slippage effective limit price
# ============================================================================
class TestSlippageDispatch:
def test_buy_slippage_floor_to_tick(self):
"""buy: effective_limit = floor_to_tick(entry * (1 + pct/100)).
dcy-030/REQ-070 CHG: cap-respecting direction (was ceil). entry=1000
is in the <2,000 band (tick 1) so floor_to_tick(1005.0) = 1005.
"""
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
_buy_to_pending(intents, entry_price=1000, slippage_pct=0.5)
broker.responder = lambda side: FillStatus(state="accepted")
execution.run_once()
order = broker.orders[0]
assert order.limit_price == 1005
def test_buy_slippage_fractional_floors_down(self):
"""floor_to_tick(1001 * 1.003) = floor(1004.003) = 1004 (tick 1)."""
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
_buy_to_pending(intents, entry_price=1001, slippage_pct=0.3)
broker.responder = lambda side: FillStatus(state="accepted")
execution.run_once()
# cap-respecting: floor (not ceil). 1004.003 -> 1004.
assert broker.orders[0].limit_price == 1004
def test_sell_slippage_ceil_to_tick(self):
"""sell: effective_limit = ceil_to_tick(limit_price * (1 - pct/100))."""
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
# drive to holding first
broker.responder = lambda side: FillStatus(
state="filled", filled_qty=10, avg_price=1000.0,
execution_id="e1", fee=0.0, tax=0.0,
)
_buy_to_pending(intents)
execution.run_once() # buy filled -> holding
# now submit sell with slippage
sid = [s.slot_id for s in repo.list_slots("default")
if s.status is SlotState.HOLDING][0]
intents.submit_sell(SellIntent(
intent_id="s1", slot_id=sid, slippage_pct=1.0, limit_price=2000.0,
))
broker.responder = lambda side: FillStatus(state="accepted")
execution.run_once() # dispatch sell (pending state already has limit_price)
sell_orders = [o for o in broker.orders if o.side == "sell"]
# ceil_to_tick(2000 * 0.99) = ceil_to_tick(1980.0) = 1980 (tick 5, exact).
assert sell_orders[0].limit_price == 1980
def test_no_slippage_when_slippage_pct_is_none(self):
"""No slippage_pct → effective_limit = entry_price unchanged."""
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
_buy_to_pending(intents, entry_price=1000, slippage_pct=None)
broker.responder = lambda side: FillStatus(state="accepted")
execution.run_once()
assert broker.orders[0].limit_price == 1000
def test_no_slippage_when_market_order_no_entry_price(self):
"""Market order (no entry_price → limit=None) → slippage not applied."""
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
intents.submit_buy(BuyIntent(
intent_id="b1", qty=10, entry_price=None,
portfolio_id="PF-1", slippage_pct=5.0,
))
broker.responder = lambda side: FillStatus(state="accepted")
execution.run_once()
assert broker.orders[0].limit_price is None
def test_zero_slippage_uses_base_price(self):
"""slippage_pct=0 → effective_limit = ceil(1000 * 1.0) = 1000."""
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
_buy_to_pending(intents, entry_price=1000, slippage_pct=0.0)
broker.responder = lambda side: FillStatus(state="accepted")
execution.run_once()
# 0.0 is falsy → slippage block skipped → no change
assert broker.orders[0].limit_price == 1000
def test_issue28_buy_147700_snaps_to_valid_tick(self):
"""issue #28: 147,700 @ 0.5% → floor_to_tick(148438.5) = 148400 (tick 100)."""
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
_buy_to_pending(intents, entry_price=147700, slippage_pct=0.5)
broker.responder = lambda side: FillStatus(state="accepted")
execution.run_once()
assert broker.orders[0].limit_price == 148400
def test_issue28_buy_54500_snaps_to_valid_tick(self):
"""issue #28: 54,500 @ 0.5% → floor_to_tick(54772.5) = 54700 (tick 100)."""
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
_buy_to_pending(intents, entry_price=54500, slippage_pct=0.5)
broker.responder = lambda side: FillStatus(state="accepted")
execution.run_once()
assert broker.orders[0].limit_price == 54700
def test_buy_sub_tick_band_floors_to_entry_tick(self):
"""band < 1 tick: buy effective ≥ entry's valid tick (no under-fill).
entry=147700 (on tick 100), pct=0.01 → raw=147714.77, floor_to_tick=147700;
guard max(147700, ceil_to_tick(147700)=147700) = 147700 ≥ entry, valid tick.
"""
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
_buy_to_pending(intents, entry_price=147700, slippage_pct=0.01)
broker.responder = lambda side: FillStatus(state="accepted")
execution.run_once()
eff = broker.orders[0].limit_price
assert eff == 147700
assert eff % 100 == 0 # valid KRX tick
assert eff <= 147700 * 1.0001 # within slippage ceiling
def test_buy_snap_never_exceeds_slippage_ceiling(self):
"""cap-respecting: buy effective ≤ entry*(1+pct/100), always a valid tick."""
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
_buy_to_pending(intents, entry_price=35000, slippage_pct=0.7)
broker.responder = lambda side: FillStatus(state="accepted")
execution.run_once()
eff = broker.orders[0].limit_price
# 35000*1.007 = 35245 -> tick 50 -> floor_to_tick = 35200
assert eff == 35200
assert eff % 50 == 0
assert eff <= 35000 * 1.007
# ============================================================================
# REQ-085 / REQ-087: order-result logging + reject ERROR visibility (dcy-029)
# ============================================================================
class TestOrderResultLogging:
def test_submit_and_fill_are_logged_with_event_keys(self, caplog):
from trex_core.runtime import logging_setup as ls
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
_buy_to_pending(intents, entry_price=1000, slippage_pct=None)
broker.responder = lambda side: FillStatus(
state="filled", filled_qty=10, avg_price=1000.0,
execution_id="e1", fee=1.5, tax=0.0,
)
with caplog.at_level(logging.INFO):
execution.run_once() # dispatch (submit) + poll (fill)
text = "\n".join(r.getMessage() for r in caplog.records)
assert "event=order_submit" in text
assert "event=order_fill" in text
assert "fee=1.5" in text
# correlation id set to the slot_id (intent->order->fill join key)
sid = broker.orders[0].slot_id
assert ls.get_correlation_id() == sid
def test_reject_is_logged_at_error_level(self, caplog):
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
broker.submit_order = lambda req: OrderAck(
accepted=False, broker_order_id=None, reason="주식주문호가단위 오류",
)
_buy_to_pending(intents, entry_price=1000)
with caplog.at_level(logging.INFO):
execution.run_once()
rejects = [r for r in caplog.records if "event=order_reject" in r.getMessage()]
assert rejects, "reject must be logged"
assert all(r.levelno == logging.ERROR for r in rejects)
assert "호가단위" in rejects[0].getMessage()
def test_normal_fill_emits_no_error(self, caplog):
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
_buy_to_pending(intents, entry_price=1000)
broker.responder = lambda side: FillStatus(
state="filled", filled_qty=10, avg_price=1000.0,
execution_id="e1", fee=0.0, tax=0.0,
)
with caplog.at_level(logging.INFO):
execution.run_once()
assert not [r for r in caplog.records if r.levelno >= logging.ERROR]
# ============================================================================
# REQ-069: timeout auto-cancel
# ============================================================================
class TestTimeoutCancel:
def _buy_and_dispatch(self, intents, execution, repo, timeout_sec):
"""Drive a pending buy into dispatched state, then age the slot."""
sid = _buy_to_pending(intents, timeout_sec=timeout_sec)
# keep order in "accepted" (not filled) so poll always lands in else branch
execution._repo # just to confirm it's wired
return sid
def test_timeout_exceeded_sends_cancel_order(self):
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
sid = _buy_to_pending(intents, timeout_sec=30)
broker.responder = lambda side: FillStatus(state="accepted")
execution.run_once() # dispatch (no fill yet)
assert len(broker.cancel_calls) == 0
# age the slot past timeout
s = repo.fetch_slot(sid)
repo._slots[sid] = replace(
s, updated_at=datetime.now(tz=timezone.utc) - timedelta(seconds=60),
)
r = execution.run_once()
assert r.timeout_cancelled == 1
assert len(broker.cancel_calls) == 1
def test_timeout_not_exceeded_no_cancel(self):
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
_buy_to_pending(intents, timeout_sec=3600)
broker.responder = lambda side: FillStatus(state="accepted")
execution.run_once() # dispatch
# do NOT age the slot — timeout_sec is large
r = execution.run_once()
assert r.timeout_cancelled == 0
assert len(broker.cancel_calls) == 0
def test_no_timeout_sec_no_cancel(self):
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
sid = _buy_to_pending(intents, timeout_sec=None)
broker.responder = lambda side: FillStatus(state="accepted")
execution.run_once() # dispatch
# age the slot
s = repo.fetch_slot(sid)
repo._slots[sid] = replace(
s, updated_at=datetime.now(tz=timezone.utc) - timedelta(seconds=9999),
)
r = execution.run_once()
assert r.timeout_cancelled == 0
assert len(broker.cancel_calls) == 0
def test_timeout_cancel_best_effort_on_exception(self, caplog):
"""Broker exception during cancel must not raise — loop continues."""
broker = _RecordingBroker()
broker.cancel_raises = True
repo, svc, intents, execution = _wire(broker)
sid = _buy_to_pending(intents, timeout_sec=1)
broker.responder = lambda side: FillStatus(state="accepted")
execution.run_once() # dispatch
s = repo.fetch_slot(sid)
repo._slots[sid] = replace(
s, updated_at=datetime.now(tz=timezone.utc) - timedelta(seconds=60),
)
with caplog.at_level(logging.WARNING):
r = execution.run_once()
# timeout_cancelled NOT incremented when the cancel call raises
assert r.timeout_cancelled == 0
assert repo.fetch_slot(sid).status is SlotState.PENDING_BUY # state unchanged
def test_timeout_cancel_does_not_change_slot_state(self):
"""Timeout cancel is best-effort: slot stays PENDING_BUY after cancel_order."""
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
sid = _buy_to_pending(intents, timeout_sec=1)
broker.responder = lambda side: FillStatus(state="accepted")
execution.run_once()
s = repo.fetch_slot(sid)
repo._slots[sid] = replace(
s, updated_at=datetime.now(tz=timezone.utc) - timedelta(seconds=60),
)
execution.run_once()
# slot still PENDING_BUY — cancel is best-effort; rollback on next poll
assert repo.fetch_slot(sid).status is SlotState.PENDING_BUY
def test_timeout_cancel_then_fill_race_handled(self):
"""Cancel sent, but broker fills the order — is_filled path wins on next poll."""
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
sid = _buy_to_pending(intents, timeout_sec=1)
broker.responder = lambda side: FillStatus(state="accepted")
execution.run_once() # dispatch
# age the slot → cancel sent
s = repo.fetch_slot(sid)
repo._slots[sid] = replace(
s, updated_at=datetime.now(tz=timezone.utc) - timedelta(seconds=60),
)
r1 = execution.run_once()
assert r1.timeout_cancelled == 1
# next poll: broker says filled anyway (race — fill beat the cancel)
broker.responder = lambda side: FillStatus(
state="filled", filled_qty=10, avg_price=1000.0,
execution_id="exec-race", fee=0.0, tax=0.0,
)
r2 = execution.run_once()
assert r2.filled == 1
assert repo.fetch_slot(sid).status is SlotState.HOLDING
# ============================================================================
# REQ-071: cancel_pending_slot (operator backstop)
# ============================================================================
class TestCancelPendingSlot:
def test_ok_sends_cancel_and_returns_ok(self):
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
sid = _buy_to_pending(intents)
# dispatch so broker_order_id is set
broker.responder = lambda side: FillStatus(state="accepted")
execution.run_once()
result = execution.cancel_pending_slot(sid)
assert result == "ok"
assert len(broker.cancel_calls) == 1
def test_not_pending_returns_not_pending(self):
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
sid = _buy_to_pending(intents)
broker.responder = lambda side: FillStatus(
state="filled", filled_qty=10, avg_price=1000.0,
execution_id="e1", fee=0.0, tax=0.0,
)
execution.run_once() # fill -> holding
assert repo.fetch_slot(sid).status is SlotState.HOLDING
result = execution.cancel_pending_slot(sid)
assert result == "not_pending"
def test_slot_not_found_returns_slot_not_found(self):
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
from uuid import uuid4
result = execution.cancel_pending_slot(uuid4())
assert result == "slot_not_found"
def test_not_dispatched_returns_not_dispatched(self):
"""Slot is PENDING_BUY but broker_order_id not yet set."""
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
sid = _buy_to_pending(intents)
# Do NOT call run_once — broker_order_id is still None
result = execution.cancel_pending_slot(sid)
assert result == "not_dispatched"
def test_cancel_fail_returns_cancel_failed(self):
broker = _RecordingBroker()
broker.cancel_raises = True
repo, svc, intents, execution = _wire(broker)
sid = _buy_to_pending(intents)
broker.responder = lambda side: FillStatus(state="accepted")
execution.run_once() # dispatch
result = execution.cancel_pending_slot(sid)
assert result == "cancel_failed"
def test_cancel_does_not_change_slot_state(self):
"""Operator cancel sends cancel_order; slot stays PENDING_BUY (execution loop transitions)."""
broker = _RecordingBroker()
repo, svc, intents, execution = _wire(broker)
sid = _buy_to_pending(intents)
broker.responder = lambda side: FillStatus(state="accepted")
execution.run_once()
execution.cancel_pending_slot(sid)
assert repo.fetch_slot(sid).status is SlotState.PENDING_BUY