Skip to main content
Version: 1.5.0

Access Logs and Request Correlation

AISIX AI Gateway writes structured access logs and records identifiers that connect requests to callers, fronting infrastructure, and upstream providers. Together, these records let operators reconstruct what happened and find the corresponding entries in each system.

Collect Access Logs​

AISIX writes access logs through the process logger to standard error. Your container runtime, service manager, or host logging pipeline can collect that stream.

Set the process log level in the startup configuration:

config.yaml
observability:
log_level: "info"

When set to a valid filter, the RUST_LOG environment variable overrides the configured log level.

note

The access_log field is reserved and currently has no effect. There is no separate access-log format or sink setting; collect the process's standard error stream.

An access log includes the request method, path, status, timing, provider, model, API key ID, request ID, token counts, routing outcome, the response-cache verdict, and the request and response body sizes when those values are available.

For a failed request, error_kind provides a stable failure category and error provides the underlying reason when available.

MCP access logs add the JSON-RPC method, called tool, and tool-discovery counts. See MCP Observability to use these fields when diagnosing tool discovery and access.

Absorb a Slow Log Consumer​

AISIX does not write log lines from the thread that produced them. Access-log and application-log lines go into an in-memory queue of 32,768 lines, and one dedicated writer thread drains it into standard error. A consumer that stops reading — a container runtime rotating the log file is the routine case — therefore fills a pipe buffer that the writer thread waits on, instead of stalling request handling.

If the stall lasts long enough to fill the queue, AISIX drops new lines rather than making requests wait for them. Each drop increments aisix_log_lines_dropped_total, and once the consumer catches up the gateway logs one log sink fell behind; dropped log events warning naming how many lines were lost. The counter is published on every scrape, so a healthy gateway reports 0.

There is no configuration for this. The queue size is fixed, and a non-zero drop count is a signal to investigate the log collector rather than the gateway. A graceful shutdown waits up to five seconds for the queue to drain, so the final lines of a controlled stop reach the collector unless the collector is itself stuck.

Read the Two Timing Fields​

Every line carries two durations, and they answer different questions:

FieldMeasures
latency_msWhat the caller waited for. It ends when the response head was written, which for a streamed response is the first token or relayed frame.
duration_msHow long the request occupied the gateway, from receipt until the request ended.

latency_ms is never greater than duration_ms, and the two coincide on a buffered response because nothing follows the head. Their difference is the length of the stream, so use latency_ms for the caller's experience and duration_ms for how long a connection was held.

Some route families measure differently by design:

  • On /a2a and the audio transcription relays, latency_ms already covers the whole stream, which is the figure the usage event reports as the caller's wait. It therefore matches duration_ms rather than being shorter than it.
  • /v1/audio/speech relays the generated audio to the caller after the upstream answers, and its duration_ms spans that relay to the last byte. A gateway at 1.4.0 or earlier ends it at the response head.
  • On /v1/videos/{id}/content, a video the gateway proxies from the provider likewise has a duration_ms that spans the relay. A redirect to the provider's own URL, or an error, ends duration_ms when the gateway produces the response. A gateway at 1.4.0 or earlier ends every /v1/videos/{id}/content duration at the response head.

Read the Body Sizes​

The line reports how many body bytes crossed the gateway in each direction. Both fields are unsigned byte counts, and a gateway at 1.4.0 or earlier does not write them:

FieldMeasures
request_body_bytesRequest body bytes the gateway read from the caller. The gateway does not decompress a request body, so this is the size on the wire.
response_body_bytesResponse body bytes the gateway handed to its HTTP server for the caller, including SSE framing such as data: and event: lines and [DONE], and keep-alive heartbeat frames. Headers, chunked transfer framing, and TLS are not counted.

A size that is unknown is omitted from the line rather than written as 0, because 0 is a real size.

request_body_bytes is present only when the gateway read the body to its end. That includes a request refused after its body was read, such as one with malformed JSON, and a 499 line whose body had been read before the caller left. It is omitted when:

  • the gateway refused the request from its Content-Length before reading the body, which is the 413 from proxy.request_body_limit_bytes;
  • the route never reads a body, as on most GET requests and an /a2a call to an unknown agent;
  • the caller disconnected before or during the upload;
  • the request opened a /v1/realtime session.

response_body_bytes is omitted only on the 499 line of a caller that left before the response head was written, and on /v1/realtime, whose WebSocket session has no HTTP response body. A response whose body the server never read, such as the answer to a HEAD request, reports 0. When the caller disconnects mid-response, the field counts what had been handed to the server until then, which can exceed what the caller received.

Identify the Target That Served the Request​

Once the gateway selects a target, the line carries upstream_model and provider_key_id beside model. model keeps its meaning — the entry the caller addressed, which is the group name for a routing request — while the new pair names the target actually dispatched to and the provider key it used. Both are omitted from the line when no target was selected, such as a request refused before dispatch or abandoned before routing resolved.

A response served from the response cache also dispatched to nothing, and what the pair reports then depends on the kind of entry the caller addressed. See Read the Cache Verdict.

Read the Cache Verdict​

On /v1/chat/completions, the line reports how the response cache answered the request:

FieldValues
cache_statusdisabled, miss, hit, or bypass
cache_hit_layerexact or semantic. Present only on a hit

Both fields are spelled as the usage event spells them, so a line and the usage events for the same request_id read the same way. They are omitted on every line that had no cache decision to report: the other routes, which do not cache, and a line written before the request produced a response. A streamed or cancelled line takes both values from the request's terminal usage event, so the two can never disagree; because streaming responses are never cached, such a line reports cache_status="disabled" even where the environment has a cache policy enabled.

A cache hit contacts no upstream, so the target-shaped fields on its line report only what the addressed entry can claim without a dispatch:

Field on a cache hitDirect modelModel Group (routing or semantic)
upstream_model, provider_key_idThe entry's own static mapping. These are properties of the model, true whether or not a request ever left the gateway — not evidence that this request reached a providerOmitted. A group has no mapping of its own, and which of its targets produced the stored response is not recorded anywhere
providerThe entry's own providerunknown. Unlike the pair above, it keeps the sentinel instead of being omitted, because it is the same string the Prometheus provider label carries for the request, and a label cannot be absent
served_by_model, provider_request_idOmittedOmitted

cache_status is what tells a cache-served response apart from a request that never reached a provider; the absence of target fields alone does not. A cache hit that an output guardrail then blocks follows every rule above and still reports cache_status="hit", even though the line ends as a 422.

A gateway at 1.2.0 or earlier writes no cache fields at all, and reported a Model Group's cache hit under whichever target the request's routing strategy happened to rank first.

The request's usage event reports the same verdict and adds what the stored response itself records; see What the Usage Log Records.

Understand Log Timing and Coverage​

AISIX writes exactly one access-log line per request, whatever the outcome. When it is written determines which details the line can carry:

SignalWrittenWhat it provides
Access log for a non-streamed requestWhen the response body has been handed to the server, or dropped because the caller leftThe request outcome and all fields the gateway resolved, including token counts and the provider response ID when available.
Access log for a streamed requestWhen the stream endsThe final outcome and the fields that exist only once the upstream has answered: token counts, provider_request_id, served_by_model, and the routing counts. It reports the same status, error_kind, and error as the request's terminal usage event.
Access log for a Realtime sessionAfter the WebSocket session closesThe session outcome, resolved request fields, and the session's token totals.
Access log for a cancelled requestWhen the caller hangs up before the response headStatus 499 and the identities the request had resolved by then, including the dispatched target. Token counts, provider_request_id, and the routing counts stay empty, because the request never produced them.
provider call completed logOnce for each provider call that returns an IDrequest_id, attempt_index, attempt_kind, and provider_request_id for that upstream attempt.
Usage eventOnce per request attempt on supported proxy pathsAttempt outcome, consumption, latency, and provider response ID when available.

A streamed request used to write its line when the response opened, which reported 200 for a stream the caller later abandoned and omitted the token counts. Both are now resolved on the single end-of-stream line. A gateway at 1.2.0 or earlier still writes that line at the response head.

Every line that has a response body is written once that body is finished with, because only then are both body sizes final. What the line reports does not change, and there is still one line per request: a streamed line still takes its status, error, and token counts from the request's terminal usage event. A gateway at 1.4.0 or earlier writes a non-streamed request's line as soon as the response is ready, before its body is sent. Writing every line at the end has two visible effects:

  • The access-log line comes after the request's provider call completed lines. A gateway at 1.4.0 or earlier can write it before them.
  • If the deployment platform stops the process while a slow caller is still reading a response body, for example when terminationGracePeriodSeconds runs out, that request's line is never written. A streamed response was already exposed to this; a buffered one is too, except on a gateway at 1.4.0 or earlier. See Shutdown and Draining for sizing that limit.

Trace Provider Attempts​

provider_request_id is the response object ID returned by the provider, such as an OpenAI chat.completion.id, an Anthropic message id, or a Responses API resp_…. Use it to find the call in the provider's console or support records.

The field is omitted rather than left blank when no ID is available, including for guardrail blocks, cache hits, requests refused before dispatch, and normalized embeddings, audio, image, and token-counting responses. A streamed response does carry it, because the ID arrives in the first frame and the line is written at the stream's end — unless the caller walked away before that frame.

The access log reports the ID of the attempt that served the request. To see the other attempts of a retried or failed-over request, read the provider call completed entries: join them to the access log by request_id, and use attempt_index to distinguish retries from failovers.

A failed upstream attempt during retries or failover also writes a WARN line with the message routing target attempt failed. The line carries request_id as its own field, beside target_model, target_attempt, error, and retryable, so it joins to the request at every log level. That includes log_level: "warn", where the info-level request span that prefixes other lines with the request ID is not written.

Correlate a Request Across Systems​

The x-aisix-request-id response header is the main join key for request records. Other supported response headers report cache outcomes, retry timing, and selected targets; see Headers and Error Codes for their route coverage.

A request can involve three kinds of identifiers, and none substitutes for another:

IdentifierAssigned byUse it to
request_idAISIX, or the caller when AISIX adopts a supplied value. Returned as x-aisix-request-id.Find the request's access log and usage events, including exported records and entries on the dashboard's Logs page.
downstream_request_idFronting infrastructure through the x-request-id request header. Recorded in gateway logs but not returned as a separate downstream ID. If AISIX adopts the value, it is returned as x-aisix-request-id.Find the same HTTP request in an ingress controller, reverse proxy, service mesh, or CDN.
provider_request_idThe provider, one for each upstream attempt whose response includes an ID.Find the attempt in the provider's console or quote its ID to provider support.

To investigate a completed response:

  1. Start with the x-aisix-request-id value returned to the caller.
  2. Find the matching access log and usage events by request_id. Use attempt_index to order retries or failovers.
  3. Read provider_request_id from the relevant attempt when you need to investigate the call with the provider.

For a disconnect before response headers, start with downstream_request_id from the fronting infrastructure when available.

Match Fronting Infrastructure​

AISIX records separate values for the network connection, forwarded request, and resolved caller address:

ValueIdentifiesMatch it with
peerThe remote end of the accepted TCP connection, including its source port.A fronting proxy's connection record. This is most useful behind a layer-4 load balancer when AISIX uses the host network.
downstream_request_idThe HTTP request ID received in x-request-id.The fronting proxy's or ingress controller's request log.
Resolved caller addressThe caller IP selected through proxy.real_ip, without a port.Access-control decisions and usage records.

When present, peer and downstream_request_id follow the request through its access log, provider call completed entries, and intermediate diagnostic lines. Missing values are omitted rather than logged as empty fields.

AISIX screens an incoming x-request-id before logging it. Recording the value does not make it the gateway's request_id; adopting it is controlled separately by proxy.request_id.accept_headers.

Diagnose Incomplete or Refused Requests​

The access log and related signals distinguish where a request stopped:

ScenarioWhat AISIX recordsAdditional signal
Caller disconnects before response headersAn access log with status 499, error_kind="client_disconnected", and error="client closed the request before the response head was written". It includes the resolved model, provider, and dispatched target when available, but no token fields.A usage event with the same status, class, and message, zero tokens, and zero cost. aisix_proxy_client_cancelled_requests_total counts the request.
Caller disconnects after the response head but before reading any of the streamThe same 499 line, with error="client closed the request before the response body was streamed".A usage event with the same values and zero delivered tokens. Because the upstream had already answered, the event names the target that served it. The cancel counter also records this case.
Caller disconnects during a streamed responseA 499 line written at the point the stream ended, with error="client closed the request while the response was streaming".A usage event with the same status, class, and message, carrying the tokens that arrived before the disconnect. This case does not raise the cancel counter, which records only what the request-level guard observed.
Upstream fails during a streamed responseA line written at the point the stream ended, with the failure's status, such as 502 for a dropped connection or 504 for a read timeout, and the failure as error_kind and error. The caller received a 200.A usage event with the same status, class, and message. See Streams That Fail After the Response Head.
Oversized request body is fully drainedAn aisix::body_limit entry with drain_outcome="completed", logged at info. The caller can receive 413 Content Too Large.aisix_proxy_request_body_limit_rejections_total counts the rejection.
Oversized body cannot be fully drainedThe diagnostic uses cap_reached, timeout, or client_read_error, and the caller usually sees a closed connection. These warn entries are limited to one per outcome per second.The rejection metric counts every occurrence, including diagnostics suppressed by the log limiter.

Body-limit diagnostic entries also carry request_id, declared_content_length, configured_limit_bytes, and drained_bytes. Join them to the access log by request_id.

If the caller disconnects before model resolution, the access log contains neither a model nor a provider. Its usage event carries an empty model_id when the entry the caller addressed was a routing group, because a group's own name is never written there; a direct model records its own identifier.

A cancelled request is recorded only when it authenticated. Requests rejected before dispatch — an authentication failure, a body that could not be parsed, or a body-size rejection — produce an access log and metrics but no usage event. See What the Usage Log Records for the full boundary.

Reuse Your Own Request ID​

If your service already generates a request ID for the business call, send it to AISIX. The adopted value then appears in the response header, access log, every usage event, AISIX Cloud Request Logs, and the x-aisix-request-id header sent upstream.

# AISIX_PROXY is the gateway origin; omit a trailing slash and endpoint path
# The local quickstarts use 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"
}
]
}'

The response echoes the same value:

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

Retries and failovers reuse the adopted ID on every usage event, so filtering by that value returns the complete attempt chain.

Accepted Values​

AISIX handles supplied values as follows:

Supplied valueResult
1–256 bytes containing only visible ASCII characters (! through ~)AISIX adopts the value. UUIDs, ULIDs, prefixed IDs such as req_abc123, and the hexadecimal nginx $request_id all qualify.
Empty, oversized, non-ASCII, space-containing, or control-character valueAISIX ignores the value, generates a UUID, and continues the request.
A value reused for separate requestsAISIX accepts it because uniqueness is not enforced, but the requests become indistinguishable in logs and event trails.

Generate a fresh ID for each request.

Choose the Accepted Headers​

By default, AISIX adopts a caller-supplied ID only from x-aisix-request-id. The following configuration also accepts an infrastructure-assigned x-request-id, while keeping the default header as a fallback:

config.yaml
proxy:
request_id:
# Default: accept only the AISIX request ID header.
# accept_headers: ["x-aisix-request-id"]

# Headers are checked from left to right; the first acceptable value wins.
accept_headers: ["x-request-id", "x-aisix-request-id"]

# To ignore all caller-supplied IDs and always generate a UUID, use:
# accept_headers: []

Use this option when AISIX is the first hop or when the ID assigned by a reverse proxy or ingress controller should become the request's identity everywhere. AISIX records an acceptable x-request-id as downstream_request_id regardless of this setting; when it also adopts that value, request_id and downstream_request_id are identical.

If you configure AISIX with environment variables, set the priority list as a comma-separated AISIX_PROXY__REQUEST_ID__ACCEPT_HEADERS value.

Use only valid, non-reserved HTTP header names. Startup fails if the list contains a malformed name or a reserved header, including credential-bearing headers, host, cookie, traceparent, and tracestate. AISIX blocks these headers because an adopted value is logged, returned to the caller, and sent upstream.

Next Steps​

Use Metrics and Usage Events to monitor aggregate traffic and compare request-level metrics with per-attempt usage events. Configure Observability Exporters to send usage events to an external destination.