From f5b4a6d3d72fea870d912e6a1b28c47ccd3247dc Mon Sep 17 00:00:00 2001 From: Matthias Date: Sat, 22 Feb 2020 11:03:25 +0100 Subject: [PATCH 1/4] Remove fetch_ticker caching --- freqtrade/exchange/exchange.py | 35 +++++++++++---------------------- freqtrade/freqtradebot.py | 4 ++-- tests/exchange/test_exchange.py | 15 +++----------- tests/rpc/test_rpc.py | 6 ------ 4 files changed, 16 insertions(+), 44 deletions(-) diff --git a/freqtrade/exchange/exchange.py b/freqtrade/exchange/exchange.py index b3b347016..e45238b07 100644 --- a/freqtrade/exchange/exchange.py +++ b/freqtrade/exchange/exchange.py @@ -66,8 +66,6 @@ class Exchange: self._config.update(config) - self._cached_ticker: Dict[str, Any] = {} - # Holds last candle refreshed time of each pair self._pairs_last_refresh_time: Dict[Tuple[str, str], int] = {} # Timestamp of last markets refresh @@ -591,28 +589,17 @@ class Exchange: raise OperationalException(e) from e @retrier - def fetch_ticker(self, pair: str, refresh: Optional[bool] = True) -> dict: - if refresh or pair not in self._cached_ticker.keys(): - try: - if pair not in self._api.markets or not self._api.markets[pair].get('active'): - raise DependencyException(f"Pair {pair} not available") - data = self._api.fetch_ticker(pair) - try: - self._cached_ticker[pair] = { - 'bid': float(data['bid']), - 'ask': float(data['ask']), - } - except KeyError: - logger.debug("Could not cache ticker data for %s", pair) - return data - except (ccxt.NetworkError, ccxt.ExchangeError) as e: - raise TemporaryError( - f'Could not load ticker due to {e.__class__.__name__}. Message: {e}') from e - except ccxt.BaseError as e: - raise OperationalException(e) from e - else: - logger.info("returning cached ticker-data for %s", pair) - return self._cached_ticker[pair] + def fetch_ticker(self, pair: str) -> dict: + try: + if pair not in self._api.markets or not self._api.markets[pair].get('active'): + raise DependencyException(f"Pair {pair} not available") + data = self._api.fetch_ticker(pair) + return data + except (ccxt.NetworkError, ccxt.ExchangeError) as e: + raise TemporaryError( + f'Could not load ticker due to {e.__class__.__name__}. Message: {e}') from e + except ccxt.BaseError as e: + raise OperationalException(e) from e def get_historic_ohlcv(self, pair: str, timeframe: str, since_ms: int) -> List: diff --git a/freqtrade/freqtradebot.py b/freqtrade/freqtradebot.py index 127586437..032e3e8f7 100644 --- a/freqtrade/freqtradebot.py +++ b/freqtrade/freqtradebot.py @@ -253,7 +253,7 @@ class FreqtradeBot: else: if not tick: logger.info('Using Last Ask / Last Price') - ticker = self.exchange.fetch_ticker(pair, refresh) + ticker = self.exchange.fetch_ticker(pair) else: ticker = tick if ticker['ask'] < ticker['last']: @@ -631,7 +631,7 @@ class FreqtradeBot: rate = order_book['bids'][0][0] else: - rate = self.exchange.fetch_ticker(pair, refresh)['bid'] + rate = self.exchange.fetch_ticker(pair)['bid'] return rate def handle_trade(self, trade: Trade) -> bool: diff --git a/tests/exchange/test_exchange.py b/tests/exchange/test_exchange.py index 8b2e439c3..3830d0acb 100644 --- a/tests/exchange/test_exchange.py +++ b/tests/exchange/test_exchange.py @@ -1121,25 +1121,16 @@ def test_fetch_ticker(default_conf, mocker, exchange_name): assert ticker['bid'] == 0.5 assert ticker['ask'] == 1 - assert 'ETH/BTC' in exchange._cached_ticker - assert exchange._cached_ticker['ETH/BTC']['bid'] == 0.5 - assert exchange._cached_ticker['ETH/BTC']['ask'] == 1 - - # Test caching - api_mock.fetch_ticker = MagicMock() - exchange.fetch_ticker(pair='ETH/BTC', refresh=False) - assert api_mock.fetch_ticker.call_count == 0 - ccxt_exceptionhandlers(mocker, default_conf, api_mock, exchange_name, "fetch_ticker", "fetch_ticker", - pair='ETH/BTC', refresh=True) + pair='ETH/BTC') api_mock.fetch_ticker = MagicMock(return_value={}) exchange = get_patched_exchange(mocker, default_conf, api_mock, id=exchange_name) - exchange.fetch_ticker(pair='ETH/BTC', refresh=True) + exchange.fetch_ticker(pair='ETH/BTC') with pytest.raises(DependencyException, match=r'Pair XRP/ETH not available'): - exchange.fetch_ticker(pair='XRP/ETH', refresh=True) + exchange.fetch_ticker(pair='XRP/ETH') @pytest.mark.parametrize("exchange_name", EXCHANGES) diff --git a/tests/rpc/test_rpc.py b/tests/rpc/test_rpc.py index a35bfa0d6..2d1fa5b2d 100644 --- a/tests/rpc/test_rpc.py +++ b/tests/rpc/test_rpc.py @@ -67,8 +67,6 @@ def test_rpc_trade_status(default_conf, ticker, fee, mocker) -> None: mocker.patch('freqtrade.exchange.Exchange.fetch_ticker', MagicMock(side_effect=DependencyException(f"Pair 'ETH/BTC' not available"))) - # invalidate ticker cache - rpc._freqtrade.exchange._cached_ticker = {} results = rpc._rpc_trade_status() assert isnan(results[0]['current_profit']) assert isnan(results[0]['current_rate']) @@ -136,8 +134,6 @@ def test_rpc_status_table(default_conf, ticker, fee, mocker) -> None: mocker.patch('freqtrade.exchange.Exchange.fetch_ticker', MagicMock(side_effect=DependencyException(f"Pair 'ETH/BTC' not available"))) - # invalidate ticker cache - rpc._freqtrade.exchange._cached_ticker = {} result, headers = rpc._rpc_status_table(default_conf['stake_currency'], 'USD') assert 'instantly' == result[0][2] assert 'ETH/BTC' in result[0][1] @@ -262,8 +258,6 @@ def test_rpc_trade_statistics(default_conf, ticker, ticker_sell_up, fee, # Test non-available pair mocker.patch('freqtrade.exchange.Exchange.fetch_ticker', MagicMock(side_effect=DependencyException(f"Pair 'ETH/BTC' not available"))) - # invalidate ticker cache - rpc._freqtrade.exchange._cached_ticker = {} stats = rpc._rpc_trade_statistics(stake_currency, fiat_display_currency) assert stats['trade_count'] == 2 assert stats['first_trade_date'] == 'just now' From 97e6e5e9766c87bb728fe396f4f5119616eeda1a Mon Sep 17 00:00:00 2001 From: Matthias Date: Sat, 22 Feb 2020 11:12:33 +0100 Subject: [PATCH 2/4] Implement caching in the correct place --- freqtrade/freqtradebot.py | 32 ++++++++++++++++++++++++++------ tests/rpc/test_rpc.py | 6 +++--- 2 files changed, 29 insertions(+), 9 deletions(-) diff --git a/freqtrade/freqtradebot.py b/freqtrade/freqtradebot.py index 032e3e8f7..d9126370b 100644 --- a/freqtrade/freqtradebot.py +++ b/freqtrade/freqtradebot.py @@ -11,6 +11,7 @@ from threading import Lock from typing import Any, Dict, List, Optional, Tuple import arrow +from cachetools import TTLCache from requests.exceptions import RequestException from freqtrade import __version__, constants, persistence @@ -54,6 +55,9 @@ class FreqtradeBot: self._heartbeat_msg = 0 + self._sell_rate_cache = TTLCache(maxsize=100, ttl=5) + self._buy_rate_cache = TTLCache(maxsize=100, ttl=5) + self.heartbeat_interval = self.config.get('internals', {}).get('heartbeat_interval', 60) self.strategy: IStrategy = StrategyResolver.load_strategy(self.config) @@ -234,11 +238,19 @@ class FreqtradeBot: return trades_created - def get_buy_rate(self, pair: str, refresh: bool, tick: Dict = None) -> float: + def get_buy_rate(self, pair: str, refresh: bool) -> float: """ Calculates bid target between current ask price and last price + :param pair: Pair to get rate for + :param refresh: allow cached data :return: float: Price """ + if not refresh: + rate = self._sell_rate_cache.get(pair) + # Check if cache has been invalidated + if rate: + return rate + config_bid_strategy = self.config.get('bid_strategy', {}) if 'use_order_book' in config_bid_strategy and\ config_bid_strategy.get('use_order_book', False): @@ -251,11 +263,8 @@ class FreqtradeBot: logger.info('...top %s order book buy rate %0.8f', order_book_top, order_book_rate) used_rate = order_book_rate else: - if not tick: - logger.info('Using Last Ask / Last Price') - ticker = self.exchange.fetch_ticker(pair) - else: - ticker = tick + logger.info('Using Last Ask / Last Price') + ticker = self.exchange.fetch_ticker(pair) if ticker['ask'] < ticker['last']: ticker_rate = ticker['ask'] else: @@ -263,6 +272,8 @@ class FreqtradeBot: ticker_rate = ticker['ask'] + balance * (ticker['last'] - ticker['ask']) used_rate = ticker_rate + self._buy_rate_cache[pair] = used_rate + return used_rate def get_trade_stake_amount(self, pair: str) -> float: @@ -621,8 +632,16 @@ class FreqtradeBot: The orderbook portion is only used for rpc messaging, which would otherwise fail for BitMex (has no bid/ask in fetch_ticker) or remain static in any other case since it's not updating. + :param pair: Pair to get rate for + :param refresh: allow cached data :return: Bid rate """ + if not refresh: + rate = self._sell_rate_cache.get(pair) + # Check if cache has been invalidated + if rate: + return rate + config_ask_strategy = self.config.get('ask_strategy', {}) if config_ask_strategy.get('use_order_book', False): logger.debug('Using order book to get sell rate') @@ -632,6 +651,7 @@ class FreqtradeBot: else: rate = self.exchange.fetch_ticker(pair)['bid'] + self._sell_rate_cache[pair] = rate return rate def handle_trade(self, trade: Trade) -> bool: diff --git a/tests/rpc/test_rpc.py b/tests/rpc/test_rpc.py index 2d1fa5b2d..40b2d6627 100644 --- a/tests/rpc/test_rpc.py +++ b/tests/rpc/test_rpc.py @@ -65,7 +65,7 @@ def test_rpc_trade_status(default_conf, ticker, fee, mocker) -> None: 'open_order': '(limit buy rem=0.00000000)' } == results[0] - mocker.patch('freqtrade.exchange.Exchange.fetch_ticker', + mocker.patch('freqtrade.freqtradebot.FreqtradeBot.get_sell_rate', MagicMock(side_effect=DependencyException(f"Pair 'ETH/BTC' not available"))) results = rpc._rpc_trade_status() assert isnan(results[0]['current_profit']) @@ -132,7 +132,7 @@ def test_rpc_status_table(default_conf, ticker, fee, mocker) -> None: assert 'ETH/BTC' in result[0][1] assert '-0.59% (-0.09)' == result[0][3] - mocker.patch('freqtrade.exchange.Exchange.fetch_ticker', + mocker.patch('freqtrade.freqtradebot.FreqtradeBot.get_sell_rate', MagicMock(side_effect=DependencyException(f"Pair 'ETH/BTC' not available"))) result, headers = rpc._rpc_status_table(default_conf['stake_currency'], 'USD') assert 'instantly' == result[0][2] @@ -256,7 +256,7 @@ def test_rpc_trade_statistics(default_conf, ticker, ticker_sell_up, fee, assert prec_satoshi(stats['best_rate'], 6.2) # Test non-available pair - mocker.patch('freqtrade.exchange.Exchange.fetch_ticker', + mocker.patch('freqtrade.freqtradebot.FreqtradeBot.get_sell_rate', MagicMock(side_effect=DependencyException(f"Pair 'ETH/BTC' not available"))) stats = rpc._rpc_trade_statistics(stake_currency, fiat_display_currency) assert stats['trade_count'] == 2 From 77ef3240cd17b932f499a19e7820e39818cf1aa9 Mon Sep 17 00:00:00 2001 From: Matthias Date: Sat, 22 Feb 2020 11:16:20 +0100 Subject: [PATCH 3/4] Implement log messages --- freqtrade/freqtradebot.py | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/freqtrade/freqtradebot.py b/freqtrade/freqtradebot.py index d9126370b..4b54b79e1 100644 --- a/freqtrade/freqtradebot.py +++ b/freqtrade/freqtradebot.py @@ -246,9 +246,10 @@ class FreqtradeBot: :return: float: Price """ if not refresh: - rate = self._sell_rate_cache.get(pair) + rate = self._buy_rate_cache.get(pair) # Check if cache has been invalidated if rate: + logger.info(f"Using cached buy rate for {pair}.") return rate config_bid_strategy = self.config.get('bid_strategy', {}) @@ -577,7 +578,7 @@ class FreqtradeBot: """ Sends rpc notification when a buy cancel occured. """ - current_rate = self.get_buy_rate(trade.pair, True) + current_rate = self.get_buy_rate(trade.pair, False) msg = { 'type': RPCMessageType.BUY_CANCEL_NOTIFICATION, @@ -640,6 +641,7 @@ class FreqtradeBot: rate = self._sell_rate_cache.get(pair) # Check if cache has been invalidated if rate: + logger.info(f"Using cached sell rate for {pair}.") return rate config_ask_strategy = self.config.get('ask_strategy', {}) @@ -1078,7 +1080,7 @@ class FreqtradeBot: """ 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, True) + current_rate = self.get_sell_rate(trade.pair, False) profit_percent = trade.calc_profit_ratio(profit_rate) gain = "profit" if profit_percent > 0 else "loss" From 2fe7b683cb3a11b4c629b7a796b30ff5838a5682 Mon Sep 17 00:00:00 2001 From: Matthias Date: Sat, 22 Feb 2020 11:23:13 +0100 Subject: [PATCH 4/4] Add tests for cached rates --- tests/test_freqtradebot.py | 23 +++++++++++++++++++++-- 1 file changed, 21 insertions(+), 2 deletions(-) diff --git a/tests/test_freqtradebot.py b/tests/test_freqtradebot.py index 5ed4d296c..c7a70be8c 100644 --- a/tests/test_freqtradebot.py +++ b/tests/test_freqtradebot.py @@ -915,13 +915,21 @@ def test_process_informative_pairs_added(default_conf, ticker, mocker) -> None: (5, 10, 1.0, 5), # last bigger than ask (5, 10, 0.5, 5), # last bigger than ask ]) -def test_get_buy_rate(mocker, default_conf, ask, last, last_ab, expected) -> None: +def test_get_buy_rate(mocker, default_conf, caplog, ask, last, last_ab, expected) -> None: default_conf['bid_strategy']['ask_last_balance'] = last_ab freqtrade = get_patched_freqtradebot(mocker, default_conf) mocker.patch('freqtrade.exchange.Exchange.fetch_ticker', MagicMock(return_value={'ask': ask, 'last': last})) assert freqtrade.get_buy_rate('ETH/BTC', True) == expected + assert not log_has("Using cached buy rate for ETH/BTC.", caplog) + + assert freqtrade.get_buy_rate('ETH/BTC', False) == expected + assert log_has("Using cached buy rate for ETH/BTC.", caplog) + # Running a 2nd time with Refresh on! + caplog.clear() + assert freqtrade.get_buy_rate('ETH/BTC', True) == expected + assert not log_has("Using cached buy rate for ETH/BTC.", caplog) def test_execute_buy(mocker, default_conf, fee, limit_buy_order) -> None: @@ -3614,7 +3622,7 @@ def test_order_book_ask_strategy(default_conf, limit_buy_order, limit_sell_order assert freqtrade.handle_trade(trade) is True -def test_get_sell_rate(default_conf, mocker, ticker, order_book_l2) -> None: +def test_get_sell_rate(default_conf, mocker, caplog, ticker, order_book_l2) -> None: mocker.patch.multiple( 'freqtrade.exchange.Exchange', @@ -3626,8 +3634,15 @@ def test_get_sell_rate(default_conf, mocker, ticker, order_book_l2) -> None: # Test regular mode ft = get_patched_freqtradebot(mocker, default_conf) rate = ft.get_sell_rate(pair, True) + assert not log_has("Using cached sell rate for ETH/BTC.", caplog) assert isinstance(rate, float) assert rate == 0.00001098 + # Use caching + rate = ft.get_sell_rate(pair, False) + assert rate == 0.00001098 + assert log_has("Using cached sell rate for ETH/BTC.", caplog) + + caplog.clear() # Test orderbook mode default_conf['ask_strategy']['use_order_book'] = True @@ -3635,8 +3650,12 @@ def test_get_sell_rate(default_conf, mocker, ticker, order_book_l2) -> None: default_conf['ask_strategy']['order_book_max'] = 2 ft = get_patched_freqtradebot(mocker, default_conf) rate = ft.get_sell_rate(pair, True) + assert not log_has("Using cached sell rate for ETH/BTC.", caplog) assert isinstance(rate, float) assert rate == 0.043936 + rate = ft.get_sell_rate(pair, False) + assert rate == 0.043936 + assert log_has("Using cached sell rate for ETH/BTC.", caplog) def test_startup_state(default_conf, mocker):