Měření času psql přes VPN: oddělení čekání sítě od práce dotazu

Váš report skončí přibližně za sekundu na hostiteli databáze a za čtyři přes VPN, a číslo, které psql vypíše, ukazuje přímo na databázi. To číslo je stopky na straně klienta, ne měření serveru. Zahrnuje příkaz na cestě ven, čekání na odpověď a řádky na cestě zpět. Oddělit tyto tři věci je jediný způsob, jak zjistit, kterou stranu ladit.

Co časovač psql skutečně měří

\timing on spustí stopky těsně předtím, než klient zapíše příkaz do socketu, a zastaví je, když je přečten poslední řádek výsledku. Vlastní provádění serveru leží někde uvnitř tohoto okna a stejně tak každá milisekunda, kterou pakety stráví v tunelu. Nic ve výstupu je neodděluje. EXPLAIN také vypisuje číslo, ale to vytváří server a vylučuje čekání klienta. Dvě čísla, dvě různé otázky.

Spusťte jednu relaci, nechte měření zapnuté a spusťte příkaz, který vás zajímá, zevnitř ní. Opětovné použití relace drží cenu připojení mimo první měření.

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

Číslo stále zahrnuje přenos výsledku, což je zde to, co chcete. Už nezahrnuje výměnu připojení a ověření, kterou by přidal nový příkaz.

Porovnejte jeden příkaz na třech cestách

Spusťte stejný příkaz přes Unix socket, přes LAN adresu a přes název hostitele VPN a porovnejte všechny tři. Pokud je pomalá jen poslední, dotaz není proměnná.

Každé volání se nejprve připojí a teprve potom měří příkaz, takže cena připojení zůstává mimo číslo, zatímco přenos zůstává uvnitř. Držte klauzuli WHERE, počet řádků i klientský stroj stejné, jinak porovnáváte pracovní zátěž, a ne cesty.

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

V LAN je rozdíl obvykle dost malý na to, aby se zanedbal; přes VPN často ne. Setřídění tří výsledků vám pak řekne, na které čekání zaútočit.

Pomalý místní socket znamená práci serveru nebo plánování. Pomalý výsledek v LAN znamená dotaz nebo objem, který přenáší. Jen pomalý výsledek přes VPN znamená latenci, MTU nebo dostupnou šířku pásma na cestě a žádné změny indexů to nespraví.

Vytáhněte vlastní dobu provádění serveru

Server umí oznámit, kolik času strávil, a právě toto číslo je třeba srovnávat s klientským. EXPLAIN s ANALYZE spustí příkaz a vypíše čas plánování a provádění uvnitř plánu, zatímco BUFFERS přidává chování mezipaměti, které často vysvětluje teplý běh proti studenému. Neobracejte to na zapisovací příkazy, pokud nechcete zapisovat. Na replice pouze pro čtení je to nejbezpečnější místo pro začátek a referenční příručka psql dokumentuje rozsah časovače na straně klienta.

Pro příkazy, které aplikace už spouští, pg_stat_statements agreguje provádění na straně serveru, aniž by cokoli spouštěl znovu. Řádky jsou po normalizovaném dotazu, takže jeden záznam může pokrýt několik míst volání.

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

Názvy sloupců se liší podle verze: PostgreSQL 13 a novější vystavují mean_exec_time, zatímco starší verze mu říkají mean_time, takže zkontrolujte pomocí \d pg_stat_statements, pokud tento dotaz vrátí chybu. Tyto hodnoty vylučují plánování a vylučují cestu k vašemu klientovi. Právě toto vyloučení je činí užitečnými pro srovnání.

Počítejte zpáteční cesty, ne jen milisekundy

Report složený ze dvou set malých závislých příkazů násobí jakoukoli latenci, kterou cesta přidá, dvěma sty. Jediný příkaz vracející milion řádků zaplatí tuto latenci jednou a pak dlouho platí šířku pásma. Oba vypadají v klientském časovači stejně a potřebují opačné opravy.

Změřte počet příkazů, místo abyste ho odhadovali. Přečtěte součet, jednou spusťte report, pak ho přečtěte znovu a odečtěte.

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

Pokud je delta velká a každý příkaz je na serveru levný, dávkování je oprava, která se vyplatí. Zkombinujte závislé dotazy, použijte jediný příkaz nad množinou nebo veďte smyčku z kurzoru. V interaktivním psql, \set FETCH_COUNT 1000 nutí velký výsledek přicházet v dávkách a mění chování přenosu i klientské paměti. Nesnižuje práci serveru, takže pomalý dotaz nezachrání.

Zkontrolujte tunel na opakované přenosy a zaseknutí MTU

Když jsou malé příkazy rychlé a velké výsledky se zaseknou v polovině, dotaz bývá v pořádku a cesta ne. Tunel s nižším MTU, než má podkladové spojení, v kombinaci s blokovaným ICMP vytváří přesně takový vzorec: první pakety dorazí, velké zmizí a přenos visí, dokud to znovu nezkusí. Počítadla opakovaných přenosů na straně klienta to ukazují.

Sledujte socket a počítadla jádra, zatímco běží záměrně pomalý přenos. Součty opakovaných přenosů jsou kumulativní, takže si je poznamenejte před a po, místo abyste četli jeden vzorek.

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

Opakované přenosy, které během přenosu rostou, spolu s pingem, který uspěje při 1400 bajtech, ale selže při 1472, ukazují na problém s MTU, ne s databází. Snížení MTU rozhraní tunelu nebo sevření MSS na bráně je obvyklá oprava a stejné tři příkazy to poté potvrdí. Pokud opakované přenosy zůstávají ploché, zatímco přenos je stále pomalý, dívejte se na šířku pásma povolenou tunelu, ne na ztráty.

Krátká posloupnost pokrývá další pomalý report: porovnejte jeden příkaz lokálně, v LAN a přes VPN; přečtěte provádění serveru z EXPLAIN nebo pg_stat_statements; spočítejte volání před jedním spuštěním a po něm; a sledujte opakované přenosy, zatímco se velký výsledek pohybuje. Každý krok vylučuje jednu stranu cesty. Žádný z nich nevyžaduje hádat, kterou komponentu restartovat.