Como soluciono problemas de um aumento na métrica TargetResponseTime para um Application Load Balancer?

Breve descrição

TargetResponseTime é o tempo decorrido, em segundos, entre o momento em que a solicitação sai do balanceador de carga e o recebimento de uma resposta do destino. Isso é equivalente ao campo target_processing_time nos logs de acesso do Application Load Balancer.

As possíveis causas de um aumento em TargetResponseTime incluem:

• Os hosts não estão íntegros.
• As instâncias de backend estão sobrecarregadas com muitas solicitações.
• Há uma alta utilização de CPU nas instâncias de backend.
• Um ou mais dos destinos estão com defeito.
• Há problemas com dependências de aplicações Web em execução em instâncias de backend.

Resolução

Os hosts não estão íntegros

Verifique se todos os destinos do Application Load Balancer estão íntegros. Consulte Como identifico e corrijo verificações de integridade com falha no Application Load Balancers?

As instâncias de backend estão sobrecarregadas com muitas solicitações

Verifique a estatística Sum das métricasRequestCount e ActiveConnectionCount do Amazon CloudWatch para seu Application Load Balancer. Um aumento de soma que coincide com o aumento em TargetResponseTime pode indicar que as instâncias de backend estão sobrecarregadas pela carga de solicitações.

Para resolver esse problema, configure um grupo de Auto Scaling para suas instâncias de backend. Consulte Tutorial: Configure uma aplicação escalável e com carga balanceada

Há alta utilização da CPU nas instâncias de backend

Verifique a métrica CPUUtilization do CloudWatch das suas instâncias de backend. Se a utilização da CPU for alta ou se houver um pico na utilização, atualize suas instâncias para um tipo de instância maior.

Um ou mais dos destinos estão com defeito

Se você estiver enfrentando destinos com defeito, siga estas etapas para resolver o problema:

1.    Habilite o registro em log de acesso para seu balanceador de carga.

2.    Baixe logs de acesso para o intervalo de tempo em que TargetResponseTime estiver alto. Por exemplo, para baixar os logs de acesso entre 2022-02-01T 03:00 e 2022-02-01T 03:35 usando a AWS Command Line Interface (AWS CLI):

aws s3 cp s3://bucket-name[/prefix]/AWSLogs/aws-account-id/elasticloadbalancing/region/2022/02/01/ ./alblogs --recursive --exclude "*" --include "*20220201T03[0123]*"

Observação: substitua bucket-name pelo nome do seu bucket, aws-account-id pelo ID da sua conta da AWS e region pela região da AWS em que sua conta está localizada.

3.    Use ferramentas de linha de comando para analisar os logs de acesso:

Os logs de acesso do Elastic Load Balancing (ELB) são compactados em formato .gzip.

Etapa opcional: para extrair os logs, use o seguinte comando:

$   gzip -dr ./alblogs

Cenários de exemplo

Para obter a latência máxima para target_processing_time, execute o seguinte comando.

Arquivo de log compactado:

$zcat *.log.gz | awk '$7 != -1' | awk 'BEGIN{a=0}{if ($7>0+a) a=$7} END{print a}'

Arquivo de log não compactado:

$cat *.log | awk '$7 != -1' | awk 'BEGIN{a=0}{if ($7>0+a) a=$7} END{print a}'

-ou-

Para contar o número de solicitações que têm target_processing_time “>=N” segundos por destino, modifique N com o número de segundos para seus requisitos.

Exemplo de comando para arquivo de log compactado:

$zcat *.log.gz | awk '{if($7 >= N){print $5}}' | sort | uniq -c

Exemplo de comando para arquivo de log descompactado:

$cat *.log | awk '{if($7 >= N){print $5}}' | sort | uniq -c

Exemplo de saída:

12 10.10.20.111:80 
12 10.10.60.163:80
254 10.10.70.7:80
6 10.10.80.109:80
20656 10.3.19.141:80

No exemplo anterior, o destino com endereço IP 10.3.19.141 é responsável pela maior parte do aumento em TargetResponseTime. Nesse caso, verifique o sistema operacional (SO) e a aplicação Web para o destino.

Há problemas com dependências de aplicações Web em execução em instâncias de backend

Execute uma captura de pacote no destino para identificar o atraso na resposta do destino. Para o sistema operacional Linux, use tcpdump.

Para capturar uma transmissão HTTP POST de entrada e saída completa, incluindo solicitação e resposta HTTP na porta TCP/80:

tcpdump -i any -ns 0 -A 'tcp dst port 80 and tcp[((tcp[12:1] & 0xf0) >> 2):4] = 0x504F5354 or tcp[((tcp[12:1] & 0xf0) >> 2):4] = 0x48545450 or tcp[((tcp[12:1] & 0xf0) >> 2):4] = 0x3C21444F'

Para capturar uma transmissão HTTP GET de entrada e saída completa, incluindo solicitação e resposta HTTP na porta TCP/80:

tcpdump -i any -ns 0 -A 'tcp dst port 80 and tcp[((tcp[12:1] & 0xf0) >> 2):4] = 0x47455420 or tcp[((tcp[12:1] & 0xf0) >> 2):4] = 0x48545450 or tcp[((tcp[12:1] & 0xf0) >> 2):4] = 0x3C21444F'

Saídas de exemplo:

14:04:12.186593 IP 10.10.30.219.13000 > 10.10.60.10.http: Flags [P.], seq 641705534:641705793, ack 1587610435, win 106, options [nop,nop,TS val 1165674323 ecr 263805247],
    length 259: HTTP: GET / HTTP/1.1 E..7."@...I. .. < 2..P&?.>^..C...j9...... Ez.S..Y?GET / HTTP/1.1 X-Forwarded-For: 54.66.76.204 X-Forwarded-Proto: http X-Forwarded-Port: 80 Host: labalbinternet-1236602672.ap-southeast-2.elb.amazonaws.com
    X-Amzn-Trace-Id: Root=1-6254355c-15db4904726649b66a1e47d7 User-Agent: curl/7.79.1 Accept: */* ................

14:04:21.187892 IP 10.10.60.10.http > 10.10.30.219.13000: Flags [P.], seq 1:592, ack 259, win 488, options [nop,nop,TS val 263814250
    ecr 1165674323], length 591: HTTP: HTTP/1.1 200 OK E...\.@.@.l. < ...P2.^..C&?.A....qn..... ..|jEz.SHTTP/1.1 200 OK Date: Mon, 11 Apr 2022 14:04:12 GMT Server: Apache/2.4.52 () OpenSSL/1.0.2k-fips X-Powered-By: PHP/7.2.34 Upgrade: h2,h2c
    Connection: Upgrade Transfer-Encoding: chunked Content-Type: text/html; charset=UTF-8 159 PHP file name: /index.php<br> ................

Observação: nas saídas do exemplo anterior, o HTTP GET responde às 14:04:12, e o destino responde às 14:04:21. O TargetResponseTime é de aproximadamente 9 segundos. Você pode usar X-Amzn-Trace-Id: Root para rastrear esse registro nos logs de acesso.

Exemplo de comando para arquivo de log compactado:

$zcat *.log.gz | awk '{if($20 ~ "1-6254355c-15db4904726649b66a1e47d7"){print $6,$7,$8 }}'

Exemplo de comando para arquivo de log descompactado:

$cat *.log | awk '{if($20 ~ "1-6254355c-15db4904726649b66a1e47d7"){print $6,$7,$8 }}'

Exemplo de saída:

0.008 9.002 0.000

---