Introduktion til auto_explain:Sådan logger du automatisk langsomme Postgres-forespørgselsplaner

Vil du vide, hvorfor en PostgreSQL-forespørgsel er langsom? Så er EXPLAIN ANALYZE et godt udgangspunkt. Men forespørgselsplaner kan afhænge af anden serveraktivitet, kan tage et stykke tid at køre og kan ændre sig over tid, så hvis du vil se de faktiske udførelsesplaner for dine langsomste forespørgsler, er auto_explain det værktøj, du har brug for. I dette indlæg vil vi se på, hvad det gør, hvordan man konfigurerer det, og hvordan man bruger disse logfiler til at fremskynde dine forespørgsler.

Hvad er auto_explain?

auto_explain er en PostgreSQL-udvidelse, der giver dig mulighed for at logge forespørgselsplanerne for forespørgsler, der er langsommere end en (konfigurerbar) tærskel. Dette er utrolig nyttigt til fejlretning af langsomme forespørgsler, især dem, der kun nogle gange er problematiske. Det er et af bidragsmodulerne, så det kan nemt installeres og konfigureres på almindelig PostgreSQL, og det er så nyttigt, at vi har det på som standard på ScaleGrid.

Kæmpe tak til Takahiro Itagaki, hovedforfatteren bag den første version af auto_explain (commit, tråd), Dean Rasheed, hvis første patch og forslag den var baseret på, og de mange bidragydere og anmeldere til det siden.

Hvilke auto_explain-parametre skal jeg bruge?

Nedenfor vil vi diskutere de vigtigste parametre, men se venligst nedenstående tabel eller den officielle dokumentation for at få flere oplysninger om det fulde udvalg af ting, du kan spore.

Den vigtigste parameter for auto_explain er log_min_duration . Som standard er dette indstillet til -1 , hvilket betyder, at der ikke bliver logget noget - så hvis vi vil have nogle logfiler, skal vi ændre det! Standardenheden er ms, så en indstilling på 100 vil logge forespørgselsplanerne for alle forespørgsler, der overstiger 100 ms. Dette er hvad vi valgte som standard i ScaleGrid, men det kan konfigureres under Admin -> Config. Hvis du af en eller anden grund ønsker at logge forespørgselsplanen for hver forespørgsel, kan du indstille denne til 0 – men pas på, dette kan have alvorlige præstationsimplikationer.

Da forespørgslerne allerede udføres på serveren, vil du sandsynligvis også aktivere auto_explain.log_analyze . Dette gør output svarende til at køre EXPLAIN ANALYZE . Som standard betyder det også, at timings pr. operation spores. Dette kommer med nogle ekstra omkostninger, som kan minimeres ved at slå auto_explain.log_timing fra (til som standard med log_analyze ). Naturligvis er timing pr. operation meget nyttig, når du fejler langsomme forespørgsler! Vores interne test viste acceptable overheads for dette, så det er slået til som standard i ScaleGrid, men som altid, prøv venligst din arbejdsbyrde for at se, om overhead er acceptabelt i dit tilfælde. Der er i øjeblikket begrænset offentligt tilgængelig information om dette emne, men et nyligt indlæg fra pgMustard-teamet viste, at overhead, i det mindste på en lille transaktionsmæssig arbejdsbyrde, kan være så lavt som 2%. Som de bemærkede, kunne dette reduceres med auto_explain.sample_rate parameter, på bekostning af kun at spore en delmængde af dine forespørgsler.

Den sidste parameter, vi vil diskutere lidt detaljeret, er auto_explain.log_format . Standardoutputtet er TEKST, hvilket sandsynligvis er det, du er mest bekendt med ved at bruge EXPLAIN .

Her er et simpelt eksempel på, hvordan auto_explain output i TEXT-format kan se ud:

2021-09-10 15:32:04.606 BST [22770] LOG:  duration: 3184.383 ms  plan:
	Query Text: select * from table1 order by column1;
	Sort  (cost=12875.92..13125.92 rows=100000 width=37) (actual time=2703.799..3055.401 rows=100000 loops=1)
	  Sort Key: column1
	  Sort Method: external merge  Disk: 4696kB
	  Buffers: shared hit=837, temp read=587 written=589
	  ->  Seq Scan on table  (cost=0.00..1834.01 rows=100000 width=37) (actual time=0.033..27.795 rows=100000 loops=1)
	        Buffers: shared hit=834

Du kan se her, at du får forespørgselsvarigheden i begyndelsen, som du måske er vant til at se i slutningen af ​​forespørgselsplaner. Du vil også se forespørgselsteksten, inklusive eventuelle parametre.

De populære visualiseringsværktøjer explain.depesz og explain.dalibo accepterer begge forespørgselsplaner i TEXT-format, men de understøtter også begge JSON-format. Hvis nogle af dit team foretrækker at bruge værktøjer som PEV og pgMustard, der kun understøtter JSON-formatet, vil du måske indstille det som formatet. For kunder på ScaleGrid valgte vi JSON-formatet, delvist fordi vi ønskede at parse det lettere for vores egen langsomme forespørgselsanalysefunktion.

Her er en komplet liste over auto_explain-parametrene og deres standardindstillinger:

Installation af auto_explain

På ScaleGrid er auto_explain slået til som standard med en tærskel på 100 ms. Du kan konfigurere dette under Admin -> Konfig.

På vanilla PostgreSQL kan du installere auto_explain ved blot at tilføje det til et af session_preload_libraries eller shared_preload_libraries . Førstnævnte har fordelene ved a) ikke at kræve genstart (men det vil kun blive indlæst i nye sessioner) og b) gør det muligt kun at aktivere det for nogle brugere (ved at indstille denne parameter med ALTER ROLE SET ).

session_preload_libraries = auto_explain
auto_explain.log_min_duration = 100
auto_explain.log_analyze = true
auto_explain.log_buffers = true
auto_explain.log_format = JSON

LOAD 'auto_explain';