Logging with queueHandler

freqtrade/loggers.py

@@ -1,14 +1,15 @@
 import logging
+import queue
 import sys
-
 from logging import Formatter
-from logging.handlers import RotatingFileHandler, SysLogHandler
+from logging.handlers import RotatingFileHandler, SysLogHandler, QueueHandler, QueueListener
 from typing import Any, Dict, List
 
 from freqtrade.exceptions import OperationalException
 
-
 logger = logging.getLogger(__name__)
+log_queue = queue.Queue(-1)
+LOGFORMAT = '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
 
 
 def _set_loggers(verbosity: int = 0, api_verbosity: str = 'info') -> None:
@@ -33,6 +34,25 @@ def _set_loggers(verbosity: int = 0, api_verbosity: str = 'info') -> None:
     )
 
 
+def setup_logging_pre() -> None:
+    """
+    Setup early logging.
+    This uses a queuehandler, which delays logging.
+    # TODO: How does QueueHandler work if no listenerhandler is attached??
+    """
+    logging.root.setLevel(logging.INFO)
+    fmt = logging.Formatter(LOGFORMAT)
+
+    queue_handler = QueueHandler(log_queue)
+    queue_handler.setFormatter(fmt)
+    logger.root.addHandler(queue_handler)
+
+    # Add streamhandler here to capture Errors before QueueListener is started
+    sth = logging.StreamHandler(sys.stderr)
+    sth.setFormatter(fmt)
+    logger.root.addHandler(sth)
+
+
 def setup_logging(config: Dict[str, Any]) -> None:
     """
     Process -v/--verbose, --logfile options
@@ -41,7 +61,7 @@ def setup_logging(config: Dict[str, Any]) -> None:
     verbosity = config['verbosity']
 
     # Log to stderr
-    log_handlers: List[logging.Handler] = [logging.StreamHandler(sys.stderr)]
+    log_handlers: List[logging.Handler] = []
 
     logfile = config.get('logfile')
     if logfile:
@@ -76,10 +96,10 @@ def setup_logging(config: Dict[str, Any]) -> None:
                                                     maxBytes=1024 * 1024,  # 1Mb
                                                     backupCount=10))
 
-    logging.basicConfig(
+    listener = QueueListener(log_queue, *log_handlers)
-        level=logging.INFO if verbosity < 1 else logging.DEBUG,
+
-        format='%(asctime)s - %(name)s - %(levelname)s - %(message)s',
+    # logging.root.setFormatter(logging.Formatter(LOGFORMAT))
-        handlers=log_handlers
+    logging.root.setLevel(logging.INFO if verbosity < 1 else logging.DEBUG)
-    )
+    listener.start()
     _set_loggers(verbosity, config.get('api_server', {}).get('verbosity', 'info'))
     logger.info('Verbosity set to %s', verbosity)

freqtrade/main.py

@@ -3,18 +3,18 @@
 Main Freqtrade bot script.
 Read the documentation to know what cli arguments you need.
 """
-
+# flake8: noqa E402
-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 +28,7 @@ def main(sysargv: List[str] = None) -> None:
 
     return_code: Any = 1
     try:
+        setup_logging_pre()
         arguments = Arguments(sysargv)
         args = arguments.get_parsed_arg()