Trailing Safety Order tries to cancel order, fails, then counts SO as filled (Paper Trading)

[MisterMelons]

Hi,

I'm running into a problem with trailingstoploss_tp.py

While paper trading on 3Commas, the script follows the price action down and creates a safety order. When the price rises the script cancels the safety order, but doesn't think it has done so successfully. That would be fine, but it then reports that the safety order has been filled, even though it was actually cancelled. This error leads to the safety order tracking being incorrect and skipping the safety order entirely. Could this be a paper trading thing?

Here are some logs:

2024-01-31 08:24:33 - trailingstoploss_tp - ERROR - 2219774551: cancel of order 470698406 failed!
2024-01-31 08:24:33 - trailingstoploss_tp - DEBUG - 2219774551: cancel of order 470698406 failed! Received data from 3C: [{'order_id': '470698406', 'order_type': 'BUY', 'deal_order_type': 'Manual Safety', 'cancellable': False, 'status_string': 'Active', 'created_at': '2024-01-31T15:21:28.291Z', 'updated_at': '2024-01-31T15:24:34.631Z', 'quantity': '17.63', 'quantity_remaining': '17.63', 'total': '0.0', 'rate': '22.7', 'average_price': '0.0'}, {'order_id': '469627316', 'order_type': 'BUY', 'deal_order_type': 'Manual Safety', 'cancellable': False, 'status_string': 'Filled', 'created_at': '2024-01-31T00:25:59.734Z', 'updated_at': '2024-01-31T00:26:25.382Z', 'quantity': '8.53', 'quantity_remaining': '0.0', 'total': '200.3139138', 'rate': '23.46', 'average_price': '23.48346'}, {'order_id': '468734453', 'order_type': 'BUY', 'deal_order_type': 'Base', 'cancellable': False, 'status_string': 'Filled', 'created_at': '2024-01-30T13:33:41.419Z', 'updated_at': '2024-01-30T13:33:57.158Z', 'quantity': '4.45', 'quantity_remaining': '0.0', 'total': '107.174067', 'rate': '24.06', 'average_price': '24.08406'}].
2024-01-31 08:24:33 - trailingstoploss_tp - DEBUG - https://api.3commas.io:443 "GET /public/api/ver1/deals/2219774551/market_orders HTTP/1.1" 200 None
2024-01-31 08:24:33 - trailingstoploss_tp - WARNING - "Demo Bot": USDT_AUCTION/2219774551: cancellation of order 470698406 failed. Current state is Cancelled. Evaluate next interval again.
2024-01-31 08:24:39 - trailingstoploss_tp - DEBUG - https://api.3commas.io:443 "GET /public/api/ver1/bots/11949660/show HTTP/1.1" 200 None
2024-01-31 08:24:39 - trailingstoploss_tp - INFO - "Demo Bot": USDT_AUCTION/2219774551: order 470698406 has been filled. 2/3 Safety Order(s) are filled.

Thank you for any help!

[amargedon]

Could you post a screenshot of the deal details in 3Commas? I've seen during my own testing in the past that SO's could not be cancelled, however, in that case the order was (partially) filled at the same moment the script decided it should be cancelled (meaning the SO should be counted).

[MisterMelons]

I certainly can. I'm attaching 2 screenshots. This isn't the first time it has happened and the case you brought up would make sense. Unfortunately, I don't see that any of the effected deals had any partial fills. Let me know if you need to see my bot details. Thank you!

[MisterMelons]

FWIW, I was trying to backtrack the source of the problem in the code. That brought me to threecommas.py and the def for threecommas_deal_cancel_order (line 672). I was wondering if 3Commas had a delay between the api.request (line 677) and the cancellation of the order, if the expected "data" just below the api.request wouldn't see the "status_string" as "cancelled". By the time the script gets to the WARNING line in my first post the script reports that the status is Cancelled, but that is a little further down the line. Maybe the script should wait for a second or two for the order to cancel before checking the "status_string"?

I don't know... I'm just tinkering around.

[amargedon]

I'm thinking someting else, actually. In the first image you posted (thanks for that), the status of order 470698406 shows Cancelled. That makes me think about this line again: "cancellation of order 470698406 failed. Current state is Cancelled". Why does the script wants to cancel an order, of which the state is already cancelled...?

This raises the question what has happened with order 470698406 before. Are you able to 'grep' that from the logfile? Was it cancelled before from the script and not administrated properly, was it cancelled from 3C website maybe?

[MisterMelons]

Order 470698406 was created by the script three minutes before the attempt to cancel it:

2024-01-31 08:21:27 - trailingstoploss_tp - INFO - "Demo Bot": USDT_AUCTION/2219774551: profit -5.75% passed Add Funds threshold at -5.77% (trailing from -5.25%). Created order '470698406' for 17.6300 AUCTION.

Your question of why does the script want to cancel an order of which the state is already cancelled, led to my theory above. The script sends the api.request to cancel the order then immediately checks the "data" to see if there are any orders cancelled. If the 3Commas database doesn't show the order is cancelled yet on their side, the script continues past that section of code.

The second line of the error in my first post shows that 3C is reporting a status of Active for the deal it just tried to Cancel:

cancel of order 470698406 failed! Received data from 3C: [{'order_id': '470698406', 'order_type': 'BUY', 'deal_order_type': 'Manual Safety', 'cancellable': False, 'status_string': 'Active'

By the time the script gets to the "def evaluate_deal_orders" section of trailingstoploss.py the 3Commas database has updated to a status of Cancelled. This section of the script is what is causing the Warning in the logs because the status is Cancelled and does not match the status of Filled:

else:
                orderstatus = get_threecommas_deal_order_status(
                    logger, api, deal_data["pair"], deal_data["id"], order_db_data["order_id"]
                )

                if orderstatus.lower() == "filled":
                    # Order is filled, however deal data not yet updated at 3C?
                    openorderfilled = True
                else:
                    logger.warning(
                        f"\"{bot_data['name']}\": {deal_data['pair']}/{deal_data['id']}: "
                        f"cancellation of order {order_db_data['order_id']} failed. "
                        f"Current state is {orderstatus}. Evaluate next interval again."
                    )

[amargedon]

I see what you are thinking. Will need to check the code myself and see how and what.

I'm out of the country for work and back end of next week, so will try to have a look when I'm back.

[MisterMelons]

No problem. Thank you for the response and safe travels to you!