Chronométrage psql via un VPN : séparer l’attente réseau du travail de la requête

Votre rapport se termine en une seconde environ sur l’hôte de la base de données et en quatre via le VPN, et le chiffre que psql affiche pointe droit vers la base de données. Ce chiffre est un chronomètre côté client, pas une mesure du serveur. Il couvre l’instruction à l’aller, l’attente d’une réponse et les lignes au retour. Séparer ces trois choses est le seul moyen de savoir quel côté régler.

Ce que le minuteur de psql mesure vraiment

\timing on démarre un chronomètre juste avant que le client n’écrive l’instruction dans la socket et l’arrête quand la dernière ligne de ce résultat a été lue. L’exécution du serveur lui-même se trouve quelque part dans cette fenêtre, tout comme chaque milliseconde que les paquets passent dans le tunnel. Rien dans la sortie ne les sépare. EXPLAIN imprime aussi un chiffre, mais celui-ci est produit par le serveur et exclut l’attente du client. Deux chiffres, deux questions différentes.

Lancez une session, laissez la mesure active et exécutez l’instruction qui vous intéresse depuis l’intérieur. Réutiliser une session garde le coût de connexion hors de la première mesure.

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';"

Le chiffre inclut encore le transfert du résultat, ce qui est voulu ici. Il n’inclut plus l’échange de connexion et d’authentification qu’une nouvelle invocation ajouterait.

Comparez une instruction sur trois chemins

Exécutez la même instruction via la socket Unix, via l’adresse LAN et via le nom d’hôte VPN, puis comparez les trois. Si seule la dernière est lente, la requête n’est pas la variable.

Chaque invocation se connecte d’abord et ne mesure l’instruction qu’ensuite, donc le coût de connexion reste hors du chiffre tandis que le transfert reste dedans. Gardez la clause WHERE, le nombre de lignes et la machine cliente identiques, sinon vous comparez des charges de travail et non des chemins.

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;"

Sur un LAN, la différence est généralement assez faible pour être ignorée ; via un VPN, elle ne l’est souvent pas. Trier les trois résultats vous dit ensuite quelle attente attaquer.

Une socket locale lente signifie du travail serveur ou de la planification. Un résultat LAN lent signifie la requête ou le volume qu’elle déplace. Seul un résultat VPN lent signifie de la latence, du MTU ou de la bande passante disponible sur le chemin, et aucun changement d’index n’y remédie.

Extraire le temps d’exécution du serveur lui-même

Le serveur peut indiquer le temps qu’il a passé, et c’est ce chiffre qu’il faut comparer à celui du client. EXPLAIN avec ANALYZE exécute l’instruction et imprime le temps de planification et d’exécution dans le plan, tandis que BUFFERS ajoute le comportement du cache qui explique souvent une exécution à chaud face à une exécution à froid. Ne le pointez pas vers des instructions d’écriture sans intention d’écrire. Sur une réplique en lecture seule, c’est l’endroit le plus sûr pour commencer, et la référence psql documente la portée du minuteur côté client.

Pour les instructions que l’application exécute déjà, pg_stat_statements agrège l’exécution côté serveur sans rien réexécuter. Les lignes sont par requête normalisée, donc une entrée peut couvrir plusieurs sites d’appel.

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

Les noms de colonnes varient selon la version : PostgreSQL 13 et ultérieur exposent mean_exec_time, tandis que les versions antérieures l’appellent mean_time, alors vérifiez avec \d pg_stat_statements si cette requête renvoie une erreur. Ces valeurs excluent la planification et excluent le trajet jusqu’à votre client. Cette exclusion est précisément pourquoi elles sont utiles pour la comparaison.

Comptez les allers-retours, pas seulement les millisecondes

Un rapport construit à partir de deux cents petites instructions dépendantes multiplie par deux cents toute latence ajoutée par le chemin. Une seule instruction qui renvoie un million de lignes paie cette latence une fois puis paie de la bande passante longtemps. Les deux se ressemblent dans un minuteur client, et ils demandent des corrections opposées.

Mesurez le nombre d’instructions au lieu de l’estimer. Lisez le total, exécutez le rapport une fois, relisez-le puis soustrayez.

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

Si le delta est important et que chaque instruction est bon marché sur le serveur, le regroupement est la correction qui paie. Combinez les requêtes dépendantes, utilisez une seule instruction basée sur des ensembles ou pilotez la boucle depuis un curseur. Dans psql interactif, \set FETCH_COUNT 1000 fait arriver un gros résultat par lots et change le comportement du transfert et de la mémoire du client. Cela ne réduit pas le travail du serveur, donc cela ne sauvera pas une requête lente.

Vérifiez le tunnel pour les retransmissions et les blocages de MTU

Quand les petites instructions sont rapides et que les gros résultats bloquent à mi-chemin, la requête est généralement correcte et le chemin non. Un tunnel dont le MTU est inférieur au lien sous-jacent, combiné à un ICMP bloqué, produit exactement ce schéma : les premiers paquets arrivent, les gros disparaissent et le transfert reste suspendu jusqu’à ce qu’il réessaie. Les compteurs de retransmission côté client le montrent.

Surveillez la socket et les compteurs du noyau pendant qu’un transfert volontairement lent s’exécute. Les totaux de retransmission sont cumulatifs, donc notez-les avant et après plutôt que de lire un seul échantillon.

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

Les retransmissions qui montent pendant le transfert, avec un ping qui réussit à 1400 octets mais échoue à 1472, indiquent un problème de MTU plutôt qu’un problème de base de données. Baisser le MTU de l’interface du tunnel ou brider le MSS à la passerelle est la correction habituelle, et les mêmes trois commandes le confirment ensuite. Si les retransmissions restent plates alors que le transfert est encore lent, regardez la bande passante autorisée au tunnel plutôt que les pertes.

Une courte séquence couvre le prochain rapport lent : comparez une instruction en local, sur le LAN et via le VPN ; lisez l’exécution du serveur depuis EXPLAIN ou pg_stat_statements ; comptez les appels avant et après une seule exécution ; et surveillez les retransmissions pendant que le gros résultat circule. Chaque étape écarte un côté du chemin. Aucune n’exige de deviner quel composant redémarrer.