Customize Envoy Access Log Fields for Structured Observability - Alibaba Cloud Service Mesh - Alibaba Cloud - Alibaba Cloud Service Mesh

Prerequisites

Step 1: Enable access logging

For ASM instances earlier than 1.17.2.35

Log on to the ASM console. In the left-side navigation pane, choose Service Mesh > Mesh Management.
On the Mesh Management page, click the name of the ASM instance. In the left-side navigation pane, choose ASM Instance > Base Information.
In the upper-right corner of the Basic Information page, click Settings.

In the Settings Update panel, select Enable access logging and print it to container stdout and click OK.

The istio-proxy container outputs logs that contain the following fields by default. If you disable access logging, the istio-proxy container does not generate access logs in JSON format.

Default log fields


    "authority_for":"%REQ(:AUTHORITY)%",
    "bytes_received":"%BYTES_RECEIVED%",
    "bytes_sent":"%BYTES_SENT%",
    "downstream_local_address":"%DOWNSTREAM_LOCAL_ADDRESS%",
    "downstream_remote_address":"%DOWNSTREAM_REMOTE_ADDRESS%",
    "duration":"%DURATION%",
    "istio_policy_status":"%DYNAMIC_METADATA(istio.mixer:status)%",
    "method":"%REQ(:METHOD)%",
    "path":"%REQ(X-ENVOY-ORIGINAL-PATH?:PATH)%",
    "protocol":"%PROTOCOL%",
    "request_id":"%REQ(X-REQUEST-ID)%",
    "requested_server_name":"%REQUESTED_SERVER_NAME%",
    "response_code":"%RESPONSE_CODE%",
    "response_flags":"%RESPONSE_FLAGS%",
    "route_name":"%ROUTE_NAME%",
    "start_time":"%START_TIME%",
    "trace_id":"%REQ(X-B3-TRACEID)%",
    "upstream_cluster":"%UPSTREAM_CLUSTER%",
    "upstream_host":"%UPSTREAM_HOST%",
    "upstream_local_address":"%UPSTREAM_LOCAL_ADDRESS%",
    "upstream_service_time":"%RESP(X-ENVOY-UPSTREAM-SERVICE-TIME)%",
    "upstream_transport_failure_reason":"%UPSTREAM_TRANSPORT_FAILURE_REASON%",
    "user_agent":"%REQ(USER-AGENT)%",
    "x_forwarded_for":"%REQ(X-FORWARDED-FOR)%"

For ASM instances 1.17.2.35 and later

Log on to the ASM console. In the left-side navigation pane, choose Service Mesh > Mesh Management.
On the Mesh Management page, click the name of the ASM instance. In the left-side navigation pane, choose Observability Management Center > Observability Settings.
On the Observability Settings page, click the Global, Namespace, or Custom tab based on your requirements.
- If you click the Namespace tab, click Create and select a Namespace as required.
- If you click the Custom tab, click Create, select a Namespace, and enter a Name and Match Label as required.
In the Log Settings section, turn on the Enable Log Output switch and click Submit.

After you turn on the switch, the sidecars or gateways on the service mesh data plane will output access logs to standard output. ASM also supports log filtering. For more information, see Filter logs.

View logs in the stdout of the data plane sidecar container.

The following examples show how to view access logs by using kubectl.

Run the following command to view sidecar logs:

kubectl logs httpbin-5c5944c58c-w**** -c istio-proxy --tail 1

Sample output

{
    "authority_for":"47.110.XX.XXX",
    "bytes_received":"0",
    "bytes_sent":"22382",
    "downstream_local_address":"192.168.0.29:80",
    "downstream_remote_address":"221.220.XXX.XXX:0",
    "duration":"80",
    "istio_policy_status":"-",
    "method":"GET",
    "path":"/static/favicon.ico",
    "protocol":"HTTP/1.1",
    "request_id":"0f2cf829-3da5-4810-a618-08d9745d****",
    "requested_server_name":"outbound_.8000_._.httpbin.default.svc.cluster.local",
    "response_code":"200",
    "response_flags":"-",
    "route_name":"default",
    "start_time":"2023-06-30T04:00:36.841Z",
    "trace_id":"-",
    "upstream_cluster":"inbound|80||",
    "upstream_host":"192.168.0.29:80",
    "upstream_local_address":"127.0.X.X:55879",
    "upstream_response_time":"79",
    "upstream_service_time":"79",
    "upstream_transport_failure_reason":"-",
    "user_agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.X.X Safari/537.36",
    "x_forwarded_for":"221.220.XXX.XXX"
}

Run the following command to view ingress gateway logs:

kubectl -n istio-system logs istio-ingressgateway-6cff9b6b58-r**** --tail 1

Sample output

{
    "authority_for":"47.110.XX.XXX",
    "bytes_received":"0",
    "bytes_sent":"22382",
    "downstream_local_address":"192.168.0.63:80",
    "downstream_remote_address":"221.220.XXX.XXX:64284",
    "duration":"81",
    "istio_policy_status":"-",
    "method":"GET",
    "path":"/static/favicon.ico",
    "protocol":"HTTP/1.1",
    "request_id":"0f2cf829-3da5-4810-a618-08d9745d****",
    "requested_server_name":"-",
    "response_code":"200",
    "response_flags":"-",
    "route_name":"httpbin",
    "start_time":"2023-06-30T04:00:36.841Z",
    "trace_id":"-",
    "upstream_cluster":"outbound|8000||httpbin.default.svc.cluster.local",
    "upstream_host":"192.168.0.29:80",
    "upstream_local_address":"192.168.0.63:36140",
    "upstream_response_time":"81",
    "upstream_service_time":"81",
    "upstream_transport_failure_reason":"-",
    "user_agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.X.X Safari/537.36",
    "x_forwarded_for":"221.220.XXX.XXX"
}

(Optional) View access logs in the Container Service for Kubernetes console.

If you use an Alibaba Cloud Container Service for Kubernetes (ACK) cluster, you can also view access logs in the ACK console.
1. Log on to the ACK console. In the left navigation pane, click Clusters.
2. On the Clusters page, click the name of your cluster. In the left navigation pane, click Workloads > Pods.
3. On the Pods page, click the name of the target pod, and then click the Logs tab at the bottom of the page to view the access logs.

For more information about logs, see Observability Settings and Enable control plane log collection and log-based alerting (New).

Step 2: Customize access log content

For ASM instances earlier than 1.17.2.35

Log on to the ASM console. In the left-side navigation pane, choose Service Mesh > Mesh Management.
On the Mesh Management page, click the name of the ASM instance. In the left-side navigation pane, choose ASM Instance > Base Information.
In the Basic Information section of the Config Info page, click Enable access logging and print it to container stdout next to Update Access Log Format.
In the Update Access Log Format dialog box, add a custom access log format. Set accessLogFormat key to my_custom_key and accessLogFormat value to %REQ(end-user)%, and then click Submit.

This example shows how to obtain the end-user header field from an HTTP request in the Bookinfo sample application. When you customize the access log format, you can select optional fields that are provided by ASM or add custom fields. After you select the fields, access logs are output in the custom format. You do not have to select the following four fields: request_duration (%REQUEST_DURATION%), request_tx_duration (%REQUEST_TX_DURATION%), response_duration (%RESPONSE_DURATION%), and response_tx_duration (%RESPONSE_TX_DURATION%).

For ASM instances 1.17.2.35 and later

Log on to the ASM console. In the left-side navigation pane, choose Service Mesh > Mesh Management.
On the Mesh Management page, click the name of the ASM instance. In the left-side navigation pane, choose Observability Management Center > Observability Settings.
On the Observability Settings page, click the Global, Namespace, or Custom tab based on your requirements.
- If you click the Namespace tab, click Create and select a Namespace as required.
- If you click the Custom tab, click Create, select a Namespace, and enter a Name and Match Label as required.
In the Log Settings section, select fields, modify the information about the target fields, or click the icon next to the log metrics at the bottom to add a log field as required. Then, click Submit.

You can customize the log format only after you turn on the Enable Log Output switch. In the Log Format section, the log fields selected by default are required and cannot be modified. Log fields can retrieve values from request headers, response headers, and Envoy built-in values.

The following example shows how to print the accept-encoding header in a request. Set accessLogFormat key to accept-encoding, Type to Request Properties, and accessLogFormat value to Accept-Encoding. For example, the format expression for the request attribute field authority_for is %REQ(:AUTHORITY)%, the format expression for the response attribute field upstream_response_time is %RESP(X-ENVOY-UPSTREAM-SERVICE-TIME)%, and Envoy built-in properties include fields such as request_duration and response_duration.

Run the following command to view logs from a service mesh data plane component:

kubectl logs httpbin-5c5944c58c-w**** -c istio-proxy --tail 1|grep accept-encoding --color=auto

Sample output

{
    "bytes_received":"0",
    "bytes_sent":"9593",
    "downstream_local_address":"192.168.0.29:80",
    "downstream_remote_address":"69.164.XXX.XX:0",
    "duration":"2",
    "istio_policy_status":"-",
    "method":"GET",
    "path":"/",
    "protocol":"HTTP/1.1",
    "request_id":"29939dc9-62be-4ddf-acf6-32cb098d****",
    "requested_server_name":"outbound_.8000_._.httpbin.default.svc.cluster.local",
    "response_code":"200",
    "response_flags":"-",
    "route_name":"default",
    "start_time":"2023-06-30T04:18:19.734Z",
    "trace_id":"-",
    "upstream_cluster":"inbound|80||",
    "upstream_host":"192.168.0.29:80",
    "upstream_local_address":"127.0.X.X:34723",
    "upstream_service_time":"2",
    "upstream_transport_failure_reason":"-",
    "user_agent":"Mozilla/5.0 zgrab/0.x",
    "x_forwarded_for":"69.164.XXX.XX",
    "authority_for":"47.110.XX.XXX",
    "upstream_response_time":"2",
    "accept-encoding":"gzip"
}

The output shows that the value of the Accept-Encoding header that is added in Step 2 is included in the access log. For more information about logs, see Observability Settings and Enable control plane log collection and log-based alerting (New).

Step 3: View access logs

After you enable access logging, the requesting sidecar container outputs access logs in the specified custom format.

In the address bar of your browser, enter <Ingress gateway address>/productpage to access the productpage application.
Log on to the ACK console. In the left navigation pane, click Clusters.
On the Clusters page, click the name of your cluster. In the left navigation pane, click Workloads > Deployments.
At the top of the Deployments page, set Namespace to default. Then, find the productpage-v1 application and click Details in the Actions column.

On the application details page, click the Logs tab and set Container to istio-proxy.

The log output pane displays the following entry. The presence of the my_custom_key field with the value jason indicates that you successfully configured the custom log content.

{"method":"GET","x_forwarded_for":null,"upstream_host":"172.19.16.90:9080","protocol":"HTTP/1.1","my_custom_key":"jason","authority_for":"addedvalues:9080","response_code":200,"start_time":"2021-10-21T11:40:12.0552","request_id":"5222b7fb-05a6-4fae-8e13-xxx","bytes_sent":883,"downstream_remote_address":"172.19.16.11:33752","upstream_transport_failure_reason":null,"downstream_local_address":"192.168.237.140:9080","requested_server_name":null,"response_flags":"-","duration":4,"user_agent":"python-requests/2.18.4","route_name":"default","trace_id":null,"istio_policy_status":null,"path":"/addedvalues/0","upstream_cluster":"outbound|9080||addedvalues.default.svc.cluster.local","bytes_received":0,"upstream_service_time":"3","authority":"addedvalues:9080","upstream_local_address":"172.19.16.11:52430"}

Access log fields

In Service Mesh ASM, "upstream" refers to the receiver of a request in a call chain, and "downstream" refers to the initiator of the request. For example, when Service A sends a request to Service B, Service A is the "downstream", and Service B is the "upstream".

Parameter	Value	Description
authority_for	%REQ(:AUTHORITY)%	The destination hostname in the request. For an HTTP/1.1 request, this corresponds to the value of the `Host` request header. For an HTTP/2 request, this corresponds to the value of the `:authority` request header.
bytes_received	%BYTES_RECEIVED%	HTTP: The number of bytes in the request body. TCP: The number of bytes received from the downstream connection.
bytes_sent	%BYTES_SENT%	HTTP: The number of bytes sent in the request body. For a WebSocket connection, this value includes the length of the response header. TCP: The number of bytes sent to the downstream connection.
downstream_local_address	%DOWNSTREAM_LOCAL_ADDRESS%	The destination address and port of the downstream connection. This can be considered the original destination address of the downstream connection.
downstream_remote_address	%DOWNSTREAM_REMOTE_ADDRESS%	The client address and port of the downstream connection.
method	%REQ(:METHOD)%	The request method. This field is valid only for HTTP requests.
path	%REQ(X-ENVOY-ORIGINAL-PATH?:PATH)%	The request path.
protocol	%PROTOCOL%	The request protocol.
request_id	%REQ(X-REQUEST-ID)%	The unique ID of the request.
requested_server_name	%REQUESTED_SERVER_NAME%	The server name specified in the SSL connection (Server Name Indication).
response_code	%RESPONSE_CODE%	The HTTP response status code.
response_flags	%RESPONSE_FLAGS%	Additional information about the response or connection. For more information about the values and their meanings, see response_flag reference.
route_name	%ROUTE_NAME%	The name of the matched route. This is consistent with the route name defined in the virtual service. An empty value (-) indicates that no route matched.
start_time	%START_TIME%	The time when request processing began, with millisecond precision.
trace_id	%TRACE_ID%	The trace ID for tracing.
upstream_cluster	%UPSTREAM_CLUSTER%	The upstream destination service and subset.
upstream_host	%UPSTREAM_HOST%	The upstream destination host, usually the Pod IP address and port.
upstream_local_address	%UPSTREAM_LOCAL_ADDRESS%	The local address used to establish a connection with the upstream service.
duration	%DURATION%	For an HTTP request, this field indicates the total time elapsed from when the request starts to be read until the last byte of the response is sent to the downstream service. This is the total time a sidecar or gateway takes to process a request. For a TCP request, this field indicates the total duration of the downstream connection.
request_duration	%REQUEST_DURATION%	For an HTTP request, this field indicates the time taken to read the entire request (headers and body) from the downstream service. If this duration is long, investigate the following: Whether the network quality is good and the bandwidth is sufficient. Whether the upstream or downstream application has a bottleneck under a similar I/O load. For a TCP request, this field is not implemented and is displayed as - in the log.
request_tx_duration	%REQUEST_TX_DURATION%	For an HTTP request, this field indicates the time elapsed from when the request starts until its last byte is sent to the upstream service. If this duration is long, investigate the following: Whether the network quality is good and the bandwidth is sufficient. Whether the upstream or downstream application has a bottleneck under a similar I/O load. For a TCP request, this field is not implemented and is displayed as - in the log.
response_duration	%RESPONSE_DURATION%	For an HTTP request, this field indicates the time elapsed from when the request starts until the first byte of the response is read from the upstream service. If this duration is long and request_tx_duration is short, investigate whether the upstream application has a performance bottleneck. For a TCP request, this field is not implemented and is displayed as - in the log.
response_tx_duration	%RESPONSE_TX_DURATION%	For an HTTP request, this field indicates the time elapsed from when the first byte of the response from the upstream service is read until the last byte is sent to the downstream service. If this duration is long, investigate the following: Whether the network quality is good and the bandwidth is sufficient. Whether the upstream or downstream application has a bottleneck under a similar I/O load. For a TCP request, this field is not implemented and is displayed as - in the log.
upstream_service_time (sidecar)	%RESP(X-ENVOY-UPSTREAM-SERVICE-TIME)%	In the access logs of a sidecar or gateway, this field indicates the processing time of the upstream service and the time taken for network communication with the upstream service. If this duration is long, investigate whether: The processing performance of the upstream application meets expectations. The network latency and bandwidth for communication with the upstream service meet expectations.
upstream_response_time (gateway)	%RESP(X-ENVOY-UPSTREAM-SERVICE-TIME)%

Note

For HTTP requests with a body (Content-Length > 0), Envoy streams the request to the upstream service as it receives it, rather than waiting for the entire request to arrive before forwarding. Therefore, a slow downstream client can increase the total request time for all services in the upstream call chain.

Response flag values

The response_flag field in the access log provides additional information about the request or connection. The following table describes the different response_flag values.

Value	Description
UH	Envoy could not find a healthy upstream host. This is usually because no available endpoint exists for the destination service.
UF	Failed to connect to the upstream host. This is usually because the upstream application is not listening or the port is incorrectly configured.
UO	Upstream overflow (circuit breaking).
NR	Envoy did not find a route for the request.
NC	Envoy could not find the destination service. This usually means that the hostname or subset name in the configured routing rule is incorrect.
URX	The request was rate-limited.
DC	The downstream client disconnected.
UR	The upstream service reset the connection.
UAEX	An external authorization service rejected the request. This means that the ASM proxy rejected the request based on the response from the external authorization service.
DPE	Downstream protocol error. This indicates that the request sent by the downstream application uses an unexpected protocol. Check whether the port names of the services in your cluster are prefixed with the correct protocol, such as `http-80`, `http`, or `grpc`.
UPE	Upstream protocol error. This indicates that the ASM proxy attempted to forward a request to the upstream service by using an unexpected protocol. Check whether the port names of the services in your cluster are prefixed with the correct protocol, such as `http-80`, `http`, or `grpc`.

Related operations

You can also use Log Service (SLS) to collect data plane access logs. For more information, see Generate and collect ASM gateway access logs.