Pix HTTP performance

Este documento serve para o diagnóstico de problemas de performance utilizando as APIs de comunicação HTTP do módulo Pix do Dinamo.

Este fluxograma é destinado a resolução de problemas de performance. Para direcionamentos arquiteturais, veja o tópico Pix.

O diagnóstico básico inicial pode ser feito utilizando o fluxograma abaixo.

Fluxo para diagnóstico

Análise de logs do cliente do HSM

1. Gerar os logs do client do HSM em depuração

Habilitar os logs da biblioteca cliente do HSM em depuração e com flush habilitado.

1. Definir a seguinte variável de ambiente com a pasta de destino. Lembre-se de definir uma pasta de destino sem o nome do arquivo. Para mais detalhes sobre como habilitar os logs, consulte o tópico Log.

HSM_LOG_DIR=/pasta_de_destino/

2. Reinicie a aplicação e refaça os testes.

3. Na pasta de destino dos logs, abrir o arquivo de log gerado. Deverá ter o nome tacndlib_xxxx.log, onde xxxx será o PID (Process ID) da aplicação.

2. Identificar as operações problemáticas

1. Identificar as operações consideradas lentas. É possível ver o tempo total da operação Pix HTTP no item total_time_ms da linha de log LogDebugRequestInfo.

2021/02/03 19:06:21 144E0000 0000008C 408e0e2f debug LogDebugRequestInfo fpos="m" name_lookup_time_ms=0.000047 connect_time_ms=0.000227 appconnect_time_ms=5.000350 pretransfer_time_ms=5.000403 starttransfer_time_ms=5.000554 total_time_ms=6.000215 redirect_time_ms=0.000000

3. Analisar os dados encontrados

Com os logs das operações problemáticas identificados é possível ver os pontos dentro da operação onde se gastou mais tempo.

Os logs de tempo da operação tem contadores em milissegundos que marcam o tempo entre o início da operação até o tempo do marcador. Por exemplo: connect_time_ms é o tempo do início da operação até o final da conexão com o servidor remoto. appconnect_time_ms é o tempo do início da operação até o final do handshake TLS. Para saber o tempo levado na operação de appconnect_time_ms, basta diminuir o tempo levado em connect_time_ms do tempo de appconnect_time_ms. Assim: tempo do handshake TLS = appconnect_time_ms - connect_time_ms.

Alguns dos pontos mais comuns que devem ser verificados.

• Tempo alto em appconnect_time_ms

  • Na primeira abertura de sessão é possível que se tenha um tempo maior em appconnect_time_ms. Isto acontece porque neste momento acontece o handshake TLS e o uso da chave no HSM, o que causa um tempo maior. Nas operações seguintes com a mesma sessão esse tempo deve ser baixo, porque que o túnel já está estabelecido e será reutilizado daqui pra frente.

  • Caso este tempo esteja extremamente alto, verificar a qualidade da conexão com o HSM.

  • Este é o único ponto da operação onde há comunicação com o HSM.

  • Caso as operações seguintes continuem com um tempo maior, verifique se os parâmetros de sessão estão habilitado corretamente; para detalhes consulte o tópico Sessões.

  • Caso continue com tempo alto, verificar se a sessão não está sendo reutilizada. O reuso de sessão um fator importante para performance.

• Tempo alto em starttransfer_time

  • Este contador marca o tempo do início da operação até o recebimento do primeiro byte. Pode indicar uma lentidão entre a comunicação com o servidor remoto.

  • Algumas possíveis causas são lentidão da rede, demora processamento do servidor remoto etc.

  • Em casos de erro o BACEN pode esperar um tempo de delay para enviar a resposta. Geralmente são tempos bem definidos. É possível ver casos de espera de 5 segundos neste ponto.

Outros pontos podem ser verificados para depurar as conexões. A tabela abaixo descreve as outras informações disponíveis nos logs.

Dado	Descrição
name_lookup_time_ms	Tempo decorrido entre o início da requisição até o final da resolução de nome. Tempo em milissegundos.
connect_time_ms	Tempo decorrido entre o início da requisição até o final conexão com o host remoto (ou proxy). Se houver redirecionamento o tempo é adicionado. Tempo em milissegundos.
appconnect_time_ms	Tempo decorrido entre o início da requisição até o final do handshake SSL/SSH com o host remoto. Tempo em milissegundos.
pretransfer_time_ms	Tempo decorrido entre o início da requisição até o momento imediatamente antes do envio dos dados. Se houver redirecionamento o tempo é adicionado. Tempo em milissegundos.
starttransfer_time_ms	Tempo decorrido entre o início da requisição até o momento do recebimento do primeiro byte. Se houver redirecionamento o tempo é adicionado. Tempo em milissegundos.
total_time_ms	Tempo total da requisição. Se houver redirecionamento o tempo é adicionado. Tempo em milissegundos.
redirect_time_ms	Tempo total levado nos redirecionamentos. Tempo em milissegundos.
content_length_upload	Tamanho do content-length no upload dos dados. Recuperado do campo Content-Length. Recebe -1 caso o tamanho não seja conhecido. Tamanho em bytes.
content_length_download	Tamanho do content-length no download dos dados. Recuperado do campo Content-Length. Recebe -1 caso o tamanho não seja conhecido. Tamanho em bytes.
upload_speed	Velocidade média do upload completo. Velocidade em bytes/segundo.
download_speed	Velocidade média do download completo. Velocidade em bytes/segundo.
download_size	Tamanho total do payload (body) do download. Os metadados e headers não entram nesta contagem. Tamanho em bytes.
upload_size	Tamanho total do payload (body) upload. Tamanho em bytes.
redirect_count	Contagem de redirecionamentos feitos.
num_connects	Contagem de conexões criadas para concluir a transferência anterior.
request_size	Tamanho total da requisição enviada. Tamanho em bytes.
received_header_size	Tamanho total de todos os headers recebidos. Tamanho em bytes.
http_response_code	Código de resposta HTTP da requisição. Será zero se nenhum código de resposta for recebido.