fastapi日志全链路追踪

fastapi 协程方式运行，日志无法通过线程号区分请求，使用 contextvars 管理一个 request-id 上下文带入日志。这里日志模块用的 loguru。

1. 在全局位置声明

import contextvars  # noqa

request_id_context = contextvars.ContextVar("request-id", default="-")
request_id_context.set("-")

2. 添加一个中间件，在处理请求前生成一个 uuid 赋值给 request_id_context，处理过之后再恢复默认

@app.middleware("http")
async def extra_process(request: Request, call_next):
    start_time = time.time()
    request_id = uuid.uuid4().hex
    request_id_context.set(request_id)
    response: Response = await call_next(request)
    ptime = time.time() - start_time
    logger.info(f"process time [{ptime}s]: {response.status_code}-{request.url}")
    request_id_context.set("-")
    return response

3. 把该 request-id 加进日志信息里

def _filter(record):
    record["extra"] = {"traceid": request_id_context.get("request-id")}
    return True


# 日志简单配置
logger.add(
    log_sink, rotation="50 MB", enqueue=True, level="INFO", encoding="utf-8",
    format=("<green>{time:YYYY-MM-DD HH:mm:ss.SSS}</green> | "
            "<level>{level: <8}</level> | "
            "<level>{extra[traceid]: <32}</level> | "
            "<cyan>{name}</cyan>:<cyan>{function}</cyan>:<cyan>{line}</cyan> - <level>{message}</level>"),
    filter=_filter
)

4. 至此会有一个问题，contextvars 线程隔离，对于使用 loop.run_in_executor 包过的使用线程池执行的方法中的日志访问不到第1步声明的这个上下文，需要重新定义一下线程池。这里用的Python3.8版本，Python3.9好像有更简单的解决方案，可参考 fastapi_issues_2776

class ContextSafeThreadPoolExecutor(ThreadPoolExecutor):

    def submit(self, fn: Callable, *args, **kwargs):
        ctx = contextvars.copy_context()
        return super().submit(partial(ctx.run, partial(fn, *args, **kwargs)))


def sync_to_async(func: Callable) -> Callable:
    """
    将同步函数转换成异步，协程使用
    :param func: 同步函数
    :return: 异步函数
    """

    @wraps(func)
    async def run_in_executor(*args, **kwargs):
        loop = asyncio.get_event_loop()
        p_func = partial(func, *args, **kwargs)
        return await loop.run_in_executor(ContextSafeThreadPoolExecutor(), p_func)

    return run_in_executor

参考：

FastAPI 全链路日志追踪

Context vars set in an async dependency are visible for sync routes but not for sync functions run inside ThreadPoolExecutor · Issue #2776 · tiangolo/fastapi · GitHub