Introduktion till auto_explain:Hur man loggar långsamma Postgres-frågeplaner automatiskt

Vill du veta varför en PostgreSQL-fråga är långsam? Då är EXPLAIN ANALYZE en bra utgångspunkt. Men frågeplaner kan bero på annan serveraktivitet, kan ta ett tag att köra och kan ändras över tiden, så om du vill se de faktiska exekveringsplanerna för dina långsammaste frågor är auto_explain verktyget du behöver. I det här inlägget kommer vi att undersöka vad det gör, hur man konfigurerar det och hur man använder dessa loggar för att snabba upp dina frågor.

Vad är auto_explain?

auto_explain är ett PostgreSQL-tillägg som låter dig logga frågeplanerna för frågor som är långsammare än en (konfigurerbar) tröskel. Detta är otroligt användbart för att felsöka långsamma frågor, särskilt de som bara ibland är problematiska. Det är en av bidragsmodulerna, så den kan installeras och konfigureras enkelt på vanlig PostgreSQL, och är så användbar att vi har den på som standard på ScaleGrid.

Enormt tack till Takahiro Itagaki, huvudförfattaren bakom den första versionen av auto_explain (commit, tråd), Dean Rasheed, vars första patch och förslag den baserades på, och de många bidragsgivare och recensenter sedan dess.

Vilka auto_explain-parametrar ska jag använda?

Nedan kommer vi att diskutera de viktigaste parametrarna, men vänligen gå igenom tabellen nedan eller den officiella dokumentationen för mer information om hela utbudet av saker du kan spåra.

Den viktigaste parametern för auto_explain är log_min_duration . Som standard är detta inställt på -1 , vilket betyder att ingenting kommer att loggas – så om vi vill ha några loggar måste vi ändra det! Standardenheten är ms, så en inställning på 100 kommer att logga frågeplanerna för alla frågor som överstiger 100 ms. Detta är vad vi valde som standard i ScaleGrid, men det kan konfigureras under Admin -> Config. Om du av någon anledning vill logga frågeplanen för varje fråga kan du ställa in den på 0 – men se upp, detta kan få allvarliga prestandakonsekvenser.

Eftersom frågorna redan körs på servern vill du förmodligen också aktivera auto_explain.log_analyze . Detta gör utdata likvärdiga med att köra EXPLAIN ANALYZE . Som standard betyder det också att timings per operation spåras. Detta kommer med några extra kostnader, som kan minimeras genom att stänga av auto_explain.log_timing (på som standard med log_analyze ). Naturligtvis är timings per operation mycket användbara när du felsöker långsamma frågor! Våra interna tester visade acceptabla omkostnader för detta, så det är på som standard i ScaleGrid, men som alltid vänligen testa din arbetsbelastning för att se om overheaden är acceptabel i ditt fall. Det finns för närvarande begränsad allmänt tillgänglig information om detta ämne, men ett nyligen inlägg av pgMustard-teamet visade att, åtminstone på en liten transaktionsarbetsbelastning, kan omkostnaderna vara så låga som 2%. Som de noterade kunde detta minskas med auto_explain.sample_rate parameter, till priset av att endast spåra en delmängd av dina frågor.

Den sista parametern som vi kommer att diskutera lite i detalj är auto_explain.log_format . Standardutgången är TEXT, vilket troligen är det du är mest bekant med genom att använda EXPLAIN .

Här är ett enkelt exempel på hur auto_explain-utdata i TEXT-format kan se ut:

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 här att du får frågelängden i början, vilket du kanske är van vid att se i slutet av frågeplanerna vanligtvis. Du kommer också att se frågetexten, inklusive eventuella parametrar.

De populära visualiseringsverktygen explain.depesz och explain.dalibo accepterar båda frågeplaner i TEXT-format, men båda stöder även JSON-format. Om några i ditt team föredrar att använda verktyg som PEV och pgMustard, som bara stöder JSON-formatet, kanske du vill ställa in det som formatet. För kunder på ScaleGrid valde vi JSON-formatet, delvis eftersom vi ville analysera det lättare för vår egen funktion för långsam frågeanalys.

Här är en fullständig lista över parametrarna för auto_explain och deras standardinställningar:

Installerar auto_explain

På ScaleGrid är auto_explain på som standard, med ett tröskelvärde på 100 ms. Du kan konfigurera detta under Admin -> Konfig.

På vanilla PostgreSQL kan du installera auto_explain genom att helt enkelt lägga till det i ett av session_preload_libraries eller shared_preload_libraries . Det förstnämnda har fördelarna av att a) inte kräver omstart (men det kommer bara att laddas i nya sessioner) och b) gör det möjligt att aktivera det endast för vissa användare (genom att ställa in denna 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';