Dead Packets

02/11/2011

Troubleshooting de lentidão com firewall, MPLS e HP-UX

Filed under: checkpoint,troubleshooting — drak @ 9:20 PM

Enfrentava um problema de lentidão em um sistema web acessado por uma empresa parceira que chegava no meu cliente por uma MPLS contratada de um ISP.

Testes de ping mostravam entre 25% a 75% de perda de pacotes, a operadora já havia tentado corrigir a situação aplicando QoS no roteador de WAN mais próximo do cliente porém não surtiu efeito. No meio do caminho havia um Check Point R71.30 splat com conhecido problema de alto processamento (CPU constantemente entre 75% e 85%).

Inicialmente queria estabelecer um baseline desse sistema web que era afetado pela lentidão. Fui informado que outra empresa parceira tambem acessava esse mesmo sistema e que seu desempenho era medido por agentes que mostravam um tempo médio de resposta de 2s.

Com essa informação confrontei com o tempo a partir da parceira problemática. Eles obteram essa informação com o HttpWatch, ferramenta que provê gratuitamenta esse tipo de métrica, podemos ver um exemplo de medição para o site yahoo.com abaixo.

O tempo foi em média 30s, portanto muito maior, comparativamente, com a velocidade esperada do sistema.

O próximo passo seria um traceroute a partir da parceira afetada até o web server, não conseguimos progredir com essa abordagem pois o firewall no parceiro não possuia liberação para isso.

Mudamos a abordagem e fizemos um traceroute a partir do roteador da wan que estava na frente deste firewall (da parceira), o gateway do firewall para a rede MPLS. A partir desse ponto obtivemos o caminho até o web server, cada asterisco é um IP que mapeamos usando o traceroute.

|LAN PARCEIRA| – |FW PARC| – |ROUTER WAN PARC| – *|ROUTER1| – *|ROUTER2| – *|ROUTER WAN CUST| – *|FW CLIENTE| – *|WEB SERVER|

Com um traceroute no sentido contrário, feito a partir do firewall (pois o web server estava diretamente conectado) cruzamos as duas informações e montamos a topologia completa do ambiente afetado pelo problema:

|LAN PARCEIRA| – |FW PARC| – |ROUTER WAN PARC|* – *|ROUTER1|* – *|ROUTER2|* – *|ROUTER WAN CUST|* – *|FW CLIENTE| – *|WEB SERVER|

Com o ambiente mapeado começamos os testes. Ping a partir do equipamento ROUTER WAN PARC para o WEB SERVER indicava perdas de até 75%!

Próximo hop mesmo teste, e assim por diante, vejam os resultados.

ROUTER WAN PARC, WEB SERVER: 75%
ROUTER1, WEB SERVER: 75%
ROUTER2, WEB SERVER: 75%
ROUTER WAN CUST, WEB SERVER: 0%
FW CLIENTE: 0%

Com os resultados desses testes, imaginei que havíamos descoberto que o problema estava entre o segmento ROUTER WAN PARC e a interface mais próxima dele do ROUTER WAN CUST, porém ao fazer testes iniciando do ROUTER2 também tinhamos uma quantidade alta de perda, a príncipio eliminando a possibilidade de ser algo no segmento anteriormente suspeito.

Ao analisar o resultado das falhas de ping do ROUTER2 notamos algo estranho, ele não simplemente perdia os pacotes por time-out mas sim por algum outro motivo, vejam a imagem:

Pesquisando um pouco descobrimos que a mensagem icmp !Q era enviada quando o servidor estava com seu buffer estava cheio e não conseguia lidar com todos os pings enviados para ele, essa mensagem solicita ao host que está enviando os pacotes que o mesmo diminuia a velocidade de envio.

Outra informação importante é que, embora no firewall ele não definisse os pacotes como perdidos também estávamos recebendo pacotes de ICMP source-quench, segue um exemplo dos logs que víamos no firewall.

FIREWALL[admin]# ping -s 1400 XXX.XXX.XXX.177
PING XXX.XXX.XXX.177 (XXX.XXX.XXX.177): 1400 data bytes
1408 bytes from XXX.XXX.XXX.177: icmp_seq=0 ttl=255 time=2.025 ms
1408 bytes from XXX.XXX.XXX.177: icmp_seq=1 ttl=255 time=0.343 ms
1408 bytes from XXX.XXX.XXX.177: icmp_seq=2 ttl=255 time=0.336 ms
1408 bytes from XXX.XXX.XXX.177: icmp_seq=3 ttl=255 time=3.196 ms
...
1408 bytes from XXX.XXX.XXX.177: icmp_seq=50 ttl=255 time=0.334 ms
1408 bytes from XXX.XXX.XXX.177: icmp_seq=51 ttl=255 time=0.312 ms
1408 bytes from XXX.XXX.XXX.177: icmp_seq=52 ttl=255 time=0.672 ms
1408 bytes from XXX.XXX.XXX.177: icmp_seq=53 ttl=255 time=1.046 ms
1408 bytes from XXX.XXX.XXX.177: icmp_seq=54 ttl=255 time=0.344 ms
92 bytes from XXX.XXX.XXX.177: Source Quench
Vr HL TOS Len ID Flg off TTL Pro cks Src Dst
4 5 00 0594 00e4 0 0000 40 01 f861 XXX.XXX.XXX.10 XXX.XXX.XXX.177

1408 bytes from XXX.XXX.XXX.177: icmp_seq=55 ttl=255 time=0.456 ms
92 bytes from XXX.XXX.XXX.177: Source Quench
Vr HL TOS Len ID Flg off TTL Pro cks Src Dst
4 5 00 0594 010c 0 0000 40 01 f839 XXX.XXX.XXX.10 XXX.XXX.XXX.177

1408 bytes from XXX.XXX.XXX.177: icmp_seq=56 ttl=255 time=0.362 ms
92 bytes from XXX.XXX.XXX.177: Source Quench
Vr HL TOS Len ID Flg off TTL Pro cks Src Dst
4 5 00 0594 0132 0 0000 40 01 f813 XXX.XXX.XXX.10 XXX.XXX.XXX.177

1408 bytes from XXX.XXX.XXX.177: icmp_seq=57 ttl=255 time=0.276 ms
92 bytes from XXX.XXX.XXX.177: Source Quench
Vr HL TOS Len ID Flg off TTL Pro cks Src Dst
4 5 00 0594 0154 0 0000 40 01 f7f1 XXX.XXX.XXX.10 XXX.XXX.XXX.177

1408 bytes from XXX.XXX.XXX.177: icmp_seq=58 ttl=255 time=0.314 ms
92 bytes from XXX.XXX.XXX.177: Source Quench
Vr HL TOS Len ID Flg off TTL Pro cks Src Dst
4 5 00 0594 0178 0 0000 40 01 f7cd XXX.XXX.XXX.10 XXX.XXX.XXX.177

1408 bytes from XXX.XXX.XXX.177: icmp_seq=59 ttl=255 time=0.286 ms
92 bytes from XXX.XXX.XXX.177: Source Quench
Vr HL TOS Len ID Flg off TTL Pro cks Src Dst
4 5 00 0594 01a1 0 0000 40 01 f7a4 XXX.XXX.XXX.10 XXX.XXX.XXX.177

1408 bytes from XXX.XXX.XXX.177: icmp_seq=60 ttl=255 time=2.355 ms
92 bytes from XXX.XXX.XXX.177: Source Quench
Vr HL TOS Len ID Flg off TTL Pro cks Src Dst
4 5 00 0594 01c8 0 0000 40 01 f77d XXX.XXX.XXX.10 XXX.XXX.XXX.177

1408 bytes from XXX.XXX.XXX.177: icmp_seq=61 ttl=255 time=0.333 ms
92 bytes from XXX.XXX.XXX.177: Source Quench
Vr HL TOS Len ID Flg off TTL Pro cks Src Dst
4 5 00 0594 01ee 0 0000 40 01 f757 XXX.XXX.XXX.10 XXX.XXX.XXX.177

1408 bytes from XXX.XXX.XXX.177: icmp_seq=62 ttl=255 time=0.592 ms
92 bytes from XXX.XXX.XXX.177: Source Quench
Vr HL TOS Len ID Flg off TTL Pro cks Src Dst
4 5 00 0594 020f 0 0000 40 01 f736 XXX.XXX.XXX.10 XXX.XXX.XXX.177

Para forçar esse log a aparecer de maneira mais constante, usamos a opção de ping “flood” (ping host -f), ao fazer isso constatamos que o comportamento do servidor era o mesmo tanto para o router quanto para o firewall, que estava diretamente conectado.

Após verificação da saúde do servidor (CPU, memória, velocidade da placa de rede, erros na interface) começamos a investigar outros motivos para que essa mensagem possa ser enviada que não envolvam o servidor não estar “aguentando” a taxa de pings enviados. O servidor em questão era um HP-UX e isso nos trouxe alguns artigos interessantes.

Descobrimos que havia uma certa proteção interna nos servidores HP-UX e que havia um meio de desativar essa proteção, dada a natureza do nosso teste (envio de repetidos pings a partir de um router, que tem uma taxa de envio bem alta, certamente isso estava atrapalhando os testes. Após desabilitar a proteção seguindo o conselho de um dos blogs (Set “Source quench” to 0 as “ndd -set /dev/ip ip_send_souce_quench 0” and include this parameter inside “nddconf” file.) refizemos os testes, com os seguintes resultados:

ROUTER WAN PARC, WEB SERVER: 25%
ROUTER1, WEB SERVER: 25%
ROUTER2, WEB SERVER: 0%
ROUTER WAN CUST, WEB SERVER: 0%
FW CLIENTE: 0%

Agora sim, uma vez removido o fator “source-quench” que estava mascarando os resultados conseguimos isolar em que trecho da rede estava o real problema de lentidão. O ISP investigou o problema e informou que o problema estava com uma política de QoS nesse trecho, uma vez removida a política as perdas pararam e o acesso Web voltou ao patamar esperado (cerca de 2s).

Referências
Understanding the Ping and Traceroute Commands
HttpWatch
ICMP Source Quench
HP-UX ping source quench

Deixe um comentário »

Nenhum comentário ainda.

RSS feed for comments on this post. TrackBack URI

Deixe um comentário

Preencha os seus dados abaixo ou clique em um ícone para log in:

Logotipo do WordPress.com

Você está comentando utilizando sua conta WordPress.com. Sair / Alterar )

Imagem do Twitter

Você está comentando utilizando sua conta Twitter. Sair / Alterar )

Foto do Facebook

Você está comentando utilizando sua conta Facebook. Sair / Alterar )

Foto do Google+

Você está comentando utilizando sua conta Google+. Sair / Alterar )

Conectando a %s

Blog no WordPress.com.

%d blogueiros gostam disto: