From 5cff72a42e1ab58d841d42cae43cf59f6fbcf932 Mon Sep 17 00:00:00 2001 From: Matthias Date: Thu, 9 Apr 2020 09:22:38 +0200 Subject: [PATCH 1/6] Improve logging to ensure which branch is used for buy order cancels --- freqtrade/freqtradebot.py | 1 + 1 file changed, 1 insertion(+) diff --git a/freqtrade/freqtradebot.py b/freqtrade/freqtradebot.py index 570f8bea8..16e4d4d2d 100644 --- a/freqtrade/freqtradebot.py +++ b/freqtrade/freqtradebot.py @@ -904,6 +904,7 @@ class FreqtradeBot: logger.info('Buy order %s for %s.', reason, trade) if corder.get('remaining', order['remaining']) == order['amount']: + logger.info('Buy order removed from database %s', trade) # if trade is not partially completed, just delete the trade Trade.session.delete(trade) Trade.session.flush() From 346e09fed1045b73a9fa5aa25fa8226660fb7356 Mon Sep 17 00:00:00 2001 From: Matthias Date: Thu, 9 Apr 2020 19:32:10 +0200 Subject: [PATCH 2/6] Add test verifying that cancel_order with empty remaining is causing the bug --- tests/test_freqtradebot.py | 12 +++++++----- 1 file changed, 7 insertions(+), 5 deletions(-) diff --git a/tests/test_freqtradebot.py b/tests/test_freqtradebot.py index e37270bd3..2536d57db 100644 --- a/tests/test_freqtradebot.py +++ b/tests/test_freqtradebot.py @@ -2204,14 +2204,11 @@ def test_check_handle_timedout_exception(default_conf, ticker, open_trade, mocke caplog) -def test_handle_timedout_limit_buy(mocker, default_conf, limit_buy_order) -> None: +def test_handle_timedout_limit_buy(mocker, caplog, default_conf, limit_buy_order) -> None: patch_RPCManager(mocker) patch_exchange(mocker) cancel_order_mock = MagicMock(return_value=limit_buy_order) - mocker.patch.multiple( - 'freqtrade.exchange.Exchange', - cancel_order=cancel_order_mock - ) + mocker.patch('freqtrade.exchange.Exchange.cancel_order', cancel_order_mock) freqtrade = FreqtradeBot(default_conf) @@ -2227,9 +2224,14 @@ def test_handle_timedout_limit_buy(mocker, default_conf, limit_buy_order) -> Non assert not freqtrade.handle_timedout_limit_buy(trade, limit_buy_order) assert cancel_order_mock.call_count == 1 + mocker.patch('freqtrade.exchange.Exchange.cancel_order', side_effect=InvalidOrderException) + assert not freqtrade.handle_timedout_limit_buy(trade, limit_buy_order) + assert log_has_re(r"Could not cancel buy order", caplog) + @pytest.mark.parametrize('cancelorder', [ {}, + {'remaining': None}, 'String Return value', 123 ]) From cbf5bf6735fa1b0aabfce9ba58fe370dd2d600c4 Mon Sep 17 00:00:00 2001 From: Matthias Date: Thu, 9 Apr 2020 19:34:48 +0200 Subject: [PATCH 3/6] Add safe_value_fallback function --- freqtrade/misc.py | 15 +++++++++++++++ tests/test_misc.py | 15 ++++++++++++++- 2 files changed, 29 insertions(+), 1 deletion(-) diff --git a/freqtrade/misc.py b/freqtrade/misc.py index 1f52b75ec..ea7bab843 100644 --- a/freqtrade/misc.py +++ b/freqtrade/misc.py @@ -134,6 +134,21 @@ def round_dict(d, n): return {k: (round(v, n) if isinstance(v, float) else v) for k, v in d.items()} +def safe_value_fallback(dict1: dict, dict2: dict, key1: str, key2: str, default_value=None): + """ + Search a value in dict1, return this if it's not None. + Fall back to dict2 - return key2 from dict2 if it's not None. + Else falls back to None. + + """ + if key1 in dict1 and dict1[key1] is not None: + return dict1[key1] + else: + if key2 in dict2 and dict2[key2] is not None: + return dict2[key2] + return default_value + + def plural(num: float, singular: str, plural: str = None) -> str: return singular if (num == 1 or num == -1) else plural or singular + 's' diff --git a/tests/test_misc.py b/tests/test_misc.py index c1e23926b..1bb5b40af 100644 --- a/tests/test_misc.py +++ b/tests/test_misc.py @@ -9,7 +9,7 @@ import pytest from freqtrade.data.converter import ohlcv_to_dataframe from freqtrade.misc import (datesarray_to_datetimearray, file_dump_json, file_load_json, format_ms_time, pair_to_filename, - plural, shorten_date) + plural, safe_value_fallback, shorten_date) def test_shorten_date() -> None: @@ -93,6 +93,19 @@ def test_format_ms_time() -> None: assert format_ms_time(date_in_epoch_ms) == res.astimezone(None).strftime('%Y-%m-%dT%H:%M:%S') +def test_safe_value_fallback(): + dict1 = {'keya': None, 'keyb': 2, 'keyc': 5} + dict2 = {'keya': 20, 'keyb': None, 'keyc': 6} + assert safe_value_fallback(dict1, dict2, 'keya', 'keya') == 20 + assert safe_value_fallback(dict2, dict1, 'keya', 'keya') == 20 + + assert safe_value_fallback(dict1, dict2, 'keyb', 'keyb') == 2 + assert safe_value_fallback(dict2, dict1, 'keyb', 'keyb') == 2 + + assert safe_value_fallback(dict1, dict2, 'keyc', 'keyc') == 5 + assert safe_value_fallback(dict2, dict1, 'keyc', 'keyc') == 6 + + def test_plural() -> None: assert plural(0, "page") == "pages" assert plural(0.0, "page") == "pages" From f39706cabd78c35aaf668bf290ba4c79ae744bcb Mon Sep 17 00:00:00 2001 From: Matthias Date: Thu, 9 Apr 2020 19:35:27 +0200 Subject: [PATCH 4/6] Fix #3130 - when corder['remaining'] contains none-type --- freqtrade/freqtradebot.py | 19 +++++++++++++------ 1 file changed, 13 insertions(+), 6 deletions(-) diff --git a/freqtrade/freqtradebot.py b/freqtrade/freqtradebot.py index 16e4d4d2d..b5c2ac4ee 100644 --- a/freqtrade/freqtradebot.py +++ b/freqtrade/freqtradebot.py @@ -20,6 +20,7 @@ from freqtrade.data.dataprovider import DataProvider from freqtrade.edge import Edge from freqtrade.exceptions import DependencyException, InvalidOrderException from freqtrade.exchange import timeframe_to_minutes, timeframe_to_next_date +from freqtrade.misc import safe_value_fallback from freqtrade.pairlist.pairlistmanager import PairListManager from freqtrade.persistence import Trade from freqtrade.resolvers import ExchangeResolver, StrategyResolver @@ -892,18 +893,23 @@ class FreqtradeBot: """ if order['status'] != 'canceled': reason = "cancelled due to timeout" - corder = self.exchange.cancel_order(trade.open_order_id, trade.pair) - # Some exchanges don't return a dict here. - if not isinstance(corder, dict): + try: + corder = self.exchange.cancel_order(trade.open_order_id, trade.pair) + # Some exchanges don't return a dict here. + if not isinstance(corder, dict): + corder = {} + logger.info('Buy order %s for %s.', reason, trade) + except InvalidOrderException: corder = {} - logger.info('Buy order %s for %s.', reason, trade) + logger.exception( + f"Could not cancel buy order {trade.open_order_id} for pair {trade.pair}") else: # Order was cancelled already, so we can reuse the existing dict corder = order reason = "cancelled on exchange" logger.info('Buy order %s for %s.', reason, trade) - if corder.get('remaining', order['remaining']) == order['amount']: + if safe_value_fallback(corder, order, 'remaining', 'remaining') == order['amount']: logger.info('Buy order removed from database %s', trade) # if trade is not partially completed, just delete the trade Trade.session.delete(trade) @@ -915,7 +921,8 @@ class FreqtradeBot: # cancel_order may not contain the full order dict, so we need to fallback # to the order dict aquired before cancelling. # we need to fall back to the values from order if corder does not contain these keys. - trade.amount = order['amount'] - corder.get('remaining', order['remaining']) + trade.amount = order['amount'] - safe_value_fallback(corder, order, + 'remaining', 'remaining') trade.stake_amount = trade.amount * trade.open_rate # verify if fees were taken from amount to avoid problems during selling try: From c03f637f5b629b55e74c4b8e0405bc8f7767bd7e Mon Sep 17 00:00:00 2001 From: Matthias Date: Thu, 9 Apr 2020 19:40:04 +0200 Subject: [PATCH 5/6] Improve safe_value_fallback test --- tests/test_misc.py | 12 ++++++++++-- 1 file changed, 10 insertions(+), 2 deletions(-) diff --git a/tests/test_misc.py b/tests/test_misc.py index 1bb5b40af..832bcb3a9 100644 --- a/tests/test_misc.py +++ b/tests/test_misc.py @@ -94,8 +94,8 @@ def test_format_ms_time() -> None: def test_safe_value_fallback(): - dict1 = {'keya': None, 'keyb': 2, 'keyc': 5} - dict2 = {'keya': 20, 'keyb': None, 'keyc': 6} + dict1 = {'keya': None, 'keyb': 2, 'keyc': 5, 'keyd': None} + dict2 = {'keya': 20, 'keyb': None, 'keyc': 6, 'keyd': None} assert safe_value_fallback(dict1, dict2, 'keya', 'keya') == 20 assert safe_value_fallback(dict2, dict1, 'keya', 'keya') == 20 @@ -105,6 +105,14 @@ def test_safe_value_fallback(): assert safe_value_fallback(dict1, dict2, 'keyc', 'keyc') == 5 assert safe_value_fallback(dict2, dict1, 'keyc', 'keyc') == 6 + assert safe_value_fallback(dict1, dict2, 'keyd', 'keyd') is None + assert safe_value_fallback(dict2, dict1, 'keyd', 'keyd') is None + assert safe_value_fallback(dict2, dict1, 'keyd', 'keyd', 1234) == 1234 + + assert safe_value_fallback(dict1, dict2, 'keyNo', 'keyNo') is None + assert safe_value_fallback(dict2, dict1, 'keyNo', 'keyNo') is None + assert safe_value_fallback(dict2, dict1, 'keyNo', 'keyNo', 1234) == 1234 + def test_plural() -> None: assert plural(0, "page") == "pages" From 1f70fcfa2da744b70f71190f575928c0c42ea6ca Mon Sep 17 00:00:00 2001 From: Matthias Date: Thu, 16 Apr 2020 20:19:34 +0200 Subject: [PATCH 6/6] Update logmessage --- freqtrade/freqtradebot.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/freqtrade/freqtradebot.py b/freqtrade/freqtradebot.py index b5c2ac4ee..8afe7d6f9 100644 --- a/freqtrade/freqtradebot.py +++ b/freqtrade/freqtradebot.py @@ -910,7 +910,7 @@ class FreqtradeBot: logger.info('Buy order %s for %s.', reason, trade) if safe_value_fallback(corder, order, 'remaining', 'remaining') == order['amount']: - logger.info('Buy order removed from database %s', trade) + logger.info('Buy order fully cancelled. Removing %s from database.', trade) # if trade is not partially completed, just delete the trade Trade.session.delete(trade) Trade.session.flush()