python: allow to override the UvicornServer's default log config

It is useful to be able to change Uvicorn's log settings, for example to be able to change the access log's format. The Uvicorn's Config class provides a "configure_logging" function that is smart about the log_config parameter - if it is a string, and not a dictionary, it is interpreted as a file containing logging directives and that needs to be loaded from disk. This is very convenient for the KServe use case: one can either use the default config, hardcoded in a dictionary, or anything provided as yaml or json file. This change fixes also the default UvicornServer's config. Sadly the current Uvicorn implementation doesn't support changing the access log format, but they suggest to use asgi-logger: encode/uvicorn#947 (comment) It seems the only way forward to allow a decent customization of a vital sign like the access log. The main downside is that asgi-logger requires python3.8+, so to make CI happy I had to move the python3.7-slim images to python3.8-slim. Since Python 3.7 is going to be EOLed in a couple of months, it seems good to move the minimum compatibility to Python 3.8. Fixes: kserve#2778 Signed-off-by: Luca Toscano <[email protected]>
elukey · Apr 4, 2023 · 38a8ade · 38a8ade
1 parent f7ac613
commit 38a8ade
Show file tree

Hide file tree

Showing 8 changed files with 79 additions and 46 deletions.
diff --git a/docs/samples/explanation/aif/germancredit/server/Dockerfile b/docs/samples/explanation/aif/germancredit/server/Dockerfile
@@ -1,6 +1,6 @@
 # Use the official lightweight Python image.
 # https://hub.docker.com/_/python
-FROM python:3.7-slim
+FROM python:3.8-slim
 
 ENV APP_HOME /app
 WORKDIR $APP_HOME

diff --git a/docs/samples/kafka/transformer.Dockerfile b/docs/samples/kafka/transformer.Dockerfile
@@ -1,4 +1,4 @@
-FROM python:3.7-slim
+FROM python:3.8-slim
 
 RUN apt-get update && apt-get install -y libglib2.0-0
 COPY . .

diff --git a/docs/samples/v1beta1/triton/bert/bert_tokenizer_v2/Dockerfile b/docs/samples/v1beta1/triton/bert/bert_tokenizer_v2/Dockerfile
@@ -1,4 +1,4 @@
-FROM python:3.7-slim
+FROM python:3.8-slim
 RUN  apt-get update \
   && apt-get install -y wget \
   && rm -rf /var/lib/apt/lists/*

diff --git a/python/aixexplainer.Dockerfile b/python/aixexplainer.Dockerfile
@@ -1,4 +1,4 @@
-ARG BASE_IMAGE=python:3.7-slim
+ARG BASE_IMAGE=python:3.8-slim
 FROM $BASE_IMAGE
 
 COPY third_party third_party

diff --git a/python/kserve/kserve/model_server.py b/python/kserve/kserve/model_server.py
@@ -55,6 +55,10 @@
                     help="Enable docs url '/docs' to display Swagger UI.")
 parser.add_argument("--enable_latency_logging", default=True, type=lambda x: bool(strtobool(x)),
                     help="Output a log per request with latency metrics.")
+parser.add_argument("--log_config_file", default=None, type=str,
+                    help="File path containing UvicornServer's log config. Needs to be a yaml or json file.")
+parser.add_argument("--access_log_format", default=None, type=str,
+                    help="Format to set for the access log (provided by asgi-logger).")
 
 args, _ = parser.parse_known_args()
 
@@ -76,6 +80,7 @@ class ModelServer:
         enable_grpc (bool): Whether to turn on grpc server. Default: ``True``
         enable_docs_url (bool): Whether to turn on ``/docs`` Swagger UI. Default: ``False``.
         enable_latency_logging (bool): Whether to log latency metric. Default: ``True``.
+        log_config_file (dict): File path containing UvicornServer's log config. Default: ``None``.
     """
 
     def __init__(self, http_port: int = args.http_port,
@@ -86,7 +91,9 @@ def __init__(self, http_port: int = args.http_port,
                  registered_models: ModelRepository = ModelRepository(),
                  enable_grpc: bool = args.enable_grpc,
                  enable_docs_url: bool = args.enable_docs_url,
-                 enable_latency_logging: bool = args.enable_latency_logging):
+                 enable_latency_logging: bool = args.enable_latency_logging,
+                 log_config_file: str = args.log_config_file,
+                 access_log_format: str = args.access_log_format):
         self.registered_models = registered_models
         self.http_port = http_port
         self.grpc_port = grpc_port
@@ -100,6 +107,8 @@ def __init__(self, http_port: int = args.http_port,
         self.model_repository_extension = ModelRepositoryExtension(
             model_registry=self.registered_models)
         self._grpc_server = GRPCServer(grpc_port, self.dataplane, self.model_repository_extension)
+        self.log_config_file = log_config_file
+        self.access_log_format = access_log_format
 
     def start(self, models: Union[List[Model], Dict[str, Deployment]]) -> None:
         if isinstance(models, list):
@@ -143,7 +152,9 @@ async def serve():
                     sig, lambda s=sig: asyncio.create_task(self.stop(sig=s))
                 )
             self._rest_server = UvicornServer(self.http_port, [serversocket],
-                                              self.dataplane, self.model_repository_extension, self.enable_docs_url)
+                                              self.dataplane, self.model_repository_extension,
+                                              self.enable_docs_url, log_config_file=self.log_config_file,
+                                              access_log_format=self.access_log_format)
             if self.workers == 1:
                 await self._rest_server.run()
             else:
@@ -153,7 +164,8 @@ async def serve():
                 # https://github.com/tiangolo/fastapi/issues/1586
                 multiprocessing.set_start_method('fork')
                 server = UvicornServer(self.http_port, [serversocket],
-                                       self.dataplane, self.model_repository_extension, self.enable_docs_url)
+                                       self.dataplane, self.model_repository_extension,
+                                       self.enable_docs_url, custom_log_config=self.log_config)
                 for _ in range(self.workers):
                     p = Process(target=server.run_sync)
                     p.start()

diff --git a/python/kserve/kserve/protocol/rest/server.py b/python/kserve/kserve/protocol/rest/server.py
@@ -19,6 +19,7 @@
 
 import pkg_resources
 import uvicorn
+from asgi_logger import AccessLoggerMiddleware
 from fastapi import FastAPI, Request, Response
 from fastapi.routing import APIRoute as FastAPIRoute
 from fastapi.responses import ORJSONResponse
@@ -126,7 +127,8 @@ def create_application(self) -> FastAPI:
 
 class UvicornServer:
     def __init__(self, http_port: int, sockets: List[socket.socket],
-                 data_plane: DataPlane, model_repository_extension, enable_docs_url):
+                 data_plane: DataPlane, model_repository_extension, enable_docs_url,
+                 log_config_file: str = None, access_log_format: str = None):
         super().__init__()
         self.sockets = sockets
         rest_server = RESTServer(data_plane, model_repository_extension, enable_docs_url)
@@ -136,46 +138,66 @@ def __init__(self, http_port: int, sockets: List[socket.socket],
             client=PrintTimings(),
             metric_namer=StarletteScopeToName(prefix="kserve.io", starlette_app=app)
         )
+        log_config = {
+            "version": 1,
+            "formatters": {
+                "default": {
+                    "()": "uvicorn.logging.DefaultFormatter",
+                    "datefmt": DATE_FMT,
+                    "fmt": "%(asctime)s.%(msecs)03d %(name)s %(levelprefix)s %(message)s",
+                    "use_colors": None,
+                },
+                "access": {
+                    "()": "uvicorn.logging.AccessFormatter",
+                    "datefmt": DATE_FMT,
+                    "fmt": '%(asctime)s.%(msecs)03d %(name)s %(levelprefix)s %(client_addr)s %(process)s - '
+                           '"%(request_line)s" %(status_code)s',
+                    # noqa: E501
+                },
+            },
+            "handlers": {
+                "default": {
+                    "formatter": "default",
+                    "class": "logging.StreamHandler",
+                    "stream": "ext://sys.stderr",
+                },
+                "access": {
+                    "formatter": "access",
+                    "class": "logging.StreamHandler",
+                    "stream": "ext://sys.stdout",
+                },
+            },
+            "loggers": {
+                "uvicorn": {"handlers": ["default"], "level": "INFO"},
+                "uvicorn.error": {"level": "INFO"},
+                "uvicorn.access": {"handlers": ["access"], "level": "INFO", "propagate": False},
+            },
+        }
+
+        # If the log_config value is a string ending up with ".json"
+        # or ".yaml", it is interpreted as file path and the log configuration
+        # is loaded from disk.
+        if log_config_file:
+            log_config = log_config_file
+
         self.cfg = uvicorn.Config(
             app=app,
             host="0.0.0.0",
+            log_config=log_config,
             port=http_port,
-            log_config={
-                "version": 1,
-                "formatters": {
-                    "default": {
-                        "()": "uvicorn.logging.DefaultFormatter",
-                        "datefmt": DATE_FMT,
-                        "fmt": "%(asctime)s.%(msecs)03d %(name)s %(levelprefix)s %(message)s",
-                        "use_colors": None,
-                    },
-                    "access": {
-                        "()": "uvicorn.logging.AccessFormatter",
-                        "datefmt": DATE_FMT,
-                        "fmt": '%(asctime)s.%(msecs)03d %(name)s %(levelprefix)s %(client_addr)s %(process)s - '
-                               '"%(request_line)s" %(status_code)s',
-                        # noqa: E501
-                    },
-                },
-                "rest": {
-                    "default": {
-                        "formatter": "default",
-                        "class": "logging.StreamHandler",
-                        "stream": "ext://sys.stderr",
-                    },
-                    "access": {
-                        "formatter": "access",
-                        "class": "logging.StreamHandler",
-                        "stream": "ext://sys.stdout",
-                    },
-                },
-                "loggers": {
-                    "uvicorn": {"rest": ["default"], "level": "INFO"},
-                    "uvicorn.error": {"level": "INFO"},
-                    "uvicorn.access": {"rest": ["access"], "level": "INFO", "propagate": False},
-                },
-            }
         )
+
+        # More context in https://github.com/encode/uvicorn/pull/947
+        # At the time of writing the ASGI specs are not clear when it comes
+        # to change the access log format, and hence the Uvicorn upstream devs
+        # chose to create a custom middleware for this.
+        # The allowed log format is specified in https://github.com/Kludex/asgi-logger#usage
+        if access_log_format:
+            logging.getLogger("uvicorn.access").handlers = []
+            app.add_middleware(
+                AccessLoggerMiddleware, format=access_log_format,
+                logger=logging.getLogger("uvicorn.access"))
+
         self.server = _NoSignalUvicornServer(config=self.cfg)
 
     def run_sync(self):

diff --git a/python/kserve/requirements.txt b/python/kserve/requirements.txt
@@ -20,4 +20,4 @@ httpx>=0.23.0
 fastapi>=0.89.1
 timing_asgi>=0.3.0
 pandas>=1.3.5
-
+asgi-logger>=0.1.0
diff --git a/python/kserve/setup.py b/python/kserve/setup.py
@@ -42,7 +42,7 @@
     url="https://github.com/kserve/kserve/tree/master/python/kserve",
     description="KServe Python SDK",
     long_description="Python SDK for KServe Server and Client.",
-    python_requires='>=3.7',
+    python_requires='>=3.8',
     packages=[
         'kserve',
         'kserve.api',
@@ -62,7 +62,6 @@
         'Intended Audience :: Education',
         'Intended Audience :: Science/Research',
         'Programming Language :: Python :: 3',
-        'Programming Language :: Python :: 3.7',
         'Programming Language :: Python :: 3.8',
         'Programming Language :: Python :: 3.9',
         "License :: OSI Approved :: Apache Software License",