nautechsystems / nautilus_trader

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

Duplicate trade_id when running EmaCross strategy backtest #1141

Closed rterbush closed 1 year ago

rterbush commented 1 year ago

Bug Report

Expected Behavior

EmaCross strategy backtest should run on any valid data without error.

Actual Behavior

Log data and backtrace below. Strategy logs multiple instances of the failed to apply error throughout the backtest. Backtest ends without printing backtest results and exits with error below. The behavior does not appear to happen on Windows or Linux using the same data, same backtest script.

Steps to Reproduce the Problem

  1. Run example EmaCross strategy on 25min data derived from 15 years ES futures data in QuoteTick format.
  2. Run on MacOS M1

Specifications

Digging into this deeper and will report back with any other findings.

2021-10-12T00:00:59.700000000Z [ERR] BACKTESTER-001.ExecEngine: Error on applying OrderFilled(trader_id=BACKTESTER-001, strategy_id=EMACross-097, instrument_id=ESZ21.CME, client_order_id=O-20211012-0000-001-097-3627, venue_order_id=CME-49-3710, account_id=CME-001, trade_id=CME-49-3710, position_id=CME-49-7254, order_side=SELL, order_type=MARKET, last_qty=1, last_px=4332.25 USD, commission=0.00 USD, liquidity_side=TAKER, event_id=f33f40fd-3892-4db6-a2d2-a8155fa7e58d, ts_event=1633996859700000000, ts_init=1633996859700000000) to Position(LONG 3 ESM15.CME, id=CME-49-7254)
KeyError("The 'fill.trade_id' CME-49-3710 was already contained in the '_trade_ids' collection")
Traceback (most recent call last):
  File "nautilus_trader/execution/engine.pyx", line 1013, in nautilus_trader.execution.engine.ExecutionEngine._update_position
  File "nautilus_trader/model/position.pyx", line 435, in nautilus_trader.model.position.Position.apply
  File "nautilus_trader/core/correctness.pyx", line 504, in nautilus_trader.core.correctness.Condition.not_in

2021-12-02T11:00:59.700000000Z [ERR] BACKTESTER-001.ExecEngine: Error on applying OrderFilled(trader_id=BACKTESTER-001, strategy_id=EMACross-048, instrument_id=ESZ21.CME, client_order_id=O-20211202-1100-001-048-5373, venue_order_id=CME-49-7201, account_id=CME-001, trade_id=CME-49-7201, position_id=CME-49-10745, order_side=BUY, order_type=MARKET, last_qty=1, last_px=4571.00 USD, commission=0.00 USD, liquidity_side=TAKER, event_id=5aadfe14-f972-4ff8-8b79-c8873cc6c025, ts_event=1638442859700000000, ts_init=1638442859700000000) to Position(FLAT ESU21.CME, id=CME-49-10745)
KeyError("The 'fill.trade_id' CME-49-7201 was already contained in the '_trade_ids' collection")
Traceback (most recent call last):
  File "nautilus_trader/execution/engine.pyx", line 992, in nautilus_trader.execution.engine.ExecutionEngine._open_position
  File "nautilus_trader/model/position.pyx", line 435, in nautilus_trader.model.position.Position.apply
  File "nautilus_trader/core/correctness.pyx", line 504, in nautilus_trader.core.correctness.Condition.not_in

2021-12-02T11:30:59.700000000Z [ERR] BACKTESTER-001.ExecEngine: Error on applying OrderFilled(trader_id=BACKTESTER-001, strategy_id=EMACross-097, instrument_id=ESZ21.CME, client_order_id=O-20211202-1130-001-097-5374, venue_order_id=CME-49-7204, account_id=CME-001, trade_id=CME-49-7204, position_id=CME-49-10748, order_side=BUY, order_type=MARKET, last_qty=1, last_px=4584.25 USD, commission=0.00 USD, liquidity_side=TAKER, event_id=867379a0-b43e-4043-812c-df61e783d98f, ts_event=1638444659700000000, ts_init=1638444659700000000) to Position(FLAT ESU21.CME, id=CME-49-10748)
KeyError("The 'fill.trade_id' CME-49-7204 was already contained in the '_trade_ids' collection")
Traceback (most recent call last):
  File "nautilus_trader/execution/engine.pyx", line 992, in nautilus_trader.execution.engine.ExecutionEngine._open_position
  File "nautilus_trader/model/position.pyx", line 435, in nautilus_trader.model.position.Position.apply
  File "nautilus_trader/core/correctness.pyx", line 504, in nautilus_trader.core.correctness.Condition.not_in

Traceback (most recent call last):
  File "/Users/randy/Develop/_Personal/systemdev_base/scripts/backtest_using_tick_data.py", line 123, in <module>
    engine.run()
  File "nautilus_trader/backtest/engine.pyx", line 870, in nautilus_trader.backtest.engine.BacktestEngine.run
  File "nautilus_trader/backtest/engine.pyx", line 895, in nautilus_trader.backtest.engine.BacktestEngine.end
  File "nautilus_trader/backtest/exchange.pyx", line 754, in nautilus_trader.backtest.exchange.SimulatedExchange.process
  File "nautilus_trader/backtest/exchange.pyx", line 787, in nautilus_trader.backtest.exchange.SimulatedExchange.process
  File "nautilus_trader/backtest/matching_engine.pyx", line 617, in nautilus_trader.backtest.matching_engine.OrderMatchingEngine.process_order
  File "nautilus_trader/backtest/matching_engine.pyx", line 653, in nautilus_trader.backtest.matching_engine.OrderMatchingEngine.process_order
  File "nautilus_trader/backtest/matching_engine.pyx", line 735, in nautilus_trader.backtest.matching_engine.OrderMatchingEngine._process_market_order
  File "nautilus_trader/backtest/matching_engine.pyx", line 1360, in nautilus_trader.backtest.matching_engine.OrderMatchingEngine.fill_market_order
  File "nautilus_trader/backtest/matching_engine.pyx", line 1523, in nautilus_trader.backtest.matching_engine.OrderMatchingEngine.apply_fills
  File "nautilus_trader/backtest/matching_engine.pyx", line 1636, in nautilus_trader.backtest.matching_engine.OrderMatchingEngine.fill_order
  File "nautilus_trader/backtest/matching_engine.pyx", line 2114, in nautilus_trader.backtest.matching_engine.OrderMatchingEngine._generate_order_filled
  File "nautilus_trader/msgbus/bus.pyx", line 274, in nautilus_trader.msgbus.bus.MessageBus.send
  File "nautilus_trader/execution/engine.pyx", line 601, in nautilus_trader.execution.engine.ExecutionEngine.process
  File "nautilus_trader/execution/engine.pyx", line 613, in nautilus_trader.execution.engine.ExecutionEngine.process
  File "nautilus_trader/execution/engine.pyx", line 886, in nautilus_trader.execution.engine.ExecutionEngine._handle_event
  File "nautilus_trader/execution/engine.pyx", line 951, in nautilus_trader.execution.engine.ExecutionEngine._apply_event_to_order
  File "nautilus_trader/msgbus/bus.pyx", line 486, in nautilus_trader.msgbus.bus.MessageBus.publish_c
  File "nautilus_trader/portfolio/portfolio.pyx", line 406, in nautilus_trader.portfolio.portfolio.Portfolio.update_order
  File "nautilus_trader/portfolio/portfolio.pyx", line 456, in nautilus_trader.portfolio.portfolio.Portfolio.update_order
  File "nautilus_trader/accounting/manager.pyx", line 119, in nautilus_trader.accounting.manager.AccountsManager.update_balances
  File "nautilus_trader/accounting/manager.pyx", line 494, in nautilus_trader.accounting.manager.AccountsManager._update_balance_single_currency
  File "nautilus_trader/model/objects.pyx", line 1136, in nautilus_trader.model.objects.AccountBalance.__init__
  File "nautilus_trader/core/correctness.pyx", line 57, in nautilus_trader.core.correctness.Condition.true
ValueError: `total` amount was negative
rterbush commented 1 year ago

Closing this as it appears it was caused by duplicate list of contracts in the futures_contract.parquet which caused the backtest to run on duplicate data...