Merge pull request #3320 from freqtrade/fix_sell_spamming

Fix sell spamming

freqtrade/freqtradebot.py

@@ -879,10 +879,10 @@ class FreqtradeBot:
                 logger.info('Cannot query order for %s due to %s', trade, traceback.format_exc())
                 continue
 
-            trade_state_update = self.update_trade_state(trade, order)
+            fully_cancelled = self.update_trade_state(trade, order)
 
-            if (order['side'] == 'buy' and (
+            if (order['side'] == 'buy' and (order['status'] == 'open' or fully_cancelled) and (
-                    trade_state_update
+                    fully_cancelled
                     or self._check_timed_out('buy', order)
                     or strategy_safe_wrapper(self.strategy.check_buy_timeout,
                                              default_retval=False)(pair=trade.pair,
@@ -890,8 +890,8 @@ class FreqtradeBot:
                                                                    order=order))):
                 self.handle_cancel_buy(trade, order, constants.CANCEL_REASON['TIMEOUT'])
 
-            elif (order['side'] == 'sell' and (
+            elif (order['side'] == 'sell' and (order['status'] == 'open' or fully_cancelled) and (
-                  trade_state_update
+                  fully_cancelled
                   or self._check_timed_out('sell', order)
                   or strategy_safe_wrapper(self.strategy.check_sell_timeout,
                                            default_retval=False)(pair=trade.pair,
@@ -1126,6 +1126,11 @@ class FreqtradeBot:
         """
         Sends rpc notification when a sell cancel occured.
         """
+        if trade.sell_order_status == reason:
+            return
+        else:
+            trade.sell_order_status = reason
+
         profit_rate = trade.close_rate if trade.close_rate else trade.close_rate_requested
         profit_trade = trade.calc_profit(rate=profit_rate)
         current_rate = self.get_sell_rate(trade.pair, False)

freqtrade/persistence.py

@@ -86,7 +86,7 @@ def check_migrate(engine) -> None:
         logger.debug(f'trying {table_back_name}')
 
     # Check for latest column
-    if not has_column(cols, 'fee_close_cost'):
+    if not has_column(cols, 'sell_order_status'):
         logger.info(f'Running database migration - backup available as {table_back_name}')
 
         fee_open = get_column_def(cols, 'fee_open', 'fee')
@@ -113,6 +113,7 @@ def check_migrate(engine) -> None:
         close_profit_abs = get_column_def(
             cols, 'close_profit_abs',
             f"(amount * close_rate * (1 - {fee_close})) - {open_trade_price}")
+        sell_order_status = get_column_def(cols, 'sell_order_status', 'null')
 
         # Schema migration necessary
         engine.execute(f"alter table trades rename to {table_back_name}")
@@ -131,7 +132,7 @@ def check_migrate(engine) -> None:
                 stake_amount, amount, open_date, close_date, open_order_id,
                 stop_loss, stop_loss_pct, initial_stop_loss, initial_stop_loss_pct,
                 stoploss_order_id, stoploss_last_update,
-                max_rate, min_rate, sell_reason, strategy,
+                max_rate, min_rate, sell_reason, sell_order_status, strategy,
                 ticker_interval, open_trade_price, close_profit_abs
                 )
             select id, lower(exchange),
@@ -153,6 +154,7 @@ def check_migrate(engine) -> None:
                 {initial_stop_loss_pct} initial_stop_loss_pct,
                 {stoploss_order_id} stoploss_order_id, {stoploss_last_update} stoploss_last_update,
                 {max_rate} max_rate, {min_rate} min_rate, {sell_reason} sell_reason,
+                {sell_order_status} sell_order_status,
                 {strategy} strategy, {ticker_interval} ticker_interval,
                 {open_trade_price} open_trade_price, {close_profit_abs} close_profit_abs
                 from {table_back_name}
@@ -228,6 +230,7 @@ class Trade(_DECL_BASE):
     # Lowest price reached
     min_rate = Column(Float, nullable=True)
     sell_reason = Column(String, nullable=True)
+    sell_order_status = Column(String, nullable=True)
     strategy = Column(String, nullable=True)
     ticker_interval = Column(Integer, nullable=True)
 
@@ -267,6 +270,7 @@ class Trade(_DECL_BASE):
             'stake_amount': round(self.stake_amount, 8),
             'close_profit': self.close_profit,
             'sell_reason': self.sell_reason,
+            'sell_order_status': self.sell_order_status,
             'stop_loss': self.stop_loss,
             'stop_loss_pct': (self.stop_loss_pct * 100) if self.stop_loss_pct else None,
             'initial_stop_loss': self.initial_stop_loss,
@@ -370,6 +374,7 @@ class Trade(_DECL_BASE):
         self.close_profit_abs = self.calc_profit()
         self.close_date = datetime.utcnow()
         self.is_open = False
+        self.sell_order_status = 'closed'
         self.open_order_id = None
         logger.info(
             'Marking %s as closed as the trade is fulfilled and found no open orders for it.',

freqtrade/rpc/telegram.py

@@ -226,9 +226,13 @@ class Telegram(RPC):
                     # Adding stoploss and stoploss percentage only if it is not None
                     "*Stoploss:* `{stop_loss:.8f}` " +
                     ("`({stop_loss_pct:.2f}%)`" if r['stop_loss_pct'] else ""),
-
-                    "*Open Order:* `{open_order}`" if r['open_order'] else ""
                 ]
+                if r['open_order']:
+                    if r['sell_order_status']:
+                        lines.append("*Open Order:* `{open_order}` - `{sell_order_status}`")
+                    else:
+                        lines.append("*Open Order:* `{open_order}`")
+
                 # Filter empty lines using list-comprehension
                 messages.append("\n".join([l for l in lines if l]).format(**r))
 

tests/rpc/test_rpc.py

@@ -60,6 +60,7 @@ def test_rpc_trade_status(default_conf, ticker, fee, mocker) -> None:
         'open_trade_price': ANY,
         'close_rate_requested': ANY,
         'sell_reason': ANY,
+        'sell_order_status': ANY,
         'min_rate': ANY,
         'max_rate': ANY,
         'strategy': ANY,
@@ -103,6 +104,7 @@ def test_rpc_trade_status(default_conf, ticker, fee, mocker) -> None:
         'open_trade_price': ANY,
         'close_rate_requested': ANY,
         'sell_reason': ANY,
+        'sell_order_status': ANY,
         'min_rate': ANY,
         'max_rate': ANY,
         'strategy': ANY,

tests/rpc/test_rpc_apiserver.py

@@ -520,6 +520,7 @@ def test_api_status(botclient, mocker, ticker, fee, markets):
                         'open_rate_requested': 1.098e-05,
                         'open_trade_price': 0.0010025,
                         'sell_reason': None,
+                        'sell_order_status': None,
                         'strategy': 'DefaultStrategy',
                         'ticker_interval': 5}]
 
@@ -626,6 +627,7 @@ def test_api_forcebuy(botclient, mocker, fee):
                        'open_rate_requested': None,
                        'open_trade_price': 0.2460546025,
                        'sell_reason': None,
+                       'sell_order_status': None,
                        'strategy': None,
                        'ticker_interval': None
                        }

tests/rpc/test_rpc_telegram.py

@@ -170,6 +170,7 @@ def test_status(default_conf, update, mocker, fee, ticker,) -> None:
             'current_profit': -0.59,
             'initial_stop_loss': 1.098e-05,
             'stop_loss': 1.099e-05,
+            'sell_order_status': None,
             'initial_stop_loss_pct': -0.05,
             'stop_loss_pct': -0.01,
             'open_order': '(limit buy rem=0.00000000)'

tests/test_freqtradebot.py

@@ -1976,6 +1976,10 @@ def test_check_handle_timedout_buy_usercustom(default_conf, ticker, limit_buy_or
 
     Trade.session.add(open_trade)
 
+    # Ensure default is to return empty (so not mocked yet)
+    freqtrade.check_handle_timedout()
+    assert cancel_order_mock.call_count == 0
+
     # Return false - trade remains open
     freqtrade.strategy.check_buy_timeout = MagicMock(return_value=False)
     freqtrade.check_handle_timedout()
@@ -2106,6 +2110,9 @@ def test_check_handle_timedout_sell_usercustom(default_conf, ticker, limit_sell_
     open_trade.is_open = False
 
     Trade.session.add(open_trade)
+    # Ensure default is false
+    freqtrade.check_handle_timedout()
+    assert cancel_order_mock.call_count == 0
 
     freqtrade.strategy.check_sell_timeout = MagicMock(return_value=False)
     # Return false - No impact
@@ -2407,30 +2414,47 @@ def test_handle_cancel_buy_corder_empty(mocker, default_conf, limit_buy_order,
     assert cancel_order_mock.call_count == 1
 
 
-def test_handle_cancel_sell_limit(mocker, default_conf) -> None:
+def test_handle_cancel_sell_limit(mocker, default_conf, fee) -> None:
-    patch_RPCManager(mocker)
+    send_msg_mock = patch_RPCManager(mocker)
     patch_exchange(mocker)
     cancel_order_mock = MagicMock()
     mocker.patch.multiple(
         'freqtrade.exchange.Exchange',
-        cancel_order=cancel_order_mock
+        cancel_order=cancel_order_mock,
     )
+    mocker.patch('freqtrade.freqtradebot.FreqtradeBot.get_sell_rate', return_value=0.245441)
 
     freqtrade = FreqtradeBot(default_conf)
-    freqtrade._notify_sell_cancel = MagicMock()
 
-    trade = MagicMock()
+    trade = Trade(
+        pair='LTC/ETH',
+        amount=2,
+        exchange='binance',
+        open_rate=0.245441,
+        open_order_id="123456",
+        open_date=arrow.utcnow().datetime,
+        fee_open=fee.return_value,
+        fee_close=fee.return_value,
+    )
     order = {'remaining': 1,
              'amount': 1,
              'status': "open"}
     reason = CANCEL_REASON['TIMEOUT']
     assert freqtrade.handle_cancel_sell(trade, order, reason)
     assert cancel_order_mock.call_count == 1
+    assert send_msg_mock.call_count == 1
+
+    send_msg_mock.reset_mock()
+
     order['amount'] = 2
-    assert (freqtrade.handle_cancel_sell(trade, order, reason)
+    assert freqtrade.handle_cancel_sell(trade, order, reason) == CANCEL_REASON['PARTIALLY_FILLED']
-            == CANCEL_REASON['PARTIALLY_FILLED'])
     # Assert cancel_order was not called (callcount remains unchanged)
     assert cancel_order_mock.call_count == 1
+    assert send_msg_mock.call_count == 1
+    assert freqtrade.handle_cancel_sell(trade, order, reason) == CANCEL_REASON['PARTIALLY_FILLED']
+    # Message should not be iterated again
+    assert trade.sell_order_status == CANCEL_REASON['PARTIALLY_FILLED']
+    assert send_msg_mock.call_count == 1
 
 
 def test_handle_cancel_sell_cancel_exception(mocker, default_conf) -> None:

tests/test_persistence.py

@@ -477,6 +477,7 @@ def test_migrate_old(mocker, default_conf, fee):
     assert trade.close_rate_requested is None
     assert trade.close_rate is not None
     assert pytest.approx(trade.close_profit_abs) == trade.calc_profit()
+    assert trade.sell_order_status is None
 
 
 def test_migrate_new(mocker, default_conf, fee, caplog):
@@ -756,6 +757,7 @@ def test_to_json(default_conf, fee):
                       'stake_amount': 0.001,
                       'close_profit': None,
                       'sell_reason': None,
+                      'sell_order_status': None,
                       'stop_loss': None,
                       'stop_loss_pct': None,
                       'initial_stop_loss': None,
@@ -810,6 +812,7 @@ def test_to_json(default_conf, fee):
                       'open_rate_requested': None,
                       'open_trade_price': 12.33075,
                       'sell_reason': None,
+                      'sell_order_status': None,
                       'strategy': None,
                       'ticker_interval': None}