跳到主要内容
版本:1.5.0

访问日志与请求关联

AISIX AI 网关会写入结构化访问日志,并记录可将请求与调用方、前置基础设施和上游模型服务提供方关联起来的标识符。借助这些记录,运维人员可以还原请求过程,并在各个系统中找到对应的条目。

收集访问日志​

AISIX 通过进程日志记录器将访问日志写入标准错误流。容器运行时、服务管理器或主机日志流水线可以收集该数据流。

在启动配置中设置进程日志级别:

config.yaml
observability:
log_level: "info"

当 RUST_LOG 环境变量设置为有效过滤器时,它会覆盖已配置的日志级别。

备注

access_log 字段为保留字段,目前不起作用。访问日志没有单独的格式或接收端配置;请收集进程的标准错误流。

在相应值可用时,访问日志会包含请求方法、路径、状态、耗时、模型服务提供方、模型、API Key ID、请求 ID、Token 数量、路由结果、响应缓存的判定结果,以及请求体和响应体的大小。

对于失败的请求,error_kind 提供稳定的失败类别,error 则在可用时提供底层原因。

MCP 访问日志还会添加 JSON-RPC 方法、调用的工具和工具发现计数。诊断工具发现和访问问题时如何使用这些字段,请参见 MCP 可观测性。

消化消费缓慢的日志接收端​

AISIX 不在产生日志行的线程上写出日志。访问日志和应用日志都先进入一个容量为 32,768 行的内存队列,再由一个专用的写入线程排空到标准错误流。因此,当接收端停止读取(容器运行时轮转日志文件是最常见的情形)时,被阻塞在管道缓冲区上的是那个写入线程,而不是请求处理。

如果阻塞持续到队列被填满,AISIX 会丢弃新产生的日志行,而不是让请求为它们等待。每次丢弃都会增加 aisix_log_lines_dropped_total;接收端恢复消费后,网关会记录一条 log sink fell behind; dropped log events 警告,说明总共丢失了多少行。该计数器在每次抓取时都会发出,因此健康的网关报告 0。

该行为没有任何配置项,队列容量是固定的。丢弃计数非零是排查日志采集链路的信号,而不是网关本身的问题。优雅关闭时,网关最多等待五秒让队列排空,因此只要接收端本身没有卡住,受控停止过程的最后几行日志都会送达。

解读两个耗时字段​

每条日志都携带两个耗时字段,它们回答的是不同的问题:

字段度量内容
latency_ms调用方等待的时间。它在响应头写出时结束;对于流式响应,即首个 Token 或转发帧到达的时刻。
duration_ms请求占用网关的时长,从收到请求直到请求结束。

latency_ms 永远不会大于 duration_ms;对于非流式响应,响应头之后不再有内容,两者相等。二者之差就是整个流的长度,因此请用 latency_ms 衡量调用方体验,用 duration_ms 衡量连接被占用的时长。

部分路由按设计采用不同口径:

  • 在 /a2a 和音频转录中继上,latency_ms 本身就覆盖整个流,这也是用量事件中作为调用方等待时间上报的数值。因此它与 duration_ms 相等,而不是更短。
  • /v1/audio/speech 在上游应答后才把生成的音频转发给调用方,它的 duration_ms 覆盖整个转发过程,直到最后一个字节。1.4.0 及更早版本的网关则在响应头处结束该时长。
  • 在 /v1/videos/{id}/content 上,由网关从模型服务提供方代理下载的视频,其 duration_ms 同样覆盖整个转发过程;重定向到模型服务提供方自身 URL 或返回错误时,duration_ms 在网关生成响应时结束。1.4.0 及更早版本的网关对所有 /v1/videos/{id}/content 请求都在响应头处结束该时长。

解读请求体与响应体大小​

访问日志会记录每个方向上经过网关的消息体字节数。两个字段都是无符号字节数,1.4.0 及更早版本的网关不会写出它们:

字段度量内容
request_body_bytes网关从调用方读取的请求体字节数。网关不会解压请求体,因此这是线上传输的大小。
response_body_bytes网关交给其 HTTP 服务器、发往调用方的响应体字节数,包括 data:、event: 行和 [DONE] 等 SSE 帧格式,以及保活心跳帧。响应头、分块传输编码的帧格式和 TLS 不计入。

大小未知时,该字段会从日志中省略,而不是写成 0,因为 0 是一个真实的大小。

只有当网关把请求体读到末尾时,request_body_bytes 才会出现。这包括读完请求体后才被拒绝的请求(例如 JSON 格式错误),以及调用方离开前请求体已被读取的 499 日志。以下情况会省略该字段:

  • 网关根据 Content-Length 在读取请求体之前就拒绝了请求,即 proxy.request_body_limit_bytes 返回的 413;
  • 路由从不读取请求体,例如大多数 GET 请求,以及调用未知智能体的 /a2a 请求;
  • 调用方在上传之前或上传过程中断开连接;
  • 请求打开的是 /v1/realtime 会话。

只有两种情况会省略 response_body_bytes:调用方在响应头写出前离开时的 499 日志,以及 /v1/realtime,因为其 WebSocket 会话没有 HTTP 响应体。服务器从未读取响应体的响应(例如对 HEAD 请求的应答)报告 0。调用方在响应中途断开时,该字段统计截至当时已交给服务器的字节数,可能超过调用方实际收到的字节数。

识别实际处理请求的目标​

网关选定目标后,日志会在 model 旁携带 upstream_model 和 provider_key_id。model 的含义不变——调用方寻址的条目,对于路由请求即模型组名称——而新增的这一对字段标识实际下发到的目标以及所使用的 Provider Key。如果没有选定目标,例如请求在下发前被拒绝,或在路由解析完成前被放弃,这两个字段会从日志中省略。

由响应缓存返回的响应同样没有下发到任何目标,此时这对字段上报什么取决于调用方寻址的条目是哪种类型。参见解读缓存判定结果。

解读缓存判定结果​

在 /v1/chat/completions 上,日志会上报响应缓存如何处理了该请求:

字段取值
cache_statusdisabled、miss、hit 或 bypass
cache_hit_layerexact 或 semantic,仅在命中时出现

这两个字段的拼写与用量事件完全一致,因此同一 request_id 的访问日志和用量事件读起来是一致的。凡是没有缓存判定可上报的日志都会省略它们:不做缓存的其他路由,以及在请求产生响应之前就写出的日志。流式请求和被取消请求的日志则从该请求的最终用量事件中取这两个值,因此两者不会出现分歧;由于流式响应从不被缓存,即使环境中启用了缓存策略,这类日志也会上报 cache_status="disabled"。

缓存命中不会联系任何上游,因此其日志中与目标相关的字段只上报在没有下发的情况下该条目仍能声明的内容:

缓存命中时的字段直连模型模型组(routing 或 semantic)
upstream_model、provider_key_id该条目自身的静态映射。它们是该模型的属性,无论请求是否真的离开过网关都成立——并不代表本次请求到达了模型服务提供方省略。模型组没有自己的映射,而哪个目标产出了所存响应也没有被记录在任何地方
provider该条目自身的模型服务提供方unknown。与上面那对字段不同,它保留这个哨兵值而不是省略,因为它与 Prometheus 的 provider 标签是同一个字符串,而标签不能缺省
served_by_model、provider_request_id省略省略

要把缓存返回的响应与从未到达模型服务提供方的请求区分开,靠的是 cache_status,仅凭目标字段缺失无法判断。被输出安全护栏拦下的缓存命中同样遵守上述全部规则,并且仍然上报 cache_status="hit",即使这条日志最终是 422。

1.2.0 及更早版本的网关完全不写缓存相关字段,并且会把模型组的缓存命中记在该请求的路由策略恰好排在首位的那个目标名下。

该请求的用量事件会上报相同的判定结果,并补充所存响应自身记录的信息,参见用量日志记录了什么。

了解日志写入时机和覆盖范围​

无论结果如何,AISIX 对每个请求只写一条访问日志。写入时机决定了这条日志能够携带哪些信息:

信号写入时机提供的信息
非流式请求的访问日志响应体已全部交给服务器,或因调用方离开而被丢弃时请求结果及网关解析出的所有字段,包括可用时的 Token 数量和模型服务提供方响应 ID。
流式请求的访问日志流结束时最终结果,以及只有在上游应答后才存在的字段:Token 数量、provider_request_id、served_by_model 和路由计数。它上报的 status、error_kind 和 error 与该请求的最终用量事件一致。
Realtime 会话的访问日志WebSocket 会话关闭后会话结果、已解析的请求字段,以及该会话的 Token 总数。
被取消请求的访问日志调用方在响应头写出前断开时状态 499,以及请求此时已解析出的各项标识,包括已下发的目标。Token 数量、provider_request_id 和路由计数保持为空,因为请求从未产生这些值。
provider call completed 日志每个返回 ID 的模型服务提供方调用各写入一次该上游尝试的 request_id、attempt_index、attempt_kind 和 provider_request_id。
用量事件支持的代理路径中,每次请求尝试写入一次尝试结果、用量、延迟,以及可用时的模型服务提供方响应 ID。

流式请求过去在响应打开时写出日志,因此调用方随后放弃的流会被记为 200,而且日志中没有 Token 数量。现在这两点都由流结束时的单条日志解决。1.2.0 及更早版本的网关仍在响应头处写出该日志。

凡是有响应体的请求,其日志都在响应体处理完毕后才写出,因为只有到那时两个消息体大小才最终确定。日志的内容不变,每个请求仍只有一条日志:流式请求的日志仍从该请求的最终用量事件中取得状态、错误和 Token 数量。1.4.0 及更早版本的网关会在非流式请求的响应就绪时、响应体发送之前就写出日志。所有日志都在最后写出,会带来两个可见的影响:

  • 访问日志排在该请求的 provider call completed 日志之后。1.4.0 及更早版本的网关可能先写出访问日志。
  • 如果部署平台在慢速调用方仍在读取响应体时终止进程(例如 terminationGracePeriodSeconds 耗尽),该请求的日志将不会写出。流式响应此前就存在这种情况;非流式响应现在也是如此,1.4.0 及更早版本的网关除外。如何设置该期限,请参见关闭与排空。

追踪模型服务提供方调用尝试​

provider_request_id 是模型服务提供方返回的响应对象 ID,例如 OpenAI 的 chat.completion.id、Anthropic 消息 id 或 Responses API 的 resp_…。可以用它在模型服务提供方的控制台或支持记录中查找对应调用。

没有可用 ID 时,该字段会被省略而不是留空,包括安全护栏拦截、缓存命中、在下发前被拒绝的请求,以及经过规范化的嵌入、音频、图像和 Token 计数响应。流式响应同样携带该字段,因为 ID 随首帧到达,而日志在流结束时写出——除非调用方在该帧到达前就已离开。

访问日志上报的是实际处理该请求的那次尝试的 ID。要查看发生重试或故障转移的请求的其他尝试,请阅读 provider call completed 条目:通过 request_id 将其与访问日志关联,并使用 attempt_index 区分重试与故障转移。

重试或故障转移过程中失败的上游尝试还会写入一条 WARN 日志,消息为 routing target attempt failed。该日志行把 request_id 作为独立字段携带,与 target_model、target_attempt、error 和 retryable 并列,因此在任何日志级别下都能与请求关联,包括 log_level: "warn":此时不会写入在其他日志行前加上请求 ID 的 info 级请求 span。

跨系统关联请求​

x-aisix-request-id 响应头是关联请求记录的主要键。其他受支持的响应头会报告缓存结果、重试时间和所选目标;其路由覆盖范围请参阅响应头和错误码。

一个请求可能涉及三类标识符,彼此不能替代:

标识符分配方用途
request_idAISIX;如果 AISIX 接受调用方提供的值,则由调用方分配。以 x-aisix-request-id 返回。查找请求的访问日志和用量事件,包括导出的记录以及控制台 Logs 页面中的条目。
downstream_request_id前置基础设施通过 x-request-id 请求头分配。记录在网关日志中,但不会作为独立的下游 ID 返回。如果 AISIX 接受该值,则以 x-aisix-request-id 返回。在 Ingress Controller、反向代理、服务网格或 CDN 中查找同一个 HTTP 请求。
provider_request_id模型服务提供方;响应中包含 ID 的每次上游尝试各有一个。在模型服务提供方控制台中查找该次尝试,或向其支持团队提供该 ID。

调查已完成的响应时:

  1. 从返回给调用方的 x-aisix-request-id 值开始。
  2. 通过 request_id 查找对应的访问日志和用量事件。使用 attempt_index 对重试或故障转移排序。
  3. 需要与模型服务提供方一起调查调用时,从相关尝试中读取 provider_request_id。

如果连接在响应头发送前断开,请从前置基础设施提供的 downstream_request_id 开始调查。

匹配前置基础设施​

AISIX 会分别记录网络连接、转发请求和解析出的调用方地址:

值标识对象匹配对象
peer已接受 TCP 连接的远端,包括其源端口。前置代理的连接记录。AISIX 使用主机网络并位于四层负载均衡器后方时最有用。
downstream_request_id从 x-request-id 接收的 HTTP 请求 ID。前置代理或 Ingress Controller 的请求日志。
解析出的调用方地址通过 proxy.real_ip 选择的不带端口的调用方 IP。访问控制决策和用量记录。

如果存在,peer 和 downstream_request_id 会贯穿请求的访问日志、provider call completed 条目和中间诊断日志。缺失的值会被省略,而不是以空字段记录。

AISIX 会先检查传入的 x-request-id,再将其写入日志。记录该值并不会让它成为网关的 request_id;是否接受该值由 proxy.request_id.accept_headers 单独控制。

诊断未完成或被拒绝的请求​

访问日志和相关信号可用于区分请求停止的位置:

场景AISIX 记录附加信号
调用方在响应头发送前断开状态为 499、error_kind="client_disconnected" 且 error="client closed the request before the response head was written" 的访问日志。如果模型、模型服务提供方和已下发的目标已经解析,则日志会包含这些信息,但不含 Token 字段。一条状态、类别和消息均相同的用量事件,Token 数量和成本均为零。aisix_proxy_client_cancelled_requests_total 对该请求计数。
调用方在响应头写出后、尚未读取流内容前断开同样的 499 日志,error="client closed the request before the response body was streamed"。一条取值相同、已投递 Token 为零的用量事件。由于上游已经应答,该事件会标明处理它的目标。该场景同样会被取消计数器统计。
调用方在流式响应期间断开在流结束时写出的 499 日志,error="client closed the request while the response was streaming"。一条状态、类别和消息均相同的用量事件,携带断开前已到达的 Token。该场景不会增加取消计数器,因为该计数器只记录请求级守卫自己观测到的情况。
上游在流式响应过程中失败在流结束时写入一行,状态为该失败的状态,例如连接断开为 502、读取超时为 504,并以 error_kind 和 error 记录该失败。调用方收到的是 200。一条状态、类别和消息都相同的用量事件。参见响应头发出后失败的流。
超大请求正文被完全排空info 级别的 aisix::body_limit 条目,其中 drain_outcome="completed"。调用方可以收到 413 Content Too Large。aisix_proxy_request_body_limit_rejections_total 对该拒绝计数。
超大正文无法完全排空诊断结果为 cap_reached、timeout 或 client_read_error,调用方通常会看到连接关闭。这些 warn 条目按每种结果每秒最多一条进行限制。拒绝指标会对每次发生计数,包括日志限流器抑制的诊断。

正文限制诊断条目还包含 request_id、declared_content_length、configured_limit_bytes 和 drained_bytes。使用 request_id 将其与访问日志关联。

如果调用方在模型解析前断开,访问日志既不包含模型,也不包含模型服务提供方。当调用方寻址的条目是模型组时,其用量事件的 model_id 为空,因为模型组自身的名称永远不会写入该字段;直连模型则会记录自己的标识符。

只有通过认证的请求在被取消时才会被记录。在下发前被拒绝的请求——认证失败、请求正文无法解析、正文超过大小限制——只产生访问日志和指标,不产生用量事件。完整边界请参阅用量日志记录了什么。

复用自己的请求 ID​

如果服务已经为业务调用生成请求 ID,请将其发送给 AISIX。被接受的值随后会出现在响应头、访问日志、每个用量事件、AISIX Cloud 请求日志以及发送到上游的 x-aisix-request-id 请求头中。

# AISIX_PROXY 是网关 Origin;不要包含末尾斜杠和端点路径
# 本地快速入门使用 http://127.0.0.1:3000
export AISIX_PROXY="YOUR_AISIX_GATEWAY_URL"
export AISIX_API_KEY="YOUR_CALLER_API_KEY"
export MODEL_ALIAS="YOUR_MODEL_ALIAS"

curl -i "$AISIX_PROXY/v1/chat/completions" \
-H "Authorization: Bearer $AISIX_API_KEY" \
-H "Content-Type: application/json" \
-H "x-aisix-request-id: req_abc123-orders-svc" \
-d '{
"model": "'"$MODEL_ALIAS"'",
"messages": [
{
"role": "user",
"content": "Hello"
}
]
}'

响应会回显相同的值:

HTTP/1.1 200 OK
x-aisix-request-id: req_abc123-orders-svc

重试和故障转移会在每个用量事件中复用已接受的 ID,因此按该值筛选可以返回完整的尝试链。

可接受的值​

AISIX 按以下方式处理调用方提供的值:

提供的值结果
长度为 1–256 字节,且仅包含可见 ASCII 字符(! 到 ~)AISIX 接受该值。UUID、ULID、req_abc123 等带前缀的 ID,以及 nginx $request_id 生成的十六进制 ID 都符合要求。
空值、超长值、非 ASCII 值、包含空格或控制字符的值AISIX 忽略该值,生成 UUID,并继续处理请求。
在不同请求中重复使用的值AISIX 会接受该值,因为它不强制唯一性,但这些请求在日志和事件轨迹中将无法区分。

请为每个请求生成新的 ID。

选择接受的请求头​

默认情况下,AISIX 只从 x-aisix-request-id 接受调用方提供的 ID。以下配置还会接受基础设施分配的 x-request-id,并保留默认请求头作为后备:

config.yaml
proxy:
request_id:
# 默认:只接受 AISIX 请求 ID 请求头。
# accept_headers: ["x-aisix-request-id"]

# 请求头按从左到右的顺序检查;采用第一个可接受的值。
accept_headers: ["x-request-id", "x-aisix-request-id"]

# 要忽略调用方提供的所有 ID 并始终生成 UUID,请使用:
# accept_headers: []

当 AISIX 是请求的第一跳,或者需要让反向代理或 Ingress Controller 分配的 ID 在所有位置成为请求标识时,请使用此选项。无论该设置如何,AISIX 都会将可接受的 x-request-id 记录为 downstream_request_id;如果同时接受该值,request_id 和 downstream_request_id 将完全相同。

如果使用环境变量配置 AISIX,请将优先级列表设置为逗号分隔的 AISIX_PROXY__REQUEST_ID__ACCEPT_HEADERS 值。

只能使用有效且非保留的 HTTP 请求头名称。如果列表包含格式错误或保留的请求头(包括携带凭证的请求头、host、cookie、traceparent 和 tracestate),启动会失败。AISIX 会阻止这些请求头,因为接受的值会被记录、返回给调用方并发送到上游。

后续步骤​

使用指标与用量事件监控聚合流量,并比较请求级指标与每次尝试的用量事件。配置可观测性导出器,将用量事件发送到外部目标。