如何为FastAPI的Uvicorn访问日志添加响应时间？

你遇到的问题很常见——Uvicorn的默认AccessFormatter确实没有内置响应时间的日志字段，因为Uvicorn本身的访问日志机制没有记录这个指标的逻辑。不过我们有两种可靠的方法来实现需求：

方案一：自定义FastAPI中间件，手动记录带响应时间的访问日志 #

这种方法最直观，不需要修改Uvicorn的日志配置结构，而是通过中间件拦截请求和响应，计算耗时后自行输出符合格式的日志。

步骤1：编写计时中间件 #

import time
import logging
from fastapi import FastAPI, Request
from starlette.middleware.base import BaseHTTPMiddleware

# 复用你现有的uvicorn.access日志记录器
access_logger = logging.getLogger("uvicorn.access")

app = FastAPI()

class TimingMiddleware(BaseHTTPMiddleware):
    async def dispatch(self, request: Request, call_next):
        # 记录请求开始时间
        start_time = time.time()
        # 处理请求并获取响应
        response = await call_next(request)
        # 计算响应耗时（秒，保留3位小数）
        process_time = time.time() - start_time
        
        # 按照你现有日志格式输出内容
        access_logger.info(
            '%s::%s %s - "%s" %.3f %d',
            time.strftime("%Y-%m-%dT%H:%M:%S%z"),
            "INFO",  # 对应原配置中的levelprefix
            request.client.host if request.client else "-",
            f"{request.method} {request.url.path} HTTP/{request.scope.get('http_version')}",
            process_time,
            response.status_code
        )
        return response

# 注册中间件到FastAPI应用
app.add_middleware(TimingMiddleware)

步骤2：避免重复日志 #

因为我们的中间件已经会输出访问日志，需要调整原log_config中的uvicorn.access日志级别，防止Uvicorn默认的访问日志重复输出：

"loggers": { 
    "uvicorn":{"handlers": ["default"], "level": "INFO", "propagate": False}, 
    "uvicorn.access":{"handlers": ["access"], "level": "WARNING", "propagate": False},  # 提升级别到WARNING，关闭默认日志
}

方案二：自定义AccessFormatter，注入响应时间字段 #

如果你想保留Uvicorn原有的日志触发逻辑，可以通过继承AccessFormatter并配合日志过滤器来注入响应时间。

步骤1：自定义日志格式化器 #

from uvicorn.logging import AccessFormatter

class CustomAccessFormatter(AccessFormatter):
    def format(self, record):
        # 给日志记录添加响应时间字段，默认值为"-"
        if hasattr(record, 'process_time'):
            # 格式化为保留3位小数的字符串
            record.process_time = f"{record.process_time:.3f}"
        else:
            record.process_time = "-"
        return super().format(record)

步骤2：修改日志配置中的access格式化器 #

把原log_config里的access formatter替换为我们自定义的类：

"access": { 
    "()": "app.main.CustomAccessFormatter",  # 替换成你的Formatter所在的模块路径
    "datefmt": "%Y-%m-%dT%H:%M:%S%z", 
    "fmt": '%(asctime)s::%(levelprefix)s %(client_addr)s - "%(request_line)s" %(process_time)s %(status_code)s', 
    "use_colors": False, 
}, 

步骤3：添加日志过滤器注入响应时间 #

通过中间件计算耗时，并通过日志过滤器把时间注入到Uvicorn的日志记录中：

import time
import logging
from fastapi import FastAPI, Request
from starlette.middleware.base import BaseHTTPMiddleware

app = FastAPI()

class TimingFilter(logging.Filter):
    def __init__(self, process_time):
        self.process_time = process_time
        super().__init__()
    
    def filter(self, record):
        record.process_time = self.process_time
        return True

class TimingMiddleware(BaseHTTPMiddleware):
    async def dispatch(self, request: Request, call_next):
        start_time = time.time()
        response = await call_next(request)
        process_time = time.time() - start_time
        
        # 获取uvicorn.access日志器并添加过滤器
        access_logger = logging.getLogger("uvicorn.access")
        # 添加一次性过滤器，避免重复注入
        access_logger.addFilter(TimingFilter(process_time))
        return response

app.add_middleware(TimingMiddleware)

推荐方案 #

我更推荐方案一，它逻辑简单、易于调试，不需要对Uvicorn的内部日志机制做太多修改，而且你可以完全控制日志的输出格式和内容。

内容的提问来源于stack exchange，提问作者ScipioAfricanus