Medir o tempo do psql por VPN: separar a espera de rede do trabalho da consulta

O seu relatório termina em cerca de um segundo no host do banco de dados e em quatro pela VPN, e o número que o psql imprime aponta directamente para o banco de dados. Esse número é um cronómetro do lado do cliente, não uma medição do servidor. Abrange a instrução na saída, a espera por uma resposta e as linhas no regresso. Separar esses três é a única forma de saber que lado ajustar.

O que o temporizador do psql mede realmente

\timing on inicia um cronómetro mesmo antes de o cliente escrever a instrução no socket e pára-o quando a última linha desse resultado foi lida. A execução do próprio servidor está algures dentro dessa janela, e também cada milissegundo que os pacotes passam no túnel. Nada na saída os separa. O EXPLAIN também imprime um número, mas esse é produzido pelo servidor e exclui a espera do cliente. Dois números, duas perguntas diferentes.

Inicie uma sessão, deixe a medição ligada e execute a instrução que lhe interessa de dentro dela. Reutilizar uma sessão mantém o custo da conexão fora da primeira medição.

psql "host=db.internal port=5432 dbname=appdb user=app" \
  -c "\timing on" \
  -c "select count(*) from orders where created_at > now() - interval '1 day';"

O número ainda inclui a transferência do resultado, que é o que se pretende aqui. Já não inclui a troca de conexão e autenticação que uma nova invocação acrescentaria.

Compare uma instrução por três caminhos

Execute a mesma instrução pelo socket Unix, pelo endereço LAN e pelo nome de host VPN, e compare os três. Se apenas o último for lento, a consulta não é a variável.

Cada invocação liga-se primeiro e só depois mede a instrução, por isso o custo da conexão fica fora do número enquanto a transferência fica dentro. Mantenha a cláusula WHERE, a contagem de linhas e a máquina cliente idênticas, ou está a comparar cargas de trabalho em vez de caminhos.

psql -h /var/run/postgresql -U app -d appdb -c "\timing on" -c "select count(*) from orders;"
psql -h 10.40.0.12 -U app -d appdb -c "\timing on" -c "select count(*) from orders;"
psql -h db.vpn.internal -U app -d appdb -c "\timing on" -c "select count(*) from orders;"

Numa LAN a diferença costuma ser pequena o suficiente para ignorar; por VPN muitas vezes não é. Ordenar os três resultados diz-lhe depois contra que espera atacar.

Um socket local lento significa trabalho do servidor ou planeamento. Um resultado LAN lento significa a consulta ou o volume que ela move. Só um resultado VPN lento significa latência, MTU ou largura de banda disponível no caminho, e nenhuma alteração de índice o resolve.

Extraia o tempo de execução do próprio servidor

O servidor pode reportar quanto tempo passou, e é esse número que deve ser comparado com o do cliente. O EXPLAIN com ANALYZE executa a instrução e imprime o tempo de planeamento e execução dentro do plano, enquanto o BUFFERS acrescenta comportamento de cache que muitas vezes explica uma execução quente face a uma fria. Não o aponte a instruções de escrita a menos que pretenda escrever. Numa réplica só de leitura é o local mais seguro para começar, e a referência do psql documenta o âmbito do temporizador do lado do cliente.

Para instruções que a aplicação já executa, o pg_stat_statements agrega a execução do lado do servidor sem voltar a executar nada. As linhas são por consulta normalizada, por isso uma entrada pode abranger vários pontos de chamada.

select calls, round(mean_exec_time::numeric, 2) as mean_ms, rows
from pg_stat_statements
order by mean_exec_time desc
limit 5;

Os nomes das colunas variam consoante a versão: o PostgreSQL 13 e posteriores expõem mean_exec_time, enquanto as versões antigas lhe chamam mean_time, por isso verifique com \d pg_stat_statements se essa consulta der erro. Estes valores excluem o planeamento e excluem a viagem até ao seu cliente. É precisamente essa exclusão que os torna úteis para a comparação.

Conte as idas e voltas, não apenas os milissegundos

Um relatório construído com duzentas instruções pequenas dependentes multiplica por duzentas qualquer latência acrescentada pelo caminho. Uma única instrução que devolve um milhão de linhas paga essa latência uma vez e depois paga largura de banda durante muito tempo. Ambas parecem iguais num temporizador de cliente, e precisam de correções opostas.

Meça a contagem de instruções em vez de a estimar. Leia o total, execute o relatório uma vez, volte a lê-lo e subtraia.

select sum(calls) as calls from pg_stat_statements;
-- run the report here
select sum(calls) as calls from pg_stat_statements;

Se o delta for grande e cada instrução for barata no servidor, o agrupamento é a correção que compensa. Combine consultas dependentes, use uma única instrução baseada em conjuntos ou conduza o ciclo a partir de um cursor. No psql interactivo, \set FETCH_COUNT 1000 faz com que um resultado grande chegue em lotes e altera o comportamento da transferência e da memória do cliente. Não reduz o trabalho do servidor, por isso não salvará uma consulta lenta.

Verifique o túnel quanto a retransmissões e paragens de MTU

Quando as instruções pequenas são rápidas e os resultados grandes param a meio caminho, a consulta está normalmente bem e o caminho não. Um túnel cujo MTU é inferior à ligação subjacente, combinado com ICMP bloqueado, produz exactamente esse padrão: os primeiros pacotes chegam, os grandes desaparecem e a transferência fica pendurada até tentar de novo. Os contadores de retransmissão do lado do cliente mostram-no.

Observe o socket e os contadores do kernel enquanto decorre uma transferência deliberadamente lenta. Os totais de retransmissão são cumulativos, por isso anote-os antes e depois em vez de ler uma única amostra.

ss -tin dst 10.40.0.12
netstat -s | grep -iE "retransmit|segments retransmitted"
ping -M do -s 1400 -c 3 10.40.0.12

As retransmissões que sobem durante a transferência, em conjunto com um ping que tem sucesso a 1400 bytes mas falha a 1472, apontam para um problema de MTU e não de base de dados. Baixar o MTU da interface do túnel ou limitar o MSS na gateway é a correção habitual, e os mesmos três comandos confirmam-no depois. Se as retransmissões ficarem planas enquanto a transferência continua lenta, olhe para a largura de banda permitida ao túnel e não para as perdas.

Uma sequência curta cobre o próximo relatório lento: compare uma instrução localmente, na LAN e pela VPN; leia a execução do servidor a partir do EXPLAIN ou do pg_stat_statements; conte as chamadas antes e depois de uma única execução; e observe as retransmissões enquanto o resultado grande se move. Cada passo exclui um lado do caminho. Nenhum exige adivinhar que componente reiniciar.