Merge pull request #1491 from fractal-analytics-platform/uvicorn-logging

Improve uvicorn/gunicorn logging

CHANGELOG.md

@@ -2,13 +2,21 @@
 
 # Unreleased
 
+> NOTE: This version changes log formats.
+> For `uvicorn` logs, this change requires no action.
+> For `gunicorn`, logs formats are only changed by adding the following
+> command-line option:
+> `gunicorn ... --logger-class fractal_server.logger.gunicorn_logger.FractalGunicornLogger`.
+
 * API:
     * Add `FRACTAL_API_V1_MODE` environment variable to include/exclude V1 API (\#1480).
+    * Change format of uvicorn loggers (\#1491).
+    * Introduce `FractalGunicornLogger` class (\#1491).
 * Runner:
     * Fix missing `.log` files in server folder for SLURM jobs (\#1479).
 * Database:
     * Remove `UserOAuth.project_list` and `UserOAuth.project_list_v2` relationships (\#1482).
-* Dev depdendencies:
+* Dev dependencies:
     * Bump `pytest` to `8.1.*` (#1486).
     * Bump `coverage` to `7.5.*` (#1486).
     * Bump `pytest-docker` to `3.1.*` (#1486).

fractal_server/logger.py → fractal_server/logger/__init__.py

@@ -17,8 +17,8 @@
 from typing import Optional
 from typing import Union
 
-from .config import get_settings
-from .syringe import Inject
+from ..config import get_settings
+from ..syringe import Inject
 
 
 LOG_FORMAT = "%(asctime)s - %(name)s - %(levelname)s - %(message)s"
@@ -136,3 +136,29 @@ def reset_logger_handlers(logger: logging.Logger) -> None:
     """
     close_logger(logger)
     logger.handlers.clear()
+
+
+def config_uvicorn_loggers():
+    """
+    Change the formatter for the uvicorn access/error loggers.
+
+    This is similar to https://stackoverflow.com/a/68864979/19085332. See also
+    https://github.com/tiangolo/fastapi/issues/1508.
+
+    This function is meant to work in two scenarios:
+
+    1. The most relevant case is for a `gunicorn` startup command, with
+       `--access-logfile` and `--error-logfile` options set.
+    2. The case of `fractalctl start` (directly calling `uvicorn`).
+
+    Because of the second use case, we need to check whether uvicorn loggers
+    already have a handler. If not, we skip the formatting.
+    """
+
+    access_logger = logging.getLogger("uvicorn.access")
+    if len(access_logger.handlers) > 0:
+        access_logger.handlers[0].setFormatter(LOG_FORMATTER)
+
+    error_logger = logging.getLogger("uvicorn.error")
+    if len(error_logger.handlers) > 0:
+        error_logger.handlers[0].setFormatter(LOG_FORMATTER)

fractal_server/logger/gunicorn_logger.py

@@ -0,0 +1,19 @@
+"""
+This module (which is only executed if `gunicorn` can be imported) subclasses
+the gunicorn `Logger` class in order to slightly change its log formats.
+
+This class can be used by including this `gunicorn` command-line option:
+```
+--logger-class fractal_server.logger.gunicorn_logger.FractalGunicornLogger
+```
+"""
+
+try:
+    from gunicorn.glogging import Logger as GunicornLogger
+
+    class FractalGunicornLogger(GunicornLogger):
+        error_fmt = r"%(asctime)s   - gunicorn.error - %(levelname)s - [pid %(process)d] - %(message)s"  # noqa: E501
+        datefmt = r"%Y-%m-%d %H:%M:%S,%u"
+
+except (ModuleNotFoundError, ImportError):
+    pass

fractal_server/main.py

@@ -19,6 +19,7 @@
 
 from .app.security import _create_first_user
 from .config import get_settings
+from .logger import config_uvicorn_loggers
 from .logger import reset_logger_handlers
 from .logger import set_logger
 from .syringe import Inject
@@ -84,6 +85,7 @@ async def __on_startup() -> None:
     callable.
     """
     check_settings()
+    config_uvicorn_loggers()
 
 
 def start_application() -> FastAPI:

tests/data/example_server_startup/.gitignore

@@ -4,6 +4,7 @@ fractal-server.err
 artifacts
 LOG*
 logs
+logs*
 *.db
 FRACTAL_TASKS_DIR
 .fractal_server.env

tests/data/example_server_startup/cleanup.sh

@@ -3,3 +3,4 @@
 rm test.db
 rm -r Tasks
 rm -r Artifacts
+rm logs*

tests/data/example_server_startup/run_server_gunicorn.sh

@@ -0,0 +1,13 @@
+#!/bin/bash
+
+# Create an empty db
+poetry run fractalctl set-db
+
+# Start the server
+poetry run gunicorn fractal_server.main:app \
+    --workers 4 \
+    --worker-class uvicorn.workers.UvicornWorker \
+    --bind 0.0.0.0:8000 \
+    --access-logfile logs-fractal-server.access \
+    --error-logfile logs-fractal-server.error \
+    --logger-class fractal_server.logger.gunicorn_logger.FractalGunicornLogger \

tests/data/example_server_startup/run_server_uvicorn.sh

@@ -0,0 +1,7 @@
+#!/bin/bash
+
+# Create an empty db
+poetry run fractalctl set-db
+
+# Start the server
+poetry run fractalctl start --port 8000

tests/no_version/test_unit_config_uvicorn_loggers.py

@@ -0,0 +1,9 @@
+from fractal_server.main import config_uvicorn_loggers
+
+
+def test_config_uvicorn_loggers():
+    """
+    This test simply runs `config_uvicorn_loggers`, but it does not assert
+    anything. It is only meant to catch some trivial errors.
+    """
+    config_uvicorn_loggers()