psql-tidsmåling over en VPN: adskil netværksventetid fra forespørgselsarbejde

Din rapport bliver færdig på omkring et sekund på databaseserveren og på fire over VPN'en, og det tal psql udskriver peger direkte på databasen. Det tal er et stopur på klientsiden, ikke en servermåling. Det dækker sætningen på vej ud, ventetiden på et svar og rækkerne på vej tilbage. At dele de tre op er den eneste måde at vide, hvilken side der skal justeres.

Hvad psql-timeren egentlig måler

\timing on starter et stopur lige før klienten skriver sætningen til soklen og stopper, når den sidste række i resultatet er læst. Selve serverens udførelse ligger et sted inde i det vindue, og det gør hver millisekund, pakkerne bruger i tunnelen, også. Intet i outputtet skiller dem. EXPLAIN udskriver også et tal, men det produceres af serveren og udelukker klientens ventetid. To tal, to forskellige spørgsmål.

Start én session, lad tidsmålingen være slået til, og kør den sætning, du interesserer dig for, inde fra den. Genbrug af en session holder forbindelsesomkostningen ude af den første måling.

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

Tallet omfatter stadig overførslen af resultatet, hvilket er det, du vil have her. Det omfatter ikke længere forbindelses- og godkendelsesudvekslingen, som et nyt kald ville tilføje.

Sammenlign én sætning over tre veje

Kør den samme sætning over Unix-soklen, over LAN-adressen og over VPN-værtsnavnet, og sammenlign de tre. Hvis kun den sidste er langsom, er forespørgslen ikke variablen.

Hvert kald forbinder først og måler først derefter sætningen, så forbindelsesomkostningen bliver ude af tallet, mens overførslen bliver inde. Hold WHERE-klausulen, rækkeantallet og klientmaskinen identiske, ellers sammenligner du arbejdsbyrder i stedet for veje.

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

På et LAN er forskellen normalt lille nok til at ignorere; over en VPN er den det ofte ikke. At sortere de tre resultater fortæller dig derefter, hvilken ventetid du skal angribe.

En langsom lokal sokkel betyder serverarbejde eller planlægning. Et langsomt LAN-resultat betyder forespørgslen eller det volumen, den flytter. Kun et langsomt VPN-resultat betyder latenstid, MTU eller tilgængelig båndbredde på vejen, og ingen indeksændringer retter det.

Hent serverens egen udførelsestid

Serveren kan rapportere, hvor lang tid den brugte, og det tal er det, du skal holde op mod klientens. EXPLAIN med ANALYZE kører sætningen og udskriver planlægnings- og udførelsestid inde i planen, mens BUFFERS tilføjer cacheadfærd, som ofte forklarer en varm kørsel mod en kold. Ret det ikke mod skrive-sætninger, medmindre du har tænkt dig at skrive. På en skrivebeskyttet replika er det det sikreste sted at begynde, og den psql-reference dokumenterer timerens omfang på klientsiden.

For sætninger, som applikationen allerede kører, samler pg_stat_statements udførelsen på serversiden uden at køre noget igen. Rækkerne er pr. normaliseret forespørgsel, så en post kan dække flere kaldesteder.

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

Kolonnenavne varierer efter version: PostgreSQL 13 og nyere eksponerer mean_exec_time, mens ældre versioner kalder det mean_time, så tjek med \d pg_stat_statements, hvis den forespørgsel giver en fejl. Disse værdier udelukker planlægning og udelukker turen til din klient. Netop den udelukkelse er grunden til, at de er nyttige til sammenligningen.

Tæl rundture, ikke kun millisekunder

En rapport bygget af to hundrede små afhængige sætninger ganger den latenstid, vejen tilføjer, med to hundrede. En enkelt sætning, der returnerer en million rækker, betaler den latenstid én gang og betaler derefter båndbredde i lang tid. Begge ser identiske ud i en klienttimer, og de kræver modsatte rettelser.

Mål antallet af sætninger i stedet for at gætte det. Læs totalen, kør rapporten én gang, læs den så igen og træk fra.

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

Hvis deltaet er stort, og hver sætning er billig på serveren, er batching den rettelse, der betaler sig. Kombiner afhængige forespørgsler, brug én sætningsbaseret forespørgsel, eller styr løkken fra en markør. I interaktiv psql, \set FETCH_COUNT 1000 får et stort resultat til at ankomme i portioner og ændrer, hvordan overførslen og klienthukommelsen opfører sig. Det reducerer ikke serverarbejde, så det redder ikke en langsom forespørgsel.

Tjek tunnelen for gensendinger og MTU-stop

Når små sætninger er hurtige, og store resultater stopper halvvejs, er forespørgslen som regel i orden, og vejen er det ikke. En tunnel, hvis MTU er lavere end det underliggende link, kombineret med blokeret ICMP, giver præcis det mønster: de første pakker ankommer, de store forsvinder, og overførslen hænger, indtil den prøver igen. Gensendelsestællere på klientsiden viser det.

Hold øje med soklen og kernetællerne, mens en bevidst langsom overførsel kører. Gensendelsessummer er kumulative, så noter dem før og efter i stedet for at læse én prøve.

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

Gensendinger, der stiger under overførslen, sammen med en ping, der lykkes ved 1400 byte men fejler ved 1472, peger på et MTU-problem snarere end et databaseproblem. At sænke tunnelinterfacet MTU eller klemme MSS ved gatewayen er den sædvanlige rettelse, og de samme tre kommandoer bekræfter det bagefter. Hvis gensendingerne forbliver flade, mens overførslen stadig er langsom, så se på den båndbredde, tunnelen får lov at bruge, snarere end på tab.

En kort sekvens dækker den næste langsomme rapport: sammenlign én sætning lokalt, på LAN og over VPN; læs serverudførelse fra EXPLAIN eller pg_stat_statements; tæl kald før og efter én kørsel; og hold øje med gensendinger, mens det store resultat flytter sig. Hvert skridt udelukker den ene side af vejen. Ingen af dem kræver at gætte, hvilken komponent der skal genstartes.