A Importância da Validação em Janela — Tshoot 02

Álcool gel… Syn, syn-ack, ack!!! (pa dum tss)…

Fala pessoal!! Interrompemos a programação normal para conversarmos sobre um caso real de troubleshoot que apareceu para mim. Lembrando que você pode encontrar todos os meus posts publicados neste link. Recomendo que sejam lidos na ordem, caso você tenha chegado agora.

E como sempre, fiquem ligados no TechRebels e sigam-me no Medium clicando follow lá em cima para acompanhar os próximos posts.

Interrompemos a programação normal dos artigos para um relato de um caso de troubleshoot que trouxe à tona um velho problema dos profissionais de TI: A validação das atividades em janela! Neste caso real, irei contar para vocês como o problema foi inicialmente relatado, o que se passou em minha cabeça e claro, o que foi feito para resolver!

Por conta do timing e também como forma de preservar NDAs, não teremos vídeo. Peço desculpas e agradeço a compreensão.

Então, como sempre, prepare seu café ou coca-cola geladinha e vamos nessa!

De forma alguma esse relato de troubleshoot (e os futuros que puderem vir a existir) tem como objetivo apontar o dedo na cara de ninguém ou muito menos o de achar “o culpado”. Meu objetivo aqui é o de puramente relatar o que se passou pela minha cabeça e as preocupações técnicas que tive. Todos nós somos humanos e, portanto, passíveis de erro. Principalmente eu que vos falo.

Tudo começou em uma janela de manutenção executada durante a madrugada do dia 14/04/2020. Tratava-se da migração de um contexto com 23 aplicações balanceadas em um antigo ACE para um par de BIG-IPs em ativo/standby.

Scripts aplicados e aplicações validadas em janela tivemos o sinal verde para encerrar a atividade com sucesso.

Avancemos no tempo em 11 dias…

Logo pela manhã, o cliente me liga informando que temos um problema no ambiente migrado. Uma das aplicações não estaria funcionando corretamente.

Quando questiono qual erro ou comportamento está apresentando, me enviam a seguinte mensagem de log:

INFO,24 Apr 2020 09:58:02,825,[XL_INTG.OID],com.thortech.xl.integration.OID.tcUtilOIDUserOperations:modifyUser(S,S,S,S) Returning with code: USER_UPDATE_SUCCESSFUL  for cn=xxxxxx
20/04/24 09:58:03 Running Get Lookup Values
20/04/24 09:58:03 Running Set User Password
ERROR,24 Apr 2020 09:58:03,377,[xxxxx.yyyy],Communication Errorsimple bind failed: 10.32.xx.xx:636

Junto do erro, sou informado também que esse erro aparece no log de um dos nodes de uma das aplicações. Chamaremos esse node de 10.51.xx.xx.

De posse dessas duas informações, meu entendimento sobre o problema é que o node 10.51.xx.xx está tentando acessar algo no servidor 10.32.xx.xx na porta 636 e está tendo problemas.

Meu primeiro instinto é verificar qual VS do ambiente migrado balancearia 10.32.xx.xx na porta 636. E para minha surpresa não tínhamos tal VS, ou seja, esse era um fluxo secundário apenas roteado pelo BIG-IP.

Olhando a topologia do ambiente, temos o seguinte:

Explicando isso para o time do cliente, ainda assim existia uma vontade de realizar o rollback da migração do dia 14 só para ter certeza. Estamos falando aqui de executar um rollback de uma atividade ocorrido há 11 dias atrás devido a uma aplicação (que é apenas roteada pelo BIG-IP). Lembrando que esse ambiente possui 23 outras aplicações funcionando perfeitamente.

Para tentar ajudar a evitar esse rollback, conectei no ambiente e solicitei um teste da aplicação problemática. Minha intenção era evidenciar ainda mais que:

1. O fluxo de fato era somente roteado pelo BIG-IP.
2. Com a captura tentar verificar o que poderia ser a causa raiz do problema e auxiliar os times envolvidos na resolução.

O tcpdump executado foi:

tcpdump -nni VLAN_174 host 10.51.xx.xx and port 636 -s0 app_issue.pcap

Assim que recebi o informe de que o erro permanecia, coletei o pcap e analisei rapidamente.

Seguindo os detaques em vermelho temos o seguinte:

1. 3-way-handshake acontecendo entre o node 10.51.xx.xx e o server 10.32.xx.xx na porta 636. (frames 1 até 4).
2. Node 10.51.xx.xx iniciando uma conexão SSLv2, indicando que a transmissão é protegida.
3. O node 10.51.xx.xx informando um alerta fatal do TLSv1, indicando um problema com o certificado que ele recebeu do server 10.32.xx.xx.
4. O node 10.51.xx.xx enviando a finalização da conexão TCP (com o FIN=1). O que entendo ser o procedimento normal uma vez que a conexão TLS foi abortada, só restou o cleanup natural da conexão TCP.

Com essas informações, informei ao time do cliente que acreditava que poderia haver um problema com o certificado recebido, destaquei essas descobertas na captura de pacotes e perguntei se era possível verificar a aplicação pois entendia que não havia erros sendo introduzidos pelo BIG-IP, que estava apenas roteando esse fluxo.

Depois de passadas algumas horas, recebo um whatsapp do time do cliente informando que realmente houve uma mudança no certificado que o server 10.32.xx.xx envia e esse certificado novo não havia sido “liberado” no node 10.51.xx.xx. E que quando esse ajuste foi feito, o problema na aplicação foi resolvido.

Ufa!

Mas obviamente que eu não me aguentei e conectei no BIG-IP para ver o mesmo fluxo agora funcionando. Vamos lá?!

Novamente, vamos aos detaques em vermelho:

1. 3-way-handshake acontecendo entre o node 10.51.xx.xx e o server 10.32.xx.xx (frames 2 até 7).
2. O node 10.51.xx.xx enviando o SSLv2 client hello, determinando a criptografia da conexão. Até aqui temos a mesma mecânica da captura passada.
3. Opaaaa!! Aqui temos o avanço natural do processo de TLS com o node 10.51.xx.xx iniciando o key-exchange. Curiosidade: Reparem nesse frame a coluna “delta time” como está elevada. Essa coluna mostra o tempo decorrido desde o último pacote capturado. O último pacote capturado foi o ACK do server 10.32.xx.xx para o 10.51.xx.xx e o próximo passo natural para o node 10.51.xx.xx são os cálculos de key-exchange, que sabemos devido às nossas conversas sobre criptografia ser um passo custoso em CPU e por isso temos o delta time elevado. O node 10.51.xx.xx demorou para transmitir algo pois estava calculando/gerando esse pacote.
4. O node 10.51.xx.xx sinalizando o change cipher spec, sinalizando estar pronto para envio de dados usando criptografia em massa (bulk encryption).
5. O Server 10.32.xx.xx sinalizando também o change cipher spec.

Ou seja, conexão TCP OK, conexão TLS também OK. A partir dali é tráfego 100% criptografado e não teríamos como ver nada, afinal, para esse fluxo, o BIG-IP é somente o roteador.

Esse comportamento confirma o que me foi informado: havia alguma correção a ser feita com o certificado para que o node 10.51.xx.xx pudesse seguir com a conexão TLS. Depois da correção feita, vemos o estabeleciomento normal desse fluxo e a aplicação funcionando conforme esperado.

Sabemos que a validação das aplicações deveria acontecer preferencialmente antes e depois das atividades. Infelizmente nem sempre isso é possível por “n” razões e particularidades de cada projeto. Mas certamente esses passos extras nos salvariam dores de cabeça como essa.

Algo que considero muito importante — além de muita calma nessas horas — é conseguir reproduzir o problema enquanto se monitora (nesse caso, o tcpdump do problema acontecendo). E, se possível, um tcpdump após o problema resolvido para conseguimos evidenciar e confirmar diversos entendimentos e sairmos do “está resolvido então está bom”.

Me lembrei de um ditado que li uma vez na internet: Os pacotes nunca mentem.

Sobre o autor

Rafael Bianco Nacif é analista de redes sênior. Graduado em Redes de Computadores, certificado 2xF5 Solutions Expert (Cloud/Sec), Cisco CCNP DC e RS e também AWS CSA. Iniciou a carreira na área de TI como help-desk e hoje atua em projetos de DC de alta complexidade. linkedin.com/in/rafaelbn