search

nautechsystems / nautilus_trader

A high-performance algorithmic trading platform and event-driven backtester
https://nautilustrader.io
GNU Lesser General Public License v3.0
1.71k stars 402 forks source link

Delays for live trading #1617

Closed cuberone closed 2 months ago

cuberone commented 2 months ago

Bug Report

After fixing the delays for live trading, I found a new random delay when reaching Exec Client. See the log (0.2 s)

{"timestamp":"2024-04-27T10:47:10.444593358Z","trader_id":"NODE-1","level":"INFO","color":"NORMAL","component":"GridSimple","message":"<--[EVT] OrderInitialized(instrument_id=BTCUSDT-PERP.BINANCE, client_order_id=O-20240427-1047-1-01-11, side=BUY, type=LIMIT, quantity=0.512, time_in_force=GTC, post_only=False, reduce_only=False, quote_quantity=False, options={'price': '62566.0', 'display_qty': None, 'expire_time_ns': 0}, emulation_trigger=NO_TRIGGER, trigger_instrument_id=None, contingency_type=NO_CONTINGENCY, order_list_id=None, linked_order_ids=None, parent_order_id=None, exec_algorithm_id=None, exec_algorithm_params=None, exec_spawn_id=None, tags=['78'])"}
{"timestamp":"2024-04-27T10:47:10.444722465Z","trader_id":"NODE-1","level":"INFO","color":"NORMAL","component":"GridSimple","message":"[CMD]--> SubmitOrder(order=LimitOrder(BUY 0.512 BTCUSDT-PERP.BINANCE LIMIT @ 62566.0 GTC, status=INITIALIZED, client_order_id=O-20240427-1047-1-01-11, venue_order_id=None, position_id=None, tags=['78']), position_id=None)"}
{"timestamp":"2024-04-27T10:47:10.444903651Z","trader_id":"NODE-1","level":"INFO","color":"NORMAL","component":"GridSimple","message":"<--[EVT] OrderInitialized(instrument_id=BTCUSDT-PERP.BINANCE, client_order_id=O-20240427-1047-1-01-12, side=SELL, type=LIMIT, quantity=0.512, time_in_force=GTC, post_only=False, reduce_only=False, quote_quantity=False, options={'price': '62880.0', 'display_qty': None, 'expire_time_ns': 0}, emulation_trigger=NO_TRIGGER, trigger_instrument_id=None, contingency_type=NO_CONTINGENCY, order_list_id=None, linked_order_ids=None, parent_order_id=None, exec_algorithm_id=None, exec_algorithm_params=None, exec_spawn_id=None, tags=['80'])"}
{"timestamp":"2024-04-27T10:47:10.444990472Z","trader_id":"NODE-1","level":"INFO","color":"NORMAL","component":"GridSimple","message":"[CMD]--> SubmitOrder(order=LimitOrder(SELL 0.512 BTCUSDT-PERP.BINANCE LIMIT @ 62880.0 GTC, status=INITIALIZED, client_order_id=O-20240427-1047-1-01-12, venue_order_id=None, position_id=None, tags=['80']), position_id=None)"}
{"timestamp":"2024-04-27T10:47:10.620145096Z","trader_id":"NODE-1","level":"INFO","color":"BLUE","component":"ExecClient-BINANCE","message":"Submit LimitOrder(BUY 0.512 BTCUSDT-PERP.BINANCE LIMIT @ 62566.0 GTC, status=INITIALIZED, client_order_id=O-20240427-1047-1-01-11, venue_order_id=None, position_id=None, tags=['78'])"}
{"timestamp":"2024-04-27T10:47:10.620297554Z","trader_id":"NODE-1","level":"INFO","color":"BLUE","component":"ExecClient-BINANCE","message":"Submit LimitOrder(SELL 0.512 BTCUSDT-PERP.BINANCE LIMIT @ 62880.0 GTC, status=INITIALIZED, client_order_id=O-20240427-1047-1-01-12, venue_order_id=None, position_id=None, tags=['80'])"}
{"timestamp":"2024-04-27T10:47:10.621388545Z","trader_id":"NODE-1","level":"INFO","color":"NORMAL","component":"GridSimple","message":"<--[EVT] OrderSubmitted(instrument_id=BTCUSDT-PERP.BINANCE, client_order_id=O-20240427-1047-1-01-11, account_id=BINANCE-spot-master, ts_event=1714214830620404417)"}
{"timestamp":"2024-04-27T10:47:10.621456529Z","trader_id":"NODE-1","level":"INFO","color":"NORMAL","component":"GridSimple","message":"<--[EVT] OrderSubmitted(instrument_id=BTCUSDT-PERP.BINANCE, client_order_id=O-20240427-1047-1-01-12, account_id=BINANCE-spot-master, ts_event=1714214830620927488)"}

There is still a direct call to _queue.put_nowait() in the code in nautilus_trader/common/executor.py, but I'm not sure if this is the cause of the delay since there were no delays in v1.180.

Specifications

cjdsellers commented 2 months ago

Hi @cuberone

Thanks for sharing your observations.

I would say the ActorExecutor doesn't play a part in this unless you are actually using the Nautilus executor in your code? How consistent is this delay? I haven't done any detailed measurements for a while, are the Python GC events observable?

cuberone commented 2 months ago

Cannot reproduce

cjdsellers commented 2 months ago

Thanks for the update, I also couldn't see a consistent delay in that area from a light logs audit. My best guess is as above - some GC or even OS level event.

I know there are some users consistently tracking these metrics during live trading so I'll reach out and see if I can dig up any issues around this.