Istio Sidecar Proxy Access Log
1. Istio Sidecar Proxy Access Log
This document examines the Sidecar Proxy Access Logs in various cases within an Istio environment.
1.1. Test Environment Setup
![[Figure 1] Test Environment](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/test-environment.png)
[Figure 1] Test Environment
[Figure 1] shows the Istio Sidecar Proxy Access Log test environment. It consists of 2 Worker Nodes, each containing a shell Pod acting as a Client and a mock-server Pod acting as a Server. The shell Pod accesses the mock-server Pod through the configured Service, Destination Rule, and Virtual Service. For HTTP Protocol access, the curl command is used inside the shell Pod, and for gRPC Protocol access, the grpcurl command is used inside the shell Pod.
1.1.1. Kubernetes, Istio Environment Setup
# Create kubernetes cluster with kind
$ kind create cluster --config=- <<EOF
kind: Cluster
apiVersion: kind.x-k8s.io/v1alpha4
nodes:
- role: control-plane
- role: worker
- role: worker
EOF
# Install istio
$ istioctl install --set profile=demo -y
# Enable sidecar injection to default namespace
$ kubectl label namespace default istio-injection=enabled[Shell 1] shows the script for setting up the Kubernetes and Istio environment. A Kubernetes Cluster is created using kind, and Istio is installed. Then, Sidecar Injection is enabled for the default Namespace.
| |
[Text 1] shows the Istio Mesh Config for changing the format of Istio Sidecar Proxy Access Log. The default format of Access Log is in plain text format which has poor readability, so the accessLogFormat field is used to change it to JSON format.
1.1.2. Workload Setup
| |
[File 1] shows the Manifest for the mock-server Workload. The mock-server Pod is created using the mock-server Image, opening port 8080 for HTTP service and port 9090 for gRPC service. In the Virtual Service, Timeout is set to 60s, and retry is configured with 2 retries (same as default) for a maximum of 3 request attempts. Also, the retry conditions are configured by adding the 502 Status Code to the 4 default error conditions: connect-failure, refused-stream, unavailable, cancelled.
Circuit Breaking is configured in the Destination Rule for testing. The outlierDetection field defines the criteria for determining abnormal status and is configured with default values. Circuit Breaking activates when 5 consecutive 5xx errors occur at 10-second intervals, with the Circuit Breaking duration set to 30 seconds. The connectionPool field specifies settings to limit the concurrent processing count of HTTP/GRPC requests, configured to allow only one request to be processed at a time.
There are two main methods to limit concurrent processing count: limiting based on maximum TCP Connections and limiting based on maximum concurrent HTTP/GRPC request processing count. The TCP Connection-based method uses the tcp.maxConnections field to limit the maximum number of TCP Connections. In [File 1], tcp.maxConnections is set to 1 to limit the maximum TCP Connections to 1, and http.http1MaxPendingRequests is set to 1 to limit the maximum pending requests to 1 before the TCP Connection becomes Ready.
For GRPC, multiple requests can be processed simultaneously on a single TCP Connection using HTTP/2’s Stream feature. Therefore, http.maxConcurrentStreams is set to 1 to force a maximum of 1 Stream per TCP Connection, easily triggering GRPC request Pending. If http.maxConcurrentStreams is not specified, unlimited Streams can be processed on a single TCP Connection, so GRPC request Pending does not occur.
| |
The method to limit maximum concurrent HTTP/GRPC request processing count uses the http.http2MaxRequests field. In [File 2], http.http2MaxRequests is set to 1 to limit the maximum HTTP/GRPC request processing count to 1. Also, the remaining connectionPool fields are not set to prevent Request from being Pending. The Destination Rule set in [File 1] is used for most Cases, while [File 2]’s Destination Rule is used in some Circuit Breaking Cases.
| Endpoint | Description |
|---|---|
| /status/{code} | Return specific HTTP status code |
| /bytes/{bytes} | Return specified number of bytes |
| /delay/{ms} | Delay response by milliseconds |
| /reset-before-response/{ms} | Server sends TCP RST before response after delay |
| /reset-after-response/{ms} | Server sends dummy data, then TCP RST after delay |
| /close-before-response/{ms} | Server closes connection before response after delay |
| /close-after-response/{ms} | Server sends dummy data, then closes connection after delay |
| Function | Description |
|---|---|
| /mock.MockService/Status | Return specific gRPC status code |
| /mock.MockService/Delay | Delay response by milliseconds |
| /mock.MockService/ResetBeforeResponse | Server sends TCP RST before response after delay |
| /mock.MockService/ResetAfterResponse | Server sends dummy data, then TCP RST after delay |
| /mock.MockService/CloseBeforeResponse | Server closes connection before response after delay |
| /mock.MockService/CloseAfterResponse | Server sends dummy data, then closes connection after delay |
[Table 1] and [Table 2] show the behavior of the mock-server Workload’s HTTP Endpoints and gRPC Functions. The endpoints provided by mock-server are used to reproduce various cases.
| |
| |
| |
[File 3] shows the Manifest for the shell Pod. The shell Pod is created using the netshoot Image, with Network Admin privileges to enable the use of the iptables command. [File 4] shows the Proto file for calling the mock-server gRPC Service using the grpcurl command. [Shell 2] shows an example of copying the Proto file to the shell Pod.
1.2. HTTP Cases
1.2.1. OK Case
![[Figure 2] HTTP OK Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/http-ok-case.png)
[Figure 2] HTTP OK Case
| |
[Figure 2] shows the HTTP OK Case where a GET request is sent to the mock-server’s /status/200 Endpoint using the curl command from the shell Pod, and a 200 OK response is received. [Shell 3] shows an example of executing [Figure 2].
| |
| |
[Text 2] shows the Access Log of the shell Pod’s istio-proxy, and [Text 3] shows the Access Log of the mock-server’s istio-proxy. Both Access Logs confirm the access to the /status/200 Endpoint and the 200 OK response.
1.2.2. Service Unavailable Case
![[Figure 3] HTTP Service Unavailable Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/http-service-unavailable-case.png)
[Figure 3] HTTP Service Unavailable Case
| |
[Figure 3] shows the HTTP Service Unavailable Case where a GET request is sent to the mock-server’s /status/503 Endpoint using the curl command from the shell Pod, and a 503 Service Unavailable response is received. [Shell 4] shows an example of executing [Figure 3].
| |
| |
[Text 4] shows the Access Log of the shell Pod’s istio-proxy, and [Text 5] shows the Access Log of the mock-server’s istio-proxy. Both Access Logs confirm the access to the /status/503 Endpoint and the 503 Service Unavailable response.
1.2.3. Downstream TCP Close Case
![[Figure 4] Downstream TCP Close Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/http-downstream-tcp-close-case.png)
[Figure 4] Downstream TCP Close Case
| |
[Figure 4] shows the Downstream TCP Close Case where a GET request is sent to the mock-server’s /delay/5000 Endpoint using the curl command from the shell Pod, and the request is forcefully terminated using Ctrl+C before 5000ms passes. [Shell 5] shows an example of executing [Figure 4].
When the curl command is forcefully terminated during execution, the curl command internally terminates the Connection and sends a TCP FIN Flag to the shell Pod’s istio-proxy. The shell Pod’s istio-proxy that received the TCP FIN Flag aborts the request in progress and sends a TCP FIN Flag to the mock-server Pod, which is ultimately delivered to the mock-server Container. Afterward, when the mock-server Container sends the response after 5000ms, the mock-server Pod’s istio-proxy sends a TCP RST Flag to the mock-server Container because the Connection is already terminated.
| |
| |
[Text 6] shows the Access Log of the shell Pod’s istio-proxy, and [Text 7] shows the Access Log of the mock-server’s istio-proxy. Both Access Logs confirm the access to the /delay/5000 Endpoint and response_code showing as 0. Also, response_flags showing as DC (DownstreamConnectionTermination) can be confirmed.
1.2.4. Downstream TCP RST Case
![[Figure 5] Downstream TCP RST Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/http-downstream-tcp-rst-case.png)
[Figure 5] Downstream TCP RST Case
| |
[Shell 6] shows the Downstream TCP RST Case where a GET request is sent to the mock-server’s /delay/5000 Endpoint from the shell Pod, and the request is forcefully terminated by sending a TCP RST Flag instead of a TCP FIN Flag before 5000ms passes. Since the curl command cannot control the Socket’s SO_LINGER Option and therefore cannot send a TCP RST Flag, the python3 command is used to set the SO_LINGER Option to 0 and close the Socket 1000ms after sending the request, which sends a TCP RST Flag.
The shell Pod’s istio-proxy that received the TCP RST Flag does not forward the TCP RST Flag to the mock-server Pod as-is, but instead sends a TCP FIN Flag to terminate the Connection, identical to the Downstream TCP Close Case. Since istio-proxy manages the Downstream Connection and the Upstream Connection as separate TCP Connections, even if the Downstream Connection is abnormally terminated with a TCP RST Flag, the Upstream Connection is gracefully terminated with a TCP FIN Flag. The mock-server Pod’s istio-proxy that received the TCP FIN Flag also sends a TCP FIN Flag to the mock-server Container. Afterward, the mock-server Container sends the response after 5000ms, but since the Connection is already terminated, it receives a TCP RST Flag from the mock-server Pod’s istio-proxy.
| |
| |
[Text 8] shows the Access Log of the shell Pod’s istio-proxy, and [Text 9] shows the Access Log of the mock-server’s istio-proxy. Both Access Logs show response_code as 0, response_flags as DC (DownstreamConnectionTermination), and response_code_details as downstream_remote_disconnect, identical to the Downstream TCP Close Case. In other words, it can be confirmed that istio-proxy does not distinguish between receiving a TCP FIN Flag and a TCP RST Flag from the Downstream in the Access Log.
1.2.5. Downstream TCP RST with Backpressure Case
![[Figure 6] Downstream TCP RST with Backpressure Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/http-downstream-tcp-rst-with-backpressure-case.png)
[Figure 6] Downstream TCP RST with Backpressure Case
| |
[Shell 7] shows the Downstream TCP RST with Backpressure Case where a GET request is sent to the mock-server’s /bytes/50000000 Endpoint from the shell Pod to receive a 50MB response, and while receiving the response, the request is forcefully terminated by sending a TCP RST Flag after waiting 4000ms without reading the response.
When the Client does not read the response, the shell Pod’s istio-proxy keeps the data it could not deliver to the Client in its internal Buffer, and when the Buffer becomes full (High Watermark), Backpressure kicks in and the istio-proxy stops reading Upstream data. The data subsequently sent by the mock-server Pod accumulates in the Kernel Receive Buffer of the Upstream Socket since the istio-proxy no longer reads it. The ss command output in [Shell 7] shows about 1.8MB of unread data stacked in the Recv-Q of the istio-proxy’s Upstream Socket (10.244.1.10:8080).
In this state, the shell Pod’s istio-proxy that received the TCP RST Flag terminates the Upstream Connection, but unlike the Downstream TCP RST Case, it closes a Socket with unread data remaining in the Kernel Receive Buffer, so according to TCP rules, a TCP RST Flag is sent to the mock-server Pod instead of a TCP FIN Flag. In other words, the Flag that istio-proxy sends when terminating the Upstream Connection is determined by whether unread data exists in the Kernel Receive Buffer at the time of termination. The mock-server Pod’s istio-proxy that received the TCP RST Flag also sends a TCP RST Flag to the mock-server Container for the same reason. Due to Backpressure, the mock-server Pod’s istio-proxy was also not reading the data sent by the mock-server Container, so unread data also remains in the Kernel Receive Buffer of the Socket connected to the mock-server Container.
| |
| |
[Text 10] shows the Access Log of the shell Pod’s istio-proxy, and [Text 11] shows the Access Log of the mock-server’s istio-proxy. Both Access Logs record response_flags as DC (DownstreamConnectionTermination) and response_code_details as downstream_remote_disconnect, identical to the Downstream TCP RST Case, and since the request was terminated while the response was being sent, response_code is recorded as 200. The bytes_sent field shows how much data each istio-proxy sent to its Downstream before the termination.
In other words, the Downstream TCP RST Case and the Downstream TCP RST with Backpressure Case cannot be distinguished in the Access Log, and the difference that istio-proxy sends a TCP RST Flag instead of a TCP FIN Flag to the Upstream can only be confirmed through a Packet Dump.
1.2.6. Upstream Request Retry Case
![[Figure 7] Upstream Request Retry Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/http-upstream-request-retry-case.png)
[Figure 7] Upstream Request Retry Case
Since the retryOn Field of the Virtual Service in [File 1] includes the 502 Status Code, up to 2 retries are performed when a 502 Status Code response is received, so up to 3 requests are sent.
| |
[Shell 8] shows the Upstream Request Retry Case where a GET request is sent to the mock-server’s /status/502 Endpoint using the curl command from the shell Pod. Since the mock-server returns a 502 Bad Gateway response for every request, the shell Pod’s istio-proxy delivers the last received 502 Bad Gateway response to the curl command after performing both retries.
| |
| |
[Text 12] shows the Access Log of the shell Pod’s istio-proxy, and [Text 13] shows the Access Log of the mock-server’s istio-proxy. In [Text 12], upstream_request_attempt_count is recorded as 3, which includes the first attempt and both retries, and response_flags is recorded as URX (UpstreamRetryLimitExceeded), indicating that the retry limit was exhausted.
In [Text 13], three logs with the same request_id are recorded. Since retries are performed by the istio-proxy of the shell Pod that serves as the client, the mock-server Pod’s istio-proxy handles each retry as a separate request, so upstream_request_attempt_count is recorded as 1 in every log.
1.2.7. Upstream TCP RST before Response Case
![[Figure 8] Upstream TCP RST before Response Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/http-upstream-tcp-rst-before-response-case.png)
[Figure 8] Upstream TCP RST before Response Case
| |
[Figure 8] shows the Upstream TCP RST before Response Case where a GET request is sent to the mock-server’s /reset-before-response/1000 Endpoint using the curl command from the shell Pod, and after 1000ms, the mock-server Pod sends a TCP RST Flag to forcefully terminate the Connection. [Shell 9] shows an example of executing [Figure 8].
When the mock-server Pod’s istio-proxy receives a TCP RST Flag from the mock-server Container, it does not send a TCP RST Flag to the shell Pod but sends a 503 Service Unavailable response. Therefore, the shell Pod’s istio-proxy Access Log does not have response_flags and only shows the 503 Service Unavailable response.
| |
| |
[Text 14] shows the Access Log of the shell Pod’s istio-proxy, and [Text 15] shows the Access Log of the mock-server’s istio-proxy. Both Access Logs confirm the access to the /reset-before-response/1000 Endpoint and the 503 Service Unavailable response. Also, response_flags showing as UC (UpstreamConnectionTermination) can be confirmed, and response_code_details shows upstream_reset_before_response_started{connection_termination}, indicating that a TCP RST Flag was sent from the Upstream before the response started.
1.2.8. Upstream TCP RST after Response Case
![[Figure 9] Upstream TCP RST after Response Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/http-upstream-tcp-rst-after-response-case.png)
[Figure 9] Upstream TCP RST after Response Case
| |
[Figure 9] shows the Upstream TCP RST after Response Case where a GET request is sent to the mock-server’s /reset-after-response/1000 Endpoint using the curl command from the shell Pod, and after 1000ms, the mock-server Pod sends a partial response and then sends a TCP RST Flag to forcefully terminate the Connection. [Shell 10] shows an example of executing [Figure 9].
When the mock-server Pod’s istio-proxy receives a TCP RST Flag, it sends a TCP FIN Flag to the shell Pod to terminate the TCP Connection. Also, since it was an unexpected Connection termination, a TCP RST Flag is sent after the TCP RST Flag.
| |
| |
[Text 16] shows the Access Log of the shell Pod’s istio-proxy, and [Text 17] shows the Access Log of the mock-server’s istio-proxy. Both Access Logs confirm the access to the /reset-after-response/1000 Endpoint and the 200 OK response. Also, response_flags showing as UPE (UpstreamProtocolError) can be confirmed.
response_code_details shows upstream_reset_after_response_started{protocol_error}, indicating that a TCP RST Flag was sent from the Upstream after partial response transmission. The Protocol Error occurs because the TCP RST Flag was sent from the Upstream before the complete HTTP response was transmitted.
1.2.9. Upstream TCP Close before Response Case
![[Figure 10] Upstream TCP Close before Response Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/http-upstream-tcp-close-before-response-case.png)
[Figure 10] Upstream TCP Close before Response Case
| |
[Figure 10] shows the Upstream TCP Close before Response Case where a GET request is sent to the mock-server’s /close-before-response/1000 Endpoint using the curl command from the shell Pod, and after 1000ms, the mock-server Pod forcefully terminates the Connection. [Shell 11] shows an example of executing [Figure 10].
When the mock-server Pod’s istio-proxy receives a TCP FIN Flag from the mock-server Container, it sends a 503 Service Unavailable response to the shell Pod to indicate that the request was abnormally terminated.
| |
| |
[Text 18] shows the Access Log of the shell Pod’s istio-proxy, and [Text 19] shows the Access Log of the mock-server’s istio-proxy. Both Access Logs confirm the access to the /disconnect/1000 Endpoint and the 503 Service Unavailable response. Also, response_flags showing as UC (UpstreamConnectionTermination) can be confirmed.
response_code_details shows upstream_reset_before_response_started{connection_termination}, indicating that a TCP FIN Flag was sent from the Upstream before the response started. This is the same detail as when receiving a TCP RST Flag in [Figure 8], confirming that the mock-server Pod’s istio-proxy logs the same response_code_details when receiving either a TCP FIN Flag or TCP RST Flag before the response is sent.
1.2.10. Upstream TCP Close after Response Case
![[Figure 11] Upstream TCP Close after Response Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/http-upstream-tcp-close-after-response-case.png)
[Figure 11] Upstream TCP Close after Response Case
| |
[Figure 11] shows the Upstream TCP Close after Response Case where a GET request is sent to the mock-server’s /close-after-response/1000 Endpoint using the curl command from the shell Pod, and after 1000ms, the mock-server Pod sends a response and then forcefully terminates the Connection. [Shell 12] shows an example of executing [Figure 11].
When the mock-server Pod’s istio-proxy receives a TCP FIN Flag from the mock-server Container, it sends a 503 Service Unavailable response to the shell Pod to indicate that the request was abnormally terminated.
| |
| |
[Text 20] shows the Access Log of the shell Pod’s istio-proxy, and [Text 21] shows the Access Log of the mock-server’s istio-proxy. Both Access Logs confirm the access to the /close-after-response/1000 Endpoint and the 200 OK response. Also, response_flags showing as UPE (UpstreamProtocolError) can be confirmed.
response_code_details shows upstream_reset_after_response_started{protocol_error}, indicating that a Protocol Error occurred and the Connection was forcefully terminated after the response started. This is the same detail as when receiving a TCP RST Flag in [Figure 9], confirming that the mock-server Pod’s istio-proxy logs the same response_code_details when receiving either a TCP FIN Flag or TCP RST Flag after partial response transmission.
1.2.11. Circuit Breaking with Upstream Connection Pool Overflow Case
![[Figure 12] Circuit Breaking with Upstream Connection Pool Overflow Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/http-circuit-breaking-with-upstream-connection-pool-overflow-case.png)
[Figure 12] Circuit Breaking with Upstream Connection Pool Overflow Case
| |
[Figure 12] shows the Case where 3 consecutive GET requests are sent to the mock-server’s /delay/5000 Endpoint using the curl command from the shell Pod, causing Upstream Connection Pool Overflow and triggering Circuit Breaking. [Shell 13] shows an example of executing [Figure 12].
Due to the Destination Rule in [File 1], the first request is immediately forwarded to the mock-server Pod and completes with a 200 OK response after waiting 5000ms. The second request is Pending because the first request is being processed and waits until the first request finishes before being forwarded to the mock-server Pod. Therefore, the time for the second request to be processed is 5000ms + 5000ms = 10000ms. The third request cannot even be Pending, so istio-proxy considers it Upstream Overflow and triggers Circuit Breaking, sending a 503 Service Unavailable response.
| |
| |
[Text 22] shows the Access Log of the shell Pod’s istio-proxy, and [Text 23] shows the Access Log of the mock-server’s istio-proxy. In the shell Pod’s istio-proxy Access Log, the first log recorded is for the third request which failed immediately due to Upstream Connection Pool Overflow. response_flags showing as UO (UpstreamOverflow) can be confirmed, and comparing start_time with other logs confirms it started last. The second log is for the first request, and the third log is for the second request. response_duration can be confirmed as 5000ms and 10000ms respectively.
In the mock-server Pod’s istio-proxy Access Log, only logs for the first and second requests exist, and response_duration can be confirmed as 5000ms for both. The third request was not forwarded to the mock-server Pod due to Upstream Connection Pool Overflow at the shell Pod’s istio-proxy, so there is no log for the third request in the mock-server Pod’s istio-proxy.
1.2.12. Circuit Breaking with Upstream Request Limit Overflow Case
![[Figure 13] Circuit Breaking with Upstream Request Limit Overflow Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/http-circuit-breaking-with-upstream-request-limit-overflow-case.png)
[Figure 13] Circuit Breaking with Upstream Request Limit Overflow Case
| |
[Figure 13] shows the Case where 3 consecutive GET requests are sent to the mock-server’s /delay/5000 Endpoint using the curl command from the shell Pod, causing Upstream Request Limit Overflow. To reproduce this Case, the Destination Rule set in [File 2] must be applied. [Shell 14] shows an example of executing [Figure 13].
Due to the Destination Rule settings in [File 2], the maximum concurrent requests that can be processed is one and request Pending is not possible, so the second and third requests are not forwarded to the mock-server Pod due to Upstream Overflow.
| |
| |
[Text 24] shows the Access Log of the shell Pod’s istio-proxy, and [Text 25] shows the Access Log of the mock-server Pod’s istio-proxy. In the shell Pod’s istio-proxy Access Log, the first logs recorded are for the second and third requests which failed immediately due to Upstream Request Limit Overflow. The first log is for the second request, and the second log is for the third request. Both show response_flags as UO (UpstreamOverflow). The last log is for the first request, which was successfully forwarded to the mock-server Pod and processed.
1.2.13. Circuit Breaking with No Healthy Upstream Case
![[Figure 14] Circuit Breaking with No Healthy Upstream Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/http-circuit-breaking-with-no-healthy-upstream-case.png)
[Figure 14] Circuit Breaking with No Healthy Upstream Case
| |
[Figure 14] shows the Case where 8 consecutive GET requests are sent to the mock-server’s /status/503 Endpoint using the curl command from the shell Pod, causing Circuit Breaking through No Healthy Upstream. [Shell 15] shows an example of executing [Figure 14].
Due to the Destination Rule in [File 1], Circuit Breaking activates when 5 consecutive 5XX Errors occur. Therefore, the first 5 requests from the shell Pod are all forwarded to the mock-server Pod, but the subsequent 3 requests are not forwarded to the mock-server Pod due to Circuit Breaking.
| |
| |
[Text 26] shows the Access Log of the shell Pod’s istio-proxy, and [Text 27] shows the Access Log of the mock-server Pod’s istio-proxy. In the shell Pod’s istio-proxy Access Log, only the last 3 requests show response_flags as UH (NoHealthyUpstream) and were not forwarded to the mock-server Pod. Also, in the mock-server Pod’s istio-proxy Access Log, only logs for the first 5 requests exist.
1.2.14. Upstream Connection Failure with Timeout Case
![[Figure 15] Upstream Connection Failure with Timeout Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/http-upstream-connection-failure-case-with-timeout.png)
[Figure 15] Upstream Connection Failure with Timeout Case
| |
[Figure 15] shows the Upstream Connection Failure with Timeout Case where a connection to the mock-server’s /status/200 Endpoint from the shell Pod using the curl command fails due to Timeout and is Retried. [Shell 16] shows an example of executing [Figure 15]. To trigger the Timeout, a rule is added using the iptables command to DROP traffic from the shell Pod’s IP Address, and then a request is sent using the curl command.
Due to the Virtual Service’s connect-failure setting in [File 1], 2 retries occur for a total of 3 requests. Therefore, the first request from the shell Pod performs 3 retries and then outputs a connection timeout error. The second request from the shell Pod triggers only 1 retry for a total of 2 requests, because Circuit Breaking activates when 5 consecutive 5XX Errors occur due to the Destination Rule in [File 1].
The first request’s 3 requests and the second request’s 2nd request, a total of 5 requests occurred and all failed due to Timeout, so it determines there is no Healthy Upstream and Circuit Breaking activates. Therefore, the second request’s 2nd retry is not sent to the mock-server Pod due to Circuit Breaking, and the second request outputs a no healthy upstream error. The third request immediately outputs a no healthy upstream error due to Circuit Breaking.
| |
[Text 28] shows the Access Log of the shell Pod’s istio-proxy. Since requests from the shell Pod are not forwarded to the mock-server Pod by istio-proxy, nothing is logged in the mock-server Pod’s istio-proxy Access Log. The first request shows response_flags as URX (UpstreamRetryLimitExceeded) and UF (UpstreamConnectionFailure), and response_code_details shows upstream_reset_before_response_started{connection_timeout}, confirming a Connection Timeout occurred. upstream_request_attempt_count shows as 3.
The second and third requests show response_flags as UH (NoHealthyUpstream) due to Circuit Breaking, and response_code_details shows no_healthy_upstream. The second request shows upstream_request_attempt_count as 3. The third request shows upstream_request_attempt_count as 1.
1.2.15. Upstream Connection Failure with TCP Reset Case
![[Figure 16] Upstream Connection Failure with TCP Reset Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/http-upstream-connection-failure-case-with-tcp-reset.png)
[Figure 16] Upstream Connection Failure with TCP Reset Case
| |
[Figure 16] shows the Upstream Connection Failure with TCP Reset Case where a connection to the mock-server’s /status/200 Endpoint from the shell Pod using the curl command fails due to TCP Reset and is Retried. [Shell 17] shows an example of executing [Figure 16]. To trigger TCP Reset, a rule is added using the iptables command to REJECT traffic from the shell Pod’s IP Address, and then a request is sent using the curl command. Except for the Connection Refused error message, it shows the same results as the Case where Retry is performed due to Timeout.
| |
[Text 29] shows the Access Log of the shell Pod’s istio-proxy. Since requests from the shell Pod are not forwarded to the mock-server Pod by istio-proxy, nothing is logged in the mock-server Pod’s istio-proxy Access Log. response_code_details shows upstream_reset_before_response_started{remote_connection_failure|delayed_connect_error:_Connection_refused}, confirming that Remote Connection Failure and Delayed Connect Error occurred. Except for this part, it shows the same results as the Case where Retry is performed due to Timeout.
1.2.16. Upstream Request Timeout Case
![[Figure 17] Upstream Request Timeout Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/http-upstream-request-timeout-case.png)
[Figure 17] Upstream Request Timeout Case
| |
[Figure 17] shows the Upstream Request Timeout Case where a GET request is sent to the mock-server’s /delay/70000 Endpoint from the shell Pod using the curl command, but the mock-server Pod’s istio-proxy does not receive a response after waiting 60000ms and processes the Request as Timeout. [Shell 18] shows an example of executing [Figure 17].
Due to the Virtual Service in [File 1], requests sent to the mock-server Pod can wait up to 60000ms. However, the request sent to the mock-server Pod’s /delay/70000 Endpoint requires 70000ms, so a Timeout occurs. When a Timeout occurs, the mock-server Pod’s istio-proxy sends TCP FIN Flag and TCP RST Flag sequentially to terminate the connection with the mock-server Pod. It also sends a 504 Gateway Timeout response to the shell Container.
| |
| |
[Text 30] shows the Access Log of the shell Pod’s istio-proxy, and [Text 31] shows the Access Log of the mock-server Pod’s istio-proxy. The shell Pod’s istio-proxy shows response_flags as UT (UpstreamTimeout). The mock-server Pod’s istio-proxy shows response_flags as DC (DownstreamConnectionTermination).
1.3. GRPC Cases
1.3.1. OK Case
![[Figure 18] OK Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/grpc-ok-case.png)
[Figure 18] OK Case
| |
[Figure 18] shows the OK Case where the grpcurl command is used from the shell Pod to send a code: 0 request to the mock-server’s /mock.MockService/Status function and receive an OK response. [Shell 19] shows an example of executing [Figure 18].
| |
| |
[Text 32] shows the Access Log of the shell Pod’s istio-proxy, and [Text 33] shows the Access Log of the mock-server Pod’s istio-proxy. Both Access Logs show the access to the /mock.MockService/Status function and grpc_status as OK.
1.3.2. Internal Case
![[Figure 19] Internal Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/grpc-internal-case.png)
[Figure 19] Internal Case
| |
[Figure 19] shows the Internal Case where the grpcurl command is used from the shell Pod to send a code: 13 request to the mock-server’s /mock.MockService/Status function and receive an Internal response. [Shell 20] shows an example of executing [Figure 19].
| |
| |
[Text 34] shows the Access Log of the shell Pod’s istio-proxy, and [Text 35] shows the Access Log of the mock-server Pod’s istio-proxy. Both Access Logs show the access to the /mock.MockService/Status function and grpc_status as Internal. Also, response_code shows 200 OK, and when using gRPC, response_code always shows 200 OK regardless of the gRPC result. Since the INTERNAL (13) Status Code is not included in the retryOn Field of the Virtual Service in [File 1], no retry occurs, and upstream_request_attempt_count is recorded as 1.
1.3.3. Downstream TCP Close Case
![[Figure 20] Downstream TCP Close Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/grpc-downstream-tcp-close-case.png)
[Figure 20] Downstream TCP Close Case
| |
[Figure 20] shows the Downstream TCP Close Case where the grpcurl command is used from the shell Pod to send a milliseconds: 5000 request to the mock-server’s /mock.MockService/Delay function, and forcefully terminates the request using Ctrl+C before 5000ms passes. [Shell 21] shows an example of executing [Figure 20].
When the grpcurl command is forcefully terminated during execution, the grpcurl command internally terminates the Connection and sends a TCP FIN Flag to the shell Pod’s istio-proxy, and the shell Pod’s istio-proxy that received the TCP FIN Flag sends an HTTP/2 RST_STREAM Frame to the mock-server Pod, which is ultimately delivered to the mock-server Container to terminate the request. Unlike the HTTP/1.1 Protocol, the TCP Connection between Pods using the HTTP/2 Protocol is shared by multiple requests through Stream multiplexing, so the shell Pod’s istio-proxy does not terminate the TCP Connection between Pods and only terminates the Stream of the request through the HTTP/2 RST_STREAM Frame.
| |
| |
[Text 36] shows the Access Log of the shell Pod’s istio-proxy, and [Text 37] shows the Access Log of the mock-server Pod’s istio-proxy. Both Access Logs show the access to the /mock.MockService/Delay function with response_code as 0 and grpc_status as -.
Also, the shell Pod’s istio-proxy shows response_flags as DC (DownstreamConnectionTermination) because it receives TCP FIN Flag from the grpcurl command, and the mock-server Pod’s istio-proxy shows response_flags as DR (DownstreamRemoteReset) because it receives HTTP/2 RST_STREAM Frame.
1.3.4. Downstream TCP RST Case
![[Figure 21] Downstream TCP RST Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/grpc-downstream-tcp-rst-case.png)
[Figure 21] Downstream TCP RST Case
| |
[Shell 22] shows the Downstream TCP RST Case where a milliseconds: 5000 request is sent to the mock-server’s /mock.MockService/Delay function from the shell Pod, and the request is forcefully terminated by sending a TCP RST Flag instead of a TCP FIN Flag before 5000ms passes. Since the grpcurl command cannot control the Socket’s SO_LINGER Option and therefore cannot send a TCP RST Flag, the python3 command is used to construct the HTTP/2 Frames and the gRPC Message directly to send the request, and 1000ms after sending the request, the SO_LINGER Option is set to 0 and the Socket is closed, which sends a TCP RST Flag.
The shell Pod’s istio-proxy that received the TCP RST Flag does not forward the TCP RST Flag to the mock-server Pod as-is, identical to the Downstream TCP Close Case, but sends an HTTP/2 RST_STREAM Frame to terminate only the Stream of the request. In other words, regardless of whether the Downstream Connection is gracefully terminated with a TCP FIN Flag or abnormally terminated with a TCP RST Flag, the TCP Connection between Pods is maintained and only the HTTP/2 RST_STREAM Frame is sent.
| |
| |
[Text 38] shows the Access Log of the shell Pod’s istio-proxy, and [Text 39] shows the Access Log of the mock-server Pod’s istio-proxy. Both Access Logs are identical to the Downstream TCP Close Case: the shell Pod shows response_flags as DC (DownstreamConnectionTermination) with response_code_details as downstream_remote_disconnect, and the mock-server Pod shows response_flags as DR (DownstreamRemoteReset) with response_code_details as http2.remote_reset. In other words, just like the HTTP/1.1 Protocol, it can be confirmed that istio-proxy does not distinguish between receiving a TCP FIN Flag and a TCP RST Flag from the Downstream in the Access Log for the gRPC Protocol as well.
1.3.5. Upstream Request Retry Case
![[Figure 22] Upstream Request Retry Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/grpc-upstream-request-retry-case.png)
[Figure 22] Upstream Request Retry Case
Since the retryOn Field of the Virtual Service in [File 1] includes the gRPC retry conditions unavailable and cancelled, up to 2 retries are performed when an UNAVAILABLE (14) Status Code response is received, so up to 3 requests are sent.
| |
[Shell 23] shows the Upstream Request Retry Case where the grpcurl command is used from the shell Pod to send a code: 14 (Unavailable) request to the mock-server’s /mock.MockService/Status function.
| |
| |
[Text 40] shows the Access Log of the shell Pod’s istio-proxy. upstream_request_attempt_count is recorded as 3, which includes the first attempt and both retries, and response_flags is recorded as URX (UpstreamRetryLimitExceeded), indicating that the retry limit was exhausted.
In [Text 41], three logs with the same request_id are recorded. Since retries are performed by the istio-proxy of the shell Pod that serves as the client, the mock-server Pod’s istio-proxy handles each retry as a separate request, so upstream_request_attempt_count is recorded as 1 in every log.
1.3.6. Upstream TCP RST before Response Case
![[Figure 23] Upstream TCP RST before Response Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/grpc-upstream-tcp-rst-before-response-case.png)
[Figure 23] Upstream TCP RST before Response Case
| |
[Figure 23] shows the Upstream TCP RST before Response Case where the grpcurl command is used from the shell Pod to send a milliseconds: 1000 request to the mock-server’s /mock.MockService/ResetBeforeResponse function, and after waiting 1000ms, a TCP RST Flag is sent to forcefully terminate the Connection. [Shell 24] shows an example of executing [Figure 23].
The mock-server Pod’s istio-proxy that receives the TCP RST Flag returns an Unavailable status code to notify the shell Pod’s istio-proxy that the request was abnormally terminated. Due to the unavailable setting in the Virtual Service in [File 1], the shell Pod’s istio-proxy performs 2 retries for a total of 3 requests.
| |
| |
[Text 42] shows the Access Log of the shell Pod’s istio-proxy, and [Text 43] shows the Access Log of the mock-server Pod’s istio-proxy. Both Access Logs show the access to the /mock.MockService/ResetBeforeResponse function with response_code as 200 and grpc_status as Unavailable. Also, both Access Logs show response_flags as UC (UpstreamConnectionTermination).
Since the shell Pod’s istio-proxy sends 3 requests, upstream_request_attempt_count shows 3 in the shell Pod’s istio-proxy Access Log. Also, 3 Access Logs are left in the mock-server Pod’s istio-proxy.
1.3.7. Upstream TCP RST after Response Case
![[Figure 24] Upstream TCP RST after Response Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/grpc-upstream-tcp-rst-after-response-case.png)
[Figure 24] Upstream TCP RST after Response Case
| |
[Figure 24] shows the Upstream TCP RST after Response Case where the grpcurl command is used from the shell Pod to send a milliseconds: 1000 request to the mock-server’s /mock.MockService/ResetAfterResponse function, and after 1000ms, the mock-server Pod sends a partial response and then sends a TCP RST Flag to forcefully terminate the Connection. [Shell 25] shows an example of executing [Figure 24].
| |
| |
[Text 44] shows the Access Log of the shell Pod’s istio-proxy, and [Text 45] shows the Access Log of the mock-server Pod’s istio-proxy. Both Access Logs show the access to the /mock.MockService/ResetAfterResponse function with response_code as 200 and grpc_status as Unknown. The shell Pod’s istio-proxy Access Log shows response_flags as UR (UpstreamRemoteReset), and the mock-server Pod’s istio-proxy Access Log shows response_flags as UC (UpstreamConnectionTermination).
1.3.8. Upstream TCP Close before Response Case
![[Figure 25] Upstream TCP Close before Response Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/grpc-upstream-tcp-close-before-response-case.png)
[Figure 25] Upstream TCP Close before Response Case
| |
[Figure 25] shows the Upstream TCP Close before Response Case where the grpcurl command is used from the shell Pod to send a milliseconds: 1000 request to the mock-server’s /mock.MockService/CloseBeforeResponse function, and after 1000ms, the mock-server Pod forcefully terminates the Connection. [Shell 26] shows an example of executing [Figure 25].
Except for the fact that the mock-server Container sends TCP FIN Flag, the same process as [Figure 23] which receives TCP RST Flag is performed.
| |
| |
[Text 46] shows the Access Log of the shell Pod’s istio-proxy, and [Text 47] shows the Access Log of the mock-server Pod’s istio-proxy. Both Access Logs show the access to the /mock.MockService/CloseBeforeResponse function with response_code as 200 and grpc_status as Unavailable. The same process as [Figure 23] which receives TCP RST Flag is performed.
1.3.9. Upstream TCP Close after Response Case
![[Figure 26] Upstream TCP Close after Response Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/grpc-upstream-tcp-close-after-response-case.png)
[Figure 26] Upstream TCP Close after Response Case
| |
[Figure 26] shows the Upstream TCP Close after Response Case where the grpcurl command is used from the shell Pod to send a milliseconds: 1000 request to the mock-server’s /mock.MockService/CloseAfterResponse function, and after 1000ms, the mock-server Pod sends a partial response and then forcefully terminates the Connection. [Shell 27] shows an example of executing [Figure 26].
Except for the fact that the mock-server Container sends TCP FIN Flag, the same process as [Figure 24] which receives TCP RST Flag is performed.
| |
| |
[Text 48] shows the Access Log of the shell Pod’s istio-proxy, and [Text 49] shows the Access Log of the mock-server Pod’s istio-proxy. Both Access Logs show the access to the /mock.MockService/CloseAfterResponse function with response_code as 200 and grpc_status as Unknown. The same process as [Figure 24] which receives TCP RST Flag is performed.
1.3.10. Circuit Breaking with Upstream Connection Pool Overflow Case
![[Figure 27] Circuit Breaking with Upstream Connection Pool Overflow Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/grpc-circuit-breaking-with-upstream-connection-pool-overflow-case.png)
[Figure 27] Circuit Breaking with Upstream Connection Pool Overflow Case
| |
[Figure 27] shows the Case where grpcurl command is used from the shell Pod to send 3 consecutive milliseconds: 5000 requests to the mock-server’s /mock.MockService/Delay function, causing Upstream Connection Pool Overflow. [Shell 28] shows an example of executing [Figure 27]. Except for the fact that requests and responses occur via GRPC, the same process as described in [Figure 12] is performed.
| |
| |
[Text 50] shows the Access Log of the shell Pod’s istio-proxy, and [Text 51] shows the Access Log of the mock-server Pod’s istio-proxy. Except for the fact that requests and responses occur via GRPC, the same process as [Text 22] and [Text 23] is performed.
1.3.11. Circuit Breaking with Upstream Request Limit Overflow Case
![[Figure 28] Circuit Breaking with Upstream Request Limit Overflow Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/grpc-circuit-breaking-with-upstream-request-limit-overflow-case.png)
[Figure 28] Circuit Breaking with Upstream Request Limit Overflow Case
| |
[Figure 28] shows the Case where grpcurl command is used from the shell Pod to send 3 consecutive milliseconds: 5000 requests to the mock-server’s /mock.MockService/Delay function, causing Upstream Request Limit Overflow. To reproduce this Case, the Destination Rule configured in [File 2] must be applied. [Shell 29] shows an example of executing [Figure 28]. Except for the fact that requests and responses occur via GRPC, the same process as described in [Figure 13] is performed.
| |
| |
[Text 52] shows the Access Log of the shell Pod’s istio-proxy, and [Text 53] shows the Access Log of the mock-server Pod’s istio-proxy. Except for the fact that requests and responses occur via GRPC, the same process as [Text 24] and [Text 25] is performed.
1.3.12. Circuit Breaking with No Healthy Upstream Case
![[Figure 29] Circuit Breaking with No Healthy Upstream Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/grpc-circuit-breaking-with-no-healthy-upstream-case.png)
[Figure 29] Circuit Breaking with No Healthy Upstream Case
| |
[Figure 29] shows the Case where grpcurl command is used from the shell Pod to send 8 consecutive code: 13 requests to the mock-server’s /mock.MockService/Status function, causing Circuit Breaking via No Healthy Upstream. [Shell 30] shows an example of executing [Figure 29].
According to the Destination Rule in [File 1], Circuit Breaking is activated when 5 consecutive 5XX Errors occur. Therefore, the first 5 requests from the shell Pod are all delivered to the mock-server Pod, but the subsequent 3 requests are not delivered to the mock-server Pod due to Circuit Breaking. Therefore, the response to the first 5 requests shows Internal, and the response to the subsequent 3 requests shows Unavailable.
| |
| |
[Text 54] shows the Access Log of the shell Pod’s istio-proxy, and [Text 55] shows the Access Log of the mock-server Pod’s istio-proxy. In the shell Pod’s istio-proxy Access Log, only the last 3 requests show response_flags as UH (NoHealthyUpstream) along with confirmation that requests were not delivered to the mock-server Pod. Also, only the first 5 request logs are present in the mock-server Pod’s istio-proxy Access Log.
1.3.13. Upstream Connection Failure with Timeout Case
![[Figure 30] Upstream Connection Failure with Timeout Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/grpc-upstream-connection-failure-case-with-timeout.png)
[Figure 30] Upstream Connection Failure with Timeout Case
| |
[Figure 30] shows the Upstream Connection Failure with Timeout Case where grpcurl command is used from the shell Pod to send 3 consecutive code: 0 requests to the mock-server’s /mock.MockService/Status function, causing Retry due to Timeout. [Shell 31] shows an example of executing [Figure 30]. Except for the fact that requests and responses occur via GRPC, the same process as described in [Figure 15] is performed.
| |
[Text 56] shows the Access Log of the shell Pod’s istio-proxy. Except for the fact that requests and responses occur via GRPC, the same process as [Text 28] is performed.
1.3.14. Upstream Connection Failure with TCP Reset Case
![[Figure 31] Upstream Connection Failure with TCP Reset Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/grpc-upstream-connection-failure-case-with-tcp-reset.png)
[Figure 31] Upstream Connection Failure with TCP Reset Case
| |
[Figure 31] shows the Upstream Connection Failure with TCP Reset Case where grpcurl command is used from the shell Pod to send 3 consecutive code: 0 requests to the mock-server’s /mock.MockService/Status function, causing Retry due to TCP Reset. [Shell 32] shows an example of executing [Figure 31]. Except for the fact that requests and responses occur via GRPC, the same process as described in [Figure 16] is performed.
| |
[Text 57] shows the Access Log of the shell Pod’s istio-proxy. Except for the fact that requests and responses occur via GRPC, the same process as [Text 29] is performed.
1.3.15. Upstream Request Timeout Case
![[Figure 32] Upstream Request Timeout Case](/blog-software/docs/theory-analysis/istio-sidecar-proxy-access-log/images/grpc-upstream-request-timeout-case.png)
[Figure 32] Upstream Request Timeout Case
| |
[Figure 32] shows the Upstream Request Timeout Case where the grpcurl command is used from the shell Pod to send a milliseconds: 70000 request to the mock-server’s /mock.MockService/Delay function, but the mock-server Pod’s istio-proxy does not receive a response after waiting 60000ms and processes the Request as Timeout.
Due to the Virtual Service in [File 1], requests sent to the mock-server Pod can wait up to 60000ms. However, the request sent to the mock-server Pod’s /mock.MockService/Delay function with milliseconds: 70000 requires 70000ms, so a Timeout occurs. The mock-server Pod’s istio-proxy sends an HTTP/2 RST_STREAM Frame to terminate the connection with the mock-server Pod when a Timeout occurs. It also returns an Unavailable status code to notify the shell Pod’s istio-proxy that the request was abnormally terminated.
| |
| |
[Text 58] shows the Access Log of the shell Pod’s istio-proxy, and [Text 59] shows the Access Log of the mock-server Pod’s istio-proxy. The shell Pod’s istio-proxy shows response_flags as UT (UpstreamTimeout). The mock-server Pod’s istio-proxy shows response_flags as DR (DownstreamRemoteReset).