Q:
I am writing a project which uses mostly Fastapi and ELK. with the middleware of FASTAPI I can easily collect log messages and make them into a monitoring panel, but I am seeing some issues in the console. Though it doesn’t affect the functionality. But I still want to fix this bug

Code

class JSONLogFormatter(logging.Formatter):
    def format(self, record):
        log_record = {
            "timestamp": self.formatTime(record, self.datefmt),
            "message": record.getMessage(),
            "logger_name": record.name,
            "func_name": record.funcName,
            "file_name": record.pathname,
            "response_code": record.__dict__.get("response_code", None),
            "request_method": record.__dict__.get("request_method", None),
            "request_path": record.__dict__.get("request_path", None),
            "request_ip": record.__dict__.get("request_ip", None),
            "request_time": record.__dict__.get("request_time", None)
        }
        return json.dumps(log_record)


# 设置日志通过 Logstash 发送到后端 ELK 集群上去
@app.on_event("startup")
async def startup_event():
    logger = logging.getLogger("uvicorn.access")

    # 使用自定义的 JSON 格式化器
    formatter = JSONLogFormatter()
    logstash_handler = AsynchronousLogstashHandler(
        host=LogStash_ip,
        port=5044,
        database_path=None
    )
    logstash_handler.setFormatter(formatter)
    logger.addHandler(logstash_handler)


@app.middleware("http")
async def log_requests(request: Request, call_next):
    start_time = datetime.utcnow()
    response = await call_next(request)
    process_time = (datetime.utcnow() - start_time).total_seconds()

    # 解析请求信息
    client_host = request.client.host
    request_method = request.method
    request_path = request.url.path
    status_code = response.status_code
    # 构建日志消息
    log_message = f"{client_host} - {request_method} {request_path} {status_code} -{process_time:.2f}s"

    # 获取 uvicorn 的访问日志记录器
    logger = logging.getLogger("uvicorn.access")

    try:
        # 记录日志消息
        logger.info(log_message)
    except Exception as e:
        print(f"Logging error: {e}")

    return response

When I call an interface. He will display log messages. But it also displays some error messages

Traceback (most recent call last):
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Liblogging__init__.py", line 1160, in emit
    msg = self.format(record)
          ^^^^^^^^^^^^^^^^^^^
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Liblogging__init__.py", line 999, in format
    return fmt.format(record)
           ^^^^^^^^^^^^^^^^^^
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Liblogging__init__.py", line 706, in format
    s = self.formatMessage(record)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Libsite-packagesuvicornlogging.py", line 104, in formatMessage
    (
ValueError: not enough values to unpack (expected 5, got 0)
Call stack:
  File "<string>", line 1, in <module>
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Libmultiprocessingspawn.py", line 122, in spawn_main
    exitcode = _main(fd, parent_sentinel)
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Libmultiprocessingspawn.py", line 135, in _main
    return self._bootstrap(parent_sentinel)
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Libmultiprocessingprocess.py", line 314, in _bootstrap
    self.run()
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Libmultiprocessingprocess.py", line 108, in run
    self._target(*self._args, **self._kwargs)
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Libsite-packagesuvicorn_subprocess.py", line 76, in subprocess_started
    target(sockets=sockets)
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Libsite-packagesuvicornserver.py", line 60, in run
    return asyncio.run(self.serve(sockets=sockets))
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Libasynciorunners.py", line 194, in run
    return runner.run(main)
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Libasynciorunners.py", line 118, in run
    return self._loop.run_until_complete(task)
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Libasynciobase_events.py", line 674, in run_until_complete
    self.run_forever()
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Libasynciobase_events.py", line 641, in run_forever
    self._run_once()
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Libasynciobase_events.py", line 1987, in _run_once
    handle._run()
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Libasyncioevents.py", line 88, in _run
    self._context.run(self._callback, *self._args)
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Libsite-packagesuvicornprotocolshttph11_impl.py", line 404, in run_asgi
    result = await app(  # type: ignore[func-returns-value]
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Libsite-packagesuvicornmiddlewareproxy_headers.py", line 78, in __call__
    return await self.app(scope, receive, send)
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Libsite-packagesfastapiapplications.py", line 1054, in __call__
    await super().__call__(scope, receive, send)
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Libsite-packagesstarletteapplications.py", line 123, in __call__
    await self.middleware_stack(scope, receive, send)
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Libsite-packagesstarlettemiddlewareerrors.py", line 164, in __call__
    await self.app(scope, receive, _send)
  File "C:UsersxxxAppDataLocalProgramsPythonPython312Libsite-packagesstarlettemiddlewarebase.py", line 191, in __call__
    response = await self.dispatch_func(request, call_next)
  File "D:FastApi_Blogappmain.py", line 89, in log_requests
    logger.info(log_message)
Message: '127.0.0.1 - GET /api/power/ 401 -0.00s'
Arguments: ()
INFO:     127.0.0.1:54048 - "GET /api/power/ HTTP/1.1" 401 Unauthorized

This error is not caused by a 401 error either. Because even a 200. would have this problem