Closed VeraLyu closed 1 month ago
Hey @VeraLyu
I just need to gather some more information here to know how to investigate.
Did you redact the logs in any way, did you submit orders for an instrument which you had also subscribed to data for?
Could you double check the strategy logic if 10 orders were submitted after one tick, instead of 2?
Yes, I cut part of the log to avoid messing up. and yes, I subscribed trade tick and quote for the sym. I set n_orders to 10 make sure 10 ticks will be executed (just for easier observation of the behavior)
def check_and_open_position(self):
if self.n_orders == 0:
return
# open position need to be fast
self.market_long_size = calc_market_size(self.trades_data[self.long_sym], 50, True)
self.market_short_size = calc_market_size(self.trades_data[self.short_sym], 50, False)
self.order_size = min(self.market_long_size, self.market_short_size)
buy_price = self.long_quote[-1].ask_price.as_decimal() - self.instrument_long.price_increment.as_decimal()
sell_price = self.short_quote[-1].bid_price.as_decimal() + self.instrument_short.price_increment.as_decimal()
self.sell(False, sell_price, self.order_size) #bool controls if it is market or limit order
self.buy(True, buy_price, self.order_size)
def on_trade_tick(self, tick: TradeTick) -> None:
self.log.info(f'trade tick coming in {tick}')
instrument_id = tick.instrument_id.value
self.trades_data[instrument_id].append({
'price': float(tick.price.as_decimal()),
'size': float(tick.size.as_decimal()),
'buyer_mm': tick.aggressor_side == AggressorSide.SELLER,
'ts_event': tick.ts_event,
})
if self.open_period_end:
self.check_and_close_position()
#TODO: gathering data needs to be start in advance to picking
elif len(self.trades_data[self.long_sym]) > self.start_calculation_len and len(self.trades_data[self.short_sym]) > self.start_calculation_len:
self.check_and_open_position()
not sure if it is because I used timeForce parameter
order = self.order_factory.limit(
instrument_id=self.instrument_id,
order_side=OrderSide.SELL,
price=Price(price, precision=self.instrument.price_precision),
quantity=self.instrument.make_qty(quantity),
time_in_force=TimeInForce.GTC,
)
I don't think the time in force matters here. Are you able to provide a basic MRE strategy I could run with the Binance sandbox example to help debug this?
I don't think the time in force matters here. Are you able to provide a basic MRE strategy I could run with the Binance sandbox example to help debug this?
Thanks a lot, I will try to narrow down myself first to save your time. Besides the batch problem, any idea why most order requests did not receive status report? It continuously queries the orders' status but no response came back.
[1m2024-05-27T03:31:03.389387441Z[0m [94m[INFO] TESTER-001.ExecClient-BINANCE: Query ClientOrderId('O-20240527-0330-001-000-9')[0m
[1m2024-05-27T03:31:03.389577918Z[0m [1;33m[WARN] TESTER-001.ExecClient-BINANCE: Did not receive OrderStatusReport
from request
It would be because the live trading node is setup to work with live venues in the first instance.
We're starting to discover how the simulated exchange isn't working entirely to spec as a live venue. So there is no current method which will handle generating an order status report from the simulated exchange.
As for why order accepted events weren't generated - this is what we have to determine next.
It would be because the live trading node is setup to work with live venues in the first instance.
We're starting to discover how the simulated exchange isn't working entirely to spec as a live venue. So there is no current method which will handle generating an order status report from the simulated exchange.
As for why order accepted events weren't generated - this is what we have to determine next.
Do you mean it is expected behavior for simulated exchange to not get order status report because we didn't make stub for it (with order fill part still works for sandbox). Or do you suggest after testing with backtest mode I need to switch directly to live instead of using sandbox mode?
The SimulatedExchange
has no path for generating an order status report - and it may not make sense to add one either because we already have the order in the cache so know the status. This issue is stemming from OrderAccepted
events not being generated, as far as I can guess.
I think its perfectly reasonable you should be able to test with the sandbox after backtesting. I'm still uncertain if this is a regression - or if we're just uncovering additional cases which need handling.
Hey @VeraLyu
This issue is now fixed on develop
from cbfc7035aa62df6cdf6c45cf3621cf3d0eea4faf.
It's a fairly simplistic "internal" config change which means there will be no delay in generating order accepted events, or processing other trading commands when operating in a sandbox mode.
Eventually we're going to want latency more accurately modeled in the sandbox (currently latency to the simulated exchange will be microseconds), but I've resisted the urge to go down that feature expansion track for the moment - I'll create a ticket though.
Hey @VeraLyu
This issue is now fixed on
develop
from cbfc703.It's a fairly simplistic "internal" config change which means there will be no delay in generating order accepted events, or processing other trading commands when operating in a sandbox mode.
Eventually we're going to want latency more accurately modeled in the sandbox (currently latency to the simulated exchange will be microseconds), but I've resisted the urge to go down that feature expansion track for the moment - I'll create a ticket though.
Thanks a lot! I will test with it later after I finished my current strategy backtest
Bug Report
When I test with trade tick and quote in sandbox mode, e.g. a market maker it opened two orders every tick. I observed two issues here:
Expected Behavior
Orders filled/rejected after submission according to following trade/quote. Orders submitted at once without any batch behaviour
Actual Behavior
Orders submission were batched(10 ticks opened 20 orders first submission at 2024-05-27T03:30:48.608281221Z to last submission at 1m2024-05-27T03:30:48.618151288Z) and their status were not reported after submission so none of them filled:
[1m2024-05-27T03:30:48.608281221Z[0m [INFO] TESTER-001.DoubleMakerStrategy: [CMD]--> SubmitOrder(order=LimitOrder(SELL 515 XXXXXXXX-PERP.BINANCE LIMIT @ 0.16676 GTC, status=INITIALIZED, client_order_id=O-20240527-0330-001-000-1 ........... [1m2024-05-27T03:30:48.618151288Z[0m [INFO] TESTER-001.DoubleMakerStrategy: [CMD]--> SubmitOrder(order=LimitOrder(SELL 515 xxxxxxxx-PERP.BINANCE LIMIT @ 0.16676 GTC, status=INITIALIZED, client_order_id=O-20240527-0330-001-000-19, venue_order_id=None, position_id=None, tags=None), position_id=None)
[1m2024-05-27T03:30:48.618783463Z[0m [INFO] TESTER-001.DoubleMakerStrategy: <--[EVT] OrderSubmitted(instrument_id=xxxx-PERP.BINANCE, client_order_id=O-20240527-0330-001-000-1, account_id=BINANCE-001, ts_event=1716780648614607627)[0m [1m2024-05-27T03:30:48.618803273Z[0m [INFO] TESTER-001.DoubleMakerStrategy: <--[EVT] OrderSubmitted(instrument_id=xxxxx-PERP.BINANCE, client_order_id=O-20240527-0330-001-000-2, account_id=BINANCE-001, ts_event=1716780648614607627)[0m [1m2024-05-27T03:30:48.618810138Z[0m [INFO] TESTER-001.DoubleMakerStrategy: <--[EVT] OrderSubmitted(instrument_id=xxxx-PERP.BINANCE, client_order_id=O-20240527-0330-001-000-3, account_id=BINANCE-001, ts_event=1716780648614607627)[0m [1m2024-05-27T03:30:48.618815444Z[0m [INFO] TESTER-001.DoubleMakerStrategy: <--[EVT] OrderSubmitted(instrument_id=xxxx-PERP.BINANCE, client_order_id=O-20240527-0330-001-000-4, account_id=BINANCE-001, ts_event=1716780648614607627)[0m .... .... [1m2024-05-27T03:30:48.619189179Z[0m [INFO] TESTER-001.DoubleMakerStrategy: <--[EVT] OrderSubmitted(instrument_id=-PERP.BINANCE, client_order_id=O-20240527-0330-001-000-18, account_id=BINANCE-001, ts_event=1716780648614607627)[0m [1m2024-05-27T03:30:48.619194088Z[0m [INFO] TESTER-001.DoubleMakerStrategy: <--[EVT] OrderSubmitted(instrument_id=-PERP.BINANCE, client_order_id=O-20240527-0330-001-000-19, account_id=BINANCE-001, ts_event=1716780648614607627)[0m [1m2024-05-27T03:30:48.619198760Z[0m [INFO] TESTER-001.DoubleMakerStrategy: <--[EVT] OrderSubmitted(instrument_id=-PERP.BINANCE, client_order_id=O-20240527-0330-001-000-20, account_id=BINANCE-001, ts_event=1716780648614607627)[0m
.... [1m2024-05-27T03:30:55.382429066Z[0m [94m[INFO] TESTER-001.ExecClient-BINANCE: Query ClientOrderId('O-20240527-0330-001-000-10')[0m [1m2024-05-27T03:30:55.382792012Z[0m [94m[INFO] TESTER-001.ExecClient-BINANCE: Query ClientOrderId('O-20240527-0330-001-000-11')[0m ... [1m2024-05-27T03:30:55.383395831Z[0m [1;33m[WARN] TESTER-001.ExecClient-BINANCE: Did not receive
OrderStatusReport
from request[0m [1m2024-05-27T03:30:55.383404423Z[0m [1;33m[WARN] TESTER-001.ExecClient-BINANCE: Did not receiveOrderStatusReport
from request[0m [1m2024-05-27T03:30:55.383409309Z[0m [1;33m[WARN] TESTER-001.ExecClient-BINANCE: Did not receiveOrderStatusReport
from request[0m