EXPLAIN ANALYZE: jak číst plány dotazů v Postgresu

Před dotaz napiš EXPLAIN (ANALYZE, BUFFERS), spusť ho a výstup čti zdola nahoru. Hledáš tři věci: uzel, ve kterém se skutečně stráví většina času, uzel, jehož odhadovaný počet řádků se od skutečného liší o řád, a sekvenční sken velké tabulky, který vrátí hrstku řádků. Skoro každý pomalý dotaz na malé nebo střední databázi je jedna z těchto tří věcí a řešením je index, čerstvější statistiky, nebo přepsaná klauzule WHERE. Zbytek článku popisuje, jak poznat, na kterou se díváš.

Plán není záhadný dokument. Je to strom uzlů, z nichž každý bere řádky od svých potomků a předává je rodiči, a vedle sebe jsou vytištěný odhad plánovače a realita z provedení. Jakmile víš, co znamená šest nebo sedm typů uzlů a která čísla porovnávat, přečtení plánu zabere zhruba třicet sekund.

EXPLAIN, EXPLAIN ANALYZE a volby, které stojí za použití#

Samotný EXPLAIN ukáže plán, který plánovač zvolil, aniž by dotaz spustil. Je okamžitý a bezpečný a dá ti jen odhady. EXPLAIN ANALYZE dotaz skutečně provede a vedle předpovědi vypíše, co se opravdu stalo. Tento rozdíl je celý smysl, takže ANALYZE používej, pokud nemáš důvod ne.

Dvě varování, než to uděláš. EXPLAIN ANALYZE na UPDATE, DELETE nebo INSERT zápis provede. Pokud to nechceš, obal ho:

BEGIN;EXPLAIN (ANALYZE, BUFFERS)DELETE FROM sessions WHERE expires_at < now() - interval '30 days';ROLLBACK;

A ANALYZE přidává režii měření času. Na většině strojů jsou to pár procent; na systému s pomalým zdrojem hodin může naměřený čas krátkého dotazu zdvojnásobit. Pokud čísla vypadají nemožně, spusť to znovu s TIMING OFF, které zachová počty řádků a vypustí časy jednotlivých uzlů.

Volby, které si své místo zaslouží:

• BUFFERS - kolik bloků po 8 kB každý uzel přečetl ze sdílených bufferů (shared hit), z disku nebo cache operačního systému (shared read) a kolik zapsal (shared written). To je nejblíž fyzickému počtu I/O operací, jaký dostaneš, a na sdíleném stroji je mnohem stabilnější než čas na hodinách. Od PostgreSQL 18 je součástí ANALYZE ve výchozím stavu; na starších verzích o něj musíš požádat.
• VERBOSE - vypíše seznam výstupních sloupců a názvy s uvedeným schématem. Užitečné u plánů s několika joiny a opakovanými názvy sloupců.
• SETTINGS - vypíše každé nastavení plánovače, které není na výchozí hodnotě. Stojí za přidání jednou, když se plán na jednom serveru liší od téhož plánu na jiném.
• WAL - počet záznamů write-ahead logu a bajtů, které vznikly. Smysl má jen u příkazu, který zapisuje.
• FORMAT JSON - strojově čitelný výstup, který zpracovávají webové vizualizéry plánů.
• GENERIC_PLAN (PostgreSQL 16 a novější) - umožní ti dát EXPLAIN příkazu obsahujícímu zástupné symboly $1, aniž bys dodal hodnoty, takže zjistíš, co doopravdy posílá prepared statement nebo ORM.

EXPLAIN (ANALYZE, BUFFERS, VERBOSE, SETTINGS)SELECT ...;

Dotaz spusť dvakrát a čti druhý plán. První běh platí za načtení bloků z disku do cache a ladit proti studené cache většinou nechceš, pokud si právě na studenou cache nestěžuješ.

Jak číst strom#

Každý řádek začínající -> je uzel. Odsazení je vnoření: potomci uzlu jsou odsazeni pod ním a provádění teče od nejvnitřnějšího uzlu směrem ven. Čti od nejhlubšího odsazení nahoru a sleduješ řádky.

Řádek uzlu vypadá takto:

->  Index Scan using orders_pkey on orders  (cost=0.43..8.45 rows=1 width=36)                                            (actual time=0.021..0.023 rows=1 loops=1)

Šest čísel a každé znamená něco konkrétního:

• cost=0.43..8.45 - odhadovaná počáteční a celková cena v libovolných jednotkách, kde 1,0 zhruba odpovídá přečtení jedné sekvenční stránky. První číslo je to, co je potřeba, než se může vrátit první řádek, proto má řazení vysokou počáteční cenu a sken indexu téměř žádnou. Čísla mají smysl jen ve vzájemném srovnání.
• rows=1 - odhadovaný počet řádků, které tento uzel vyprodukuje, na jedno provedení.
• width=36 - odhadovaná průměrná šířka řádku v bajtech. Hodí se, když plán přesouvá mnohem víc dat, než jsi čekal.
• actual time=0.021..0.023 - skutečné milisekundy do prvního a do posledního řádku, průměrované přes smyčky.
• loops=1 - kolikrát uzel běžel. Toto číslo lidé zapomínají: na vnitřní straně nested loop jsou actual time a rows počítané na jednu smyčku. Uzel s actual time=0.4..0.5 rows=3 loops=9000 stál zhruba 4,5 sekundy a vyprodukoval 27 000 řádků, ne půl milisekundy a tři řádky.

Časy zahrnují potomky, takže vlastní cena uzlu je jeho skutečný čas minus čas všeho pod ním. Dva řádky dole, Planning Time a Execution Time, jsou oddělené: plánovací čas, který tvoří velkou část celku, obvykle znamená partitionovanou tabulku se stovkami partition nebo obrovský počet joinů.

Řádky navíc pod uzlem jsou místem, kde je detail. Filter s Rows Removed by Filter, Index Cond, Heap Fetches, Sort Method, Buckets a Buffers ti říkají něco, co úvodní čísla neprozradí.

Uzly, které skutečně uvidíš#

Sekvenční sken není automaticky špatný. Přečíst od začátku do konce číselník o 500 řádcích je levnější než jakýkoli index a plánovač to ví. Problémem se sekvenční sken stává, když je tabulka velká, filtr selektivní a Rows Removed by Filter je číslo se šesti ciframi.

Dva řádky se vyplatí naučit se poznat hned. Sort Method: external merge Disk: 48312kB znamená, že se řazení nevešlo do work_mem a šlo do dočasných souborů, což je obvykle největší jednotlivé vylepšení, které máš k dispozici: zvýšení work_mem pro danou relaci nebo dotaz z toho udělá Sort Method: quicksort Memory: 51000kB. A Buckets: 65536 Batches: 8 Memory Usage: 3841kB u hash joinu znamená, že se hashovací tabulka ze stejného důvodu rozdělila do osmi průchodů přes data. Ladění PostgreSQL pro malé servery popisuje, jaká by tato nastavení měla být na stroji s 1 až 8 GB, a proč je globální zvyšování work_mem způsob, jak dojít paměť.

Pomalý dotaz, opravený#

Tady je plán z tabulky s 2,4 milionu objednávek, který odpovídá na „posledních dvacet objednávek jednoho zákazníka“.

EXPLAIN (ANALYZE, BUFFERS)SELECT id, created_at, totalFROM ordersWHERE customer_id = 4821  AND created_at >= now() - interval '90 days'ORDER BY created_at DESCLIMIT 20;

Limit  (cost=48231.44..48231.49 rows=20 width=20)       (actual time=812.334..812.339 rows=20 loops=1)  Buffers: shared hit=1204 read=41988  ->  Sort  (cost=48231.44..48232.07 rows=252 width=20)            (actual time=812.332..812.334 rows=20 loops=1)        Sort Key: created_at DESC        Sort Method: top-N heapsort  Memory: 27kB        ->  Seq Scan on orders  (cost=0.00..48224.72 rows=252 width=20)                                (actual time=0.412..811.903 rows=238 loops=1)              Filter: ((customer_id = 4821) AND (created_at >= (now() - '90 days'::interval)))              Rows Removed by Filter: 2399762              Buffers: shared hit=1204 read=41988Planning Time: 0.214 msExecution Time: 812.381 ms

Všechno, co potřebuješ, tam je. Sken přečetl 43 192 bloků, asi 337 MB, aby vrátil 238 řádků a zahodil 2,4 milionu. Odhad 252 řádků byl blízko skutečným 238, takže statistiky jsou v pořádku. Prostě neexistuje index, který by odpovídal filtru.

CREATE INDEX CONCURRENTLY orders_customer_created_idx    ON orders (customer_id, created_at DESC);

Limit  (cost=0.43..38.72 rows=20 width=20) (actual time=0.041..0.088 rows=20 loops=1)  Buffers: shared hit=23  ->  Index Scan using orders_customer_created_idx on orders        (cost=0.43..482.90 rows=252 width=20) (actual time=0.039..0.084 rows=20 loops=1)        Index Cond: ((customer_id = 4821) AND (created_at >= (now() - '90 days'::interval)))        Buffers: shared hit=23Planning Time: 0.302 msExecution Time: 0.114 ms

Dvacet tři bloků místo čtyřiceti tří tisíc a uzel Sort úplně zmizel: protože index ukládá created_at sestupně v rámci každého customer_id, řádky přicházejí v pořadí, které dotaz žádal, a LIMIT skončí po dvaceti. Pořadí sloupců v tom indexu není libovolné a DESC také ne. Indexy v PostgreSQL vysvětlené popisuje, proč jdou sloupce s rovností první a rozsahové poslední.

Pět věcí, které dělají plán pomalým#

Špatný odhad řádků. Porovnej rows= s actual ... rows= u každého uzlu. Dvojnásobek je nic. Stonásobek znamená, že plánovač zvolil strategii na základě špatných informací, a uzel nad ním je pravděpodobně nested loop, který měl být hash join. Příčiny: tabulka nebyla analyzována od hromadného načtení, default_statistics_target 100 je pro nerovnoměrný sloupec příliš hrubý, nebo jsou dva sloupce korelované a plánovač násobí jejich selektivity, jako by byly nezávislé. Řešení, podle pracnosti:

ANALYZE orders;ALTER TABLE orders ALTER COLUMN status SET STATISTICS 1000;CREATE STATISTICS orders_city_region (dependencies, ndistinct)    ON city, region FROM orders;ANALYZE orders;

Chybějící nebo nepoužitelný index. Index existuje, ale dotaz ho nemůže použít: funkce na sloupci (WHERE lower(email) = ... potřebuje výrazový index na lower(email)), nesoulad typů, který vynutí přetypování, úvodní zástupný znak v LIKE, nebo OR přes dva sloupce, které nepokrývá žádný jediný index.

Řazení nebo hashování na disku. Popsáno výše. Hledej Disk: kdekoli v plánu.

Příliš mnoho smyček. Nested loop se 40 000 iteracemi skenu indexu za 0,2 ms je osm sekund, které žádný jednotlivý uzel nepřiznává. Než uvěříš, že je uzel levný, vynásob actual time hodnotou loops.

Práce, kterou dotaz nepotřebuje. SELECT všech sloupců, když jsou potřeba tři, ORDER BY bez LIMIT, DISTINCT kompenzující duplikující join, COUNT přes celou tabulku při každém načtení stránky. Nejlevnější dotaz je ten, který smažeš.

Mrtvé řádky jsou šestá příčina a dobře se skrývají: tabulka, která se nafoukla, protože autovacuum nestíhá, se čte jako mnohem větší tabulka, a Index Only Scan s tisíci Heap Fetches je stejný příběh z druhé strany. Vacuum a bloat v Postgresu je text ke čtení, když se dotaz zpomalil, aniž by data narostla.

Jak pomalé dotazy vůbec najít#

Čtení plánu předpokládá, že víš, který dotaz číst. Tři nástroje, podle rostoucí náročnosti nastavení:

1. pg_stat_activity pro to, co se děje právě teď. SELECT pid, now() - query_start AS runtime, state, left(query, 80) FROM pg_stat_activity WHERE state <> 'idle' ORDER BY runtime DESC; ukáže, co běží a jak dlouho. pg_cancel_backend(pid) jeden zastaví slušně, pg_terminate_backend(pid) hrubě.
2. log_min_duration_statement pro log. Nastav ho na 500 a každý příkaz trvající déle než půl sekundy se zapíše do logu serveru s dobou trvání a parametry. Nestojí nic, když nic není pomalé.
3. pg_stat_statements pro vzorec. Tohle je ten, který změní, jak pracuješ. Musí být uveden v shared_preload_libraries a vyžaduje restart, potom CREATE EXTENSION pg_stat_statements;.

SELECT calls,       round(total_exec_time::numeric, 1) AS total_ms,       round(mean_exec_time::numeric, 2)  AS mean_ms,       rows,       left(query, 70) AS queryFROM pg_stat_statementsORDER BY total_exec_time DESCLIMIT 15;

Řaď podle total_exec_time, ne podle mean_exec_time. Dotaz, který trvá 4 ms a běží dva miliony krát denně, tě stojí víc než noční report, který trvá devět sekund, a bývá snazší ho opravit. pg_stat_statements_reset() vynuluje počítadla, takže můžeš měřit konkrétní okno.

Čtvrtá možnost, auto_explain, loguje celý plán každého příkazu přes práh, což zachytí plán, který se pokazí jen ve tři ráno s určitými parametry. Načtení stojí u každého dotazu trochu výkonu, takže ho zapni, abys zachytil něco konkrétního, a zase vypni.

Všechny čtyři potřebují superuživatele nebo odpovídajícím způsobem oprávněnou roli a možnost upravit postgresql.conf a restartovat. Na RE:NODE ti řada PostgreSQL dá heslo superuživatele vygenerované pro daný server, správce souborů a SFTP pro konfigurační soubory a konzoli pro restart, takže shared_preload_libraries je nastavení, které můžeš opravdu změnit, a nemusíš kvůli němu psát na podporu. Průvodci panelem ukazují, kde se tyto přístupové údaje objevují.

Co plán neřekne#

Plán popisuje práci, kterou server na daném příkazu vykonal. Neříká nic o:

• Čekání na zámek. Dotaz zablokovaný za příkazem ALTER TABLE ukazuje naprosto zdravý plán a trvá devadesát sekund. Zkontroluj pg_locks spojené s pg_stat_activity nebo sloupec wait_event_type.
• Režii připojení. Otevření nového připojení k PostgreSQL vytvoří proces a stojí pár milisekund plus několik megabajtů. Aplikace, která otevírá jedno na každý požadavek, stráví víc času připojováním než dotazováním. To je práce pro pooler, ne pro plánovač - viz connection pooly a limity.
• Síťových round tripech. Dvě stě malých dotazů ve smyčce, každý rychlý, je problém N+1 a každý ORM je vyrábí omylem. Všechny plány vypadají dokonale.
• Času na straně klienta. Načtení 400 000 řádků do aplikace, která potřebovala počet, je pomalé na místě, které EXPLAIN nevidí.
• Zbytku stroje. Plán, který čte 40 000 bloků, je na nevytíženém serveru v pořádku a hrozný, když totéž dělá dalších šest připojení. Grafy paměti, CPU a disku v panelu jsou kontrola, že plán a stroj si odpovídají.

Ještě jedno upřímné omezení: EXPLAIN bez ANALYZE ukazuje, co plánovač zamýšlí s aktuálními statistikami a aktuálním nastavením, a prepared statementy mohou po pěti provedeních přepnout na obecný plán, takže to, co spouští tvůj ovladač, není vždy to, co jsi otestoval ručně. EXPLAIN (GENERIC_PLAN) v PostgreSQL 16 a novějším existuje právě kvůli této mezeře.

FAQ#

Proč Postgres ignoruje můj index?

Nejčastěji proto, že věří, že dotaz vrací velkou část tabulky, a v takovém případě je sekvenční sken skutečně levnější. Nejdřív porovnej odhad se skutečností. Pokud je odhad správný a přesto čekáš sken indexu, příčinou bývá random_page_cost, který má výchozí hodnotu 4 a počítá s rotujícími disky. Na NVMe 1.1 odpovídá hardwaru a posune plánovač napříč dotazy směrem ke skenům indexu.

Je Seq Scan vždycky špatný?

Ne. Na malé tabulce je to nejrychlejší možnost a plánovač ji zvolí záměrně. Špatný je, když je tabulka velká a filtr zahodí většinu toho, co se přečetlo, což ti řádek Rows Removed by Filter řekne přesně.

Jaký je rozdíl mezi cost a actual time?

Cost je odhad bez jednotek, který plánovač používá k porovnání kandidátních plánů, ukotvený tak, že přečtení jedné sekvenční stránky stojí 1,0. Actual time jsou milisekundy naměřené při provedení. Jedno na druhé převést nejde a neměl bys to zkoušet - užitečné je jen porovnání odhadovaného a skutečného počtu řádků.

Mám prostě přidat index na každý sloupec?

Ne. Každý index se musí aktualizovat při každém insertu, updatu a deletu indexovaných sloupců, zabírá místo na disku a přidává práci vacuum. Tři dobře zvolené složené indexy obvykle porazí patnáct jednosloupcových. V pg_stat_user_indexes hledej idx_scan = 0, abys našel indexy, které od posledního restartu nic nepoužilo.

Můj dotaz je v psql rychlý a z aplikace pomalý. Proč?

Nejčastěji aplikace nespouští stejný dotaz: jiné parametry, obecný plán, obalující transakce s jinou úrovní izolace, nebo ORM přidávající LIMIT a ORDER BY, které jsi nenapsal. Zapni log_min_duration_statement, zachyť přesný příkaz, který server přijal, a ten zanalyzuj.

Jak často mám spouštět ANALYZE ručně?

Běžný případ zvládá autovacuum. Spusť ho ručně po hromadném načtení, po obnově ze zálohy a po migraci, která mění rozložení hodnot ve sloupci, protože dokud neproběhne, plánovač pracuje se statistikami popisujícími tabulku, která už neexistuje. Dump statistiky nenese, a proto je čerstvě obnovená databáze často záhadně pomalá - zbytek příběhu je v článku pg_dump a pg_restore.