nautechsystems / nautilus_trader

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

The 'order' <flag 'OrderStatus'> of 6 was not equal to the 'order_status' <flag 'OrderStatus'> of 1 #1865

Closed EvaGalois closed 1 month ago

EvaGalois commented 1 month ago

Bug Report

Expected Behavior

In each cycle, close positions according to conditions, cancel orders and re-post new limit orders

Actual Behavior

My trading strategy is a high-frequency strategy in bybit. When nautilus_trader v1.197.0 is trading live, an error occurs in the log:

[ERROR] TESTER-002.MyStrategy: Submit update Quote Error: The 'order' <flag 'OrderStatus'> of 6 was not equal to the 'order_status' <flag 'OrderStatus'> of 1

The installation of v1.198.0 and v1.199.0 will have errors of numpy and numba version conflicts. If the numpy version meets the requirements of numba, it does not meet the requirements of nautilus-trader, and vice versa. Therefore, v.1.197.0 is used as a version without version conflicts. In addition, there is another error:

2024-08-21T08:09:22.581212814Z [ERROR] TESTER-002.nautilus_common::timer: Error on callback: PyErr { type: <class 'AttributeError'>, value: AttributeError("'Timestamp' object has no attribute 'total_seconds'"), traceback: Some(<traceback object at 0x7d2494844400>) }

In fact, I did not use the attribute 'total_seconds' in the python code of my strategy, and the global search did not use it. The error may come from rust? (According to the beginning of the error "nautilus_common::timer:", it is an error caused by rust) But it is PyErr, so I don't know what the error is. The global search in the python code of the strategy does not use the code such as total_seconds. In my strategy main loop, I tried the following operation in each cycle:

for position in self.mystrategy.cache.positions_open():
    print("duration_ns", type(position.duration_ns), position.duration_ns)
    dt_value = unix_nanos_to_dt(position.duration_ns)
    print("dt_value", type(dt_value), dt_value)

The printed result is: duration_ns is int and is always 0, dt_value is pd.Timestamp, which is always the 0th second of January 1, 1970.

Steps to Reproduce the Problem

Specifications

cjdsellers commented 1 month ago

Hi @EvaGalois

Thanks for taking the time to report these findings.

Taking one thing at a time, I'm assuming you're installing via pip and have numba pre-existing in your environment? I ask because numba is not a listed dependency of nautilus_trader, and pip can't resolve version conflicts with an existing environment and the poetry.lock.

Other users have run into similar issues with conda environments with a large number of existing packages. We primarily support the use case of a separate Python virtual environment to isolate dependencies from anything else. With a package as complex as Nautilus there's a good chance of running into these sorts of compatibility issues installing with pip into a pre-existing environment.

poetry show numba

Package numba not found

If you identify any changes to version specifiers that could relax the version constraints for Nautilus to enhance compatibility, we'd be open to considering those changes on a case-by-case basis. For example, we recently relaxed the pyarrow version requirement to a >= specifier.

cjdsellers commented 1 month ago

[ERROR] TESTER-002.SMMV2Strategy: Order error: The 'order' <flag 'OrderStatus'> of 6 was not equal to the 'order_status' <flag 'OrderStatus'> of 1

It would be helpful if you were on the latest release version before we dive too far into debugging. The order status error does look familiar.

It looks like you might be trading Bybit options? this implementation isn't complete yet.

According to the beginning of the error "nautilus_common::timer:", it is an error caused by rust) But it is PyErr, so I don't know what the error is

Interesting, are you able to share further logs or a snippet of how you're using the timer? Generally we try to avoid panicking in Rust through the Python API, but there are some existing areas where this can still happen.

The printed result is: duration_ns is int and is always 0

This can be unintuitive, but because the Position does not itself have access to a clock - the duration_ns is always 0 until the position is finally closed, where the value is then assigned. Was your expectation that duration_ns would be the duration since open?

EvaGalois commented 1 month ago

Just relax the requirements of numpy version in v1.198.0 and v1.199.0 versions, and relax to numpy 2.1.0

I also like to use the latest version, but there are indeed instances of version conflicts. I have tested both source code installation and pip installation. There are no environmental issues when using it now, and the installation has been successful. Installing v.1.197.0 is a very simple task. In the end, I chose to install Nautilus in a separate conda environment, and pip install Nautilus trade==1.197.0 to successfully install it. Next, let's talk about my strategy operation issues:

This is my strategy to run the main entrance script:

from nautilus_trader.adapters.binance.factories import BinanceLiveDataClientFactory
from nautilus_trader.adapters.binance.factories import BinanceLiveExecClientFactory
from nautilus_trader.adapters.bybit.common.enums import BybitProductType
from nautilus_trader.adapters.bybit.config import BybitDataClientConfig
from nautilus_trader.adapters.bybit.config import BybitExecClientConfig
from nautilus_trader.adapters.bybit.factories import BybitLiveDataClientFactory
from nautilus_trader.adapters.bybit.factories import BybitLiveExecClientFactory
from nautilus_trader.config import CacheConfig
from nautilus_trader.config import InstrumentProviderConfig
from nautilus_trader.config import LiveExecEngineConfig
from nautilus_trader.config import LoggingConfig
from nautilus_trader.config import TradingNodeConfig
from nautilus_trader.live.node import TradingNode
from nautilus_trader.model.identifiers import InstrumentId
from nautilus_trader.model.identifiers import TraderId
from my_strategy.strategy import (
    MyStrategy, 
    MyStrategyConfig
)
...

Among these import contents, MyStrategy and MyStrategyConfig are my strategy contents.

The following is the definition of MyStrategy:

...
from nautilus_trader.trading.strategy import Strategy
...

Class MyStrategy(Strategy):
    def ...
    def ...
    def ...
    def on_start(self) -> None:
        ...
        from my_strategy.oms.oms import OrderManagementSystem
        self.oms = OrderManagementSystem(self)
        ...
    def process_parameters(self, settings: Dict, reload: bool) -> None:
        ...
        from my_strategy.quote_generators.plain import HFTQuoteGenerator
        self.quote_generator = HFTQuoteGenerator(self)

    def on_gen_place_orders(self, event: TimeEvent):
        if event.name != "market_maker":
            return None
        if not self.ready:
            self.wait_for_warmup()
            return None
        param_1 = ...
        param_2 = ...
        ...
        # Generate order queue
        new_orders = self.quote_generator.generate_orders(param_1, param_2, param_3, ...)

        self.oms.update(new_orders)
    ...

The following is the definition of HFTQuoteGenerator:

imports ...

class HFTQuoteGenerator(QuoteGenerator):
    def __init__(self, ss: MyStrategy) -> None:
        self.ss = ss
        super().__init__(self.ss)
    def ...
    def ...
    def ...
    def generate_quotes(self, param_1: float, param_2: float, ...) -> List[Order]:
        return self.prepare_limit_orders(bid_prices, bid_sizes, ask_prices, ask_sizes)

    def prepare_limit_orders(self, bid_prices: Array, bid_sizes: Array, ask_prices: Array, ask_sizes: Array) -> List[Order]:
        for bid_price, bid_size, ask_price, ask_size in zip(
            bid_prices, bid_sizes, ask_prices, ask_sizes
        ):
            orders.append(
                self.ss.order_factory.limit(
                    instrument_id=self.ss.instrument.id,
                    order_side=OrderSide.BUY,
                    time_in_force=TimeInForce.GTC,
                    price=self.ss.instrument.make_price(bid_price),
                    quantity=self.ss.instrument.make_qty(quantity),
                    post_only=True,
                    tags = [f'buy_{str_level}']
                )

            )
            quantity=self.ss.instrument.make_qty(ask_size)
            if quantity < self.ss.instrument.min_quantity:
                quantity = self.ss.instrument.min_quantity + self.ss.instrument.size_increment

            orders.append(
                self.ss.order_factory.limit(
                    instrument_id=self.ss.instrument.id,
                    order_side=OrderSide.SELL,
                    time_in_force=TimeInForce.GTC,
                    price=self.ss.instrument.make_price(ask_price),
                    quantity=self.ss.instrument.make_qty(quantity),
                    post_only=True,
                    tags = [f'sell_{str_level}']
                )
            )
            level += 1

        return orders

    def generate_orders(self, param_1: float, param_2: float, ...) -> List[Order]:
            # Among them, position_executor is an order generator for closing market orders on open positions, and generate_quotes is a limit order queue generator for pending orders
            return self.position_executor() + self.generate_quotes(param_1, param_2, ...)

    def position_executor(self, max_duration: float=10.0) -> List[Order]:
        sell_size = 0
        buy_size = 0
        for position in self.ss.cache.positions_open():
            print("duration_ns", type(position.duration_ns), position.duration_ns)
            dt_value = unix_nanos_to_dt(position.duration_ns)
            print("dt_value", type(dt_value), dt_value)
            time_delta = unix_nanos_to_dt(position.ts_last) - unix_nanos_to_dt(position.ts_opened)
            elapsed_seconds = time_delta.total_seconds()

            if elapsed_seconds > max_duration:
                if position.side == PositionSide.LONG:
                    buy_size += position.quantity.as_double()
                elif position.side == PositionSide.SHORT:
                    sell_size += position.quantity.as_double()
        if buy_size != 0:
            order.append(self.ss.order_factory.market(
                            instrument_id=self.ss.instrument.id,
                            order_side=OrderSide.SELL,    
                            time_in_force=TimeInForce.GTC,
                            quantity=self.ss.instrument.make_qty(buy_size),
                        ))
        if sell_size != 0:
            order.append(self.ss.order_factory.market(
                            instrument_id=self.ss.instrument.id,
                            order_side=OrderSide.BUY,  
                            time_in_force=TimeInForce.GTC,
                            quantity=self.ss.instrument.make_qty(sell_size),
                        ))
        return order
    ...

The following is the definition of OrderManagementSystem:

from my_strategy.strategy import MyStrategy
from nautilus_trader.model.orders import Order, LimitOrder, MarketOrder
class OrderManagementSystem:
    def __init__(self, ss: MyStrategy) -> None:
        self.ss = ss
        self.prev_intended_orders: List[Order] = []
    def ...
    def ...
    def ...
    def update(self, new_orders: List[Order]) -> None:
        try:
            debugpy.breakpoint()
            print("=====STEP ZERO=====")

            # Step 1
            if len(self.ss.cache.orders_open(instrument_id=self.ss.instrument_id)) == 0:
                print("=====STEP ONE=====")
                for order in new_orders:
                    self.ss.submit_order(order)
                return None

            # Step 2
            if len(self.ss.cache.orders_open(instrument_id=self.ss.instrument_id)) > self.ss.parameters["total_orders"]:
                print("=====STEP TWO=====")
                active_tags = set()

                for order in self.ss.cache.orders_open(instrument_id=self.ss.instrument_id):
                    tag = str(order.tags[0])

                    if tag not in active_tags:
                        active_tags.add(tag)
                    else:
                        self.ss.submit_order(order)

            # Step 3
            for order in new_orders:
                print("=====STEP THREE=====")
                if isinstance(order, MarketOrder) : 
                    self.ss.submit_order(order)

                elif isinstance(order, LimitOrder):
                    matched_old_order = self.find_matched_order(order)

                    if matched_old_order and self.is_out_of_bounds(matched_old_order, order):
                        self.ss.cancel_order(matched_old_order)
                        self.ss.submit_order(order)
                    else:
                        self.ss.submit_order(order)

                else :
                    raise ValueError(f"Invalid order type: {order.order_type}")

        except Exception as e:
            self.ss.log.error(f"Submit update Quote Error: {e}")

The above is my detailed code, which explains the code logic of generating closing market orders, revoking them, and creating limit orders.

ERRORINFO: Error from position check section:

...
2024-08-22T08:09:44.456085250Z [ERROR] TESTER-002.nautilus_common::timer: Error on callback: PyErr { type: <class 'AttributeError'>, value: AttributeError("'Timestamp' object has no attribute 'total_seconds'"), traceback: Some(<traceback object at 0x7d2494844400>) }
Repeated errors...
Repeated errors...
Repeated errors...
...

Error from order status check section:

2024-08-22T08:09:45.906031850Z [INFO] TESTER-002.ExecEngine: Reconciling order for ClientOrderId('O-20240822-080848-002-000-30')
=====STEP ZERO=====
=====STEP TWO=====
2024-08-22T08:10:12.304667415Z [ERROR] TESTER-002.MyStrategy: Submit update Quote Error: The 'order' <flag 'OrderStatus'> of 6 was not equal to the 'order_status' <flag 'OrderStatus'> of 1
=====STEP ZERO=====
=====STEP ZERO=====
2024-08-22T08:11:39.229028875Z [INFO] TESTER-002.MyStrategy: <--[EVT] OrderFilled(instrument_id=PENDLEUSDT-LINEAR.BYBIT, client_order_id=O-20240822-080848-002-000-21, venue_order_id=e666c0fe-b20a-4021-a6e7-7a46d411c61c, account_id=BYBIT-UNIFIED, trade_id=5a4ccd85-0b63-566a-93e8-805d2f0d2df1, position_id=PENDLEUSDT-LINEAR.BYBIT-SMMV2Strategy-000, order_side=BUY, order_type=LIMIT, last_qty=2, last_px=2.8245 USDT, commission=0.0011 USDT, liquidity_side=MAKER, ts_event=1724314234342000128)
2024-08-22T08:11:39.229294778Z [INFO] TESTER-002.Portfolio: PENDLEUSDT-LINEAR.BYBIT net_position=2
2024-08-22T08:11:39.229450594Z [INFO] TESTER-002.MyStrategy: <--[EVT] PositionOpened(instrument_id=PENDLEUSDT-LINEAR.BYBIT, position_id=PENDLEUSDT-LINEAR.BYBIT-MyStrategy-000, account_id=BYBIT-UNIFIED, opening_order_id=O-20240822-080848-002-000-21, closing_order_id=None, entry=BUY, side=LONG, signed_qty=2.0, quantity=2, peak_qty=2, currency=USDT, avg_px_open=2.8245, avg_px_close=0.0, realized_return=0.00000, realized_pnl=-0.0011 USDT, unrealized_pnl=0.00000000 USDT, ts_opened=1724314234342000128, ts_last=1724314234342000128, ts_closed=0, duration_ns=0)
=====STEP ZERO=====
=====STEP TWO=====
2024-08-22T08:11:49.392769331Z [ERROR] TESTER-002.MyStrategy: Submit update Quote Error: The 'order' <flag 'OrderStatus'> of 6 was not equal to the 'order_status' <flag 'OrderStatus'> of 1
duration_ns <class 'int'> 0
dt_value <class 'pandas._libs.tslibs.timestamps.Timestamp'> 1970-01-01 00:00:00+00:00
=====STEP ZERO=====
=====STEP TWO=====
2024-08-22T08:11:51.175377628Z [ERROR] TESTER-002.MyStrategy: Submit update Quote Error: The 'order' <flag 'OrderStatus'> of 6 was not equal to the 'order_status' <flag 'OrderStatus'> of 1
duration_ns <class 'int'> 0
dt_value <class 'pandas._libs.tslibs.timestamps.Timestamp'> 1970-01-01 00:00:00+00:00
=====STEP ZERO=====
=====STEP TWO=====
cjdsellers commented 1 month ago

[ERROR] TESTER-002.MyStrategy: Submit update Quote Error: The 'order' <flag 'OrderStatus'> of 6 was not equal to the 'order_status' <flag 'OrderStatus'> of 1

This error is rather unclear, but you're submitting an order which isn't in the INITIALIZED state (6 is ACCEPTED). I'll improve this error today, but this looks like a strategy bug. https://github.com/nautechsystems/nautilus_trader/blob/develop/nautilus_trader/trading/strategy.pyx#L774

2024-08-21T08:09:22.581212814Z [ERROR] TESTER-002.nautilus_common::timer: Error on callback: PyErr { type: <class 'AttributeError'>, value: AttributeError("'Timestamp' object has no attribute 'total_seconds'"), traceback: Some(<traceback object at 0x7d2494844400>) }

Even though this is a PyErr from Rust, it's originating from the callback the TimeEvent is being passed to in Python (probably the strategy handler?). I can't find anywhere in the codebase we're calling total_seconds on a pd.Timestamp.

On develop branch (and from the 1.200.0 release) I've relaxed the numpy version requirement to >= 2.0.1, so if you have that version installed then numba will pip install without complaint. It may be several weeks before we release the next version though.

nautilus-trader-8_k21njW-py3.10 ❯ pip install numba
Collecting numba
  Using cached numba-0.60.0-cp310-cp310-macosx_11_0_arm64.whl.metadata (2.7 kB)
Collecting llvmlite<0.44,>=0.43.0dev0 (from numba)
  Using cached llvmlite-0.43.0-cp310-cp310-macosx_11_0_arm64.whl.metadata (4.8 kB)
Requirement already satisfied: numpy<2.1,>=1.22 in /Users/cjdsellers/Library/Caches/pypoetry/virtualenvs/nautilus-trader-8_k21njW-py3.10/lib/python3.10/site-packages (from numba) (2.0.1)
Using cached numba-0.60.0-cp310-cp310-macosx_11_0_arm64.whl (2.7 MB)
Using cached llvmlite-0.43.0-cp310-cp310-macosx_11_0_arm64.whl (28.8 MB)
Installing collected packages: llvmlite, numba
Successfully installed llvmlite-0.43.0 numba-0.60.0

Closing this for now as I don't believe there is a bug here.

cjdsellers commented 1 month ago

The error is now improved from c20634df8a6dba7fd154a583cb07c0ea270bf1a8.

Will now be more descriptive, something like:

Invalid order status on submit: expected 'INITIALIZED', was 'ACCEPTED'
EvaGalois commented 1 month ago

Thank you for your help and your time.