Skip to content

Commit

Permalink
python: allow to override the UvicornServer's default log config
Browse files Browse the repository at this point in the history
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 <toscano.luca@gmail.com>
  • Loading branch information
elukey committed Apr 8, 2023
1 parent 94052fd commit 3ce26c3
Show file tree
Hide file tree
Showing 5 changed files with 76 additions and 42 deletions.
Original file line number Diff line number Diff line change
@@ -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
Expand Down
2 changes: 1 addition & 1 deletion docs/samples/kafka/transformer.Dockerfile
Original file line number Diff line number Diff line change
@@ -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 . .
Expand Down
Original file line number Diff line number Diff line change
@@ -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/*
Expand Down
18 changes: 15 additions & 3 deletions python/kserve/kserve/model_server.py
Original file line number Diff line number Diff line change
Expand Up @@ -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()

Expand All @@ -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,
Expand All @@ -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
Expand All @@ -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):
Expand Down Expand Up @@ -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:
Expand All @@ -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()
Expand Down
94 changes: 58 additions & 36 deletions python/kserve/kserve/protocol/rest/server.py
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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)
Expand All @@ -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):
Expand Down

0 comments on commit 3ce26c3

Please sign in to comment.