Merge pull request #11159 from xmatthias/rich_console

Add rich log handler

freqtrade/commands/arguments.py

@@ -11,7 +11,15 @@ from freqtrade.commands.cli_options import AVAILABLE_CLI_OPTIONS
 from freqtrade.constants import DEFAULT_CONFIG
 
 
-ARGS_COMMON = ["verbosity", "logfile", "version", "config", "datadir", "user_data_dir"]
+ARGS_COMMON = [
+    "verbosity",
+    "print_colorized",
+    "logfile",
+    "version",
+    "config",
+    "datadir",
+    "user_data_dir",
+]
 
 ARGS_STRATEGY = [
     "strategy",
@@ -58,7 +66,6 @@ ARGS_HYPEROPT = ARGS_COMMON_OPTIMIZE + [
     "epochs",
     "spaces",
     "print_all",
-    "print_colorized",
     "print_json",
     "hyperopt_jobs",
     "hyperopt_random_state",
@@ -74,13 +81,12 @@ ARGS_EDGE = ARGS_COMMON_OPTIMIZE + ["stoploss_range"]
 ARGS_LIST_STRATEGIES = [
     "strategy_path",
     "print_one_column",
-    "print_colorized",
     "recursive_strategy_search",
 ]
 
-ARGS_LIST_FREQAIMODELS = ["freqaimodel_path", "print_one_column", "print_colorized"]
+ARGS_LIST_FREQAIMODELS = ["freqaimodel_path", "print_one_column"]
 
-ARGS_LIST_HYPEROPTS = ["hyperopt_path", "print_one_column", "print_colorized"]
+ARGS_LIST_HYPEROPTS = ["hyperopt_path", "print_one_column"]
 
 ARGS_BACKTEST_SHOW = ["exportfilename", "backtest_show_pair_list", "backtest_breakdown"]
 
@@ -202,7 +208,6 @@ ARGS_HYPEROPT_LIST = [
     "hyperopt_list_max_total_profit",
     "hyperopt_list_min_objective",
     "hyperopt_list_max_objective",
-    "print_colorized",
     "print_json",
     "hyperopt_list_no_details",
     "hyperoptexportfilename",

freqtrade/configuration/configuration.py

@@ -135,6 +135,12 @@ class Configuration:
         if "logfile" in self.args and self.args["logfile"]:
             config.update({"logfile": self.args["logfile"]})
 
+        if "print_colorized" in self.args and not self.args["print_colorized"]:
+            logger.info("Parameter --no-color detected ...")
+            config.update({"print_colorized": False})
+        else:
+            config.update({"print_colorized": True})
+
         setup_logging(config)
 
     def _process_trading_options(self, config: Config) -> None:
@@ -326,12 +332,6 @@ class Configuration:
         ]
         self._args_to_config_loop(config, configurations)
 
-        if "print_colorized" in self.args and not self.args["print_colorized"]:
-            logger.info("Parameter --no-color detected ...")
-            config.update({"print_colorized": False})
-        else:
-            config.update({"print_colorized": True})
-
         configurations = [
             ("print_json", "Parameter --print-json detected ..."),
             ("export_csv", "Parameter --export-csv detected: {}"),

freqtrade/loggers/__init__.py

@@ -3,11 +3,16 @@ from logging import Formatter
 from logging.handlers import RotatingFileHandler, SysLogHandler
 from pathlib import Path
 
+from rich.console import Console
+
 from freqtrade.constants import Config
 from freqtrade.exceptions import OperationalException
 from freqtrade.loggers.buffering_handler import FTBufferingHandler
+from freqtrade.loggers.ft_rich_handler import FtRichHandler
 from freqtrade.loggers.set_log_levels import set_loggers
-from freqtrade.loggers.std_err_stream_handler import FTStdErrStreamHandler
+
+
+# from freqtrade.loggers.std_err_stream_handler import FTStdErrStreamHandler
 
 
 logger = logging.getLogger(__name__)
@@ -17,6 +22,8 @@ LOGFORMAT = "%(asctime)s - %(name)s - %(levelname)s - %(message)s"
 bufferHandler = FTBufferingHandler(1000)
 bufferHandler.setFormatter(Formatter(LOGFORMAT))
 
+error_console = Console(stderr=True, color_system=None)
+
 
 def get_existing_handlers(handlertype):
     """
@@ -33,8 +40,16 @@ def setup_logging_pre() -> None:
     logging handlers after the real initialization, because we don't know which
     ones the user desires beforehand.
     """
+    rh = FtRichHandler(console=error_console)
+    rh.setFormatter(Formatter("%(message)s"))
     logging.basicConfig(
-        level=logging.INFO, format=LOGFORMAT, handlers=[FTStdErrStreamHandler(), bufferHandler]
+        level=logging.INFO,
+        format=LOGFORMAT,
+        handlers=[
+            # FTStdErrStreamHandler(),
+            rh,
+            bufferHandler,
+        ],
     )
 
 
@@ -45,6 +60,9 @@ def setup_logging(config: Config) -> None:
     # Log level
     verbosity = config["verbosity"]
     logging.root.addHandler(bufferHandler)
+    if config.get("print_colorized", True):
+        logger.info("Enabling colorized output.")
+        error_console._color_system = error_console._detect_color_system()
 
     logfile = config.get("logfile")
 

freqtrade/loggers/ft_rich_handler.py

@@ -0,0 +1,50 @@
+from datetime import datetime
+from logging import Handler
+
+from rich._null_file import NullFile
+from rich.console import Console
+from rich.text import Text
+from rich.traceback import Traceback
+
+
+class FtRichHandler(Handler):
+    """
+    Basic colorized logging handler using Rich.
+    Does not support all features of the standard logging handler, and uses a hard-coded log format
+    """
+
+    def __init__(self, console: Console, *args, **kwargs) -> None:
+        super().__init__(*args, **kwargs)
+        self._console = console
+
+    def emit(self, record):
+        try:
+            msg = self.format(record)
+            # Format log message
+            log_time = Text(
+                datetime.fromtimestamp(record.created).strftime("%Y-%m-%d %H:%M:%S,%f")[:-3],
+            )
+            name = Text(record.name, style="violet")
+            log_level = Text(record.levelname, style=f"logging.level.{record.levelname.lower()}")
+            gray_sep = Text(" - ", style="gray46")
+
+            if isinstance(self._console.file, NullFile):
+                # Handles pythonw, where stdout/stderr are null, and we return NullFile
+                # instance from Console.file. In this case, we still want to make a log record
+                # even though we won't be writing anything to a file.
+                self.handleError(record)
+                return
+
+            self._console.print(
+                Text() + log_time + gray_sep + name + gray_sep + log_level + gray_sep + msg
+            )
+            tb = None
+            if record.exc_info:
+                exc_type, exc_value, exc_traceback = record.exc_info
+                tb = Traceback.from_exception(exc_type, exc_value, exc_traceback, extra_lines=1)
+                self._console.print(tb)
+
+        except RecursionError:
+            raise
+        except Exception:
+            self.handleError(record)

freqtrade/optimize/hyperopt/hyperopt.py

@@ -16,11 +16,11 @@ from typing import Any
 import rapidjson
 from joblib import Parallel, cpu_count, delayed, wrap_non_picklable_objects
 from joblib.externals import cloudpickle
-from rich.console import Console
 
 from freqtrade.constants import FTHYPT_FILEVERSION, LAST_BT_RESULT_FN, Config
 from freqtrade.enums import HyperoptState
 from freqtrade.exceptions import OperationalException
+from freqtrade.loggers import error_console
 from freqtrade.misc import file_dump_json, plural
 from freqtrade.optimize.hyperopt.hyperopt_logger import logging_mp_handle, logging_mp_setup
 from freqtrade.optimize.hyperopt.hyperopt_optimizer import HyperOptimizer
@@ -93,7 +93,6 @@ class Hyperopt:
 
         self.print_all = self.config.get("print_all", False)
         self.hyperopt_table_header = 0
-        self.print_colorized = self.config.get("print_colorized", False)
         self.print_json = self.config.get("print_json", False)
 
         self.hyperopter = HyperOptimizer(self.config)
@@ -281,13 +280,10 @@ class Hyperopt:
             with Parallel(n_jobs=config_jobs) as parallel:
                 jobs = parallel._effective_n_jobs()
                 logger.info(f"Effective number of parallel workers used: {jobs}")
-                console = Console(
-                    color_system="auto" if self.print_colorized else None,
-                )
 
                 # Define progressbar
                 with get_progress_tracker(
-                    console=console,
+                    console=error_console,
                     cust_callables=[self._hyper_out],
                 ) as pbar:
                     task = pbar.add_task("Epochs", total=self.total_epochs)

tests/test_log_setup.py

@@ -6,7 +6,7 @@ import pytest
 from freqtrade.exceptions import OperationalException
 from freqtrade.loggers import (
     FTBufferingHandler,
-    FTStdErrStreamHandler,
+    FtRichHandler,
     set_loggers,
     setup_logging,
     setup_logging_pre,
@@ -72,7 +72,7 @@ def test_set_loggers_syslog():
     setup_logging(config)
     assert len(logger.handlers) == 3
     assert [x for x in logger.handlers if isinstance(x, logging.handlers.SysLogHandler)]
-    assert [x for x in logger.handlers if isinstance(x, FTStdErrStreamHandler)]
+    assert [x for x in logger.handlers if isinstance(x, FtRichHandler)]
     assert [x for x in logger.handlers if isinstance(x, FTBufferingHandler)]
     # setting up logging again should NOT cause the loggers to be added a second time.
     setup_logging(config)
@@ -96,7 +96,7 @@ def test_set_loggers_Filehandler(tmp_path):
     setup_logging(config)
     assert len(logger.handlers) == 3
     assert [x for x in logger.handlers if isinstance(x, logging.handlers.RotatingFileHandler)]
-    assert [x for x in logger.handlers if isinstance(x, FTStdErrStreamHandler)]
+    assert [x for x in logger.handlers if isinstance(x, FtRichHandler)]
     assert [x for x in logger.handlers if isinstance(x, FTBufferingHandler)]
     # setting up logging again should NOT cause the loggers to be added a second time.
     setup_logging(config)
@@ -145,7 +145,7 @@ def test_set_loggers_journald(mocker):
     setup_logging(config)
     assert len(logger.handlers) == 3
     assert [x for x in logger.handlers if type(x).__name__ == "JournaldLogHandler"]
-    assert [x for x in logger.handlers if isinstance(x, FTStdErrStreamHandler)]
+    assert [x for x in logger.handlers if isinstance(x, FtRichHandler)]
     # reset handlers to not break pytest
     logger.handlers = orig_handlers