0

I am migrate flask app to fastapi and occurred with logging error, example code:

import logging
from logging.handlers import TimedRotatingFileHandler
from fastapi import Body, FastAPI, Request
from fastapi.staticfiles import StaticFiles
from fastapi.templating import Jinja2Templates



app = FastAPI()
app.mount("/static", StaticFiles(directory="static"), name="static")
templates = Jinja2Templates(directory="templates")

logformat = logging.Formatter(
        "[%(asctime)s][%(filename)s:%(lineno)d][%(levelname)s][%(process)d][%(threadName)s] - %(message)s")
logger = logging.getLogger("uvicorn.access")

# time rotating handler
# debug
debug_rotating_handler = TimedRotatingFileHandler(
    'pml_debug.log',
    when="midnight",
    interval=1,
    backupCount=15,
    encoding='utf-8'
)
debug_rotating_handler.setFormatter(logformat)
debug_rotating_handler.setLevel(logging.DEBUG)
logger.addHandler(debug_rotating_handler)
logger.setLevel(logging.DEBUG)



@app.get("/")
async def home(request: Request):
    # logging
    logger.debug("test")
    return {"test": 1}

the output:

--- Logging error ---
Traceback (most recent call last):
  File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/logging/__init__.py", line 1098, in emit
    msg = self.format(record)
  File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/logging/__init__.py", line 942, in format
    return fmt.format(record)
  File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/logging/__init__.py", line 681, in format
    s = self.formatMessage(record)
  File "/Users/gui/Documents/workspace/fastapi-celery/venv/lib/python3.10/site-packages/uvicorn/logging.py", line 92, in formatMessage
    (
ValueError: not enough values to unpack (expected 5, got 0)
Call stack:
  File "<string>", line 1, in <module>
  File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/multiprocessing/spawn.py", line 116, in spawn_main
    exitcode = _main(fd, parent_sentinel)
  File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/multiprocessing/spawn.py", line 129, in _main
    return self._bootstrap(parent_sentinel)
  File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/multiprocessing/process.py", line 315, in _bootstrap
    self.run()
  File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)
  File "/Users/gui/Documents/workspace/fastapi-celery/venv/lib/python3.10/site-packages/uvicorn/subprocess.py", line 61, in subprocess_started
    target(sockets=sockets)
  File "/Users/gui/Documents/workspace/fastapi-celery/venv/lib/python3.10/site-packages/uvicorn/server.py", line 49, in run
    loop.run_until_complete(self.serve(sockets=sockets))
  File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/asyncio/base_events.py", line 628, in run_until_complete
    self.run_forever()
  File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/asyncio/base_events.py", line 595, in run_forever
    self._run_once()
  File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/asyncio/base_events.py", line 1881, in _run_once
    handle._run()
  File "/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/asyncio/events.py", line 80, in _run
    self._context.run(self._callback, *self._args)
  File "/Users/gui/Documents/workspace/fastapi-celery/venv/lib/python3.10/site-packages/uvicorn/protocols/http/h11_impl.py", line 396, in run_asgi
    result = await app(self.scope, self.receive, self.send)
  File "/Users/gui/Documents/workspace/fastapi-celery/venv/lib/python3.10/site-packages/uvicorn/middleware/proxy_headers.py", line 45, in __call__
    return await self.app(scope, receive, send)
  File "/Users/gui/Documents/workspace/fastapi-celery/venv/lib/python3.10/site-packages/fastapi/applications.py", line 199, in __call__
    await super().__call__(scope, receive, send)
  File "/Users/gui/Documents/workspace/fastapi-celery/venv/lib/python3.10/site-packages/starlette/applications.py", line 111, in __call__
    await self.middleware_stack(scope, receive, send)
  File "/Users/gui/Documents/workspace/fastapi-celery/venv/lib/python3.10/site-packages/starlette/middleware/errors.py", line 159, in __call__
    await self.app(scope, receive, _send)
  File "/Users/gui/Documents/workspace/fastapi-celery/venv/lib/python3.10/site-packages/starlette/exceptions.py", line 71, in __call__
    await self.app(scope, receive, sender)
  File "/Users/gui/Documents/workspace/fastapi-celery/venv/lib/python3.10/site-packages/starlette/routing.py", line 566, in __call__
    await route.handle(scope, receive, send)
  File "/Users/gui/Documents/workspace/fastapi-celery/venv/lib/python3.10/site-packages/starlette/routing.py", line 227, in handle
    await self.app(scope, receive, send)
  File "/Users/gui/Documents/workspace/fastapi-celery/venv/lib/python3.10/site-packages/starlette/routing.py", line 41, in app
    response = await func(request)
  File "/Users/gui/Documents/workspace/fastapi-celery/venv/lib/python3.10/site-packages/fastapi/routing.py", line 201, in app
    raw_response = await run_endpoint_function(
  File "/Users/gui/Documents/workspace/fastapi-celery/venv/lib/python3.10/site-packages/fastapi/routing.py", line 148, in run_endpoint_function
    return await dependant.call(**values)
  File "/Users/gui/Documents/workspace/fastapi-celery/project/main.py", line 36, in home
    logger.debug("test")
Message: 'test'
Arguments: ()
INFO:     127.0.0.1:52982 - "GET / HTTP/1.1" 200 OK

So, how can we fix it? what causes this?And is it necessary to use async logging metric?

Gui
  • 21
  • 5
  • You might find [this](https://stackoverflow.com/a/71517830/17865804) and [this](https://stackoverflow.com/a/70899261/17865804) helpful. – Chris Oct 25 '22 at 09:51
  • no, i have watched, this just log request and file, and it didn't help :( – Gui Oct 26 '22 at 02:30

0 Answers0