diff --git a/keel/execution/executor.py b/keel/execution/executor.py index cde31fcc..30c2d6bf 100644 --- a/keel/execution/executor.py +++ b/keel/execution/executor.py @@ -51,6 +51,16 @@ gate; `_fetch_available_quote` swallows any exception from the call and returns `None`, which rail 13 then treats as fail-closed (vetoes the BUY) exactly like an unknown balance from a missing quote-currency account. SELL intents never fetch a balance (the rail exempts them). + +**Entry routing is unconditional market (#258, #260).** Every signal -- whatever its +`Setup.entry` encodes -- is routed as an immediate market order; the rule's entry price is +recorded on the order row as `expected_fill` and then not used to execute. #258 pinned that as +the faithful-engine decision; #260 records the cost (`pullback_continuation`, whose +`signal_candle.high + buffer_ticks` entry is a follow-through filter, took 124 trades +market-filled where the rule intended 58, at gross PF 0.7736 vs 0.9219) and deliberately +defers resting-order routing until a price-conditional rule earns it. What is NOT deferred is +visibility: `_warn_if_market_routing_overrides_entry` logs at WARNING whenever a routed entry +sits materially off the venue's own book, so the override is visible rather than silent. """ from __future__ import annotations @@ -468,6 +478,21 @@ def _run_order( mode=mode, ) + # #260: ROUTING AN ENTRY AS MARKET OVERRIDES WHATEVER CONDITION THE RULE ENCODED IN ITS + # ENTRY PRICE. That is deliberate twice over. It is the behavior #258's faithful-engine + # decision pinned -- live and the simulator agree that every signal becomes an immediate + # market order, and the rule's own entry is recorded as `expected_fill` and then not used + # to execute. And it is deliberately unchanged here, because #260's full remediation + # (resting limit/stop orders, reconciliation across cycles, a cancel/replace policy) is + # deferred until a price-conditional rule earns it -- the only rule whose entry currently + # encodes a condition (`pullback_continuation`) is independently measured dead, and + # upgrading money-moving order routing to rescue it is a bad trade. What is NOT deferred + # is visibility: the landmine is the NEXT rule, which would be silently mis-executed the + # same way. So the moment the venue's own book -- the `best_ask` in the preview just + # fetched, no extra call -- says the intended entry is materially off the market, say so + # at WARNING, before the confirm gate and before placement. + _warn_if_market_routing_overrides_entry(intent, preview, order_configuration) + if mode == "confirm": approved = confirm_fn(preview) if confirm_fn is not None else False if not approved: @@ -653,7 +678,133 @@ def _log_intent_divergence(order_id: int, intent: OrderIntent | None, realized: ) +#: The routing-time entry-override visibility threshold, in basis points (#260). +#: +#: A VISIBILITY threshold, not a correctness one: crossing it changes no order, only whether +#: the operator is told. Anchored in this repo's own cost model, where a fill is priced at a +#: 1.2% taker fee per leg (`strategy/backtest.TAKER_FEE_PCT`) plus 5bp of slippage +#: (`cli._SIM_SLIPPAGE_PCT`). Against that, a deviation of a few bp is microstructure -- the +#: drift any enter-at-close rule (`turtle_breakout`, `rsi_meanrev`) accumulates by routing one +#: cycle after its signal bar -- while tens of bp means the rule's entry encodes a CONDITION: +#: `pullback_continuation` enters at `signal_candle.high + buffer_ticks`, which sits above +#: the market by however much follow-through the rule demands, and THAT gap is what market +#: routing silently removes (#260 measured it: 124 trades taken where the rule intended 58). +#: 50bp sits between the two: 10x the slippage assumption, so ordinary conditions do not +#: trip it, yet small enough that any deliberate entry condition -- at least a fraction of +#: a bar's range from spot, by construction -- does. A genuine >50bp gap-up between an +#: enter-at-close rule's signal and the next cycle's ask CAN exceed the line in volatile +#: stretches; that firing is truthful (the fill really is that far off intent) and +#: informative, not spurious. This is a VISIBILITY threshold, not a correctness one. +#: The comparison is strictly greater: a deviation exactly at the line is "at", not +#: "beyond", and logs nothing. +ENTRY_OVERRIDE_WARN_BP = Decimal("50") + + +def _preview_best_ask(preview: Preview | dict[str, Any]) -> Decimal | None: + """The venue's best ask out of a preview response, in whichever of its two shapes. + + Both shapes already cross this module (`ConfirmFn`'s docstring explains why they coexist): + the pre-port `CoinbaseClient.preview_order` dict, which maps `best_ask` to a `Decimal`, and + the port's `Preview`, whose Coinbase adapter carries the same book as a string inside + `detail`. `None` when the venue returned no usable ask -- a degraded response, not an + error, and nothing downstream may compute a deviation against a guess. + """ + raw: Any = None + if isinstance(preview, Mapping): + raw = preview.get("best_ask") + else: + detail = getattr(preview, "detail", None) + raw = detail.get("best_ask") if detail is not None else None + if raw is None: + return None + try: + ask = Decimal(str(raw)) + except (InvalidOperation, TypeError, ValueError): + return None + # `is_finite()` first, deliberately outside any try: Decimal('NaN') > 0 RAISES + # InvalidOperation, and a venue string of "NaN" parses into exactly that -- the + # sibling `_log_intent_divergence` keeps the same hazard inside its own try for the + # same reason. A non-finite ask is a degraded preview, not a routing failure. + return ask if ask.is_finite() and ask > 0 else None + + +def _warn_if_market_routing_overrides_entry( + intent: OrderIntent, + preview: Preview | dict[str, Any] | None, + order_configuration: dict[str, Any] | None = None, +) -> None: + """WARNING, at routing time, when a BUY's intended entry is materially off the market. + + #260's minimum viable mitigation. Every entry is routed `market_market_ioc` (#258's + faithful-engine decision), so a rule whose `Setup.entry` encodes a condition has that + condition bypassed in production -- `pullback_continuation` demands follow-through via + `signal_candle.high + buffer_ticks`, and the faithful measurement showed live taking 124 + trades the rule meant to decline at gross PF 0.7736 (vs 0.9219 intended). This reclaims + only the VISIBILITY, the same principle as #247 printing the fee rate: the operator can + see, order by order, which rule's design the routing overrode. + + The market reference is the venue's own `best_ask` from the preview `_run_order` JUST + fetched -- the price a market BUY actually pays, drawn from the one book quote already in + the hot path (no new broker call; a mid would misstate the gap by half the spread either + way). Below `ENTRY_OVERRIDE_WARN_BP` nothing is logged: a warning that fires every + order is a warning nobody reads. + + Scoped to BUYs on the market configuration only. SELL intents (exits, brackets, stop + rolls) either carry no entry condition or hand their prices to the venue verbatim, and a + caller passing its own non-market `order_configuration` -- a future resting order out of + #260's remediation plan -- is not on the override path at all. Never raises: telemetry + must not be able to fail a routing. `deviation_bps` is signed, positive meaning the rule + intended to enter ABOVE the market (follow-through demanded, pullback's case), negative + below it (a dip the market has not offered) -- the OPPOSITE sense of + `executor.intent_divergence`'s `divergence_bps`, which measures the venue's fill against + the intent; for one overridden trade the two readings have opposite signs, and a + dashboard must not average across them. + """ + if preview is None or intent.side != Side.BUY: + return + if order_configuration is None: + # Same resolution `_run_order` performs: no explicit configuration means the default + # routing, which today is always market. + order_configuration = _order_configuration(intent) + config_type = next(iter(order_configuration), "") + if not config_type.startswith("market_"): + return + ref = _preview_best_ask(preview) + if ref is None: + return + try: + expected = Decimal(str(intent.entry)) + except (InvalidOperation, TypeError, ValueError): + return + if not expected.is_finite() or expected <= 0: + return + deviation_bps = (expected - ref) / ref * Decimal(10_000) + if abs(deviation_bps) <= ENTRY_OVERRIDE_WARN_BP: + return + log_event( + logger, + logging.WARNING, + "executor.entry_override_market_routed", + rule=intent.rule_kind, + product=intent.product_id, + expected_fill=str(expected), + market_ref=str(ref), + market_ref_source="preview_best_ask", + deviation_bps=f"{deviation_bps:.2f}", + threshold_bps=f"{ENTRY_OVERRIDE_WARN_BP:.2f}", + detail=( + "the rule's conditional entry price was OVERRIDDEN -- entries are always routed " + "as market orders (#258), so the condition this rule encoded in its entry price " + "was bypassed and the order is going out at the venue's price instead (#260)" + ), + ) + + def _order_row(intent: OrderIntent, mode: str, now_ts: int) -> dict[str, Any]: + # Routed MARKET unconditionally (#258's faithful-engine decision): `expected_fill` below + # records the rule's intended entry even though execution ignores it -- the override + # #260's routing-time warning (`_warn_if_market_routing_overrides_entry` in `_run_order`) + # exists to make visible rather than silent. return dict( mode="live", product_id=intent.product_id, diff --git a/tests/execution/test_executor.py b/tests/execution/test_executor.py index cc9b9f63..83e2af36 100644 --- a/tests/execution/test_executor.py +++ b/tests/execution/test_executor.py @@ -1695,3 +1695,238 @@ def test_never_raises_on_unusable_input(self, caplog) -> None: _log_intent_divergence(order_id=10, intent=None, realized=Decimal("50000")) _log_intent_divergence(order_id=11, intent=self._intent("0"), realized=Decimal("1")) _log_intent_divergence(order_id=12, intent=self._intent(), realized="not-a-number") + + +# -- #260: the routing-time entry-override warning -------------------------------------------- + + +#: The stable event id the routing-time warning emits -- a name, never a sentence, per +#: `keel_core.telemetry`'s contract, so tests (and any aggregation) key on it. +_OVERRIDE_EVENT = "executor.entry_override_market_routed" + + +def _override_fields(caplog) -> dict: + """The structured payload of the last `executor.entry_override_market_routed` record. + + Same shape as `_divergence_fields` above: `log_event` attaches fields via `extra`, so + `caplog.text` shows only the event name and asserting on it would pass for any values. + """ + from keel_core.telemetry import _FIELDS_ATTR + + records = [r for r in caplog.records if r.getMessage() == _OVERRIDE_EVENT] + assert records, f"no {_OVERRIDE_EVENT} record was emitted" + return getattr(records[-1], _FIELDS_ATTR) + + +def _quoted_preview(best_ask: str) -> dict[str, Any]: + """A `CoinbaseClient.preview_order`-shaped dict carrying the venue's own book. + + The real client maps `best_bid`/`best_ask` to `Decimal` when the venue returns them; the + default `FakeBroker` preview omits them, which is exactly the degraded shape the warning + code has to survive (a preview with no book is not an error, it is just not a reference). + """ + return { + "order_total": Decimal("50.00"), + "commission_total": Decimal("0.30"), + "errs": [], + "warning": [], + "best_ask": Decimal(best_ask), + } + + +class TestEntryOverrideWarningAtRouting: + """#260's minimum viable mitigation, at ROUTING time (the divergence class above reports + after the fill; this warns before/at placement). + + Every entry is routed market (`_order_configuration` -> `market_market_ioc`), so a rule + whose `Setup.entry` encodes a CONDITION -- `pullback_continuation` demands follow-through + via `signal_candle.high + buffer_ticks` -- has that condition silently bypassed in + production. The warning makes the override visible using the one market price already in + the hot path: the `best_ask` the executor's own `preview_order` call just returned. + """ + + @staticmethod + def _intent(entry: str = "50000") -> OrderIntent: + return OrderIntent( + product_id="BTC-USD", + side=Side.BUY, + qty=Decimal("0.001"), + entry=Decimal(entry), + stop=Decimal("49000"), + notional=Decimal("50"), + is_dca=False, + rule_kind="pullback_continuation", + ) + + def test_routing_an_offset_entry_warns_loudly_at_warning_level(self, repo, caplog) -> None: + """The pullback case: entry ABOVE the market by more than the threshold. + + 50,300 intended against a 50,000 ask is +60bp -- beyond `ENTRY_OVERRIDE_WARN_BP` -- so + the order the rule meant to make conditional is about to go out unconditional, and the + log must say so at WARNING (loud, not the divergence class's after-the-fact INFO). + """ + broker = FakeBroker(preview=_quoted_preview("50000")) + signal = _enter_signal(_setup(entry=Decimal("50300"))) + + with caplog.at_level(logging.WARNING): + execute(signal, broker, repo, _config(), "autonomous", now_ts=NOW_TS) + + fields = _override_fields(caplog) + assert fields["rule"] == "pullback_continuation" + assert fields["product"] == "BTC-USD" + assert fields["expected_fill"] == "50300" + assert fields["market_ref"] == "50000" + assert fields["deviation_bps"] == "60.00" + assert fields["market_ref_source"] == "preview_best_ask" + # The sentence is the point: an operator must read WHAT was overridden, not just that + # a number differed -- the event id alone cannot say "your rule's design was bypassed". + assert "OVERRIDDEN" in fields["detail"] + assert "market" in fields["detail"] + records = [r for r in caplog.records if r.getMessage() == _OVERRIDE_EVENT] + assert records[-1].levelno == logging.WARNING + + def test_a_deviation_within_the_threshold_is_silent(self, repo, caplog) -> None: + """A warning that fires every order is a warning nobody reads. + + 50,010 against a 50,000 ask is +2bp -- the microstructure drift any enter-at-close rule + (`turtle_breakout`, `rsi_meanrev`) accumulates by routing one cycle after its signal + bar. That is noise, and noise must not train the operator to skip this line. + """ + broker = FakeBroker(preview=_quoted_preview("50000")) + signal = _enter_signal(_setup(entry=Decimal("50010"))) + + with caplog.at_level(logging.WARNING): + execute(signal, broker, repo, _config(), "autonomous", now_ts=NOW_TS) + + assert not [r for r in caplog.records if r.getMessage() == _OVERRIDE_EVENT] + + def test_exactly_at_the_threshold_does_not_warn(self, caplog) -> None: + """The boundary is pinned: strictly greater than `ENTRY_OVERRIDE_WARN_BP` warns. + + `>` rather than `>=` so an operator comparing a logged deviation against the documented + threshold reads "warned" as "beyond", never "at". Computed FROM the constant so this + test keeps pinning the boundary if the constant is ever retuned. + """ + from keel.execution.executor import ( + ENTRY_OVERRIDE_WARN_BP, + _warn_if_market_routing_overrides_entry, + ) + + market = Decimal("50000") + at_the_line = market * (Decimal(1) + ENTRY_OVERRIDE_WARN_BP / Decimal(10_000)) + + with caplog.at_level(logging.WARNING): + _warn_if_market_routing_overrides_entry( + self._intent(entry=str(at_the_line)), _quoted_preview("50000") + ) + + assert not [r for r in caplog.records if r.getMessage() == _OVERRIDE_EVENT] + + def test_entry_below_market_warns_with_a_negative_sign(self, caplog) -> None: + """The other direction: a rule whose entry rests BELOW the market (a limit at support). + + 49,700 intended against a 50,000 ask is -60bp. Signed so direction is legible without + recomputing: positive = the rule demanded follow-through ABOVE the market (pullback's + case), negative = it wanted a dip the market has not offered. + """ + from keel.execution.executor import _warn_if_market_routing_overrides_entry + + with caplog.at_level(logging.WARNING): + _warn_if_market_routing_overrides_entry( + self._intent(entry="49700"), _quoted_preview("50000") + ) + + fields = _override_fields(caplog) + assert fields["deviation_bps"] == "-60.00" + assert fields["expected_fill"] == "49700" + + def test_a_preview_without_a_book_quote_is_silent_not_fatal(self, caplog) -> None: + """No `best_ask`, no honest reference -- and a warning built on a guess would be noise. + + The default `FakeBroker` preview shape (no bid/ask keys) models a degraded venue + response; the cycle must proceed exactly as before this warning existed. + """ + from keel.execution.executor import _warn_if_market_routing_overrides_entry + + bookless = FakeBroker()._preview # the default shape: no best_bid/best_ask keys + with caplog.at_level(logging.WARNING): + _warn_if_market_routing_overrides_entry(self._intent(entry="50300"), bookless) + _warn_if_market_routing_overrides_entry( + self._intent(entry="50300"), + {**_quoted_preview("50000"), "best_ask": "not-a-number"}, + ) + # "nan" PARSES -- Decimal('NaN') constructs fine, and NaN > 0 raises + # InvalidOperation. cb_client does Decimal(value) on venue strings with no + # finiteness check, so this input is reachable; telemetry must swallow it, + # not abort the routing (the sibling intent_divergence path guards the same + # hazard inside its try). + _warn_if_market_routing_overrides_entry( + self._intent(entry="50300"), + {**_quoted_preview("50000"), "best_ask": "nan"}, + ) + # A zero/unusable intended entry has no meaningful deviation either. + _warn_if_market_routing_overrides_entry( + self._intent(entry="0"), _quoted_preview("50000") + ) + + assert not [r for r in caplog.records if r.getMessage() == _OVERRIDE_EVENT] + + def test_the_port_preview_shape_is_read_too(self, caplog) -> None: + """`preview` arrives as the port's `Preview` once Phase B migrates the call, and the + Coinbase adapter carries the same book in `detail` -- the warning must survive the + migration (values are strings there, not Decimals).""" + from keel_broker_api.results import Preview + + from keel.execution.executor import _warn_if_market_routing_overrides_entry + + preview = Preview( + product_id="BTC-USD", + side=Side.BUY, + est_base_size=Decimal("0.001"), + est_quote_size=Decimal("50"), + est_fee=Decimal("0.30"), + synthetic=False, + detail={"best_ask": "50000"}, + ) + + with caplog.at_level(logging.WARNING): + _warn_if_market_routing_overrides_entry(self._intent(entry="50300"), preview) + + assert _override_fields(caplog)["market_ref"] == "50000" + + def test_sell_intents_never_warn(self, caplog) -> None: + """Only the ENTRY routing is the override. A SELL intent's `entry` is a trigger or an + average cost, and the bracket/scale-out configurations carry their prices to the venue + verbatim -- warning there would be noise about orders that were NOT overridden.""" + from keel.execution.executor import _warn_if_market_routing_overrides_entry + + sell_intent = OrderIntent( + product_id="BTC-USD", + side=Side.SELL, + qty=Decimal("0.001"), + entry=Decimal("40000"), # 20,000bp off the ask -- deliberately absurd + stop=None, + notional=Decimal("50"), + is_dca=False, + rule_kind="position_rule", + ) + + with caplog.at_level(logging.WARNING): + _warn_if_market_routing_overrides_entry(sell_intent, _quoted_preview("50000")) + + assert not [r for r in caplog.records if r.getMessage() == _OVERRIDE_EVENT] + + def test_an_explicitly_non_market_configuration_never_warns(self, caplog) -> None: + """A caller that passes its own order configuration (the bracket, a stop roll, and any + FUTURE resting-entry routing from #260's remediation plan) is not on the + market-override path -- its prices reach the venue, and this warning must not fire.""" + from keel.execution.executor import _warn_if_market_routing_overrides_entry + + resting = {"limit_limit_gtc": {"base_size": "0.001", "limit_price": "50300"}} + + with caplog.at_level(logging.WARNING): + _warn_if_market_routing_overrides_entry( + self._intent(entry="50300"), _quoted_preview("50000"), resting + ) + + assert not [r for r in caplog.records if r.getMessage() == _OVERRIDE_EVENT]