Identificar a causa da alta latência de resposta usando logs de acesso - Alibaba Cloud Service Mesh: Central de Documentação do Alibaba Cloud

Os proxies sidecar injetados nas cargas de trabalho interceptam e roteiam o tráfego com base em políticas configuradas. Cada proxy adiciona um pequeno tempo de processamento, mas essa sobrecarga é insignificante para o processamento simultâneo quando os nós possuem recursos adequados.

Quando a latência de resposta for maior que o esperado, os campos de tempo nos logs de acesso ajudam a isolar a causa. O processo consiste em duas etapas:

Identifique qual componente no caminho da requisição está introduzindo a latência.
Determine se a causa raiz é uma transmissão de rede lenta ou um processamento upstream lento.

Pré-requisitos

Antes de começar, verifique se:

O log de acesso está ativado para sua instância do ASM. Para mais informações, consulte Ative coleta de logs de acesso.
É possível recuperar os logs do proxy sidecar executando kubectl logs <pod-name> -c istio-proxy -n <namespace>.

Como funcionam os campos de tempo nos logs de acesso

Cada componente do plano de dados (proxy sidecar ou gateway) registra campos de tempo em sua entrada de log de acesso. Esses campos medem diferentes segmentos do ciclo de vida da requisição:

                          Request lifecycle at a single data plane component

  Downstream                    Data plane component                    Upstream
  (client)                    (sidecar proxy / gateway)                 (service)
     |                                   |                                  |
     |-------- request_duration -------->|                                  |
     |   (start -> last byte received   |                                  |
     |    from downstream)              |                                  |
     |                                  |-------- request_tx_duration ----->|
     |                                  |   (start -> last byte sent       |
     |                                  |    to upstream)                   |
     |                                  |                                   |
     |                                  |<--- response_duration ------------|
     |                                  |   (start -> first byte received  |
     |                                  |    from upstream)                 |
     |                                  |                                   |
     |<-------- response_tx_duration ---|                                   |
     |   (first byte received from      |                                  |
     |    upstream -> last byte sent    |                                  |
     |    to downstream)               |                                  |
     |                                  |                                   |

     |<===================== duration =================================>|
                        (start -> last byte out)

Campo	O que mede	De	Até
`duration`	Ciclo total de requisição-resposta	Início da requisição	Último byte enviado ao downstream
`request_duration`	Requisição completa recebida do downstream	Início da requisição	Último byte da requisição recebido do downstream
`request_tx_duration`	Requisição completa transmitida ao upstream	Início da requisição	Último byte da requisição enviado ao upstream
`response_duration`	Tempo até o primeiro byte de resposta do upstream	Início da requisição	Primeiro byte da resposta recebido do upstream
`response_tx_duration`	Resposta completa entregue ao downstream	Primeiro byte da resposta recebido do upstream	Último byte da resposta enviado ao downstream

Comparação de exemplo de logs de acesso

O exemplo a seguir mostra os campos de tempo do sidecar do lado do cliente e do sidecar do lado do servidor para a mesma requisição. Comparar os valores entre ambos os lados ajuda a identificar exatamente onde ocorre a latência.

Campo	Sidecar do lado do cliente	Sidecar do lado do servidor	Interpretação
`duration`	250 ms	30 ms	O componente do lado do cliente responde pela maior parte da latência.
`request_duration`	5 ms	2 ms	A requisição foi recebida rapidamente em ambos os lados.
`request_tx_duration`	200 ms	3 ms	O proxy do lado do cliente demorou muito para encaminhar a requisição ao upstream, sugerindo problemas de rede entre os dois sidecars.
`response_duration`	220 ms	25 ms	A diferença é consistente com uma transmissão lenta da requisição pelo lado do cliente.
`response_tx_duration`	30 ms	5 ms	A entrega da resposta foi relativamente rápida em ambos os lados.

Etapa 1: Identificar o componente que introduz a latência

Verifique o campo duration no log de acesso de cada componente ao longo do caminho da requisição. Esse valor representa o tempo total que o componente gastou recebendo a requisição, encaminhando-a ao upstream, aguardando a resposta e enviando a resposta de volta ao downstream.

Compare os valores de duration entre os componentes no caminho da requisição:

Comece pelo ponto de entrada (gateway ou primeiro proxy sidecar) e anote seu duration.
Verifique o duration do próximo componente upstream.
- Se o duration do componente upstream estiver dentro da faixa esperada, o componente atual é a source do excesso de latência.
- Se o duration do componente upstream também estiver acima do esperado, avance mais um salto no upstream e repita a comparação.
Continue até encontrar o componente onde a latência cai para níveis normais. O componente imediatamente downstream dele é aquele que está introduzindo o excesso de latência.

Etapa 2: Determinar a causa raiz

Após identificar o componente, examine seus campos de log de acesso para distinguir entre duas causas raízes: transmissão de rede lenta e processamento upstream lento.

Transmissão de rede lenta

Analise request_duration e request_tx_duration:

**Alto request_duration** -- O componente levou muito tempo para receber a requisição do nó downstream, indicando problemas de rede entre o nó downstream e este componente (proxy sidecar ou gateway).
**Alto request_tx_duration** -- O componente demorou muito para encaminhar a requisição ao serviço upstream, indicando problemas de rede entre este componente e o serviço upstream.

Para requisições HTTP com corpo, o componente lê e encaminha o corpo simultaneamente, em vez de armazená-lo inteiramente em buffer antes do envio. Como resultado, um request_duration alto frequentemente causa um request_tx_duration correspondentemente alto. Se apenas o request_tx_duration estiver alto enquanto o request_duration estiver normal, a requisição foi recebida rapidamente, mas encaminhada lentamente ao serviço upstream.

Verifique request_duration e response_tx_duration juntos para identificar problemas no caminho de resposta:

Se **tanto request_duration quanto response_tx_duration** estiverem altos, a resposta foi lida lentamente do serviço upstream ou encaminhada lentamente ao nó downstream.

Processamento upstream lento

Compare response_duration e request_tx_duration:

A diferença entre esses dois valores aproxima o tempo que o serviço upstream gastou processando a requisição:

Upstream processing time ≈ response_duration - request_tx_duration

Uma grande diferença indica que o serviço upstream está lento para processar a requisição ou que há alta latência de rede entre o componente e o serviço upstream.

Referência rápida: padrões de campos e causas prováveis

Padrão de campo	Causa provável	Próxima etapa
Alto `request_duration`	Rede lenta entre downstream e o componente atual	Verifique a rede do nó downstream, perda de pacotes e largura de banda.
Apenas alto `request_tx_duration`	Rede lenta entre o componente atual e o upstream	Verifique o caminho de rede upstream e a resolução DNS.
Alto `request_duration` + alto `request_tx_duration`	Rede downstream lenta (efeito cascata do streaming de corpo)	Concentre-se no caminho de rede downstream.
Alto `request_duration` + alto `response_tx_duration`	Leitura lenta da resposta do upstream ou encaminhamento lento ao downstream	Verifique a rede do caminho de resposta e a integridade do serviço upstream.
Alto `response_duration` - `request_tx_duration`	Processamento upstream lento ou alta latência de rede upstream	Faça profiling do serviço upstream e verifique o uso de recursos upstream.
Alto `response_tx_duration`	Entrega lenta da resposta ao downstream	Verifique o tamanho da resposta e a capacidade da rede downstream.