diff --git a/src/chongming/app/__init__.py b/src/chongming/app/__init__.py index 21a877e..f7201a4 100644 --- a/src/chongming/app/__init__.py +++ b/src/chongming/app/__init__.py @@ -19,6 +19,7 @@ from fastapi.middleware.gzip import GZipMiddleware from fastapi.middleware.cors import CORSMiddleware from chongming_config import get_config +from starlette.types import ASGIApp, Message, Receive, Scope, Send from .core.logger import get_logger from sqlite_vfs.contrib.fastapi_static import SVFSStaticFiles from .core import lifespan_setup, call_stats @@ -198,41 +199,67 @@ def _should_log_access(status_code: int, sample_rate: float = ACCESS_SAMPLE_RATE return next(_access_log_counter) % denom == 0 -@app.middleware("http") -async def access_log_middleware(request: Request, call_next): +def _log_access(scope: Scope, status_code: int, start: float) -> None: + """按采样规则写一条访问日志(成功按 access_sample_rate,错误 >=400 全量)""" + if not _should_log_access(status_code): + return + client = scope.get("client") + logger.info( + "%s %s status=%s duration=%.2fms client=%s", + scope.get("method", "-"), scope.get("path", "-"), status_code, + (time.perf_counter() - start) * 1000, client[0] if client else "-", + extra={"status_code": status_code}, + ) + + +class AccessLogMiddleware: """ - HTTP访问日志中间件,记录每个请求的详细信息。 + HTTP访问日志中间件(纯 ASGI 实现),记录每个请求的详细信息。 记录的信息包括: - 请求方法和路径 - 响应状态码 - - 请求处理时长(毫秒) + - 请求处理时长(毫秒,按慢路径:从进入中间件到响应头产出) - 客户端IP地址 高吞吐优化: - 采样:成功请求按 access_sample_rate 记录,错误(>=400)全量 - 异步:% 参数化消息 + 队列日志(QueueHandler),格式化与文件 I/O 在后台监听线程执行,主线程仅入队 - - 参数: - request: FastAPI请求对象 - call_next: 下一个中间件或路由处理函数 - - 返回: - Response: 处理后的响应对象 + - 不用 BaseHTTPMiddleware(@app.middleware("http")):它会为每请求建 anyio + task group 并把响应体经内存流过一手,压测实测高并发下吃掉 30~50% 吞吐; + 这里只包一层 send 截获 response.start,无缓冲、无额外任务 """ - start = time.perf_counter() - response = await call_next(request) - duration = (time.perf_counter() - start) * 1000 - client = request.client.host if request.client else "-" - if _should_log_access(response.status_code): - logger.info( - "%s %s status=%s duration=%.2fms client=%s", - request.method, request.url.path, response.status_code, duration, client, - extra={"status_code": response.status_code}, - ) - return response + def __init__(self, app: ASGIApp) -> None: + self.app = app + + async def __call__(self, scope: Scope, receive: Receive, send: Send) -> None: + if scope["type"] != "http": + await self.app(scope, receive, send) + return + + start = time.perf_counter() + logged = False + + async def send_wrapper(message: Message) -> None: + nonlocal logged + # 响应头产出即记录(流式响应因此只计到首字节,不计整段流) + if message["type"] == "http.response.start" and not logged: + logged = True + _log_access(scope, message["status"], start) + await send(message) + + try: + await self.app(scope, receive, send_wrapper) + except Exception: + # 未产出响应就异常(外层 500):补一条全量错误日志后原样抛出 + if not logged: + _log_access(scope, 500, start) + raise + + +app.add_middleware(AccessLogMiddleware) @app.get("/", summary="根路径")