Reduce KuCoin logs only for 429000 error
Only KuCoin messages for 429000 error code are logged once. Logs functions are also simplified and optimized. test_remove_logs_for_pairs_already_in_blacklist is simplified as well.
This commit is contained in:
		| @@ -76,16 +76,13 @@ def calculate_backoff(retrycount, max_retries): | |||||||
| def retrier_async(f): | def retrier_async(f): | ||||||
|     async def wrapper(*args, **kwargs): |     async def wrapper(*args, **kwargs): | ||||||
|         count = kwargs.pop('count', API_RETRY_COUNT) |         count = kwargs.pop('count', API_RETRY_COUNT) | ||||||
|         self = args[0]  # Extract the exchange instance. |         kucoin = args[0].name == "Kucoin"  # Check if the exchange is KuCoin. | ||||||
|         kucoin = self.name == "Kucoin" |  | ||||||
|         try: |         try: | ||||||
|             return await f(*args, **kwargs) |             return await f(*args, **kwargs) | ||||||
|         except TemporaryError as ex: |         except TemporaryError as ex: | ||||||
|             message = f'{f.__name__}() returned exception: "{ex}"' |             logger.warning('%s() returned exception: "%s"', f.__name__, ex) | ||||||
|             (log_once_warning if kucoin else logger.warning)(message) |  | ||||||
|             if count > 0: |             if count > 0: | ||||||
|                 message = f'retrying {f.__name__}() still for {count} times' |                 logger.warning('retrying %s() still for %s times', f.__name__, count) | ||||||
|                 (log_once_warning if kucoin else logger.warning)(message) |  | ||||||
|                 count -= 1 |                 count -= 1 | ||||||
|                 kwargs['count'] = count |                 kwargs['count'] = count | ||||||
|                 if isinstance(ex, DDosProtection): |                 if isinstance(ex, DDosProtection): | ||||||
| @@ -97,13 +94,11 @@ def retrier_async(f): | |||||||
|                             f"{count} tries left before giving up") |                             f"{count} tries left before giving up") | ||||||
|                     else: |                     else: | ||||||
|                         backoff_delay = calculate_backoff(count + 1, API_RETRY_COUNT) |                         backoff_delay = calculate_backoff(count + 1, API_RETRY_COUNT) | ||||||
|                         message = f"Applying DDosProtection backoff delay: {backoff_delay}" |                         logger.info(f"Applying DDosProtection backoff delay: {backoff_delay}") | ||||||
|                         (log_once_info if kucoin else logger.info)(message) |  | ||||||
|                         await asyncio.sleep(backoff_delay) |                         await asyncio.sleep(backoff_delay) | ||||||
|                 return await wrapper(*args, **kwargs) |                 return await wrapper(*args, **kwargs) | ||||||
|             else: |             else: | ||||||
|                 message = f'Giving up retrying: {f.__name__}()' |                 logger.warning('Giving up retrying: %s()', f.__name__) | ||||||
|                 (log_once_warning if kucoin else logger.warning)(message) |  | ||||||
|                 raise ex |                 raise ex | ||||||
|     return wrapper |     return wrapper | ||||||
|  |  | ||||||
|   | |||||||
| @@ -4,7 +4,6 @@ import logging | |||||||
| import re | import re | ||||||
| from copy import deepcopy | from copy import deepcopy | ||||||
| from datetime import datetime, timedelta | from datetime import datetime, timedelta | ||||||
| from functools import reduce |  | ||||||
| from pathlib import Path | from pathlib import Path | ||||||
| from unittest.mock import MagicMock, Mock, PropertyMock | from unittest.mock import MagicMock, Mock, PropertyMock | ||||||
|  |  | ||||||
| @@ -49,44 +48,35 @@ def pytest_configure(config): | |||||||
|         setattr(config.option, 'markexpr', 'not longrun') |         setattr(config.option, 'markexpr', 'not longrun') | ||||||
|  |  | ||||||
|  |  | ||||||
| def log_contains(line, logs, count=False): | def log_contains(line, logs): | ||||||
|     # caplog mocker returns log as a tuple: ('freqtrade.something', logging.WARNING, 'spamfoobar') |     """Check if line is contained in some caplog's message.""" | ||||||
|     # and we want to check if line ('foo', for example) is contained in the tuple. |     return any(line in message for message in logs.messages) | ||||||
|     return any(line in logger_name or line in message |  | ||||||
|                for logger_name, level, message in logs.record_tuples) |  | ||||||
|  |  | ||||||
|  |  | ||||||
| def log_has(line, logs): | def log_has(line, logs): | ||||||
|     # caplog mocker returns log as a tuple: ('freqtrade.something', logging.WARNING, 'foobar') |     """Check if line is found on some caplog's message.""" | ||||||
|     # and we want to match line against foobar in the tuple |     return any(line == message for message in logs.messages) | ||||||
|     return reduce(lambda a, b: a or b, |  | ||||||
|                   filter(lambda x: x[2] == line, logs.record_tuples), |  | ||||||
|                   False) |  | ||||||
|  |  | ||||||
|  |  | ||||||
| def log_has_re(line, logs): | def log_has_re(line, logs): | ||||||
|     return reduce(lambda a, b: a or b, |     """Check if line matches some caplog's message.""" | ||||||
|                   filter(lambda x: re.match(line, x[2]), logs.record_tuples), |     return any(re.match(line, message) for message in logs.messages) | ||||||
|                   False) |  | ||||||
|  |  | ||||||
|  |  | ||||||
| def num_log_contains(line, logs, count=False): | def num_log_contains(line, logs): | ||||||
|     # caplog mocker returns log as a tuple: ('freqtrade.something', logging.WARNING, 'spamfoobar') |     """Check how many times line is contained in caplog's messages.""" | ||||||
|     # and we want to check how many times line ('foo', for example) is contained in the tuples. |     # We want to check how many times line ('foo', for example) is contained in caplog's messages. | ||||||
|     return sum(line in logger_name or line in message |     return sum(line in message for message in logs.messages) | ||||||
|                for logger_name, level, message in logs.record_tuples) |  | ||||||
|  |  | ||||||
|  |  | ||||||
| def num_log_has(line, logs, count=False): | def num_log_has(line, logs): | ||||||
|     # caplog mocker returns log as a tuple: ('freqtrade.something', logging.WARNING, 'foobar') |     """Check how many times line is found in caplog's messages.""" | ||||||
|     # and we want to check how many times line is presente in the tuples. |  | ||||||
|     return sum(line == logger_name or line == message |     return sum(line == logger_name or line == message | ||||||
|                for logger_name, level, message in logs.record_tuples) |                for logger_name, level, message in logs.record_tuples) | ||||||
|  |  | ||||||
|  |  | ||||||
| def num_log_has_re(line, logs, count=False): | def num_log_has_re(line, logs): | ||||||
|     # caplog mocker returns log as a tuple: ('freqtrade.something', logging.WARNING, 'foobar') |     """Check how many times line matches caplog's messages.""" | ||||||
|     # and we want to check how many times line matches in the tuples. |  | ||||||
|     return sum(re.match(line, logger_name) or re.match(line, message) |     return sum(re.match(line, logger_name) or re.match(line, message) | ||||||
|                for logger_name, level, message in logs.record_tuples) |                for logger_name, level, message in logs.record_tuples) | ||||||
|  |  | ||||||
|   | |||||||
| @@ -1758,24 +1758,8 @@ async def test__async_kucoin_get_candle_history(default_conf, mocker, caplog): | |||||||
|             exchange = get_patched_exchange(mocker, default_conf, api_mock, id="kucoin") |             exchange = get_patched_exchange(mocker, default_conf, api_mock, id="kucoin") | ||||||
|             await exchange._async_get_candle_history( |             await exchange._async_get_candle_history( | ||||||
|                 'ETH/BTC', "5m", (arrow.utcnow().int_timestamp - 2000) * 1000, count=1) |                 'ETH/BTC', "5m", (arrow.utcnow().int_timestamp - 2000) * 1000, count=1) | ||||||
|     assert num_log_contains('_async_get_candle_history() returned exception: "kucoin GET ', |  | ||||||
|                             caplog) == 1 |  | ||||||
|     assert num_log_contains('retrying _async_get_candle_history() still for ', caplog) == 1 |  | ||||||
|     assert num_log_contains("Kucoin 429 error, avoid triggering DDosProtection backoff delay", |     assert num_log_contains("Kucoin 429 error, avoid triggering DDosProtection backoff delay", | ||||||
|                             caplog) == 1 |                             caplog) == 1 | ||||||
|     assert num_log_contains('Giving up retrying: _async_get_candle_history()', caplog) == 1 |  | ||||||
|  |  | ||||||
|     mocker.patch('freqtrade.exchange.common.calculate_backoff', MagicMock(return_value=0.01)) |  | ||||||
|     for _ in range(3): |  | ||||||
|         with pytest.raises(DDosProtection, match=r'XYZ Too Many Requests'): |  | ||||||
|             api_mock.fetch_ohlcv = MagicMock(side_effect=ccxt.DDoSProtection( |  | ||||||
|                 "kucoin GET https://openapi-v2.kucoin.com/api/v1/market/candles?" |  | ||||||
|                 "symbol=ETH-BTC&type=5min&startAt=1640268735&endAt=1640418735" |  | ||||||
|                 "XYZ Too Many Requests" '{"code":"XYZ000","msg":"Too Many Requests"}')) |  | ||||||
|             exchange = get_patched_exchange(mocker, default_conf, api_mock, id="kucoin") |  | ||||||
|             await exchange._async_get_candle_history( |  | ||||||
|                 'ETH/BTC', "5m", (arrow.utcnow().int_timestamp - 2000) * 1000, count=1) |  | ||||||
|     assert num_log_contains('Applying DDosProtection backoff delay: ', caplog) == 1 |  | ||||||
|  |  | ||||||
|  |  | ||||||
| @pytest.mark.asyncio | @pytest.mark.asyncio | ||||||
|   | |||||||
| @@ -237,15 +237,11 @@ def test_remove_logs_for_pairs_already_in_blacklist(mocker, markets, static_pl_c | |||||||
|     # Ensure that log message wasn't generated. |     # Ensure that log message wasn't generated. | ||||||
|     assert not log_has('Pair BLK/BTC in your blacklist. Removing it from whitelist...', caplog) |     assert not log_has('Pair BLK/BTC in your blacklist. Removing it from whitelist...', caplog) | ||||||
|  |  | ||||||
|     new_whitelist = freqtrade.pairlists.verify_blacklist(whitelist + ['BLK/BTC'], logger.warning) |     for _ in range(3): | ||||||
|     # Ensure that the pair is removed from the white list, and properly logged. |         new_whitelist = freqtrade.pairlists.verify_blacklist( | ||||||
|     assert set(whitelist) == set(new_whitelist) |             whitelist + ['BLK/BTC'], logger.warning) | ||||||
|     assert num_log_has('Pair BLK/BTC in your blacklist. Removing it from whitelist...', |         # Ensure that the pair is removed from the white list, and properly logged. | ||||||
|                        caplog) == 1 |         assert set(whitelist) == set(new_whitelist) | ||||||
|  |  | ||||||
|     new_whitelist = freqtrade.pairlists.verify_blacklist(whitelist + ['BLK/BTC'], logger.warning) |  | ||||||
|     # Ensure that the pair is not logged anymore when being removed from the pair list. |  | ||||||
|     assert set(whitelist) == set(new_whitelist) |  | ||||||
|     assert num_log_has('Pair BLK/BTC in your blacklist. Removing it from whitelist...', |     assert num_log_has('Pair BLK/BTC in your blacklist. Removing it from whitelist...', | ||||||
|                        caplog) == 1 |                        caplog) == 1 | ||||||
|  |  | ||||||
|   | |||||||
		Reference in New Issue
	
	Block a user