Pagsukat ng oras ng psql sa VPN: paghihiwalay ng paghihintay sa network sa gawain ng query

Ang ulat mo ay natatapos sa halos isang segundo sa host ng database at sa apat sa VPN, at ang bilang na ipinapakita ng psql ay direktang tumuturo sa database. Ang bilang na iyon ay stopwatch sa panig ng kliyente, hindi sukat ng server. Sinasaklaw nito ang pahayag sa paglabas, ang paghihintay ng sagot at ang mga hilera sa pagbabalik. Ang paghihiwalay ng tatlong ito ang tanging paraan para malaman kung aling panig ang aayusin.

Ano ang tunay na sinusukat ng timer ng psql

\timing on ay nagsisimula ng stopwatch bago pa isulat ng kliyente ang pahayag sa socket at humihinto kapag nabasa na ang huling hilera ng resultang iyon. Ang pagpapatupad ng server mismo ay nasa isang lugar sa loob ng bintanang iyon, gayundin ang bawat millisecond na ginugol ng mga packet sa tunnel. Walang anuman sa output ang naghihiwalay sa kanila. Naglilimbag din ang EXPLAIN ng bilang, ngunit iyon ay ginagawa ng server at hindi kasama ang paghihintay ng kliyente. Dalawang bilang, dalawang magkaibang tanong.

Magsimula ng isang session, iwanang bukas ang pagsukat ng oras, at patakbuhin ang pahayag na mahalaga sa iyo mula sa loob nito. Ang muling paggamit ng session ay naglalagay ng gastos ng koneksyon sa labas ng unang sukat.

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

Kasama pa rin sa bilang ang paglipat ng resulta, na siyang kailangan dito. Hindi na kasama ang palitan ng koneksyon at pagpapatotoo na idadagdag ng bagong tawag.

Ihambing ang isang pahayag sa tatlong landas

Patakbuhin ang parehong pahayag sa socket ng Unix, sa address ng LAN at sa pangalan ng host ng VPN, at ihambing ang tatlo. Kung ang huli lang ang mabagal, ang query ay hindi ang baryabol.

Ang bawat tawag ay kumokonekta muna at pagkatapos lang sinusukat ang pahayag, kaya nananatili sa labas ng bilang ang gastos ng koneksyon habang nasa loob ang paglipat. Panatilihing pareho ang sugnay na WHERE, ang bilang ng hilera at ang makinang kliyente, kung hindi, naghahambing ka ng karga ng trabaho at hindi ng landas.

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

Sa LAN ang pagkakaiba ay karaniwang sapat na maliit para balewalain; sa VPN ay madalas na hindi. Ang pagsasaayos ng tatlong resulta ay magsasabi sa iyo kung aling paghihintay ang sasaluhin.

Ang mabagal na lokal na socket ay nangangahulugan ng gawain ng server o pagpaplano. Ang mabagal na resulta sa LAN ay nangangahulugan ng query o ang dami na inililipat nito. Tanging mabagal na resulta sa VPN ang nangangahulugan ng latency, MTU o available na bandwidth sa landas, at walang pagbabago sa index ang makakapagtatama nito.

Kunin ang sariling oras ng pagpapatupad ng server

Maaaring iulat ng server kung gaano katagal siya gumugol, at iyon ang bilang na ihahambing sa bilang ng kliyente. Ang EXPLAIN na may ANALYZE ay nagpapatakbo ng pahayag at naglilimbag ng oras ng pagpaplano at pagpapatupad sa loob ng plano, habang ang BUFFERS ay nagdaragdag ng pag-uugali ng cache na madalas nagpapaliwanag ng mainit na takbo laban sa malamig. Huwag itong itutok sa mga pahayag ng pagsulat maliban kung balak mong magsulat. Sa replica na basahin lamang, ito ang pinakaligtas na lugar upang magsimula, at ang sanggunian ng psql ay nagdodokumento ng saklaw ng timer sa panig ng kliyente.

Para sa mga pahayag na pinapatakbo na ng aplikasyon, ang pg_stat_statements ay nangongolekta ng pagpapatupad sa panig ng server nang hindi nagpapatakbo ng anuman muli. Ang mga hilera ay bawat normalisadong query, kaya ang isang entry ay maaaring sumaklaw ng maraming lugar ng tawag.

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

Nagkakaiba ang mga pangalan ng hanay ayon sa release: ang PostgreSQL 13 at mas bago ay naglalabas ng mean_exec_time, habang ang lumang bersyon ay tinatawag itong mean_time, kaya suriin gamit ang \d pg_stat_statements kung ang query na iyon ay magbigay ng error. Hindi kasama ng mga halagang ito ang pagpaplano at hindi kasama ang paglalakbay patungo sa iyong kliyente. Ang pagbubukod na iyon ang dahilan kung bakit kapaki-pakinabang ang mga ito para sa paghahambing.

Bilangin ang pagpunta at pagbabalik, hindi lang millisecond

Ang ulat na binuo mula sa dalawang daang maliliit na pahayag na umaasa ay nagpaparami ng anumang latency na idinadagdag ng landas sa dalawang daan. Ang isang pahayag na nagbabalik ng isang milyong hilera ay nagbabayad ng latency na iyon nang isang beses at pagkatapos ay nagbabayad ng bandwidth nang matagal. Pareho silang nagmumukhang magkapareho sa timer ng kliyente, at kailangan nila ng magkasalungat na pagwawasto.

Sukatin ang bilang ng pahayag sa halip na tantiyahin ito. Basahin ang kabuuan, patakbuhin ang ulat nang isang beses, pagkatapos ay basahin muli at ibawas.

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

Kung malaki ang delta at mura ang bawat pahayag sa server, ang batching ang pagwawastong nagbabayad. Pagsamahin ang mga umaasang query, gumamit ng isang pahayag na batay sa set o patakbuhin ang loop mula sa cursor. Sa interactive na psql, \set FETCH_COUNT 1000 dumarating ang malaking resulta nang paunti-unti at binabago ang pag-uugali ng paglipat at memorya ng kliyente. Hindi nito binabawasan ang gawain ng server, kaya hindi nito ililigtas ang mabagal na query.

Suriin ang tunnel para sa muling pagpapadala at paghinto ng MTU

Kapag mabilis ang maliliit na pahayag at ang malalaking resulta ay humihinto sa kalagitnaan, ang query ay karaniwang maayos at ang landas ay hindi. Ang tunnel na mas mababa ang MTU kaysa sa pinagbabatayang link, kasama ang naka-block na ICMP, ay gumagawa ng eksaktong ganoong pattern: dumarating ang mga unang packet, nawawala ang malalaki, at nakabitin ang paglipat hanggang subukan muli. Ipinapakita ito ng mga counter ng muling pagpapadala sa panig ng kliyente.

Panoorin ang socket at ang mga counter ng kernel habang tumatakbo ang sadyang mabagal na paglipat. Ang mga kabuuan ng muling pagpapadala ay kumulatif, kaya itala ang mga ito bago at pagkatapos sa halip na magbasa ng isang sample.

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

Ang mga muling pagpapadala na tumataas habang naglilipat, kasama ang ping na nagtagumpay sa 1400 byte ngunit nabigo sa 1472, ay tumuturo sa problema ng MTU at hindi sa database. Ang pagbaba ng MTU ng interface ng tunnel o paghigpit ng MSS sa gateway ang karaniwang pagwawasto, at ang parehong tatlong utos ay nagpapatunay pagkatapos. Kung ang mga muling pagpapadala ay mananatiling patag habang mabagal pa rin ang paglipat, tingnan ang bandwidth na pinapayagan sa tunnel at hindi ang pagkalugi.

Ang maikling pagkakasunod-sunod ay sumasaklaw sa susunod na mabagal na ulat: ihambing ang isang pahayag nang lokal, sa LAN at sa VPN; basahin ang pagpapatupad ng server mula sa EXPLAIN o pg_stat_statements; bilangin ang mga tawag bago at pagkatapos ng isang takbo; at panoorin ang mga muling pagpapadala habang gumagalaw ang malaking resulta. Ang bawat hakbang ay nagbubukod ng isang panig ng landas. Wala sa mga ito ang nangangailangan ng hulaan kung aling bahagi ang i-restart.