Refactor global log default handler (#347)

* 🦄 refactor: optimize log output

Unified log output using the loguru logging library

* 🌈 style: pre-commit fix

* 🌈 style: pre-commit fix

* Clean up and update some code

* Update default log output style

Author: obrua

backend/common/log.py

@@ -1,54 +1,103 @@
 #!/usr/bin/env python3
 # -*- coding: utf-8 -*-
-from __future__ import annotations
-
+import inspect
+import logging
 import os
 
-from typing import TYPE_CHECKING
+from sys import stderr, stdout
 
 from loguru import logger
 
 from backend.core import path_conf
 from backend.core.conf import settings
 
-if TYPE_CHECKING:
-    import loguru
-
-
-class Logger:
-    def __init__(self):
-        self.log_path = path_conf.LOG_DIR
-
-    def log(self) -> loguru.Logger:
-        if not os.path.exists(self.log_path):
-            os.mkdir(self.log_path)
-
-        # 日志文件
-        log_stdout_file = os.path.join(self.log_path, settings.LOG_STDOUT_FILENAME)
-        log_stderr_file = os.path.join(self.log_path, settings.LOG_STDERR_FILENAME)
-
-        # loguru 日志: https://loguru.readthedocs.io/en/stable/api/logger.html#loguru._logger.Logger.add
-        log_config = dict(rotation='10 MB', retention='15 days', compression='tar.gz', enqueue=True)
-        # stdout
-        logger.add(
-            log_stdout_file,
-            level='INFO',
-            filter=lambda record: record['level'].name == 'INFO' or record['level'].no <= 25,
-            **log_config,
-            backtrace=False,
-            diagnose=False,
-        )
-        # stderr
-        logger.add(
-            log_stderr_file,
-            level='ERROR',
-            filter=lambda record: record['level'].name == 'ERROR' or record['level'].no >= 30,
-            **log_config,
-            backtrace=True,
-            diagnose=True,
-        )
-
-        return logger
-
-
-log = Logger().log()
+
+class InterceptHandler(logging.Handler):
+    """
+    Default handler from examples in loguru documentation.
+    See https://loguru.readthedocs.io/en/stable/overview.html#entirely-compatible-with-standard-logging
+    """
+
+    def emit(self, record: logging.LogRecord):
+        # Get corresponding Loguru level if it exists
+        try:
+            level = logger.level(record.levelname).name
+        except ValueError:
+            level = record.levelno
+
+        # Find caller from where originated the logged message.
+        frame, depth = inspect.currentframe(), 0
+        while frame and (depth == 0 or frame.f_code.co_filename == logging.__file__):
+            frame = frame.f_back
+            depth += 1
+
+        logger.opt(depth=depth, exception=record.exc_info).log(level, record.getMessage())
+
+
+def setup_logging():
+    """
+    From https://pawamoy.github.io/posts/unify-logging-for-a-gunicorn-uvicorn-app/
+    https://github.com/pawamoy/pawamoy.github.io/issues/17
+    """
+    # Intercept everything at the root logger
+    logging.root.handlers = [InterceptHandler()]
+    logging.root.setLevel(settings.LOG_LEVEL)
+
+    # Remove all log handlers and propagate to root logger
+    for name in logging.root.manager.loggerDict.keys():
+        logging.getLogger(name).handlers = []
+        if 'uvicorn.access' in name or 'watchfiles.main' in name:
+            logging.getLogger(name).propagate = False
+        else:
+            logging.getLogger(name).propagate = True
+
+        logging.debug(f'{logging.getLogger(name)}, {logging.getLogger(name).propagate}')
+
+    # Remove every other logger's handlers
+    logger.remove()
+
+    # Configure logger before starts logging
+    logger.configure(handlers=[{'sink': stdout, 'level': settings.LOG_LEVEL, 'format': settings.LOG_FORMAT}])
+    logger.configure(handlers=[{'sink': stderr, 'level': settings.LOG_LEVEL, 'format': settings.LOG_FORMAT}])
+
+
+def set_customize_logfile():
+    log_path = path_conf.LOG_DIR
+    if not os.path.exists(log_path):
+        os.mkdir(log_path)
+
+    # log files
+    log_stdout_file = os.path.join(log_path, settings.LOG_STDOUT_FILENAME)
+    log_stderr_file = os.path.join(log_path, settings.LOG_STDERR_FILENAME)
+
+    # loguru logger: https://loguru.readthedocs.io/en/stable/api/logger.html#loguru._logger.Logger.add
+    log_config = {
+        'rotation': '10 MB',
+        'retention': '15 days',
+        'compression': 'tar.gz',
+        'enqueue': True,
+        'format': settings.LOG_FORMAT,
+    }
+
+    # stdout
+    logger.add(
+        log_stdout_file,
+        level='INFO',
+        filter=lambda record: record['level'].name == 'INFO' or record['level'].no <= 25,
+        **log_config,
+        backtrace=False,
+        diagnose=False,
+    )
+
+    # stderr
+    logger.add(
+        log_stderr_file,
+        level='ERROR',
+        filter=lambda record: record['level'].name == 'ERROR' or record['level'].no >= 30,
+        **log_config,
+        backtrace=True,
+        diagnose=True,
+    )
+
+
+log = logger

backend/core/conf.py

@@ -92,6 +92,8 @@ def validate_openapi_url(cls, values):
     ]
 
     # Log
+    LOG_LEVEL: str = 'INFO'
+    LOG_FORMAT: str = '<green>{time:YYYY-MM-DD HH:mm:ss.SSS}</> | <lvl>{level: <8}</> | <lvl>{message}</>'
     LOG_STDOUT_FILENAME: str = 'fba_access.log'
     LOG_STDERR_FILENAME: str = 'fba_error.log'
 

backend/core/registrar.py

@@ -9,6 +9,7 @@
 
 from backend.app.router import route
 from backend.common.exception.exception_handler import register_exception
+from backend.common.log import set_customize_logfile, setup_logging
 from backend.core.conf import settings
 from backend.core.path_conf import STATIC_DIR
 from backend.database.db_mysql import create_table
@@ -56,6 +57,9 @@ def register_app():
         lifespan=register_init,
     )
 
+    # 日志
+    register_logger()
+
     # 静态文件
     register_static_file(app)
 
@@ -74,6 +78,16 @@ def register_app():
     return app
 
 
+def register_logger() -> None:
+    """
+    系统日志
+
+    :return:
+    """
+    setup_logging()
+    set_customize_logfile()
+
+
 def register_static_file(app: FastAPI):
     """
     静态文件交互开发模式, 生产使用 nginx 静态资源服务

backend/main.py

@@ -11,8 +11,10 @@
 
 if __name__ == '__main__':
     # 如果你喜欢在 IDE 中进行 DEBUG，main 启动方法会很有帮助
-    # 如果你喜欢通过日志方式进行调试，建议使用 fastapi cli 方式启动服务
+    # 如果你喜欢通过 print 方式进行调试，建议使用 fastapi cli 方式启动服务
     try:
-        uvicorn.run(app=f'{Path(__file__).stem}:app', reload=True)
+        config = uvicorn.Config(app=f'{Path(__file__).stem}:app', reload=True)
+        server = uvicorn.Server(config)
+        server.run()
     except Exception as e:
         raise e