diff --git a/docs/rest-api.md b/docs/rest-api.md index 68754f79a..075bd7e64 100644 --- a/docs/rest-api.md +++ b/docs/rest-api.md @@ -116,6 +116,7 @@ python3 scripts/rest_client.py --config rest_config.json [optional par | `trades` | List last trades. | `delete_trade ` | Remove trade from the database. Tries to close open orders. Requires manual handling of this trade on the exchange. | `show_config` | Shows part of the current configuration with relevant settings to operation +| `logs` | Shows last log messages | `status` | Lists all open trades | `count` | Displays number of trades used and available | `profit` | Display a summary of your profit/loss from close trades and some stats about your performance @@ -138,78 +139,83 @@ python3 scripts/rest_client.py help ``` output Possible commands: + balance - Get the account balance - :returns: json object + Get the account balance. blacklist - Show the current blacklist + Show the current blacklist. + :param add: List of coins to add (example: "BNB/BTC") - :returns: json object count - Returns the amount of open trades - :returns: json object + Return the amount of open trades. daily - Returns the amount of open trades - :returns: json object + Return the amount of open trades. + +delete_trade + Delete trade from the database. + Tries to close open orders. Requires manual handling of this asset on the exchange. + + :param trade_id: Deletes the trade with this ID from the database. edge - Returns information about edge - :returns: json object + Return information about edge. forcebuy - Buy an asset + Buy an asset. + :param pair: Pair to buy (ETH/BTC) :param price: Optional - price to buy - :returns: json object of the trade forcesell - Force-sell a trade + Force-sell a trade. + :param tradeid: Id of the trade (can be received via status command) - :returns: json object + +logs + Show latest logs. + + :param limit: Limits log messages to the last logs. No limit to get all the trades. performance - Returns the performance of the different coins - :returns: json object + Return the performance of the different coins. profit - Returns the profit summary - :returns: json object + Return the profit summary. reload_config - Reload configuration - :returns: json object + Reload configuration. show_config + Returns part of the configuration, relevant for trading operations. - :return: json object containing the version start - Start the bot if it's in stopped state. - :returns: json object + Start the bot if it's in the stopped state. status - Get the status of open trades - :returns: json object + Get the status of open trades. stop - Stop the bot. Use start to restart - :returns: json object + Stop the bot. Use `start` to restart. stopbuy - Stop buying (but handle sells gracefully). - use reload_config to reset - :returns: json object + Stop buying (but handle sells gracefully). Use `reload_config` to reset. + +trades + Return trades history. + + :param limit: Limits trades to the X last trades. No limit to get all the trades. version - Returns the version of the bot - :returns: json object containing the version + Return the version of the bot. whitelist - Show the current whitelist - :returns: json object + Show the current whitelist. + + ``` ## Advanced API usage using JWT tokens diff --git a/docs/telegram-usage.md b/docs/telegram-usage.md index 9776b26ba..5f804386d 100644 --- a/docs/telegram-usage.md +++ b/docs/telegram-usage.md @@ -54,6 +54,7 @@ official commands. You can ask at any moment for help with `/help`. | `/stopbuy` | Stops the trader from opening new trades. Gracefully closes open trades according to their rules. | `/reload_config` | Reloads the configuration file | `/show_config` | Shows part of the current configuration with relevant settings to operation +| `/logs [limit]` | Show last log messages. | `/status` | Lists all open trades | `/status table` | List all open trades in a table format. Pending buy orders are marked with an asterisk (*) Pending sell orders are marked with a double asterisk (**) | `/trades [limit]` | List all recently closed trades in a table format. diff --git a/freqtrade/loggers.py b/freqtrade/loggers.py index aa08ee8a7..8f5da9bee 100644 --- a/freqtrade/loggers.py +++ b/freqtrade/loggers.py @@ -1,14 +1,18 @@ import logging import sys - from logging import Formatter -from logging.handlers import RotatingFileHandler, SysLogHandler -from typing import Any, Dict, List +from logging.handlers import (BufferingHandler, RotatingFileHandler, + SysLogHandler) +from typing import Any, Dict from freqtrade.exceptions import OperationalException - logger = logging.getLogger(__name__) +LOGFORMAT = '%(asctime)s - %(name)s - %(levelname)s - %(message)s' + +# Initialize bufferhandler - will be used for /log endpoints +bufferHandler = BufferingHandler(1000) +bufferHandler.setFormatter(Formatter(LOGFORMAT)) def _set_loggers(verbosity: int = 0, api_verbosity: str = 'info') -> None: @@ -33,17 +37,31 @@ def _set_loggers(verbosity: int = 0, api_verbosity: str = 'info') -> None: ) +def setup_logging_pre() -> None: + """ + Early setup for logging. + Uses INFO loglevel and only the Streamhandler. + Early messages (before proper logging setup) will therefore only be sent to additional + logging handlers after the real initialization, because we don't know which + ones the user desires beforehand. + """ + logging.basicConfig( + level=logging.INFO, + format=LOGFORMAT, + handlers=[logging.StreamHandler(sys.stderr), bufferHandler] + ) + + def setup_logging(config: Dict[str, Any]) -> None: """ Process -v/--verbose, --logfile options """ # Log level verbosity = config['verbosity'] - - # Log to stderr - log_handlers: List[logging.Handler] = [logging.StreamHandler(sys.stderr)] + logging.root.addHandler(bufferHandler) logfile = config.get('logfile') + if logfile: s = logfile.split(':') if s[0] == 'syslog': @@ -58,28 +76,27 @@ def setup_logging(config: Dict[str, Any]) -> None: # to perform reduction of repeating messages if this is set in the # syslog config. The messages should be equal for this. handler.setFormatter(Formatter('%(name)s - %(levelname)s - %(message)s')) - log_handlers.append(handler) + logging.root.addHandler(handler) elif s[0] == 'journald': try: from systemd.journal import JournaldLogHandler except ImportError: raise OperationalException("You need the systemd python package be installed in " "order to use logging to journald.") - handler = JournaldLogHandler() + handler_jd = JournaldLogHandler() # No datetime field for logging into journald, to allow syslog # to perform reduction of repeating messages if this is set in the # syslog config. The messages should be equal for this. - handler.setFormatter(Formatter('%(name)s - %(levelname)s - %(message)s')) - log_handlers.append(handler) + handler_jd.setFormatter(Formatter('%(name)s - %(levelname)s - %(message)s')) + logging.root.addHandler(handler_jd) else: - log_handlers.append(RotatingFileHandler(logfile, - maxBytes=1024 * 1024, # 1Mb - backupCount=10)) + handler_rf = RotatingFileHandler(logfile, + maxBytes=1024 * 1024 * 10, # 10Mb + backupCount=10) + handler_rf.setFormatter(Formatter(LOGFORMAT)) + logging.root.addHandler(handler_rf) - logging.basicConfig( - level=logging.INFO if verbosity < 1 else logging.DEBUG, - format='%(asctime)s - %(name)s - %(levelname)s - %(message)s', - handlers=log_handlers - ) + logging.root.setLevel(logging.INFO if verbosity < 1 else logging.DEBUG) _set_loggers(verbosity, config.get('api_server', {}).get('verbosity', 'info')) + logger.info('Verbosity set to %s', verbosity) diff --git a/freqtrade/main.py b/freqtrade/main.py index 08bdc5e32..dc26c2a46 100755 --- a/freqtrade/main.py +++ b/freqtrade/main.py @@ -3,18 +3,17 @@ Main Freqtrade bot script. Read the documentation to know what cli arguments you need. """ - -from freqtrade.exceptions import FreqtradeException, OperationalException +import logging import sys +from typing import Any, List + # check min. python version if sys.version_info < (3, 6): sys.exit("Freqtrade requires Python version >= 3.6") -# flake8: noqa E402 -import logging -from typing import Any, List - from freqtrade.commands import Arguments +from freqtrade.exceptions import FreqtradeException, OperationalException +from freqtrade.loggers import setup_logging_pre logger = logging.getLogger('freqtrade') @@ -28,6 +27,7 @@ def main(sysargv: List[str] = None) -> None: return_code: Any = 1 try: + setup_logging_pre() arguments = Arguments(sysargv) args = arguments.get_parsed_arg() diff --git a/freqtrade/rpc/api_server.py b/freqtrade/rpc/api_server.py index 9b0f269f0..4bbc8a1dc 100644 --- a/freqtrade/rpc/api_server.py +++ b/freqtrade/rpc/api_server.py @@ -187,6 +187,7 @@ class ApiServer(RPC): self.app.add_url_rule(f'{BASE_URI}/count', 'count', view_func=self._count, methods=['GET']) self.app.add_url_rule(f'{BASE_URI}/daily', 'daily', view_func=self._daily, methods=['GET']) self.app.add_url_rule(f'{BASE_URI}/edge', 'edge', view_func=self._edge, methods=['GET']) + self.app.add_url_rule(f'{BASE_URI}/logs', 'log', view_func=self._get_logs, methods=['GET']) self.app.add_url_rule(f'{BASE_URI}/profit', 'profit', view_func=self._profit, methods=['GET']) self.app.add_url_rule(f'{BASE_URI}/performance', 'performance', @@ -349,6 +350,18 @@ class ApiServer(RPC): return self.rest_dump(stats) + @require_login + @rpc_catch_errors + def _get_logs(self): + """ + Returns latest logs + get: + param: + limit: Only get a certain number of records + """ + limit = int(request.args.get('limit', 0)) or None + return self.rest_dump(self._rpc_get_logs(limit)) + @require_login @rpc_catch_errors def _edge(self): diff --git a/freqtrade/rpc/rpc.py b/freqtrade/rpc/rpc.py index 12e79d35b..9b5d79267 100644 --- a/freqtrade/rpc/rpc.py +++ b/freqtrade/rpc/rpc.py @@ -11,9 +11,9 @@ from typing import Any, Dict, List, Optional, Tuple, Union import arrow from numpy import NAN, mean -from freqtrade.exceptions import (ExchangeError, - PricingError) +from freqtrade.exceptions import ExchangeError, PricingError from freqtrade.exchange import timeframe_to_minutes, timeframe_to_msecs +from freqtrade.loggers import bufferHandler from freqtrade.misc import shorten_date from freqtrade.persistence import Trade from freqtrade.rpc.fiat_convert import CryptoToFiatConverter @@ -632,6 +632,24 @@ class RPC: } return res + def _rpc_get_logs(self, limit: Optional[int]) -> Dict[str, Any]: + """Returns the last X logs""" + if limit: + buffer = bufferHandler.buffer[-limit:] + else: + buffer = bufferHandler.buffer + records = [[datetime.fromtimestamp(r.created).strftime("%Y-%m-%d %H:%M:%S"), + r.created * 1000, r.name, r.levelname, + r.message + ('\n' + r.exc_text if r.exc_text else '')] + for r in buffer] + + # Log format: + # [logtime-formatted, logepoch, logger-name, loglevel, message \n + exception] + # e.g. ["2020-08-27 11:35:01", 1598520901097.9397, + # "freqtrade.worker", "INFO", "Starting worker develop"] + + return {'log_count': len(records), 'logs': records} + def _rpc_edge(self) -> List[Dict[str, Any]]: """ Returns information related to Edge """ if not self._freqtrade.edge: diff --git a/freqtrade/rpc/telegram.py b/freqtrade/rpc/telegram.py index 458007c04..748c35f08 100644 --- a/freqtrade/rpc/telegram.py +++ b/freqtrade/rpc/telegram.py @@ -12,6 +12,7 @@ from tabulate import tabulate from telegram import ParseMode, ReplyKeyboardMarkup, Update from telegram.error import NetworkError, TelegramError from telegram.ext import CallbackContext, CommandHandler, Updater +from telegram.utils.helpers import escape_markdown from freqtrade.__init__ import __version__ from freqtrade.rpc import RPC, RPCException, RPCMessageType @@ -103,6 +104,7 @@ class Telegram(RPC): CommandHandler('stopbuy', self._stopbuy), CommandHandler('whitelist', self._whitelist), CommandHandler('blacklist', self._blacklist), + CommandHandler('logs', self._logs), CommandHandler('edge', self._edge), CommandHandler('help', self._help), CommandHandler('version', self._version), @@ -638,6 +640,38 @@ class Telegram(RPC): except RPCException as e: self._send_msg(str(e)) + @authorized_only + def _logs(self, update: Update, context: CallbackContext) -> None: + """ + Handler for /logs + Shows the latest logs + """ + try: + try: + limit = int(context.args[0]) + except (TypeError, ValueError, IndexError): + limit = 10 + logs = self._rpc_get_logs(limit)['logs'] + msgs = '' + msg_template = "*{}* {}: {} \\- `{}`" + for logrec in logs: + msg = msg_template.format(escape_markdown(logrec[0], version=2), + escape_markdown(logrec[2], version=2), + escape_markdown(logrec[3], version=2), + escape_markdown(logrec[4], version=2)) + if len(msgs + msg) + 10 >= MAX_TELEGRAM_MESSAGE_LENGTH: + # Send message immediately if it would become too long + self._send_msg(msgs, parse_mode=ParseMode.MARKDOWN_V2) + msgs = msg + '\n' + else: + # Append message to messages to send + msgs += msg + '\n' + + if msgs: + self._send_msg(msgs, parse_mode=ParseMode.MARKDOWN_V2) + except RPCException as e: + self._send_msg(str(e)) + @authorized_only def _edge(self, update: Update, context: CallbackContext) -> None: """ @@ -683,6 +717,7 @@ class Telegram(RPC): "*/stopbuy:* `Stops buying, but handles open trades gracefully` \n" "*/reload_config:* `Reload configuration file` \n" "*/show_config:* `Show running configuration` \n" + "*/logs [limit]:* `Show latest logs - defaults to 10` \n" "*/whitelist:* `Show current whitelist` \n" "*/blacklist [pair]:* `Show current blacklist, or adds one or more pairs " "to the blacklist.` \n" diff --git a/scripts/rest_client.py b/scripts/rest_client.py index 598a82040..95685fd64 100755 --- a/scripts/rest_client.py +++ b/scripts/rest_client.py @@ -159,6 +159,14 @@ class FtRestClient(): """ return self._get("show_config") + def logs(self, limit=None): + """Show latest logs. + + :param limit: Limits log messages to the last logs. No limit to get all the trades. + :return: json object + """ + return self._get("logs", params={"limit": limit} if limit else 0) + def trades(self, limit=None): """Return trades history. diff --git a/tests/rpc/test_rpc_apiserver.py b/tests/rpc/test_rpc_apiserver.py index 2513f751b..d2b69ee4f 100644 --- a/tests/rpc/test_rpc_apiserver.py +++ b/tests/rpc/test_rpc_apiserver.py @@ -10,10 +10,12 @@ from flask import Flask from requests.auth import _basic_auth_str from freqtrade.__init__ import __version__ +from freqtrade.loggers import setup_logging, setup_logging_pre from freqtrade.persistence import Trade from freqtrade.rpc.api_server import BASE_URI, ApiServer from freqtrade.state import State -from tests.conftest import get_patched_freqtradebot, log_has, patch_get_signal, create_mock_trades +from tests.conftest import (create_mock_trades, get_patched_freqtradebot, + log_has, patch_get_signal) _TEST_USER = "FreqTrader" _TEST_PASS = "SuperSecurePassword1!" @@ -21,6 +23,9 @@ _TEST_PASS = "SuperSecurePassword1!" @pytest.fixture def botclient(default_conf, mocker): + setup_logging_pre() + setup_logging(default_conf) + default_conf.update({"api_server": {"enabled": True, "listen_ip_address": "127.0.0.1", "listen_port": 8080, @@ -423,6 +428,34 @@ def test_api_delete_trade(botclient, mocker, fee, markets): assert stoploss_mock.call_count == 1 +def test_api_logs(botclient): + ftbot, client = botclient + rc = client_get(client, f"{BASE_URI}/logs") + assert_response(rc) + assert len(rc.json) == 2 + assert 'logs' in rc.json + # Using a fixed comparison here would make this test fail! + assert rc.json['log_count'] > 10 + assert len(rc.json['logs']) == rc.json['log_count'] + + assert isinstance(rc.json['logs'][0], list) + # date + assert isinstance(rc.json['logs'][0][0], str) + # created_timestamp + assert isinstance(rc.json['logs'][0][1], float) + assert isinstance(rc.json['logs'][0][2], str) + assert isinstance(rc.json['logs'][0][3], str) + assert isinstance(rc.json['logs'][0][4], str) + + rc = client_get(client, f"{BASE_URI}/logs?limit=5") + assert_response(rc) + assert len(rc.json) == 2 + assert 'logs' in rc.json + # Using a fixed comparison here would make this test fail! + assert rc.json['log_count'] == 5 + assert len(rc.json['logs']) == rc.json['log_count'] + + def test_api_edge_disabled(botclient, mocker, ticker, fee, markets): ftbot, client = botclient patch_get_signal(ftbot, (True, False)) diff --git a/tests/rpc/test_rpc_telegram.py b/tests/rpc/test_rpc_telegram.py index 10738ada3..bb63f283a 100644 --- a/tests/rpc/test_rpc_telegram.py +++ b/tests/rpc/test_rpc_telegram.py @@ -16,6 +16,7 @@ from telegram.error import NetworkError from freqtrade import __version__ from freqtrade.edge import PairInfo from freqtrade.freqtradebot import FreqtradeBot +from freqtrade.loggers import setup_logging from freqtrade.persistence import Trade from freqtrade.rpc import RPCMessageType from freqtrade.rpc.telegram import Telegram, authorized_only @@ -76,7 +77,7 @@ def test_telegram_init(default_conf, mocker, caplog) -> None: "['balance'], ['start'], ['stop'], ['forcesell'], ['forcebuy'], ['trades'], " "['delete'], ['performance'], ['daily'], ['count'], ['reload_config', " "'reload_conf'], ['show_config', 'show_conf'], ['stopbuy'], " - "['whitelist'], ['blacklist'], ['edge'], ['help'], ['version']]") + "['whitelist'], ['blacklist'], ['logs'], ['edge'], ['help'], ['version']]") assert log_has(message_str, caplog) @@ -1109,6 +1110,41 @@ def test_blacklist_static(default_conf, update, mocker) -> None: assert freqtradebot.pairlists.blacklist == ["DOGE/BTC", "HOT/BTC", "ETH/BTC"] +def test_telegram_logs(default_conf, update, mocker) -> None: + msg_mock = MagicMock() + mocker.patch.multiple( + 'freqtrade.rpc.telegram.Telegram', + _init=MagicMock(), + _send_msg=msg_mock + ) + setup_logging(default_conf) + + freqtradebot = get_patched_freqtradebot(mocker, default_conf) + + telegram = Telegram(freqtradebot) + context = MagicMock() + context.args = [] + telegram._logs(update=update, context=context) + assert msg_mock.call_count == 1 + assert "freqtrade\\.rpc\\.telegram" in msg_mock.call_args_list[0][0][0] + assert "freqtrade\\.resolvers\\.iresolver" in msg_mock.call_args_list[0][0][0] + + msg_mock.reset_mock() + context.args = ["1"] + telegram._logs(update=update, context=context) + assert msg_mock.call_count == 1 + + msg_mock.reset_mock() + # Test with changed MaxMessageLength + mocker.patch('freqtrade.rpc.telegram.MAX_TELEGRAM_MESSAGE_LENGTH', 200) + context = MagicMock() + context.args = [] + telegram._logs(update=update, context=context) + # Called at least 3 times. Exact times will change with unrelated changes to setup messages + # Therefore we don't test for this explicitly. + assert msg_mock.call_count > 3 + + def test_edge_disabled(default_conf, update, mocker) -> None: msg_mock = MagicMock() mocker.patch.multiple( diff --git a/tests/test_configuration.py b/tests/test_configuration.py index 8549f00c9..4428fe240 100644 --- a/tests/test_configuration.py +++ b/tests/test_configuration.py @@ -21,7 +21,7 @@ from freqtrade.configuration.deprecated_settings import ( from freqtrade.configuration.load_config import load_config_file, log_config_error_range from freqtrade.constants import DEFAULT_DB_DRYRUN_URL, DEFAULT_DB_PROD_URL from freqtrade.exceptions import OperationalException -from freqtrade.loggers import _set_loggers, setup_logging +from freqtrade.loggers import _set_loggers, setup_logging, setup_logging_pre from freqtrade.state import RunMode from tests.conftest import (log_has, log_has_re, patched_configuration_load_config_file) @@ -674,10 +674,12 @@ def test_set_loggers_syslog(mocker): 'logfile': 'syslog:/dev/log', } + setup_logging_pre() setup_logging(config) - assert len(logger.handlers) == 2 + assert len(logger.handlers) == 3 assert [x for x in logger.handlers if type(x) == logging.handlers.SysLogHandler] assert [x for x in logger.handlers if type(x) == logging.StreamHandler] + assert [x for x in logger.handlers if type(x) == logging.handlers.BufferingHandler] # reset handlers to not break pytest logger.handlers = orig_handlers @@ -727,7 +729,10 @@ def test_set_logfile(default_conf, mocker): assert validated_conf['logfile'] == "test_file.log" f = Path("test_file.log") assert f.is_file() - f.unlink() + try: + f.unlink() + except Exception: + pass def test_load_config_warn_forcebuy(default_conf, mocker, caplog) -> None: