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.

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/
  1. Reinicie a aplicação e refaça os testes.

  2. 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.

DadoDescriçã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.

Last updated