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>
This commit is contained in:
Claude Opus 4.8
@@ -80,30 +80,32 @@ def _buy_to_pending(intents, qty=10, entry_price=1000, timeout_sec=None, slippag
|
||||
|
||||
class TestSlippageDispatch:
|
||||
|
||||
def test_buy_slippage_ceil_applied_to_limit(self):
|
||||
"""buy: effective_limit = ceil(entry_price * (1 + pct/100))."""
|
||||
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]
|
||||
# ceil(1000 * 1.005) = ceil(1005.0) = 1005
|
||||
assert order.limit_price == 1005
|
||||
|
||||
def test_buy_slippage_fractional_ceil(self):
|
||||
"""ceil(1001 * 1.003) = ceil(1004.003) = 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()
|
||||
import math
|
||||
expected = int(math.ceil(1001 * 1.003))
|
||||
assert broker.orders[0].limit_price == expected
|
||||
# cap-respecting: floor (not ceil). 1004.003 -> 1004.
|
||||
assert broker.orders[0].limit_price == 1004
|
||||
|
||||
def test_sell_slippage_floor_applied_to_limit(self):
|
||||
"""sell: effective_limit = floor(limit_price * (1 - pct/100))."""
|
||||
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
|
||||
@@ -122,10 +124,8 @@ class TestSlippageDispatch:
|
||||
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"]
|
||||
# floor(2000 * 0.99) = floor(1980.0) = 1980
|
||||
import math
|
||||
expected = int(math.floor(2000 * 0.99))
|
||||
assert sell_orders[0].limit_price == expected
|
||||
# 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."""
|
||||
@@ -158,6 +158,105 @@ class TestSlippageDispatch:
|
||||
# 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
|
||||
|
||||
@@ -0,0 +1,76 @@
|
||||
"""운영 조회 리포트 집계 단위 테스트 (REQ-088, dcy-029 FR-5)."""
|
||||
from datetime import datetime, timezone
|
||||
|
||||
from trex_core.application.operator_report import (
|
||||
Holding,
|
||||
PendingOrder,
|
||||
TradeRow,
|
||||
build_report,
|
||||
kst_day_bounds_utc,
|
||||
realized_pnl,
|
||||
render_json,
|
||||
render_text,
|
||||
)
|
||||
|
||||
|
||||
class TestRealizedPnl:
|
||||
def test_buy_then_sell_net_cash_flow_with_fee_tax(self):
|
||||
trades = [
|
||||
TradeRow(asset_id="A", side="buy", qty=10, price=1000, fee=5),
|
||||
TradeRow(asset_id="A", side="sell", qty=10, price=1100, fee=5, tax=33),
|
||||
]
|
||||
total, by_asset = realized_pnl(trades)
|
||||
# buy: -(10000+5) = -10005 ; sell: 11000-5-33 = 10962 ; net = 957
|
||||
assert total == 957.0
|
||||
assert by_asset == {"A": 957.0}
|
||||
|
||||
def test_per_asset_breakdown(self):
|
||||
trades = [
|
||||
TradeRow("A", "sell", 1, 100),
|
||||
TradeRow("B", "buy", 1, 50),
|
||||
]
|
||||
total, by_asset = realized_pnl(trades)
|
||||
assert by_asset["A"] == 100.0
|
||||
assert by_asset["B"] == -50.0
|
||||
assert total == 50.0
|
||||
|
||||
def test_empty(self):
|
||||
total, by_asset = realized_pnl([])
|
||||
assert total == 0.0 and by_asset == {}
|
||||
|
||||
|
||||
class TestBuildAndRender:
|
||||
def _rep(self):
|
||||
return build_report(
|
||||
holdings=[Holding("005930", "pf-005930", 10, 70000)],
|
||||
pending=[PendingOrder("000660", "pf-000660", "pending_buy")],
|
||||
trades=[TradeRow("pf-005930", "sell", 10, 71000, fee=10, tax=213)],
|
||||
)
|
||||
|
||||
def test_build_counts_and_pnl(self):
|
||||
rep = self._rep()
|
||||
assert rep.fills_count == 1
|
||||
assert len(rep.holdings) == 1 and len(rep.pending) == 1
|
||||
assert rep.realized_pnl == 71000 * 10 - 10 - 213
|
||||
|
||||
def test_render_text_has_sections(self):
|
||||
out = render_text(self._rep())
|
||||
assert "현재 보유" in out and "대기 주문" in out and "실현 PnL" in out
|
||||
assert "005930" in out
|
||||
|
||||
def test_render_json_shape(self):
|
||||
j = render_json(self._rep())
|
||||
assert j["fills_count"] == 1
|
||||
assert j["holdings"][0]["symbol"] == "005930"
|
||||
assert j["pending"][0]["status"] == "pending_buy"
|
||||
assert "realized_pnl" in j
|
||||
|
||||
|
||||
class TestKstBounds:
|
||||
def test_today_boundary_excludes_yesterday(self):
|
||||
# 2026-06-16 01:00 UTC == 10:00 KST -> KST day starts 2026-06-15 15:00 UTC
|
||||
now = datetime(2026, 6, 16, 1, 0, tzinfo=timezone.utc)
|
||||
start, end = kst_day_bounds_utc(now)
|
||||
assert start == datetime(2026, 6, 15, 15, 0, tzinfo=timezone.utc)
|
||||
assert end == datetime(2026, 6, 16, 15, 0, tzinfo=timezone.utc)
|
||||
assert start <= now < end
|
||||
@@ -98,6 +98,19 @@ def test_forced_close_fire_logs_warn(caplog):
|
||||
assert rec and "forced_close_at" in rec[0].message and "inst-1" in rec[0].message
|
||||
|
||||
|
||||
def test_fire_log_exposes_reason_and_actor(caplog):
|
||||
"""REQ-086 (dcy-029): safety-sell 청산 로그가 reason+actor 를 함께 노출."""
|
||||
repo, svc, broker, watchdog, service = _wire()
|
||||
_holding(svc, repo, forced_close_at=_NOW - timedelta(seconds=1))
|
||||
with caplog.at_level(logging.WARNING):
|
||||
service.check_forced_close(_NOW)
|
||||
rec = [r for r in caplog.records if "safety-sell fired" in r.message]
|
||||
assert rec
|
||||
msg = rec[0].message
|
||||
assert "reason=forced_close_at" in msg
|
||||
assert "actor=trex-safety-sell" in msg # 안전망 자율청산 구분
|
||||
|
||||
|
||||
def test_take_profit_fire_logs_info(caplog):
|
||||
repo, svc, broker, watchdog, service = _wire()
|
||||
slot = _holding(svc, repo, take_profit_price=Decimal("60000"))
|
||||
|
||||
@@ -0,0 +1,59 @@
|
||||
"""KRX 호가단위(tick) 유틸 단위 테스트 (REQ-083, dcy-030)."""
|
||||
import pytest
|
||||
|
||||
from trex_core.domain.pricing import ceil_to_tick, floor_to_tick, krx_stock_tick
|
||||
|
||||
|
||||
class TestKrxStockTick:
|
||||
@pytest.mark.parametrize("price,tick", [
|
||||
(1_500, 1),
|
||||
(3_000, 5),
|
||||
(12_000, 10),
|
||||
(35_000, 50),
|
||||
(147_700, 100),
|
||||
(300_000, 500),
|
||||
(800_000, 1_000),
|
||||
])
|
||||
def test_representative_prices(self, price, tick):
|
||||
assert krx_stock_tick(price) == tick
|
||||
|
||||
@pytest.mark.parametrize("boundary,tick", [
|
||||
(2_000, 5), # [2000, 5000) -> 5 (lower bound inclusive)
|
||||
(5_000, 10),
|
||||
(20_000, 50),
|
||||
(50_000, 100),
|
||||
(200_000, 500),
|
||||
(500_000, 1_000),
|
||||
])
|
||||
def test_boundaries_are_lower_inclusive(self, boundary, tick):
|
||||
assert krx_stock_tick(boundary) == tick
|
||||
|
||||
def test_just_below_boundary_uses_lower_band(self):
|
||||
assert krx_stock_tick(1_999) == 1
|
||||
assert krx_stock_tick(49_999) == 50
|
||||
assert krx_stock_tick(199_999) == 100
|
||||
|
||||
|
||||
class TestFloorCeilToTick:
|
||||
def test_issue28_floor_cases(self):
|
||||
assert floor_to_tick(148_439) == 148_400
|
||||
assert floor_to_tick(54_773) == 54_700
|
||||
|
||||
def test_ceil_case(self):
|
||||
assert ceil_to_tick(54_773) == 54_800
|
||||
|
||||
def test_already_on_tick_is_unchanged(self):
|
||||
assert floor_to_tick(147_700) == 147_700
|
||||
assert ceil_to_tick(147_700) == 147_700
|
||||
|
||||
@pytest.mark.parametrize("price", [
|
||||
1_500, 2_777, 4_999, 12_345, 33_333, 148_439, 234_567, 777_777,
|
||||
])
|
||||
def test_invariants_floor_le_price_le_ceil_and_valid_multiples(self, price):
|
||||
tick = krx_stock_tick(price)
|
||||
f = floor_to_tick(price)
|
||||
c = ceil_to_tick(price)
|
||||
assert f <= price <= c
|
||||
assert f % krx_stock_tick(f) == 0
|
||||
assert c % krx_stock_tick(c) == 0
|
||||
assert c - f <= tick
|
||||
@@ -0,0 +1,101 @@
|
||||
"""구조화 로깅 기반 단위 테스트 (REQ-084, dcy-029 FR-1·FR-7)."""
|
||||
import json
|
||||
import logging
|
||||
|
||||
import pytest
|
||||
|
||||
from trex_core.runtime import logging_setup as ls
|
||||
|
||||
|
||||
@pytest.fixture(autouse=True)
|
||||
def _reset_corr():
|
||||
ls.set_correlation_id("")
|
||||
yield
|
||||
ls.set_correlation_id("")
|
||||
|
||||
|
||||
def _record(msg="hello", level=logging.INFO, **extra):
|
||||
rec = logging.LogRecord("trex.test", level, __file__, 1, msg, None, None)
|
||||
for k, v in extra.items():
|
||||
setattr(rec, k, v)
|
||||
return rec
|
||||
|
||||
|
||||
class TestTextFormatter:
|
||||
def test_has_iso8601_kst_timestamp_level_and_msg(self):
|
||||
out = ls.TextFormatter().format(_record("boot ok"))
|
||||
# ISO8601 with +09:00 KST offset, level, message
|
||||
assert "+09:00" in out
|
||||
assert "INFO" in out
|
||||
assert "boot ok" in out
|
||||
|
||||
def test_includes_correlation_id_when_set(self):
|
||||
ls.set_correlation_id("slot-123")
|
||||
rec = _record("x")
|
||||
ls._CorrelationFilter().filter(rec)
|
||||
out = ls.TextFormatter().format(rec)
|
||||
assert "cid=slot-123" in out
|
||||
|
||||
def test_omits_cid_when_unset(self):
|
||||
rec = _record("x")
|
||||
ls._CorrelationFilter().filter(rec)
|
||||
out = ls.TextFormatter().format(rec)
|
||||
assert "cid=" not in out
|
||||
|
||||
|
||||
class TestJsonFormatter:
|
||||
def test_is_valid_json_with_required_keys(self):
|
||||
rec = _record("submitted")
|
||||
ls._CorrelationFilter().filter(rec)
|
||||
obj = json.loads(ls.JsonFormatter().format(rec))
|
||||
assert obj["msg"] == "submitted"
|
||||
assert obj["level"] == "INFO"
|
||||
assert obj["logger"] == "trex.test"
|
||||
assert "+09:00" in obj["ts"]
|
||||
assert obj["correlation_id"] == ""
|
||||
|
||||
def test_correlation_id_propagates(self):
|
||||
ls.set_correlation_id("slot-9")
|
||||
rec = _record("y")
|
||||
ls._CorrelationFilter().filter(rec)
|
||||
obj = json.loads(ls.JsonFormatter().format(rec))
|
||||
assert obj["correlation_id"] == "slot-9"
|
||||
|
||||
def test_extra_fields_included(self):
|
||||
rec = _record("z", symbol="005930")
|
||||
ls._CorrelationFilter().filter(rec)
|
||||
obj = json.loads(ls.JsonFormatter().format(rec))
|
||||
assert obj["symbol"] == "005930"
|
||||
|
||||
|
||||
class TestConfigureAndContext:
|
||||
def test_configure_text_default(self, monkeypatch, capsys):
|
||||
monkeypatch.delenv("TREX_LOG_FORMAT", raising=False)
|
||||
ls.configure_logging(level=logging.INFO)
|
||||
logging.getLogger("trex.x").info("via root")
|
||||
err = capsys.readouterr().err
|
||||
assert "via root" in err and "INFO" in err and "+09:00" in err
|
||||
|
||||
def test_configure_json_format(self, monkeypatch, capsys):
|
||||
monkeypatch.setenv("TREX_LOG_FORMAT", "json")
|
||||
ls.configure_logging(level=logging.INFO)
|
||||
with ls.correlation_id("slot-77"):
|
||||
logging.getLogger("trex.x").info("jsonline")
|
||||
line = [ln for ln in capsys.readouterr().err.splitlines() if "jsonline" in ln][-1]
|
||||
obj = json.loads(line)
|
||||
assert obj["msg"] == "jsonline"
|
||||
assert obj["correlation_id"] == "slot-77"
|
||||
# cleanup: restore text formatter for other tests
|
||||
monkeypatch.delenv("TREX_LOG_FORMAT", raising=False)
|
||||
ls.configure_logging(level=logging.INFO)
|
||||
|
||||
def test_correlation_id_context_manager_restores(self):
|
||||
ls.set_correlation_id("outer")
|
||||
with ls.correlation_id("inner"):
|
||||
assert ls.get_correlation_id() == "inner"
|
||||
assert ls.get_correlation_id() == "outer"
|
||||
|
||||
def test_configure_is_idempotent_single_handler(self):
|
||||
ls.configure_logging()
|
||||
ls.configure_logging()
|
||||
assert len(logging.getLogger().handlers) == 1
|
||||
Reference in New Issue
Block a user